[RPZ] 9.9.3-rpz2+rl.150.20 fails to launch "due to assertion failure"

Fri May 31 14:10:17 UTC 2013

hi vernon,

On Fri, May 31, 2013, at 06:07 AM, Vernon Schryver wrote:
> Running `named` manually by typing something like
>    named -t /var/chroot/named -n 4 -S 1024 -u named -c /etc/named.conf
>    -fd10
> to send the crash stack trace to stdderr might be illuminating.

well, not illuminating to ME :-/

with BIND 9.9.2-rpz2+rl.150.20-P2

	build/package
	rpm -e --nodeps `rpm -qa | grep -i ^bind-9`
	rpm -ivh
	/usr/src/packages/RPMS/x86_64/bind-custom-992_P2-1.x86_64.rpm
	rpm -qa | grep -i bind9
		bind-custom-992_P2-1.x86_64

	/usr/local/sbin/named -t /var/chroot/named -n 4 -S 1024 -u named
	-c /etc/named.conf -fd 10
		(no output)

	tail -f /var/log/messages
		2013-05-31T06:40:28.274880-07:00 core named[13523]:
		starting BIND 9.9.2-rpz2+rl.150.20-P2 -t
		/var/chroot/named -n 4 -S 1024 -u named -c
		/etc/named.conf -fd 10
		...
		2013-05-31T06:40:28.429118-07:00 core named[13523]:
		command channel listening on 127.0.0.1#953

running & fully functional.

with BIND 9.9.3-rpz2+rl.150.20

	build/package
	rpm -e --nodeps `rpm -qa | grep -i ^bind-9`
	rpm -ivh
	/usr/src/packages/RPMS/x86_64/bind-custom-993-1.x86_64.rpm
	rpm -qa | grep -i bind9
		bind-custom-993-1.x86_64

	/usr/local/sbin/named -t /var/chroot/named -n 4 -S 1024 -u named
	-c /etc/named.conf -fd 10
		Aborted

	tail -f /var/log/messages
		2013-05-31T06:35:39.545945-07:00 core named[13402]:
		starting BIND 9.9.3-rpz2+rl.150.20 -t /var/chroot/named
		-n 4 -S 1024 -u named -c /etc/named.conf -fd 90
		2013-05-31T06:35:39.550869-07:00 core named[13402]:
		built with '--prefix=/usr/local'
		'--bindir=/usr/local/bin' '--sbindir=/usr/local/sbin'
		'--sysconfdir=/usr/local/etc/named'
		'--localstatedir=/var' '--libdir=/usr/local/lib64'
		'--includedir=/usr/local/include/bind'
		'--mandir=/usr/local/share/man'
		'--infodir=/usr/local/share/info' '--enable-shared'
		'--disable-static' '--enable-chroot' '--enable-ipv6'
		'--with-libxml2=yes' '--with-libtool' '--without-idn'
		'--enable-threads' '--enable-largefile'
		'--with-randomdev=/dev/urandom'
		'--enable-openssl-version-check'
		'--disable-openssl-hash' '--with-openssl=/usr/local/ssl'
		'--without-pkcs11' '--with-dlz-postgres=no'
		'--with-dlz-mysql=no'
		'--with-dlz-bdb=/usr/local/dlz-bdb'
		'--with-dlz-filesystem=yes' '--with-dlz-ldap=no'
		'--with-dlz-odbc=no' '--with-dlz-stub=yes'
		'--with-dlopen=yes' '--enable-rpz-nsip'
		'--enable-rpz-nsdname' '--with-make-clean'
		'CC=/usr/bin/gcc-4.8' 'CFLAGS=-O2 -fmessage-length=0
		-D_FORTIFY_SOURCE=2 -fstack-protector -funwind-tables
		-fasynchronous-unwind-tables -march=atom -mtune=atom
		-fPIC -DPIC -D_GNU_SOURCE -fno-strict-aliasing -Wall'
		'LDFLAGS=-L/usr/local/ssl/lib64
		-Wl,-rpath,/usr/local/ssl/lib64 -lssl -lcrypto '
		'CPPFLAGS=-I/usr/local/include -I/usr/local/ssl/include
		-I/usr/include'
		2013-05-31T06:35:39.550934-07:00 core named[13402]:
		----------------------------------------------------
		2013-05-31T06:35:39.550957-07:00 core named[13402]: BIND
		9 is maintained by Internet Systems Consortium,
		2013-05-31T06:35:39.554873-07:00 core named[13402]: Inc.
		(ISC), a non-profit 501(c)(3) public-benefit
		2013-05-31T06:35:39.554927-07:00 core named[13402]:
		corporation.  Support and training for BIND 9 are
		2013-05-31T06:35:39.554973-07:00 core named[13402]:
		available at https://www.isc.org/support
		2013-05-31T06:35:39.556115-07:00 core named[13402]:
		----------------------------------------------------
		2013-05-31T06:35:39.557497-07:00 core named[13402]:
		adjusted limit on open files from 4096 to 1048576
		2013-05-31T06:35:39.558913-07:00 core named[13402]:
		found 4 CPUs, using 4 worker threads
		2013-05-31T06:35:39.560317-07:00 core named[13402]:
		using 4 UDP listeners per interface
		2013-05-31T06:35:39.561697-07:00 core named[13402]:
		using up to 1024 sockets
		2013-05-31T06:35:39.569490-07:00 core named[13402]:
		parser.c:2432: REQUIRE(prev > 0) failed
		2013-05-31T06:35:39.571202-07:00 core named[13402]:
		exiting (due to assertion failure)

where

	cat bind-9.9.3/lib/isccfg/parser.c
		...
		/*
		 * Destroy 'obj', a configuration object created in
		 'pctx'.
		 */
		void
		cfg_obj_destroy(cfg_parser_t *pctx, cfg_obj_t **objp) {
		    cfg_obj_t *obj;
2432        unsigned int refs;

		    REQUIRE(objp != NULL && *objp != NULL);
		    REQUIRE(pctx != NULL);

		    obj = *objp;

		    isc_refcount_decrement(&obj->references, &refs);
		    if (refs == 0) {
		        obj->type->rep->free(pctx, obj);
		        isc_refcount_destroy(&obj->references);
		        isc_mem_put(pctx->mctx, obj, sizeof(cfg_obj_t));
		    }
		...

and,

	cat bind-9.9.2-P2/lib/isccfg/parser.c
		...
		/*
		 * Destroy 'obj', a configuration object created in
		 'pctx'.
		 */
		void
		cfg_obj_destroy(cfg_parser_t *pctx, cfg_obj_t **objp) {
		    cfg_obj_t *obj = *objp;
		    unsigned int refs;

2432        isc_refcount_decrement(&obj->references, &refs);
		    if (refs == 0) {
		        obj->type->rep->free(pctx, obj);
		        isc_refcount_destroy(&obj->references);
		        isc_mem_put(pctx->mctx, obj, sizeof(cfg_obj_t));
		    }
		    *objp = NULL;
		}
		...

> What happened with your problem with unpatched 9.9.3 reported in
> https://lists.isc.org/pipermail/dnsrpz-interest/2013-May/000236.html 

Not a lot ... yet.  I did find that the 'stuck' CPU occurs without fail
ONLY if I'm launching 9.9.3 *AND* the systemd unit file is "enabled" for
restart (i.e., systemctl enable named.custom).  If, otoh, i DISable it,
and launch it manually, the "happens every time" vanishes (tho it still
does, rarely/occassionally).  This SEEMS to suggest systemd involvement
-- if only due to restart attempts.  Hadn't gotten further than that,
yet -- just disabled the restarting so I could troubleshoot THIS issue
...

darx