0

I have installed bind9 on ubuntu server 10.04.1.

And there is some strange things. Just after boot here is my log file: 

Feb 26 18:30:57 myserver init: apport pre-start process (793) terminated with status 1
Feb 26 18:30:57 myserver init: apport post-stop process (828) terminated with status 1
Feb 26 18:30:57 myserver named[833]: starting BIND 9.7.0-P1 -u bind -t /var/lib/named
Feb 26 18:30:57 myserver named[833]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS='
Feb 26 18:30:57 myserver named[833]: adjusted limit on open files from 1024 to 1048576
Feb 26 18:30:57 myserver named[833]: found 1 CPU, using 1 worker thread
Feb 26 18:30:57 myserver named[833]: using up to 4096 sockets
Feb 26 18:30:57 myserver named[833]: loading configuration from '/etc/bind/named.conf'
Feb 26 18:30:58 myserver named[833]: reading built-in trusted keys from file '/etc/bind/bind.keys'
Feb 26 18:30:58 myserver named[833]: using default UDP/IPv4 port range: [1024, 65535]
Feb 26 18:30:58 myserver named[833]: using default UDP/IPv6 port range: [1024, 65535]
Feb 26 18:30:58 myserver named[833]: listening on IPv4 interface lo, 127.0.0.1#53
Feb 26 18:30:58 myserver named[833]: listening on IPv4 interface eth4, 192.168.0.8#53
Feb 26 18:30:58 myserver named[833]: couldn't mkdir '/var/run/named': Permission denied
Feb 26 18:30:58 myserver named[833]: generating session key for dynamic DNS
Feb 26 18:30:58 myserver named[833]: couldn't mkdir '/var/run/named': Permission denied
Feb 26 18:30:58 myserver named[833]: could not create /var/run/named/session.key
Feb 26 18:30:58 myserver named[833]: failed to generate session key for dynamic DNS: permission denied
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 254.169.IN-ADDR.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 2.0.192.IN-ADDR.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 255.255.255.255.IN-ADDR.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: D.F.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 8.E.F.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: 9.E.F.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: A.E.F.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: automatic empty zone: B.E.F.IP6.ARPA
Feb 26 18:30:58 myserver named[833]: command channel listening on 127.0.0.1#953
Feb 26 18:30:58 myserver named[833]: command channel listening on ::1#953
Feb 26 18:30:58 myserver named[833]: zone 0.in-addr.arpa/IN: loaded serial 1
Feb 26 18:30:58 myserver named[833]: zone 127.in-addr.arpa/IN: loaded serial 1
Feb 26 18:30:58 myserver named[833]: zone 255.in-addr.arpa/IN: loaded serial 1
Feb 26 18:30:58 myserver named[833]: zone localhost/IN: loaded serial 2
Feb 26 18:30:58 myserver named[833]: zone mydomain1.my/IN: loading from master file /var/lib/bind/mydomain1.my.hosts failed: file not found
Feb 26 18:30:58 myserver named[833]: zone mydomain1.my/IN: not loaded due to errors.
Feb 26 18:30:58 myserver named[833]: zone mydomain2.my/IN: loading from master file /var/lib/bind/mydomain2.my.hosts failed: file not found
Feb 26 18:30:58 myserver named[833]: zone mydomain2.my/IN: not loaded due to errors.
Feb 26 18:30:58 myserver named[833]: running

After booting bind9 is running as you see, however all the zones I have created are not accessible.

But then I restart bind9 manually, and then all zones are accessible. However I get some permission denied, I think these are related with the first named service that is running already...

My question is what do I do wrong?

Here is my logs after this:

Feb 26 18:31:59 myserver named[1472]: starting BIND 9.7.0-P1 -c /etc/bind/named.conf
Feb 26 18:31:59 myserver named[1472]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-gnu-ld' '--with-dlz-postgres=no' '--with-dlz-mysql=no' '--with-dlz-bdb=yes' '--with-dlz-filesystem=yes' '--with-dlz-ldap=yes' '--with-dlz-stub=yes' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=-Wl,-Bsymbolic-functions' 'CPPFLAGS='
Feb 26 18:31:59 myserver named[1472]: adjusted limit on open files from 1024 to 1048576
Feb 26 18:31:59 myserver named[1472]: found 1 CPU, using 1 worker thread
Feb 26 18:31:59 myserver named[1472]: using up to 4096 sockets
Feb 26 18:31:59 myserver named[1472]: loading configuration from '/etc/bind/named.conf'
Feb 26 18:31:59 myserver named[1472]: reading built-in trusted keys from file '/etc/bind/bind.keys'
Feb 26 18:31:59 myserver named[1472]: using default UDP/IPv4 port range: [1024, 65535]
Feb 26 18:31:59 myserver named[1472]: using default UDP/IPv6 port range: [1024, 65535]
Feb 26 18:31:59 myserver named[1472]: listening on IPv4 interface lo, 127.0.0.1#53
Feb 26 18:31:59 myserver named[1472]: binding TCP socket: address in use
Feb 26 18:31:59 myserver named[1472]: listening on IPv4 interface eth4, 192.168.0.8#53
Feb 26 18:31:59 myserver named[1472]: binding TCP socket: address in use
Feb 26 18:31:59 myserver named[1472]: could not open file '/var/run/named/named.pid': Permission denied
Feb 26 18:31:59 myserver named[1472]: generating session key for dynamic DNS
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 254.169.IN-ADDR.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 2.0.192.IN-ADDR.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 255.255.255.255.IN-ADDR.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: D.F.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 8.E.F.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: 9.E.F.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: A.E.F.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: automatic empty zone: B.E.F.IP6.ARPA
Feb 26 18:31:59 myserver named[1472]: none:0: open: /etc/bind/rndc.key: permission denied
Feb 26 18:31:59 myserver named[1472]: couldn't add command channel 127.0.0.1#953: permission denied
Feb 26 18:31:59 myserver named[1472]: none:0: open: /etc/bind/rndc.key: permission denied
Feb 26 18:31:59 myserver named[1472]: couldn't add command channel ::1#953: permission denied
Feb 26 18:31:59 myserver named[1472]: zone 0.in-addr.arpa/IN: loaded serial 1
Feb 26 18:31:59 myserver named[1472]: zone 127.in-addr.arpa/IN: loaded serial 1
Feb 26 18:31:59 myserver named[1472]: zone 255.in-addr.arpa/IN: loaded serial 1
Feb 26 18:31:59 myserver named[1472]: zone localhost/IN: loaded serial 2
Feb 26 18:32:00 myserver named[1472]: zone mydomain1.my/IN: loaded serial 1269440219
Feb 26 18:32:00 myserver named[1472]: zone mydomain2.my/IN: loaded serial 1269440742
Feb 26 18:32:00 myserver named[1472]: running
Feb 26 18:32:00 myserver named[1472]: zone mydomain1.my/IN: sending notifies (serial 1269440219)
Feb 26 18:32:00 myserver named[1472]: zone mydomain2.my/IN: sending notifies (serial 1269440742)
Feb 26 18:32:00 myserver named[1472]: client 8x.x7x.x9x.5x#26763: received notify for zone 'mydomain1.my'
Feb 26 18:32:00 myserver named[1472]: client 8x.x7x.x9x.5x#34984: received notify for zone 'mydomain2.my'
radu c
  • 103
  • 1
  • 1
  • 3

1 Answers1

1

In first log named chroot to /var/lib/named. In /var/lib/named zone file don't exist. Check /etc/default/bind9 and disable chroot(delete "-t /var/lib/named" option):

# run resolvconf?
RESOLVCONF=yes

# startup options for the server
OPTIONS="-u bind"

If second log, you start named without change setuid to bind. This is wrong.

And fix "/var/run/named" permission:

killall named
rm -rf /var/run/named
service named start

To debug create strace:

# cd
# service bind9 stop
# strace -f -o bind.strace /usr/sbin/named -u bind &
# sleep 4 && killall named

Then copy bind.strace to http://pastebin.com/

ooshro
  • 11,134
  • 1
  • 32
  • 31
  • thank you for your answer. Is ok now, however I get these errors in log, after booting the server: `Feb 27 14:59:11 myserver named[677]: Could not open '/var/run/named/named.pid'. Feb 27 14:59:11 myserver named[677]: Please check file and directory permissions or reconfigure the filename. Feb 27 14:59:11 myserver named[677]: could not open file '/var/run/named/named.pid': Permission denied` How can I solve these? – radu c Feb 27 '11 at 13:46
  • 1) killall named 2) rm -rf /var/run/named 3) service named restart – ooshro Feb 27 '11 at 15:57
  • Yes I have done that. Still the same error as above persist when booting, note that now is complaining first that the file is not found, because I have deleted the directory, and then is saying permission denied. – radu c Feb 28 '11 at 06:21
  • Name start with "-u bind" options? What "ls -ld /var/run/named/"? – ooshro Feb 28 '11 at 06:26
  • Yes is only with `-u bind` options, and the return of the `ls` command is: `ekkosmos@myserver:~$ ls -ld /var/run/named/ drwxrwxr-x 2 root bind 60 2011-02-27 14:59 /var/run/named/` – radu c Feb 28 '11 at 06:56
  • I update answer(create strace) – ooshro Feb 28 '11 at 07:39
  • I have attached the file log: http://pastebin.com/ZZq81ueD – radu c Feb 28 '11 at 16:45
  • "sudo rm /var/run/named/named.pid" and run again – ooshro Feb 28 '11 at 16:54
  • When I run this command I get: `rm: cannot remove '/var/run/named/named.pid': No such file or directory` – radu c Mar 01 '11 at 06:19
  • try reinstall bind9: sudo apt-get update;sudo apt-get --reinstall install bind9 – ooshro Mar 01 '11 at 07:09
  • I will let it like this for the moment, because is working anyway. And he does what I need. Thanks for your time to answer to my question. – radu c Mar 01 '11 at 08:01