1817870 – /usr/bin/nsupdate -g segfault when connect to AD

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1817870 - /usr/bin/nsupdate -g segfault when connect to AD

Summary: /usr/bin/nsupdate -g segfault when connect to AD

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 8
Classification:	Red Hat
Component:	bind
Sub Component:
Version:	8.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	unspecified
Target Milestone:	rc
Target Release:	8.0
Assignee:	Petr Menšík
QA Contact:	Petr Sklenar
Docs Contact:
URL:
Whiteboard:
Depends On:	1818785
Blocks:	1771008 1817044 1825061
TreeView+	depends on / blocked

Reported:	2020-03-27 07:21 UTC by Petr Sklenar
Modified:	2023-10-06 19:31 UTC (History)
CC List:	3 users (show)
Fixed In Version:	bind-9.11.20-1.el8
Doc Type:	No Doc Update
Doc Text:
Clone Of:
Environment:
Last Closed:	2020-11-04 01:50:44 UTC
Type:	---
Target Upstream Version:
Embargoed:
Dependent Products:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Internet Systems Consortium (ISC)	isc-projects bind9 merge_requests 3316	0	None	None	None	2020-06-17 06:44:17 UTC
Red Hat Product Errata	RHSA-2020:4500	0	None	None	None	2020-11-04 01:51:12 UTC

Comment 4 Petr Menšík 2020-03-27 19:42:24 UTC

Interesting bug. According to backtrace SOA query arrived too late, when nsupdate already given up and is waiting for destruction. Then reply arrives, but static variable kserver is already cleaned up, when it is used in handler. Could it be because getting ticket took so long?

:[Current thread is 1 (Thread 0x3ff8987d910 (LWP 26816))]
:
:Thread 1 (Thread 0x3ff8987d910 (LWP 26816)):
:#0  isc_sockaddr_pf (sockaddr=0x0) at ../../../lib/isc/sockaddr.c:343
:No locals.
:#1  0x000002aa16b8bca8 in send_gssrequest (destaddr=0x0, msg=0x3ff8bdc5568, request=0x3ff8987bcf8, context=0x3ff841fe460) at ../../../bin/nsupdate/nsupdate.c:2991
:        result = <optimized out>
:        reqinfo = 0x3ff8bdb1058
:        options = 1
:        srcaddr = <optimized out>
:#2  0x000002aa16b8c10e in start_gssrequest (master=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:2961
:        context = 0x3ff841fe460
:        buf = {magic = 1114990113, base = 0x3ff8987c370, length = 35, used = 35, current = 35, active = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0, autore = false}
:        result = <optimized out>
:        val = 1447227121
:        rmsg = 0x3ff8bdc5568
:        request = 0x0
:        servname = 0x3ff8987bd60
:        fname = {name = {magic = 1145983854, ndata = 0x3ff8987be70 "\vDNS/sec-ad1\002ad\006baseos\005qe@AD\006BASEOS\002QE", length = 39, labels = 7, attributes = 1, offsets = 0x3ff8987bdb0 "", buffer = 0x3ff8987be30, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, offsets = "\000\f\017\026\034#&x\000\000\003\377\211\207\275@\000\000\003\377\211\207\275\030", '\000' <repeats 26 times>, "\003\377\213\332_@\000\000\003\377\212\306\023\350\000\000\003\377\212\301\340@\000\000\003\377\211\207\275\200", '\000' <repeats 47 times>, "\001", buffer = {magic = 1114990113, base = 0x3ff8987be70, length = 255, used = 39, current = 0, active = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0, autore = false}, data = "\vDNS/sec-ad1\002ad\006baseos\005qe@AD\006BASEOS\002QE\000\275\000\000\000\000\000\020", '\000' <repeats 12 times>, "\003\377\211\207\256(\000\000\000\000\000\000\020\000\000\000\003\377\211\207\276\234\000\000\000\f\000\000\000\000\000\000\003\377\211\207\276\250\000\000\000\000\000\000\000\001", '\000' <repeats 31 times>, "\024\000\371_X\017\311\\w\000\000\000\000\000\000\000\065\000\000\003\377\211\207\305x\000\000\003\377\211\207\300\210\000\000\000\000\000\200\020\000\000\000\003\377\211\207\305p\000\000\003\377\307\017\322\030\000\000\000\000\000\000\000\000\000\000"...}
:        namestr = "sec-ad1.ad.baseos.qe\000\207\305x", '\000' <repeats 15 times>, "\001\000\000\003\377\211\207\277@\000\000\003\377\213\332_@\000\000\003\377\211\207\305p\000\000\003\377\212\276O\006\000\000\003\377\211\207\277@", '\000' <repeats 34 times>, "\003\377\211\207\300\210", '\000' <repeats 50 times>, "\001\001\000\000\000\001\000\000\003\377\204\037\270\340\000\000\003\377\204\037\250\230\000\000\000\000\000\000\000\005"...
:        mykeystr = "1447227121.sig-sec-ad1.ad.baseos.qe\000\213\251\362Z\000\000\003\377\211\207\303 \000\000\003\377\213\335o\230\000\000\003\377\211\207\305\230\000\000\003\377\213z\324\340\000\000\003\377\213\302\367\220\000\000\003\377\213z\325\b\000\000\003\377\204\037\035`\000\000\003\377\213\332_@\000\000\003\377\213~\177\300\000\000\003\377\213z\325h\000\000\003\377\211\207\303p\000\000\000\000\000\000\002\000\000\000\003\377\000\000\000\000\000\371_X\017\311\\w\000\000\003\377\213\334S\240\000\000\003\377\213\332_@\000\000\003\377\211\207\304`\000\371_X\017\311\\w\000\000\003\377\211\207\303\260\000\000\003\377\213\335\\@"...
:        err_message = 0x0
:#3  0x000002aa16b8d04a in recvsoa (task=<optimized out>, event=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:2743
:        reqev = 0x0
:        request = 0x3ff8bdd1010
:        result = <optimized out>
:        eresult = <optimized out>
:        rcvmsg = 0x3ff8bdc53a0
:        section = <optimized out>
:        name = 0x3ff8bdd5ce0
:        soaset = 0x3ff8bdd8970
:        soa = {common = {rdclass = 1, rdtype = 6, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}, mctx = 0x0, origin = {magic = 1145983854, ndata = 0x3ff8bdb8636 "\asec-ad1\002ad\006baseos\002qe", length = 22, labels = 5, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, contact = {magic = 1145983854, ndata = 0x3ff8bdb864c "\nhostmaster\002ad\006baseos\002qe", length = 25, labels = 5, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, serial = 4243, refresh = 900, retry = 600, expire = 86400, minimum = 3600}
:        soarr = {data = 0x3ff8bdb8636 "\asec-ad1\002ad\006baseos\002qe", length = 67, rdclass = 1, type = 6, flags = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
:        pass = <optimized out>
:        master = {magic = 1145983854, ndata = 0x3ff8bdb8636 "\asec-ad1\002ad\006baseos\002qe", length = 22, labels = 5, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}
:        reqinfo = 0x0
:        soaquery = 0x3ff8bdc51d8
:        addr = <optimized out>
:        srcaddr = <optimized out>
:        tname = {magic = 1114990113, ndata = 0x3ff8987ca28 "sec-ad1.ad.baseos.qe", length = 1024, labels = 20, attributes = 0, offsets = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, buffer = 0xffffffffffffffff, link = {prev = 0x0, next = 0x3ff8b804168 <isc_categories+16>}, list = {head = 0x3ff841e1d50, tail = 0x3ff8bdd4170}}
:        nlabels = <optimized out>
:#4  0x000003ff8b7c2464 in dispatch (manager=0x3ff8bdbd010) at ../../../lib/isc/task.c:1143
:        dispatch_count = 1
:        done = false
:        finished = false
:        requeue = false
:        event = 0x3ff8bdd0c40
:        task = 0x3ff8bdbe010
:        task = <optimized out>
:        dispatch_count = <optimized out>
:        done = <optimized out>
:        requeue = <optimized out>
:        finished = <optimized out>
:        event = <optimized out>
:        was_idle = <optimized out>
:#5  run (uap=0x3ff8bdbd010) at ../../../lib/isc/task.c:1315
:        manager = 0x3ff8bdbd010
:#6  0x000003ff8b1080fe in start_thread (arg=0x3ff8987d910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff8987d910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396058925328, 4397232812071, 4396058923248, 4397232812070, 4397232812336, 4396058925328, 4396097888064, 4397232812336, 70189143759117505, 70189143783543455}, __fpregs = {4396091711944, 4397091246624, 4396097982480, 4397091246616, 4396058925328, 0, 8392704, 4397091251320}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#7  0x000003ff8abfb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.
:
:Thread 2 (Thread 0x3ff8bdf0c50 (LWP 26813)):
:#0  0x000003ff8b1094bc in __GI___pthread_timedjoin_ex (threadid=4396058925328, thread_return=thread_return@entry=0x0, abstime=abstime@entry=0x0, block=block@entry=true) at pthread_join_common.c:89
:        __tid = <optimized out>
:        _buffer = {__routine = 0x3ff8b109320 <cleanup>, __arg = 0x3ff8987dd30, __canceltype = 0, __prev = 0x0}
:        oldtype = <optimized out>
:        pd = 0x3ff8987d910
:        self = <optimized out>
:        result = 0
:#1  0x000003ff8b1092ee in __pthread_join (threadid=<optimized out>, thread_return=thread_return@entry=0x0) at pthread_join.c:24
:No locals.
:#2  0x000003ff8b7c3f3e in isc__taskmgr_destroy (managerp=0x2aa16b92c40 <taskmgr>) at ../../../lib/isc/task.c:1585
:        manager = 0x3ff8bdbd010
:        task = <optimized out>
:        i = 0
:#3  0x000003ff8b7c55da in isc_taskmgr_destroy (managerp=0x2aa16b92c40 <taskmgr>) at ../../../lib/isc/task.c:2109
:No locals.
:#4  0x000002aa16b85e22 in cleanup () at ../../../bin/nsupdate/nsupdate.c:3286
:No locals.
:#5  main (argc=<optimized out>, argv=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:3361
:        result = <optimized out>
:
:Thread 3 (Thread 0x3ff8a07e910 (LWP 26815)):
:#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x3ff8bdbb0a0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
:        gpr3 = 128
:        gpr5 = 0
:        _ret = -512
:        gpr2 = 18446744073709551104
:        gpr4 = 0
:        __ret = <optimized out>
:        oldtype = 0
:        err = <optimized out>
:        oldtype = <optimized out>
:        err = <optimized out>
:        __ret = <optimized out>
:        gpr2 = <optimized out>
:        gpr3 = <optimized out>
:        gpr4 = <optimized out>
:        gpr5 = <optimized out>
:        _ret = <optimized out>
:#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x3ff8bdbb028, cond=0x3ff8bdbb078) at pthread_cond_wait.c:502
:        spin = 0
:        buffer = {__routine = 0x3ff8b10dd30 <__condvar_cleanup_waiting>, __arg = 0x3ff8a07ddb8, __canceltype = 0, __prev = 0x0}
:        cbuffer = {wseq = 4, cond = 0x3ff8bdbb078, mutex = 0x3ff8bdbb028, private = 0}
:        rt = <optimized out>
:        err = <optimized out>
:        g = 0
:        flags = <optimized out>
:        g1_start = <optimized out>
:        signals = <optimized out>
:        result = 0
:        wseq = 4
:        seq = 2
:        private = 0
:        maxspin = <optimized out>
:        err = <optimized out>
:        result = <optimized out>
:        wseq = <optimized out>
:        g = <optimized out>
:        seq = <optimized out>
:        flags = <optimized out>
:        private = <optimized out>
:        signals = <optimized out>
:        g1_start = <optimized out>
:        spin = <optimized out>
:        buffer = <optimized out>
:        cbuffer = <optimized out>
:        rt = <optimized out>
:        s = <optimized out>
:#2  __pthread_cond_wait (cond=cond@entry=0x3ff8bdbb078, mutex=mutex@entry=0x3ff8bdbb028) at pthread_cond_wait.c:655
:No locals.
:#3  0x000003ff8b7c8ae4 in run (uap=0x3ff8bdbb010) at ../../../lib/isc/timer.c:812
:        manager = 0x3ff8bdbb010
:        now = {seconds = 1585326042, nanoseconds = 212359000}
:        result = <optimized out>
:#4  0x000003ff8b1080fe in start_thread (arg=0x3ff8a07e910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff8a07e910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396067318032, 4397232812135, 4396067315952, 4397232812134, 4397232812400, 4396067318032, 4396097888064, 4397232812400, 70189143759117505, 70189143775150751}, __fpregs = {4396091738120, 4397091246624, 4396097974288, 4397091246616, 4396067318032, 0, 8392704, 4397091251320}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#5  0x000003ff8abfb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.
:
:Thread 4 (Thread 0x3ff8a87f910 (LWP 26814)):
:#0  0x000003ff8abfb84a in epoll_wait (epfd=<optimized out>, events=events@entry=0x2aa55270bb0, maxevents=maxevents@entry=2048, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
:No locals.
:#1  0x000003ff8b7d7468 in watcher (uap=0x3ff8bdba010) at ../../../../lib/isc/unix/socket.c:4302
:        manager = 0x3ff8bdba010
:        done = false
:        cc = <optimized out>
:        fnname = 0x3ff8b7efc58 "epoll_wait()"
:        strbuf = '\000' <repeats 127 times>
:#2  0x000003ff8b1080fe in start_thread (arg=0x3ff8a87f910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff8a87f910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396075710736, 4397232811983, 4396075708656, 4397232811982, 4397232812248, 4396075710736, 4396097888064, 4397232812248, 70189143759117505, 70189143766774431}, __fpregs = {4396091798512, 4397091246624, 4396097970192, 4397091246616, 4396075710736, 0, 8392704, 4397091251320}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#3  0x000003ff8abfb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.

Comment 8 Petr Menšík 2020-03-27 20:37:28 UTC

It seems there is multiple issues detected, it is crashing on different places. Not sure my change would solve all of them, but it might.

# nsupdate.report1
:[Current thread is 1 (Thread 0x3ff97f7d910 (LWP 43758))]
:
:Thread 1 (Thread 0x3ff97f7d910 (LWP 43758)):
:#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
:        set = {__val = {20611, 4396169539232, 4396322253992, 4396321982208, 4396321042408, 4396301137712, 4396321997336, 4396321867046, 4396301137736, 0, 64768, 16786504, 1, 142541374619648, 0, 0}}
:        pid = <optimized out>
:        tid = <optimized out>
:        ret = <optimized out>
:#1  0x000003ff99222fd8 in __GI_abort () at abort.c:79
:        save_stage = 1
:        act = {__sigaction_handler = {sa_handler = 0x1, sa_sigaction = 0x1}, __glibc_reserved0 = 1023, sa_flags = -1745372416, sa_restorer = 0x286, sa_mask = {__val = {4396340237672, 4396301139232, 4396340237776, 2006, 0, 4396340237888, 2929877082864, 2929877082816, 4396334203024, 4396340109120, 2929198705756, 4396333879130, 4396301138344, 4396301140848, 61830786903438858, 4396301142120}}}
:        sigs = {__val = {32, 0 <repeats 15 times>}}
:#2  0x000003ff99e9b872 in isc_assertion_failed (file=file@entry=0x3ff9a2d231c "../../../lib/dns/name.c", line=line@entry=2284, type=type@entry=isc_assertiontype_require, cond=cond@entry=0x3ff9a2c68b6 "(__builtin_expect(((name) != ((void *)0)), 1) && __builtin_expect((((const isc__magic_t *)(name))->magic == ((('D') << 24 | ('N') << 16 | ('S') << 8 | ('n')))), 1))") at ../../../lib/isc/assertions.c:52
:No locals.
:#3  0x000003ff9a1a177e in dns_name_free (name=<optimized out>, mctx=<optimized out>) at ../../../lib/dns/name.c:2291
:        size = <optimized out>
:#4  0x000002aa01d86f08 in failed_gssrequest () at ../../../bin/nsupdate/nsupdate.c:2862
:No locals.
:#5  0x000002aa01d8c352 in start_gssrequest (master=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:2969
:        context = 0x0
:        buf = {magic = 1114990113, base = 0x3ff97f7c370, length = 37, used = 37, current = 37, active = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0, autore = false}
:        result = <optimized out>
:        val = 595102640
:        rmsg = 0x0
:        request = 0x0
:        servname = 0x3ff97f7bd60
:        fname = {name = {magic = 1145983854, ndata = 0x3ff97f7be70 "\aDNS/ns1\003eng\004rdu2\006redhat\006com@AD\006BASEOS\002QE", length = 42, labels = 8, attributes = 1, offsets = 0x3ff97f7bdb0 "", buffer = 0x3ff97f7be30, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, offsets = "\000\b\f\021\030\037&)\000\000\003\377\227\367\275@", '\000' <repeats 23 times>, "\024\000\000\003\377\220 =\230\000\000\003\377\232J_@\000\000\003\377\227\367\300H\000\000\003\377\231.+\270\000\000\000\000\000\000\000\020\000\000\000\000\000\000\000\002\000\000\000\000\000\000\000\b\000\000\003\377\227\367\275\310\000\000\003\377\232J_@\000\000\003\377\231\065b\300\000\000\003\377\231$\006\240", buffer = {magic = 1114990113, base = 0x3ff97f7be70, length = 255, used = 42, current = 0, active = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, mctx = 0x0, autore = false}, data = "\aDNS/ns1\003eng\004rdu2\006redhat\006com@AD\006BASEOS\002QE\000\003\377\231.+\270\000\000\003\377\227\367\300H\000\000\003\377\227\367\276X\000\333\252\305\351\217\366\n\000\000\000\000\000\000\000\000\000\000\003\377\227\367\305x\000\000\003\377\227\367\300\210\000\000\003\377\231:\033T\000\000\003\377\232J_@\000\000\003\377\000\000\000\002\000\000\003\377\231\200\373\326\000\000\003\377\227\367\276x\000\333\252\305\351\217\366\n\000\000\003\377\227\367\300H\000\000\000\000\000\000\000\002\000\000\003\377\000\000\000\f\000\000\003\377\227\367\277\330\000\000\003\377\220 ^`\000\000\003\377\227\367\277@\000\000\003\377\232J_@"...}
:        namestr = "ns1.eng.rdu2.redhat.com", '\000' <repeats 16 times>, "\001\000\000\003\377\020\001\000\025\000\000\000\002\377\377\377\377\000\000\003\377\220 ^`\000\n\235\347\000\000\000\000& \000R\000\000\020@\000\336\275\377\376\276\357|\000\000\000\000\034\001\000@\000\000\000\002\377\377\377\377\000\000\000\000\000\000\000\001", '\000' <repeats 11 times>, "\002\000\000\000\000\000\000\003\377\227\367\300\220\000\000\000\000\000\000\000\002\000\000\003\377\227\367\277x\000\000\000\001\000\000\000\000\000\000\003\377\227\367\277\330\000\000\001\001\000\000\000\002\000\000\003\377\220 ^`\000\000\003\377\220 =\230\000\000\000\000\000\000\000\005"...
:        mykeystr = "595102640.sig-ns1.eng.rdu2.redhat.com\000\362Z\000\000\003\377\227\367\303 \000\000\003\377\232Mo\300\000\000\003\377\227\367\305\230\000\000\003\377\231\360O\330\000\000\000\000\000\000\377\377\000\b\017\023\024\030\305\b\000\000\000\000\000\000\000Z\000\000\003\377\232J_@\000\333\252\305\351\217\366\n\000\000\003\377\227\367\306\260\000\000\003\377\232L\320\220\000\000\000\000\000\000\002\000\000\000\003\377\000\000\000\000\000\333\252\305\351\217\366\n\000\000\003\377\232LQ\330\000\000\003\377\232J_@\000\000\003\377\227\367\304`\000\333\252\305\351\217\366\n\000\000\003\377\227\367\303\260\000\000\003\377\232L\350\200"...
:        err_message = 0x0
:#6  0x000002aa01d8d04a in recvsoa (task=<optimized out>, event=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:2743
:        reqev = 0x0
:        request = 0x3ff9a4d1010
:        result = <optimized out>
:        eresult = <optimized out>
:        rcvmsg = 0x3ff9a4c51d8
:        section = <optimized out>
:        name = 0x3ff9a4ce8d0
:        soaset = 0x3ff9a4d0b50
:        soa = {common = {rdclass = 1, rdtype = 6, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}, mctx = 0x0, origin = {magic = 1145983854, ndata = 0x3ff9a4b8684 "\003ns1\003eng\004rdu2\006redhat\003com", length = 25, labels = 6, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, contact = {magic = 1145983854, ndata = 0x3ff9a4b869d "\aeng-ops\006redhat\003com", length = 20, labels = 4, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}, serial = 2019111400, refresh = 600, retry = 1800, expire = 604800, minimum = 300}
:        soarr = {data = 0x3ff9a4b8684 "\003ns1\003eng\004rdu2\006redhat\003com", length = 65, rdclass = 1, type = 6, flags = 0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}}
:        pass = <optimized out>
:        master = {magic = 1145983854, ndata = 0x3ff9a4b8684 "\003ns1\003eng\004rdu2\006redhat\003com", length = 25, labels = 6, attributes = 1, offsets = 0x0, buffer = 0x0, link = {prev = 0xffffffffffffffff, next = 0xffffffffffffffff}, list = {head = 0x0, tail = 0x0}}
:        reqinfo = 0x0
:        soaquery = 0x3ff9a4c53a0
:        addr = <optimized out>
:        srcaddr = <optimized out>
:        tname = {magic = 1114990113, ndata = 0x3ff97f7ca28 "ns1.eng.rdu2.redhat.com", length = 1024, labels = 23, attributes = 0, offsets = 0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, buffer = 0xffffffffffffffff, link = {prev = 0x0, next = 0x3ff99f04168 <isc_categories+16>}, list = {head = 0x3ff901d1d40, tail = 0x2aa01d9201c <interactive>}}
:        nlabels = <optimized out>
:#7  0x000003ff99ec2464 in dispatch (manager=0x3ff9a4bd010) at ../../../lib/isc/task.c:1143
:        dispatch_count = 1
:        done = false
:        finished = false
:        requeue = false
:        event = 0x3ff9a4cbe20
:        task = 0x3ff9a4be010
:        task = <optimized out>
:        dispatch_count = <optimized out>
:        done = <optimized out>
:        requeue = <optimized out>
:        finished = <optimized out>
:        event = <optimized out>
:        was_idle = <optimized out>
:#8  run (uap=0x3ff9a4bd010) at ../../../lib/isc/task.c:1315
:        manager = 0x3ff9a4bd010
:#9  0x000003ff998080fe in start_thread (arg=0x3ff97f7d910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff97f7d910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396301146384, 4397834168791, 4396301144304, 4397834168790, 4397834169056, 4396301146384, 4396340109120, 4397834169056, 61829088352892604, 61829088594639074}, __fpregs = {4396333933000, 0, 4396340203536, 2929363452784, 4396301146384, 2929363510080, 8392704, 4294967295}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#10 0x000003ff992fb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.
:
:Thread 2 (Thread 0x3ff98f7f910 (LWP 43756)):
:#0  0x000003ff992fb84a in epoll_wait (epfd=<optimized out>, events=events@entry=0x2aa2a50bbb0, maxevents=maxevents@entry=2048, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
:No locals.
:#1  0x000003ff99ed7468 in watcher (uap=0x3ff9a4ba010) at ../../../../lib/isc/unix/socket.c:4302
:        manager = 0x3ff9a4ba010
:        done = false
:        cc = <optimized out>
:        fnname = 0x3ff99eefc58 "epoll_wait()"
:        strbuf = '\000' <repeats 127 times>
:#2  0x000003ff998080fe in start_thread (arg=0x3ff98f7f910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff98f7f910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396317931792, 4397834168703, 4396317929712, 4397834168702, 4397834168968, 4396317931792, 4396340109120, 4397834168968, 61829088352892604, 61829088376527074}, __fpregs = {4396334019568, 0, 4396340191248, 2929363452784, 4396317931792, 2929363510080, 8392704, 4294967295}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#3  0x000003ff992fb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.
:
:Thread 3 (Thread 0x3ff9877e910 (LWP 43757)):
:#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x3ff9a4bb0a0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
:        gpr3 = 128
:        gpr5 = 0
:        _ret = -512
:        gpr2 = 18446744073709551104
:        gpr4 = 0
:        __ret = <optimized out>
:        oldtype = 0
:        err = <optimized out>
:        oldtype = <optimized out>
:        err = <optimized out>
:        __ret = <optimized out>
:        gpr2 = <optimized out>
:        gpr3 = <optimized out>
:        gpr4 = <optimized out>
:        gpr5 = <optimized out>
:        _ret = <optimized out>
:#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x3ff9a4bb028, cond=0x3ff9a4bb078) at pthread_cond_wait.c:502
:        spin = 0
:        buffer = {__routine = 0x3ff9980dd30 <__condvar_cleanup_waiting>, __arg = 0x3ff9877ddb8, __canceltype = 0, __prev = 0x0}
:        cbuffer = {wseq = 8, cond = 0x3ff9a4bb078, mutex = 0x3ff9a4bb028, private = 0}
:        rt = <optimized out>
:        err = <optimized out>
:        g = 0
:        flags = <optimized out>
:        g1_start = <optimized out>
:        signals = <optimized out>
:        result = 0
:        wseq = 8
:        seq = 4
:        private = 0
:        maxspin = <optimized out>
:        err = <optimized out>
:        result = <optimized out>
:        wseq = <optimized out>
:        g = <optimized out>
:        seq = <optimized out>
:        flags = <optimized out>
:        private = <optimized out>
:        signals = <optimized out>
:        g1_start = <optimized out>
:        spin = <optimized out>
:        buffer = <optimized out>
:        cbuffer = <optimized out>
:        rt = <optimized out>
:        s = <optimized out>
:#2  __pthread_cond_wait (cond=cond@entry=0x3ff9a4bb078, mutex=mutex@entry=0x3ff9a4bb028) at pthread_cond_wait.c:655
:No locals.
:#3  0x000003ff99ec8ae4 in run (uap=0x3ff9a4bb010) at ../../../lib/isc/timer.c:812
:        manager = 0x3ff9a4bb010
:        now = {seconds = 1585326713, nanoseconds = 829220000}
:        result = <optimized out>
:#4  0x000003ff998080fe in start_thread (arg=0x3ff9877e910) at pthread_create.c:486
:        ret = <optimized out>
:        start = <optimized out>
:        pd = 0x3ff9877e910
:        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {{__gregs = {4396309539088, 4397834168855, 4396309537008, 4397834168854, 4397834169120, 4396309539088, 4396340109120, 4397834169120, 61829088352892604, 61829088384919778}, __fpregs = {4396333959176, 0, 4396340195344, 2929363452784, 4396309539088, 2929363510080, 8392704, 4294967295}}}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
:        not_first_call = <optimized out>
:#5  0x000003ff992fb49e in thread_start () at ../sysdeps/unix/sysv/linux/s390/s390-64/clone.S:65
:No locals.
:
:Thread 4 (Thread 0x3ff9a4f0c50 (LWP 43755)):
:#0  0x000003ff998094bc in __GI___pthread_timedjoin_ex (threadid=4396301146384, thread_return=thread_return@entry=0x0, abstime=abstime@entry=0x0, block=block@entry=true) at pthread_join_common.c:89
:        __tid = <optimized out>
:        _buffer = {__routine = 0x3ff99809320 <cleanup>, __arg = 0x3ff97f7dd30, __canceltype = 0, __prev = 0x0}
:        oldtype = <optimized out>
:        pd = 0x3ff97f7d910
:        self = <optimized out>
:        result = 0
:#1  0x000003ff998092ee in __pthread_join (threadid=<optimized out>, thread_return=thread_return@entry=0x0) at pthread_join.c:24
:No locals.
:#2  0x000003ff99ec3f3e in isc__taskmgr_destroy (managerp=0x2aa01d92c40 <taskmgr>) at ../../../lib/isc/task.c:1585
:        manager = 0x3ff9a4bd010
:        task = <optimized out>
:        i = 0
:#3  0x000003ff99ec55da in isc_taskmgr_destroy (managerp=0x2aa01d92c40 <taskmgr>) at ../../../lib/isc/task.c:2109
:No locals.
:#4  0x000002aa01d85e22 in cleanup () at ../../../bin/nsupdate/nsupdate.c:3286
:No locals.
:#5  main (argc=<optimized out>, argv=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:3361
:        result = <optimized out>


#
# nsupdate.report2
:[New LWP 77757]
:[Thread debugging using libthread_db enabled]
:Using host libthread_db library "/lib64/libthread_db.so.1".
:Core was generated by `/usr/bin/nsupdate -g'.
:Program terminated with signal SIGABRT, Aborted.
:#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
:50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
:
:Thread 1 (Thread 0x3ffa8170c50 (LWP 77757)):
:#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
:        set = {__val = {20611, 4396553468248, 4397924868968, 7, 2929766663694, 2929766668296, 0, 0, 2, 0, 4397924874352, 2929363245056, 2929766662848, 2929363343664, 4397924875048, 4294967295}}
:        pid = <optimized out>
:        tid = <optimized out>
:        ret = <optimized out>
:#1  0x000003ffa6ea2fd8 in __GI_abort () at abort.c:79
:        save_stage = 1
:        act = {__sigaction_handler = {sa_handler = 0x5, sa_sigaction = 0x5}, __glibc_reserved0 = -1, sa_flags = -208, sa_restorer = 0xf37526ba7e55e3, sa_mask = {__val = {18446744073709551615, 18446744073709551615, 68527228538738147, 68527228538738147, 2929766662960, 2929766663168, 2929766662848, 4397924875048, 0, 2929363245056, 2929363343664, 4294967295, 1341, 4396569404188, 68527228538738147, 2929766662960}}}
:        sigs = {__val = {32, 0 <repeats 15 times>}}
:#2  0x000003ffa7b1b872 in isc_assertion_failed (file=file@entry=0x3ffa7b66f80 "../../../lib/isc/mem.c", line=line@entry=1122, type=type@entry=isc_assertiontype_insist, cond=cond@entry=0x3ffa7b6754e "ctx->stats[i].gets == 0U") at ../../../lib/isc/assertions.c:52
:No locals.
:#3  0x000003ffa7b2e71c in destroy (ctx=ctx@entry=0x2aa23b382c0) at ../../../lib/isc/mem.c:1122
:        i = 22
:        ondest = {magic = 0, events = {head = 0xf37526ba7e55e3, tail = 0x2}}
:#4  0x000003ffa7b2ec3a in isc__mem_destroy (ctxp=0x2aa08a12c20 <gmctx>) at ../../../lib/isc/mem.c:1275
:        ctx = 0x2aa23b382c0
:#5  0x000003ffa7b32ada in isc_mem_destroy (mctxp=0x2aa08a12c20 <gmctx>) at ../../../lib/isc/mem.c:2807
:No locals.
:#6  0x000002aa08a05ecc in cleanup () at ../../../bin/nsupdate/nsupdate.c:3309
:No locals.
:#7  main (argc=<optimized out>, argv=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:3361
:        result = <optimized out>

Comment 12 Petr Menšík 2020-03-30 13:44:20 UTC

It seems maybeshutdown in nsupdate.c does not expect doshutdown might be already done when called from event callback. But when getinput callback is handled, it does not lower requests. That means it can be already zero and resources are already freed.

(gdb) bt
#0  0x00007f122652e70f in raise () from /lib64/libc.so.6
#1  0x00007f1226518b25 in abort () from /lib64/libc.so.6
#2  0x00007f12288698e5 in isc_assertion_failed (file=file@entry=0x7f122930823e "../../../lib/dns/request.c", 
    line=line@entry=246, type=type@entry=isc_assertiontype_require, 
    cond=cond@entry=0x7f1229308a08 "(__builtin_expect(((requestmgr) != ((void *)0)), 1) && __builtin_expect((((const isc__magic_t *)(requestmgr))->magic == ((('R') << 24 | ('q') << 16 | ('u') << 8 | ('M')))), 1))")
    at ../../../lib/isc/assertions.c:52
#3  0x00007f1229242c1a in dns_requestmgr_shutdown (requestmgr=<optimized out>) at ../../../lib/dns/request.c:252
#4  0x000056169e08696e in maybeshutdown () at ../../../bin/nsupdate/nsupdate.c:843
#5  0x000056169e0893e5 in getinput (task=<optimized out>, event=<optimized out>) at ../../../bin/nsupdate/nsupdate.c:3323
#6  0x00007f122888f7df in dispatch (manager=0x7f122994c010) at ../../../lib/isc/task.c:1143
#7  run (uap=0x7f122994c010) at ../../../lib/isc/task.c:1315
#8  0x00007f12275ed2de in start_thread () from /lib64/libpthread.so.0
#9  0x00007f12265f2e83 in clone () from /lib64/libc.so.6
(gdb) p requestmgr
$14 = (dns_requestmgr_t *) 0x0

But this is valid case, I would just check if there is still something to shutdown. It crashes, because it wants to send shutdown event to already destroyed request manager. Unless getinput should avoid calling maybeshutdown at all, just check if is still there.

Comment 15 Petr Menšík 2020-03-31 11:33:02 UTC

Created upstream merge request [1], I think this issue might happen also in latest upstream release. Even master seem to have similar issues, but I did not test it properly, because not yet isolated required reproduction steps to trigger these issues.

1. https://gitlab.isc.org/isc-projects/bind9/-/merge_requests/3316

Comment 22 Petr Menšík 2020-06-17 20:42:53 UTC

The request was merged into 9.11.20 by commit [1], already in upstream. Even when original merge request is still unmerged, commit is already in upstream.

1. https://gitlab.isc.org/isc-projects/bind9/commit/d33aef43debf9e9737bdcb2956ed5cd487e88ec7

Comment 31 errata-xmlrpc 2020-11-04 01:50:44 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (Moderate: bind security, bug fix, and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2020:4500

Note You need to log in before you can comment on or make changes to this bug.