Skip site navigation (1)Skip section navigation (2)
Date:      Tue, 30 Jun 2009 08:35:26 +0000
From:      no-spam@people.net.au
To:        <freebsd-questions@freebsd.org>
Subject:   Re: named startup problems upgrading from 7.1p4 to 7.1p5 or 7.1p6
Message-ID:  <29382.1246350926@people.net.au>

next in thread | raw e-mail | index | archive | help
Sorry for starting a new thread with this - my ISP's mail server seems to r=
ejecting all mail recipients when I=20
send email with a mail client, so I'm having to use webmail instead. Their =
tech says they won't help - they=20
only support Outlook! Grrr!

On Sun, 28 Jun 2009 23:27:07 Matthew Seaman wrote:
> Ian wrote:
> > Well the fact that if I run  /etc/rc.d/named manually after the system
> > has booted, the script also hangs suggests it's not the next process I
> > have just check however & ntpdate is the next one in the list to be
> > started and that does start correctly - you can see it report the clock
> > being adjusted. Also, when you do a Ctrl+C to break the named script on
> > bootup, it says "Script /etc/rc.d/named interrupted".
> >
> > Something I've just realised is that named stays loaded even when you
> > 'break' the script. on bootup and DNS lookups work (I didn't think that
> > was the case originally, but it is).

Actually, some careful checking tonight shows that I had forgotten I had a=
=20
second DNS server in resolv.conf that was doing the DNS resolution - in fac=
t=20
bind on this server is not working even though a bind process appears to be=
=20
running :/

> Hmmm....
>
> Anything interesting from named in the system logs?  You might want to
> enable /var/log/all.log by following the instructions in /etc/syslog.conf
> and then see what output you get by bouncing named.  It's usually pretty
> good at pointing out exactly what it thinks the problem is.

I've enabled all.log, it only shows the following output when starting name=
d:
Jun 29 20:51:43 msgserver named[1593]: starting BIND 9.4.2-P2 -t /var/named=
 -u=20
bind
Jun 29 20:51:43 msgserver named[1593]: found 1 CPU, using 1 worker thread

a ps axw | grep named gives the following output after running /etc/rc.d/na=
med=20
start:
 1988  ??  Is     0:00.00 /usr/sbin/named -t /var/named -u bind
 1930  p0  I+     0:00.06 /bin/sh -x /etc/rc.d/named start
 1987  p0  I+     0:00.01 /usr/sbin/named -t /var/named -u bind

and then after doing a Ctrl+C in the terminal where /etc/rc.d/named start i=
s=20
running, only one process continues to run:
 1988  ??  Is     0:00.00 /usr/sbin/named -t /var/named -u bind

This process doesn't respond to DNS queries, to rndc commands,=20
to /etc/rc.d/named stop (says no process is running because there is no pid=
=20
file being created) or by a kill command other than kill -9.
(All named processes were killed before stating named)

>
> You could also try running:
>
>    # /bin/sh -x /etc/rc.d/named start


> -- make sure named isn't running when you do that.  There will be quite
> a lot of output as the rc system loads all of the various config files,
> but you should be able to trace exactly where it's got to when it does
> hang.

Here's the edited highlights of output, I can't see anything that helps:
> + _rc_subr_loaded=3D:
> + name=3Dnamed
> + rcvar=3Dnamed_enable
> + command=3D/usr/sbin/named
> + extra_commands=3Dreload
> + start_precmd=3Dnamed_precmd
> + start_postcmd=3Dmake_symlinks
> + reload_cmd=3Dnamed_reload
> + stop_cmd=3Dnamed_stop
> + stop_postcmd=3Dnamed_poststop
> + load_rc_config named
> + _name=3Dnamed
> + [ -z named ]
> + false
> + [ -r /etc/defaults/rc.conf ]
>
> <snip>
>
> + named_enable=3DNO
> + named_program=3D/usr/sbin/named
> + named_pidfile=3D/var/run/named/pid
> + named_uid=3Dbind
> + named_chrootdir=3D/var/named
> + named_chroot_autoupdate=3DYES
> + named_symlink_enable=3DYES
>
> <snip>
>
> + sourced_files=3D:/etc/rc.conf::/etc/rc.conf.local:
> + [ -r /etc/rc.conf.local ]
> + _rc_conf_loaded=3Dtrue
> + [ -f /etc/rc.conf.d/named ]
> + required_dirs=3D/var/named
> + pidfile=3D/var/run/named/pid
> + command_args=3D-u bind
> + run_rc_command start
> + _return=3D0
> + rc_arg=3Dstart
> + [ -z named ]
> + shift 1
> + rc_extra_args=3D
> + _rc_prefix=3D
> + eval _override_command=3D$named_program
> + _override_command=3D/usr/sbin/named
> + command=3D/usr/sbin/named
> + _keywords=3Dstart stop restart rcvar reload
> + rc_pid=3D
> + _pidcmd=3D
> + _procname=3D/usr/sbin/named
> + [ -n /usr/sbin/named ]
> + [ -n /var/run/named/pid ]
> + _pidcmd=3Drc_pid=3D$(check_pidfile /var/run/named/pid /usr/sbin/named )
> + [ -n rc_pid=3D$(check_pidfile /var/run/named/pid /usr/sbin/named ) ]
> + _keywords=3Dstart stop restart rcvar reload status poll
> + [ -z start ]
> + [ -n  ]
> + eval rc_flags=3D$named_flags
> + rc_flags=3D
> + eval _chdir=3D$named_chdir _chroot=3D$named_chroot _nice=3D$named_nice
> _user=3D$named_user _group=3D$named_group _groups=3D$named_groups
> + _chdir=3D _chroot=3D _nice=3D _user=3D _group=3D _groups=3D
> + [ -n  ]
> + [ -n named_enable -a start !=3D rcvar ]
> + checkyesno named_enable
> + eval _value=3D$named_enable
> + _value=3DYES
> + debug checkyesno: named_enable is set to YES.
> + return 0
> + eval rc_pid=3D$(check_pidfile /var/run/named/pid /usr/sbin/named )
> + check_pidfile /var/run/named/pid /usr/sbin/named
> + _pidfile=3D/var/run/named/pid
> + _procname=3D/usr/sbin/named
> + _interpreter=3D
> + [ -z /var/run/named/pid -o -z /usr/sbin/named ]
> + [ ! -f /var/run/named/pid ]
> + debug pid file (/var/run/named/pid): not readable.
> + return
> + rc_pid=3D
> + [ start !=3D start ]
> + eval _cmd=3D$start_cmd _precmd=3D$start_precmd _postcmd=3D$start_postcm=
d
> + _cmd=3D _precmd=3Dnamed_precmd _postcmd=3Dmake_symlinks
> + [ -n  ]
> + [ -z  -a -n  ]
> + [ ! -x /usr/sbin/named ]
> + _run_rc_precmd
> + check_required_before start
> + local _f
> + [ ! -d /var/named/. ]
> + return 0
> + [ -n named_precmd ]
> + debug run_rc_command: start_precmd: named_precmd
> + eval named_precmd
> + named_precmd
> + [ -n /var/named ]
> + rc_flags=3D -t /var/named
> + checkyesno named_chroot_autoupdate
> + eval _value=3D$named_chroot_autoupdate
> + _value=3DYES
> + debug checkyesno: named_chroot_autoupdate is set to YES.
> + return 0
> + chroot_autoupdate
> + [ -r /etc/mtree/BIND.chroot.dist ]
> + mtree -deU -f /etc/mtree/BIND.chroot.dist -p /var/named
> + [ ! -L /etc/namedb ]
> + ln -shf /var/named/etc/namedb /etc/namedb
> + umount /var/named/dev
> + devfs_domount /var/named/dev devfsrules_hide_all
> + local devdir rs _me
> + devdir=3D/var/named/dev
> + [ -n devfsrules_hide_all ]
> + rs=3Ddevfsrules_hide_all
> + _me=3Ddevfs_domount()
> + [ -z /var/named/dev ]
> + debug devfs_domount(): mount-point is (/var/named/dev), ruleset is
>
> <snip> (whole lot of devfs stuff)
>
> + devfs_set_ruleset devfsrules_hide_all /var/named/dev
> + local devdir rs _me
> + [ -n devfsrules_hide_all ]
> + eval rs=3D$devfsrules_hide_all
> + rs=3D1
> + [ -n /var/named/dev ]
> + devdir=3D-m /var/named/dev
> + _me=3Ddevfs_set_ruleset
> + [ -z 1 ]
> + debug devfs_set_ruleset: setting ruleset (1) on mount-point
> (/var/named/dev) + /sbin/devfs -m /var/named/dev ruleset 1
> + return 0
> + devfs -m /var/named/dev rule applyset
> + return 0
> + devfs -m /var/named/dev rule apply path null unhide
> + devfs -m /var/named/dev rule apply path random unhide
> + [ -r /etc/localtime ]
> + cmp -s /etc/localtime /var/named/etc/localtime
> + [ -s /var/named/etc/namedb/rndc.conf ]
> + return 0
> + _return=3D0
> + [ 0 -ne 0 ]
> + check_required_after start
> + local _f _args
> + return 0
> + return 0
> + echo Starting named.
> Starting named.
> + [ -n  ]
> + _doit=3D/usr/sbin/named  -t /var/named -u bind
> + [ -n  ]
> + [ -n  ]
> + _run_rc_doit /usr/sbin/named  -t /var/named -u bind
> + debug run_rc_command: doit: /usr/sbin/named  -t /var/named -u bind
> + eval /usr/sbin/named  -t /var/named -u bind
> + /usr/sbin/named -t /var/named -u bind


and that's where it hangs! The only thing that looks vaguely like an error =
to=20
me is about halfway down: + debug pid file (/var/run/named/pid): not=20
readable.=20
There is no /var/run/named/pid file being created, but then named isn't=20
loading properly, so it may not be an issue.

>
> You're using the system-supplied copy of bind aren't you?  Have you got
> a valid /etc/named/rndc.conf or /etc/named/rndc.key file so you can use
> rndc(8)?  If not, try running:
>
>     # rndc-confgen > /etc/namedb/rndc.conf
>
> and then cut'n'paste the indicated key and controls statements from that
> file into named.conf, stripping out the comment characters as you do (of
> course).

Yes, it's the system supplied version & yes I have a  /etc/named/rndc.key t=
hat=20
I assume is valid - I could run rndc commands in p4 (and still can if I=20
rollback to that version).
I've generated a new rndc.conf (having renamed rndc.key) to see that helps,=
=20
but it doesn't.

Running any rndc command (like rndc status or rndc debug) causes rndc to lo=
ad=20
and hang, the only way to kill it is with a kill -9, Ctrl+C or Ctrl+D don't=
=20
work. The same applies if I just run /usr/sbin/named -t /var/named -u bind.


I'm beginning to think there is something wrong with my named.conf or zone=
=20
files or dynamic update config, though they work just fine in -p4.

Cheers,
=20
Ian







Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?29382.1246350926>