DNS-Probleme nach Upgrade auf UCS 3.1

UCS - Univention Corporate Server
#1

Ich habe letzten Samstag eine Kundeninstallation von 3.0-2 auf 3.1 aktualisiert: Erst den Samba 4 DC, dann den Samba 3 File Server. Danach schien bei einigen Tests alles zu funktionieren (Windows-Anmeldung, Zugriff auf die Freigabe(n)).

Heute morgen bekam ich den Anruf dass der Zugrif auf den File Server nicht möglich sei. Lange Rede kurzer Sinn, es sieht nach einem Problem mit dem DNS-Server aus. Merkwürdigerweise funktioniert die Auflösung über loopback (dig @127.0.0.1 example.com), aber nicht über die eigentliche IP-Adresse (dig @10.135.3.11 example.com, auch auf dem Host selbst). Auch interessant ist die Receive-Queue auf dem System für den UDP Port 53:

root@vp-s01:~# netstat -lnup | grep :53
udp   229888      0 10.135.3.11:53          0.0.0.0:*                           23405/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           23405/named

Schon während des Upgrades des File Servers fiel dieses erst fehl da es ein Problem mit der Namensauflösung gab. Das Upgrade lief aber sauber durch, nachdem ich univention-upgrade einfach noch mal startete, deswegen habe ich das Problem nicht weiter beachtet.

Dem named scheint es allgemein nicht so gut zu gehen, siehe Anhang. (Im Protokoll findet sich auch die vorher erwähnte fehlgeschlagene Auflösung des Namens des Download-Servers.)
named.log (89.3 KB)

#2

Die Firewall-Regeln sehen ok aus:

root@vp-s01:~# iptables -nv -L | grep :53
   16   832 ACCEPT     tcp  --  *      *       0.0.0.0/0            0.0.0.0/0           tcp dpt:53 
47723 3511K ACCEPT     udp  --  *      *       0.0.0.0/0            0.0.0.0/0           udp dpt:53
root@vp-s01:~# ucr dump | grep /53/
security/packetfilter/package/univention-bind/tcp/53/all/en: DNS proxy
security/packetfilter/package/univention-bind/tcp/53/all: ACCEPT
security/packetfilter/package/univention-bind/udp/53/all/en: DNS proxy
security/packetfilter/package/univention-bind/udp/53/all: ACCEPT
security/packetfilter/package/univention-samba4/tcp/53/all/en: DNS
security/packetfilter/package/univention-samba4/tcp/53/all: ACCEPT
security/packetfilter/package/univention-samba4/udp/53/all/en: DNS
security/packetfilter/package/univention-samba4/udp/53/all: ACCEPT
#3

DNS-Abfragen über TCP funktionieren, nur UDP scheint Probleme zu machen. Der nächste DNS-Server ist erreichbar:

root@vp-s01:~# dig +tcp +short @10.135.3.11 example.com
192.0.43.10
root@vp-s01:~# dig +notcp +short @10.135.3.11 example.com
;; connection timed out; no servers could be reached
root@vp-s01:~# dig +notcp +short @10.135.48.1 example.com
192.0.43.10
#4

Direkt nach einem Neustart des bind-Prozesses funktioniert die Namensauflösung. Irgendwann hängt er dann scheinbar da ich ihn zuvor bereits neu gestartet hatte.

root@vp-s01:~# /etc/init.d/bind9 stop
Stopping bind9 daemon: .
done.
root@vp-s01:~# netstat -lnup | grep :53
root@vp-s01:~# /etc/init.d/bind9 start
Starting bind9 daemon:.
done.
root@vp-s01:~# netstat -lnup | grep :53
udp     2560      0 10.135.3.11:53          0.0.0.0:*                           5680/named      
udp        0      0 127.0.0.1:53            0.0.0.0:*                           5680/named      
root@vp-s01:~# netstat -lnup | grep :53
udp        0      0 10.135.3.11:53          0.0.0.0:*                           5680/named      
udp        0      0 127.0.0.1:53            0.0.0.0:*                           5680/named
root@vp-s01:~# dig +short @10.135.3.11 example.com
192.0.43.10
root@vp-s01:~# dig +short @10.135.3.11 vp-s11.doa.xxxxxxx.net
10.135.3.17
#5

Ein Neustart der File Server VM dauert recht lange und scheint das Problem im Bind auszulösen:

root@vp-s01:~# service bind9 restart
Restarting bind9 daemon: .
done.
root@vp-s01:~# dig +short @10.135.3.11 example.com
192.0.43.10
root@vp-s01:~# netstat -lnup | grep :53
udp        0      0 10.135.3.11:53          0.0.0.0:*                           9471/named      
udp        0      0 127.0.0.1:53            0.0.0.0:*                           9471/named      
root@vp-s01:~# ssh root@10.135.3.17 reboot
Broadcast message from root@vp-s11 (Mon Jan  7 11:55:25 2013):

The system is going down for reboot NOW!
Connection to 10.135.3.17 closed by remote host.
Connection to 10.135.3.17 closed.
root@vp-s01:~# ssh root@10.135.3.17 date
Mon Jan  7 11:58:24 CET 2013
root@vp-s01:~# netstat -lnup | grep :53
udp   229632      0 10.135.3.11:53          0.0.0.0:*                           9471/named      
udp        0      0 127.0.0.1:53            0.0.0.0:*                           9471/named
root@vp-s01:~# dig +short @10.135.3.11 example.com
;; connection timed out; no servers could be reached
#6

Es könnte aber auch das gleichzeitig stattfindende zw. fehlschlagende DNS-Update durch einen der Clients sein:

Jan  7 11:56:52 vp-s01 dhcpd: DHCPINFORM from 10.135.16.207 via 10.135.16.1
Jan  7 11:56:52 vp-s01 dhcpd: DHCPACK to 10.135.16.207 (d0:67:e5:26:2a:72) via eth0
Jan  7 11:57:10 vp-s01 dhcpd: DHCPINFORM from 10.135.16.235 via 10.135.16.1
Jan  7 11:57:10 vp-s01 dhcpd: DHCPACK to 10.135.16.235 (d0:67:e5:25:2f:5a) via eth0
Jan  7 11:57:13 vp-s01 dhcpd: DHCPINFORM from 10.135.16.206 via 10.135.16.1
Jan  7 11:57:13 vp-s01 dhcpd: DHCPACK to 10.135.16.206 (d4:be:d9:e1:ef:15) via eth0
Jan  7 11:57:25 vp-s01 dhcpd: DHCPINFORM from 10.135.16.202 via 10.135.16.1
Jan  7 11:57:25 vp-s01 dhcpd: DHCPACK to 10.135.16.202 (d4:be:d9:eb:a0:cc) via eth0
Jan  7 11:57:52 vp-s01 named[9471]: samba_dlz: starting transaction on zone doa.xxxxxxx.net
Jan  7 11:57:52 vp-s01 named[9471]: client 10.135.16.207#65019: update 'doa.xxxxxxx.net/IN' denied
Jan  7 11:57:52 vp-s01 named[9471]: samba_dlz: cancelling transaction on zone doa.xxxxxxx.net
Jan  7 11:57:56 vp-s01 named[9471]: samba_dlz: starting transaction on zone doa.xxxxxxx.net
Jan  7 11:57:56 vp-s01 named[9471]: client 10.135.16.207#65019: update 'doa.xxxxxxx.net/IN' denied
Jan  7 11:57:56 vp-s01 named[9471]: samba_dlz: cancelling transaction on zone doa.xxxxxxx.net
Jan  7 11:57:59 vp-s01 dhcpd: DHCPINFORM from 10.135.16.207 via 10.135.16.1
Jan  7 11:57:59 vp-s01 dhcpd: DHCPACK to 10.135.16.207 (d0:67:e5:26:2a:72) via eth0
Jan  7 11:58:09 vp-s01 named[9471]: samba_dlz: starting transaction on zone doa.xxxxxxx.net
Jan  7 11:58:09 vp-s01 named[9471]: client 10.135.16.207#65019: update 'doa.xxxxxxx.net/IN' denied
Jan  7 11:58:09 vp-s01 named[9471]: samba_dlz: cancelling transaction on zone doa.xxxxxxx.net
Jan  7 11:58:19 vp-s01 named[9471]: samba_dlz: starting transaction on zone doa.xxxxxxx.net
Jan  7 11:58:19 vp-s01 named[9471]: samba_dlz: disallowing update of signer=vp-12g\$\@DOA.XXXXXXX.NET name=vp-12g.doa.xxxxxxx.net type=AAAA error=insufficient access rights
Jan  7 11:58:19 vp-s01 named[9471]: client 10.135.16.207#57007: updating zone 'doa.xxxxxxx.net/NONE': update failed: rejected by secure update (REFUSED)
Jan  7 11:58:19 vp-s01 named[9471]: samba_dlz: cancelling transaction on zone doa.xxxxxxx.net
Jan  7 11:58:21 vp-s01 dhcpd: DHCPINFORM from 10.135.16.206 via 10.135.16.1
Jan  7 11:58:21 vp-s01 dhcpd: DHCPACK to 10.135.16.206 (d4:be:d9:e1:ef:15) via eth0
Jan  7 11:58:25 vp-s01 named[9471]: client 10.135.16.207#57007: request has invalid signature: TSIG 1436-ms-7.6-1019dc9.f3851449-5891-11e2-f386-d067e5262a72 (vp-12g\$\@DOA.XXXXXXX.NET): tsig verify failure (BADSIG)
#7

Huh? In /etc/service/univention-bind-samba4 liegt eine Datei _default.tsigkeys die scheinbar irgndwelche DNS-Update Daten für das fehlschlagende Update beinhaltet (zu erkennen am String vp-12g$@DOA.XXXXXXX.NET). Der Timestamp der Datei liegt beim Zeitpunkt des Neustarts des Dienstes. Soll das so sein?

root@vp-s01:~# ls -lh /etc/service/univention-bind-samba4
total 47M
-rw------- 1 root root  95M Jan  5 18:58 core
-rw------- 1 root root 3.5K Jan  7 11:55 _default.tsigkeys
-rw-r--r-- 1 root root    0 Jul 12 12:34 down
lrwxrwxrwx 1 root root   41 Jan  5 17:41 finish -> /usr/share/univention-runit/sleep-dynamic
-rwxr-xr-x 1 root root 1.9K Jan  5 17:46 run
drwx------ 2 root root 4.0K Jan  7 11:55 supervise
#8

Ich stelle gerade fest, dass die UDP Receive Queue des nmbd auf dem File Server scheinbar auch nicht abgebaut wird:

root@vp-s01:~# netstat -nulp4 | egrep -v '^udp +0'
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
udp   228096      0 10.135.3.11:53          0.0.0.0:*                           9471/named      
root@vp-s01:~# ssh root@10.135.3.17 netstat -nulp4 | egrep -v '^udp +0'
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
udp   229632      0 10.135.3.17:137         0.0.0.0:*                           1399/nmbd       
udp    10240      0 10.135.3.255:138        0.0.0.0:*                           1399/nmbd       
udp    10240      0 0.0.0.0:138             0.0.0.0:*                           1399/nmbd

Evtl. ein (wie auch immer gearteter) Deadlock zwischen den beiden Systemen?

#9

Am Samstag gab es kurz nach dem Update scheinbar einen Segmentation Fault im named-Prozess. Seitdem wurde dieser aber ein paar mal neu gestartet.

root@vp-s01:~# dmesg | grep named
[   30.414072] RPC: Registered named UNIX socket transport module.
[ 3138.746597] named[2354]: segfault at b0 ip 00007fb825fa1bb0 sp 00007fb8220fc638 error 4 in libdns.so.81.1.3[7fb825e63000+188000]
root@vp-s01:~# grep named /var/log/kern.log.1
Jan  5 18:06:29 vp-s01 kernel: [   30.414072] RPC: Registered named UNIX socket transport module.
Jan  5 18:58:23 vp-s01 kernel: [ 3138.746597] named[2354]: segfault at b0 ip 00007fb825fa1bb0 sp 00007fb8220fc638 error 4 in libdns.so.81.1.3[7fb825e63000+188000]
#10

Die Theorie dass der File Server das Problem auslöst ist hinfällig: Nach einem Shutdown der File Server VM und einem Reboot des Hosts zeigt sich das gleiche Problem. Es sieht wohl doch eher nach einem Konfigurationsproblem aus (s. “permission denied” unten):

Jan  7 13:36:51 vp-s01 named[2397]: starting BIND 9.8.0-P4 -c /etc/bind/named.conf.samba4 -f
Jan  7 13:36:51 vp-s01 named[2397]: built with '--prefix=/usr' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc/bind' '--localstatedir=/var' '--enable-threads' '--enabl
e-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-dlz-dlopen' '--with-geoip=/usr' '--enable-ipv6' 'CFLAGS=-fno-strict-aliasing -DDIG_SIGCHASE -O2' 'LDFLAGS=' 'CP
PFLAGS='
Jan  7 13:36:51 vp-s01 named[2397]: adjusted limit on open files from 4096 to 1048576
Jan  7 13:36:51 vp-s01 named[2397]: found 4 CPUs, using 4 worker threads
Jan  7 13:36:51 vp-s01 named[2397]: using up to 4096 sockets
Jan  7 13:36:51 vp-s01 named[2397]: loading configuration from '/etc/bind/named.conf.samba4'
Jan  7 13:36:51 vp-s01 named[2397]: reading built-in trusted keys from file '/etc/bind/bind.keys'
Jan  7 13:36:51 vp-s01 named[2397]: using default UDP/IPv4 port range: [1024, 65535]
Jan  7 13:36:51 vp-s01 named[2397]: using default UDP/IPv6 port range: [1024, 65535]
Jan  7 13:36:51 vp-s01 named[2397]: listening on IPv4 interface lo, 127.0.0.1#53
Jan  7 13:36:51 vp-s01 named[2397]: listening on IPv4 interface eth0, 10.135.3.11#53
Jan  7 13:36:51 vp-s01 named[2397]: generating session key for dynamic DNS
Jan  7 13:36:51 vp-s01 named[2397]: Loading 'samba4.zone' using driver dlopen
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: started for DN DC=doa,DC=xxxxxxx,DC=net
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: starting configure
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: trying container 'CN=MicrosoftDNS,CN=System,DC=doa,DC=xxxxxxx,DC=net'
ok: run: univention-bind-samba4: (pid 2397) 0s, normally down
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: configured writeable zone '16.135.10.in-addr.arpa'
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: trying container 'CN=MicrosoftDNS,CN=System,DC=doa,DC=xxxxxxx,DC=net'
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: configured writeable zone '3.135.10.in-addr.arpa'
Jan  7 13:36:51 vp-s01 named[2397]: samba_dlz: trying container 'CN=MicrosoftDNS,CN=System,DC=doa,DC=xxxxxxx,DC=net'
Jan  7 13:36:52 vp-s01 named[2397]: samba_dlz: configured writeable zone 'doa.xxxxxxx.net'
Jan  7 13:36:52 vp-s01 named[2397]: set up managed keys zone for view _default, file 'managed-keys.bind'
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 0.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 127.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 254.169.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 2.0.192.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 100.51.198.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 113.0.203.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 255.255.255.255.IN-ADDR.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: 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
Jan  7 13:36:52 vp-s01 named[2397]: 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
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: D.F.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 8.E.F.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 9.E.F.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: A.E.F.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: B.E.F.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: automatic empty zone: 8.B.D.0.1.0.0.2.IP6.ARPA
Jan  7 13:36:52 vp-s01 named[2397]: none:0: open: /etc/bind/rndc.key: permission denied
Jan  7 13:36:52 vp-s01 named[2397]: couldn't add command channel 127.0.0.1#953: permission denied
Jan  7 13:36:52 vp-s01 named[2397]: none:0: open: /etc/bind/rndc.key: permission denied
Jan  7 13:36:52 vp-s01 named[2397]: couldn't add command channel ::1#953: permission denied
Jan  7 13:36:52 vp-s01 named[2397]: managed-keys-zone ./IN: loading from master file managed-keys.bind failed: file not found
Jan  7 13:36:52 vp-s01 named[2397]: managed-keys-zone ./IN: loaded serial 0
Jan  7 13:36:52 vp-s01 named[2397]: running
Jan  7 13:36:56 vp-s01 named[2397]: error (network unreachable) resolving './NS/IN': 2001:7fd::1#53
Jan  7 13:40:08 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:40::1#53
Jan  7 13:40:08 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:e::1#53
Jan  7 13:40:09 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:c::1#53
Jan  7 13:40:09 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:48::1#53
Jan  7 13:40:10 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:b::1#53
Jan  7 13:40:11 vp-s01 named[2397]: error (network unreachable) resolving 'vs1.nagios.org/A/IN': 2001:500:f::1#53
Jan  7 13:40:15 vp-s01 named[2397]: success resolving 'vs1.nagios.org/A' (in 'nagios.org'?) after reducing the advertised EDNS UDP packet size to 512 octets
#11

Die ‘permission denied’-Fehler für /etc/bind/rndc.key sind etwas dubios da der named-Prozess scheinbar als root läuft und die Datei auch sonst prinzipiell die korrekten Berechtigungen hat:

root@vp-s01:~# ps -eo pid,euser,egroup,args | grep named
12249 root     root     /usr/sbin/named -c /etc/bind/named.conf.samba4 -f
root@vp-s01:~# ls -alR /etc/bind
/etc/bind:
total 112
drwxrwsr-x   3 root bind  4096 Jan  7 14:07 .
drwxr-xr-x 112 root root 12288 Jan  7 14:08 ..
-rw-rw-r--   1 root root  2389 Jul  2  2012 bind.keys
-rw-rw-r--   1 root root   237 Jul  2  2012 db.0
-rw-rw-r--   1 root root   271 Jul  2  2012 db.127
-rw-rw-r--   1 root root   237 Jul  2  2012 db.255
-rw-rw-r--   1 root root   353 Jul  2  2012 db.empty
-rw-rw-r--   1 root root   270 Jul  2  2012 db.local
-rw-rw-r--   1 root root  2994 Jul  2  2012 db.root
-rw-rw-r--   1 root root    16 May 21  2007 db.root.fake
-rw-rw-r--   1 root bind    23 Aug 15 14:17 local.conf
-rw-rw-r--   1 root bind    23 Aug 15 14:17 local.conf.proxy
-rw-rw-r--   1 root bind    23 Aug 15 14:17 local.conf.samba4
-rw-r--r--   1 root bind    74 Jan  5 17:46 local-predlz.conf.samba4
-rw-rw-r--   1 root bind   680 Jan  5 17:46 named.conf
-rw-rw-r--   1 root bind   463 Jul  2  2012 named.conf.debian
-rw-rw-r--   1 root bind   490 Jul  2  2012 named.conf.default-zones
-rw-rw-r--   1 root bind   165 Jul  2  2012 named.conf.local
-rw-rw-r--   1 root bind   572 Jul  2  2012 named.conf.options
-rw-r--r--   1 root bind  1270 Jan  5 17:46 named.conf.proxy
-rw-r--r--   1 root bind  1600 Jan  5 17:46 named.conf.samba4
-rw-rw----   1 bind bind    77 Aug 15 14:17 rndc.key
-rw-rw-r--   1 root bind   178 Dec 12 13:53 univention.conf
drwxrwsr-x   2 root bind  4096 Sep 19 00:28 univention.conf.d
-rw-rw-r--   1 root bind   196 Dec 12 13:53 univention.conf.proxy
-rw-rw-r--   1 root root  1317 Jul  2  2012 zones.rfc1918

/etc/bind/univention.conf.d:
total 32
drwxrwsr-x 2 root bind 4096 Sep 19 00:28 .
drwxrwsr-x 3 root bind 4096 Jan  7 14:07 ..
-rw-r----- 1 root bind  275 Sep 19 00:28 16.135.10.in-addr.arpa
-rw-r--r-- 1 root bind  120 Sep 19 00:28 16.135.10.in-addr.arpa.proxy
-rw-r----- 1 root bind  273 Sep 19 00:28 3.135.10.in-addr.arpa
-rw-r--r-- 1 root bind  118 Sep 19 00:28 3.135.10.in-addr.arpa.proxy
-rw-r----- 1 root bind  261 Sep 19 00:28 doa.xxxxxxx.net
-rw-r--r-- 1 root bind  106 Sep 19 00:28 doa.xxxxxxx.net.proxy
#12

Laut strace -f scheint sich einer der named-Threads mit dem byteweisen Locken/Unlocken von ldb-Dateien die Zeit zu vertreiben. WTF?

[pid 19533] stat("/var/lib/samba/private/sam.ldb", {st_mode=S_IFREG|0600, st_size=3149824, ...}) = 0
[pid 19533] open("/var/lib/samba/private/sam.ldb", O_RDWR|O_CREAT, 0600) = 9
[...]
[pid 19533] mkdir("/var/lib/samba/private/sam.ldb.d", 0700) = -1 EEXIST (File exists)
[pid 19533] stat("/var/lib/samba/private/sam.ldb.d/DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", {st_mode=S_IFREG|0600, st_size=48410624, ...}) = 0
[pid 19533] open("/var/lib/samba/private/sam.ldb.d/DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", O_RDWR|O_CREAT, 0600) = 10
[...]
[pid 19533] mkdir("/var/lib/samba/private/sam.ldb.d", 0700) = -1 EEXIST (File exists)
[pid 19533] stat("/var/lib/samba/private/sam.ldb.d/CN%3DCONFIGURATION,DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", {st_mode=S_IFREG|0600, st_size=19005440, ...}) = 0
[pid 19533] open("/var/lib/samba/private/sam.ldb.d/CN%3DCONFIGURATION,DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", O_RDWR|O_CREAT, 0600) = 11
[...]
[pid 19533] mkdir("/var/lib/samba/private/sam.ldb.d", 0700) = -1 EEXIST (File exists)
[pid 19533] stat("/var/lib/samba/private/sam.ldb.d/CN%3DSCHEMA,CN%3DCONFIGURATION,DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", {st_mode=S_IFREG|0600, st_size=20873216, ...}) = 0
[pid 19533] open("/var/lib/samba/private/sam.ldb.d/CN%3DSCHEMA,CN%3DCONFIGURATION,DC%3DDOA,DC%3DXXXXXXX,DC%3DNET.ldb", O_RDWR|O_CREAT, 0600) = 12
[...]
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=16836, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=16836, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=16836, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=16836, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(9, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(12, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=21596, len=1}) = 0
[pid 19533] fcntl(12, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=21596, len=1}) = 0
[pid 19533] fcntl(12, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(12, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=1796, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=1796, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] brk(0x9a3000)               = 0x9a3000
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=11148, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=11148, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=38300, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=24896, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] fcntl(11, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=25956, len=1}) = 0
[pid 19533] time(NULL)                  = 1357564933
[...]
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=812, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=20620, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=20620, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=28148, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=28148, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=13964, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=13964, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=2960, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=2960, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=36368, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=36368, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=3200, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=3200, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=14340, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=14340, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=29808, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=29808, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=36476, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=36476, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=25124, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=25124, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=10920, len=1}) = 0
[pid 19533] fcntl(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=10920, len=1}) = 0
#13

Ich habe [bug]28583[/bug] entdeckt. ldbsearch -H /var/lib/samba/private/sam.ldb --cross-ncs sowie samba-tool dbcheck --cross-ncs laufen aber durch. Langsam bin ich mit meinem Latein am Ende…

#14

Zum Problem mit dem rndc.key habe ich Bug [bug]25358[/bug] gefunden. Es behebt das Problem aber leider nicht, die Receive Queue läuft nache inem Neustart des File Servers wieder voll:

root@vp-s01:~# netstat -lnup | grep :53
udp        0      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp        0      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    23808      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    27648      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    26880      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    29696      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    35072      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    38656      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    41984      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    48640      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    57856      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    87040      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    99840      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named

… Moment… nachdem ich dies schrieb guckte ich gerade noch einmal und es sieht so aus als ob die Queue wieder abgebaut wird:

root@vp-s01:~# netstat -lnup | grep :53
udp    49152      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    47104      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    41728      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    38656      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    36352      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    31488      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    31488      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    26112      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp    28672      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named     
root@vp-s01:~# netstat -lnup | grep :53
udp        0      0 10.135.3.11:53          0.0.0.0:*                           32475/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           32475/named
#15

Hallo,

wenn ich richtig lese, hast du Probleme mit dem DNS Server nach dem Update auf 3.1.
Du könntest testweiße auf dem internen dns server von samba4 umsteigen.

/etc/samba/smb.conf bei services ein “+” vor dem dns setzen. bind stoppen, samba4 neu starten, dann sollte der dns über samba4 aufgelöst werden…

Auch ich hab bereits Probleme mit dem named dns festgestellt, und auf dem samba4 vorübergehend ausgeweicht…
Eventuell auch für dich eine vorübergehende Lösung

lG

#16

Da hatte ich auch schon drüber nachgedacht, möchte aber gerne sowenig es geht von der von Univention unterstützten Lösung abweichen. Wer weiß was ich mir da sonst noch für (andere) Kopfschmerzen einhandele.

#17

Existieren Hinweise in den Samba Logdateien oder in der Datei /var/log/daemon.log? Wenn möglich einmal den Samba Debug Level temporär auf 5 setzen.

#18

Auch dort (in /var/log/samba/log.samba.old) finden sich Hinweise auf das fehlgeschlagene DNS-Update:

[2013/01/07 16:06:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 16:06:28,  1] ../source4/dsdb/kcc/kcc_deleted.c:105(kccsrv_check_deleted)
  Doing a full scan on CN=Configuration,DC=doa,DC=xxxxxxx,DC=net and looking for deleted object
[2013/01/07 16:06:28,  1] ../source4/dsdb/kcc/kcc_deleted.c:105(kccsrv_check_deleted)
  Doing a full scan on DC=doa,DC=xxxxxxx,DC=net and looking for deleted object
[2013/01/07 16:16:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 16:26:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 16:36:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 16:46:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 16:56:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 17:06:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT
[2013/01/07 17:16:28,  0] ../source4/dsdb/dns/dns_update.c:294(dnsupdate_nameupdate_done)
  ../source4/dsdb/dns/dns_update.c:294: Failed DNS update - NT_STATUS_IO_TIMEOUT

Mir fiel übrigens erst später auf, dass ca. um 17.00 (also als der UDP-Port 53 keine Probleme mehr machte) der Client VP-12G (der mit den DNS-Updates) abgeschaltet wurde…

#19

Stand jetzt (VP-12G ist vermutlich wieder an, ich bin noch nicht beim Kunden):

root@vp-s01:~# netstat -lnup | grep :53
udp   230400      0 10.135.3.11:53          0.0.0.0:*                           29409/named     
udp        0      0 127.0.0.1:53            0.0.0.0:*                           29409/named
root@vp-s01:~# dig +notcp +short @10.135.3.11 example.com
;; connection timed out; no servers could be reached
#20

Hallo,

mit dem Errata Update 18 wurde die Performance bei DNS Abfragen mit dem Samba 4 Backend deutlich verbessert. Ich würde daher empfehlen zu prüfen ob sich das Verhalten auch nach dem Einspielen des Updates noch reproduzieren lässt.

Mit freundlichen Grüßen
Janis Meybohm

Mastodon