Bug 324315 – net-dns/bind - named service doesn't start anymore

• Status: RESOLVED FIXED
• Product: Gentoo Linux

[Description Bèrto 'd Sèra 2010-06-16 15:27:07 UTC]

named service doesn't start anymore

Reproducible: Always

Steps to Reproduce:
1./etc/init.d/named start
2.
3.

Actual Results:  
ks305671 aegir # /etc/init.d/named start
 * Caching service dependencies ...
/lib64/rc/sh/rc-functions.sh: line 90: shell_var: command not found                                                                                                        [ ok ]
 * Starting named ...
 * start-stop-daemon: failed to start `/usr/sbin/named'                                                                                                                    [ !! ]
 * ERROR: named failed to start


Expected Results:  
having named started

This started after a general emerge -e world due to issues with a new gcc version.

I have this much output after removing --quiet from the /etc/init.d/named script. Nothing gets written in /var/log/named/named.log

I'm using 
net-dns/bind 9.4.3_p5 with use: berkdb mysql ssl urandom
sys-apps/openrc 0.6.1-r1 with use: elibc_glibc kernel_linux ncurses pam

ks305671 aegir # emerge --info
Portage 2.1.8.3 (hardened/linux/amd64/10.0/no-multilib, gcc-4.1.2, glibc-2.10.1-r1, 2.6.32.2-xxxx-std-ipv4-64 x86_64)
=================================================================
System uname: Linux-2.6.32.2-xxxx-std-ipv4-64-x86_64-Intel-R-_Core-TM-2_Quad_CPU_Q6600_@_2.40GHz-with-gentoo-2.0.1
Timestamp of tree: Wed, 16 Jun 2010 01:00:01 +0000
app-shells/bash:     4.0_p37
dev-java/java-config: 2.1.10
dev-lang/python:     2.4.6, 2.5.4-r3, 2.6.5-r2, 3.1.2-r3
sys-apps/baselayout: 2.0.1
sys-apps/openrc:     0.6.1-r1
sys-apps/sandbox:    1.6-r2
sys-devel/autoconf:  2.13, 2.65
sys-devel/automake:  1.9.6-r2, 1.10.2, 1.11.1
sys-devel/binutils:  2.20.1-r1
sys-devel/gcc:       4.1.2, 4.3.5
sys-devel/gcc-config: 1.4.1
sys-devel/libtool:   2.2.6b
virtual/os-headers:  2.6.30-r1
ACCEPT_KEYWORDS="amd64"
ACCEPT_LICENSE="*"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -pipe -march=nocona"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /var/bind /var/qmail/alias /var/qmail/control /var/vpopmail/etc"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/eselect/postgresql /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5/ext-active/ /etc/php/cgi-php5/ext-active/ /etc/php/cli-php5/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-O2 -pipe -march=nocona"
DISTDIR="/usr/portage/distfiles"
FEATURES="assume-digests distlocks fixpackages news parallel-fetch protect-owned sfperms strict unmerge-logs unmerge-orphans"
GENTOO_MIRRORS="http://mirror.ovh.net/gentoo-distfiles/ ftp://mirror.ovh.net/gentoo-distfiles/"
LANG="en_GB"
LDFLAGS="-Wl,-O1"
MAKEOPTS="-j3"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/usr/local/portage/layman/gechi /usr/local/portage/layman/xworld_experimental /usr/portage/local/layman/ovh-overlay"
SYNC="rsync://rsync.gentoo.org/gentoo-portage"
USE="acl amd64 berkdb bzip2 cli cracklib crypt cups cxx dri gdbm gpm hardened iconv imap justify maildir mmx modules mudflap mysql ncurses netboot nls nptl nptlonly openmp pam pcre perl pic pppd python qmail-spp readline reflection session spl sse sse2 ssl sysfs tcpd urandom xorg zlib" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias proxy proxy_ajp proxy_balancer proxy_connect proxy_ftp proxy_http" ELIBC="glibc" INPUT_DEVICES="keyboard mouse evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" RUBY_TARGETS="ruby18" USERLAND="GNU" VIDEO_CARDS="fbdev glint intel mach64 mga neomagic nv r128 radeon savage sis tdfx trident vesa via vmware voodoo" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account" 
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, FFLAGS, INSTALL_MASK, LC_ALL, LINGUAS, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS

[Comment 1 Bèrto 'd Sèra 2010-06-17 03:58:52 UTC]

Actually, named probably is NOT the bad guy. After doing an emerge -e world I found the following:

101 .la file(s) has been fixed for this system:

/usr/lib64/apr-util-1/apr_dbm_db.la
/usr/lib64/apr-util-1/apr_dbm_gdbm.la
/usr/lib64/libacl.la
/usr/lib64/libbind9.la
/usr/lib64/libdns.la
/usr/lib64/libgdbm_compat.la
/usr/lib64/libgettextlib.la
/usr/lib64/libgettextsrc.la
/usr/lib64/libgmpxx.la
/usr/lib64/libisccc.la
/usr/lib64/libisccfg.la
/usr/lib64/libmpfr.la
/usr/lib64/python2.6/site-packages/libsvn/_core.la
/usr/lib64/python2.6/site-packages/libsvn/_client.la
/usr/lib64/python2.6/site-packages/libsvn/_delta.la
/usr/lib64/python2.6/site-packages/libsvn/_diff.la
/usr/lib64/python2.6/site-packages/libsvn/_fs.la
/usr/lib64/python2.6/site-packages/libsvn/_ra.la
/usr/lib64/python2.6/site-packages/libsvn/_repos.la
/usr/lib64/python2.6/site-packages/libsvn/_wc.la
/usr/lib64/python2.6/site-packages/libxsltmod.la
/usr/lib64/python2.6/site-packages/_cracklibmodule.la
/usr/lib64/apache2/modules/mod_apreq2.la
/usr/lib64/libaprutil-1.la
/usr/lib64/libneon.la
/usr/lib64/libsvn_subr-1.la
/usr/lib64/libsvn_delta-1.la
/usr/lib64/libsvn_fs_util-1.la
/usr/lib64/libsvn_fs_fs-1.la
/usr/lib64/libsvn_fs_base-1.la
/usr/lib64/libsvn_fs-1.la
/usr/lib64/libsvn_ra_svn-1.la
/usr/lib64/libsvn_repos-1.la
/usr/lib64/libsvn_ra_local-1.la
/usr/lib64/libsvn_ra_neon-1.la
/usr/lib64/libsvn_diff-1.la
/usr/lib64/libsvn_ra-1.la
/usr/lib64/libsvn_wc-1.la
/usr/lib64/libsvn_client-1.la
/usr/lib64/libgcrypt.la
/usr/lib64/libxslt.la
/usr/lib64/libexslt.la
/usr/lib64/libX11.la
/usr/lib64/libSM.la
/usr/lib64/libXt.la
/usr/lib64/libXext.la
/usr/lib64/libXpm.la
/usr/lib64/libapreq2.la
/usr/lib64/mysql/libmysqlclient.la
/usr/lib64/mysql/libmysqlclient_r.la
/usr/lib64/libgmodule-2.0.la
/usr/lib64/libgthread-2.0.la
/usr/lib64/libgobject-2.0.la
/usr/lib64/libgio-2.0.la
/usr/lib64/libfontconfig.la
/usr/lib64/libgd.la
/usr/lib64/libGeoIPUpdate.la
/usr/lib64/courier-authlib/libcourierauthsasl.la
/usr/lib64/courier-authlib/libcourierauthsaslclient.la
/usr/lib64/courier-authlib/libcourierauthcommon.la
/usr/lib64/courier-authlib/libauthuserdb.la
/usr/lib64/courier-authlib/libauthpam.la
/usr/lib64/courier-authlib/libauthshadow.la
/usr/lib64/courier-authlib/libauthmysql.la
/usr/lib64/courier-authlib/libauthcustom.la
/usr/lib64/courier-authlib/libauthpipe.la
/usr/lib64/librfc822.la
/usr/lib64/libclamunrar_iface.la
/usr/lib64/libclamav.la
/usr/lib64/libksba.la
/usr/lib64/libgeos_c.la
/usr/lib64/libsvn_swig_py-1.la
/usr/lib64/libsvn_swig_perl-1.la
/usr/lib64/libiptc.la
/usr/lib64/libassuan.la
/usr/lib64/libxcb.la
/usr/lib64/libvorbisfile.la
/usr/lib64/libvorbisenc.la
/usr/lib64/libxcb-composite.la
/usr/lib64/libxcb-damage.la
/usr/lib64/libxcb-dpms.la
/usr/lib64/libxcb-dri2.la
/usr/lib64/libxcb-glx.la
/usr/lib64/libxcb-randr.la
/usr/lib64/libxcb-record.la
/usr/lib64/libxcb-render.la
/usr/lib64/libxcb-res.la
/usr/lib64/libxcb-screensaver.la
/usr/lib64/libxcb-shape.la
/usr/lib64/libxcb-shm.la
/usr/lib64/libxcb-sync.la
/usr/lib64/libxcb-xevie.la
/usr/lib64/libxcb-xf86dri.la
/usr/lib64/libxcb-xfixes.la
/usr/lib64/libxcb-xinerama.la
/usr/lib64/libxcb-xinput.la
/usr/lib64/libxcb-xprint.la
/usr/lib64/libxcb-xtest.la
/usr/lib64/libxcb-xv.la
/usr/lib64/libxcb-xvmc.la
/usr/lib64/libX11-xcb.la

[Comment 2 Bèrto 'd Sèra 2010-06-17 04:27:55 UTC]

Created attachment 235673 [details]
strace output for /etc/init.d/named start

also adding strace output for /etc/init.d/named start

[Comment 3 Bèrto 'd Sèra 2010-06-17 04:35:53 UTC]

Created attachment 235675 [details]
strace with -f for /etc/init.d/named start

tracing the forks as well

[Comment 4 Markos Chandras (RETIRED) 2010-06-17 22:33:24 UTC]

bind also keeps logs on /var/log/named/named.log. Please attach that file ( or at least the last 50 lines ).

However the error /lib64/rc/sh/rc-functions.sh: line 90: shell_var: command not found   

doesn't seem very good

Please try to rebuild openrc

[Comment 5 Bèrto 'd Sèra 2010-06-18 06:53:03 UTC]

Created attachment 235811 [details]
named.log

/var/log/named/named.log is empty, and it does not even get to touch it (judging by the timestamp). I will attach the old one that was moved by log-rotate

I rebuilt openrc (and restarted the box) a number of times, by now, to no better result, but the shell_var thing is now vanished, I'm getting

 * Starting named ...
 * start-stop-daemon: failed to start `/usr/sbin/named'                                                                                                                    [ !! ]
 * ERROR: named failed to start

[Comment 6 Bèrto 'd Sèra 2010-06-18 13:34:39 UTC]

FWIW I did a check of the configuration files with webmin and it says OK.

[Comment 7 Christian Ruppert (idl0r) 2010-06-18 16:01:21 UTC]

(In reply to comment #6)
> FWIW I did a check of the configuration files with webmin and it says OK.
> 

Please start bind from a shell like the initscript does so that you'll get some messages.

[Comment 8 Bèrto 'd Sèra 2010-06-18 16:10:59 UTC]

Continuing my investigations, I found out that spamassassin has exactly the same problem, also, that named is logging to syslog... which suddenly explained everything (though I have no idea of how it got moved to syslog):

Jun 18 08:50:43 ks305671 named[7087]: starting BIND 9.4.3-P5 -u named -n 1
Jun 18 08:50:43 ks305671 named[7087]: using up to 4096 sockets
Jun 18 08:50:43 ks305671 named[7087]: loading configuration from '/etc/bind/named.conf'
Jun 18 08:50:43 ks305671 named[7087]: max open files (1024) is smaller than max sockets (4096)
Jun 18 08:50:43 ks305671 named[7087]: using default UDP/IPv4 port range: [1024, 65535]
Jun 18 08:50:43 ks305671 named[7087]: using default UDP/IPv6 port range: [1024, 65535]
Jun 18 08:50:43 ks305671 named[7087]: listening on IPv4 interface lo, 127.0.0.1#53
Jun 18 08:50:43 ks305671 named[7087]: listening on IPv4 interface eth0, 91.121.221.48#53
Jun 18 08:50:43 ks305671 named[7087]: could not configure root hints from 'named.ca': file not found
Jun 18 08:50:43 ks305671 named[7087]: loading configuration: file not found
Jun 18 08:50:43 ks305671 named[7087]: exiting (due to fatal error)
Jun 18 08:50:43 ks305671 /etc/init.d/named[7085]: start-stop-daemon: failed to start `/usr/sbin/named'
Jun 18 08:50:43 ks305671 /etc/init.d/named[7077]: ERROR: named failed to start

================

named.ca appears in /etc/bind/named.conf

...
        zone "." IN {
                type hint;
                file "named.ca";
        };
...

after an upgrade the file is now called named.cache, it was surely my mistake in checking the file on doing dispatch-conf. I guess the only mystery was how the logging moved to syslog :)

All's well what ends well :)

Bèrto