named shutdown blocks on dnstap Unix domain socket
Summary
When using a Unix domain socket for dnstap output, named blocks when shutting down (either using rndc stop
or kill -TERM
) if the socket is connected and the dnstap server process is not consuming messages.
BIND version used
Affects both 9.16 and 9.18 (tested on FreeBSD)
Steps to reproduce
- Configure dnstap to use a Unix domain socket.
- Start a dnstap server process (for example dnstap/golang-dnstap).
- Let named process some queries
- Stop the dnstap process either with
kill -STOP
or using ctrl-Z if running in foreground - Send some more queries to named to make sure there are unprocessed dnstap messages
- Try to stop named using
rndc stop
orkill -TERM
What is the current bug behavior?
The named process stays blocked forever.
It won't exit unless the dnstap server process is killed or resumed, consuming the messages buffered in the Unix socket.
The process has closed all of its descriptors, so it won't answer queries nor respond to rndc
.
What is the expected correct behavior?
The process should terminate. Maybe a short timeout would be in order, but it should not block on dnstap output.
Relevant configuration files
# named-checkconf -px
logging {
channel "graylog" {
syslog "local1";
severity info;
print-time iso8601-utc;
print-category yes;
};
category "default" {
"graylog";
};
};
options {
directory "/usr/local/etc/namedb/working";
dnstap-output unix"/tmp/dnstap.sock";
dump-file "/var/dump/named_dump.db";
listen-on {
127.0.0.1/32;
};
listen-on {
192.168.1.155/32;
};
listen-on-v6 {
::1/128;
X:Y:Z:5353::1/128;
X:Y:Z:5353::2/128;
};
pid-file "/var/run/named/pid";
querylog yes;
recursive-clients 256;
statistics-file "/var/stats/named.stats";
allow-recursion {
127.0.0.1/32;
192.168.1.0/24;
192.168.2.0/24;
192.168.3.0/24;
192.168.0.0/16;
::1/128;
X:Y:Z::/48;
};
disable-empty-zone "255.255.255.255.IN-ADDR.ARPA";
disable-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";
disable-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";
dnssec-validation auto;
dnstap {
all;
};
max-cache-size 16777216;
query-source address X.Y.Z.T port 0;
request-nsid no;
resolver-query-timeout 20000;
send-cookie no;
stale-answer-enable no;
allow-query {
127.0.0.1/32;
192.168.1.0/24;
192.168.2.0/24;
192.168.3.0/24;
X.Y.Z.T/32;
192.168.0.0/16;
::1/128;
X:Y:Z::/48;
};
transfer-source X.Y.Z.T;
};
statistics-channels {
inet 127.0.0.1 port 8053 allow {
127.0.0.1/32;
};
};
server 82.159.210.51/32 {
send-cookie no;
};
server 2001:500:94::/48 {
bogus yes;
};
server 204.13.251.136/32 {
bogus yes;
};
server 208.78.71.136/32 {
bogus yes;
};
zone "." {
type mirror;
};
zone "localhost" {
type master;
file "/usr/local/etc/namedb/primary/localhost-forward.db";
};
zone "127.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/localhost-reverse.db";
};
zone "255.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "rpzzone" {
type master;
file "/usr/local/etc/namedb/primary/rpz.db";
};
zone "0.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/localhost-reverse.db";
};
zone "0.0.192.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "test" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "example" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "invalid" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "example.com" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "example.net" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "example.org" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "18.198.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "19.198.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "240.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "241.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "242.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "243.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "244.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "245.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "246.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "247.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "248.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "249.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "250.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "251.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "252.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "253.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "254.in-addr.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "1.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "3.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "4.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "5.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "6.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "7.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "8.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "9.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "a.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "b.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "c.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "d.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "e.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "0.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "1.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "2.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "3.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "4.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "5.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "6.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "7.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "8.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "9.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "a.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "b.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "0.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "1.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "2.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "3.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "4.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "5.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "6.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "7.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "c.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "d.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "c.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "d.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "e.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "f.e.f.ip6.arpa" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
zone "ip6.int" {
type master;
file "/usr/local/etc/namedb/primary/empty.db";
};
Relevant logs and/or screenshots
9943 100117 named SCTL "kern.hostname"
9943 100117 named RET __sysctl 0
9943 100117 named CALL getpid
9943 100117 named RET getpid 9943/0x26d7
9943 100117 named CALL sendto(0x3,0x7fffffffc3b0,0x6c,0,0,0)
9943 100117 named GIO fd 3 wrote 108 bytes
"<142>1 2022-05-30T10:32:37.874081+00:00 elnuc named 9943 - - 2022-05-3\
0T10:32:37.874Z dnstap: closing dnstap"
9943 100117 named RET sendto 108/0x6c
9943 100117 named CALL _umtx_op(0x802102000,0x2<UMTX_OP_WAIT>,0x32d6e,0,0)
After resuming the dnstap process,
9943 208238 named GIO fd 78 wrote 4096 bytes
(some data written)
9943 208238 named RET sendmsg 8153/0x1fd9
9943 208238 named CALL sendmsg(0x4e,0x7fffdedf4ec0,0x20000<MSG_NOSIGNAL>)
9943 208238 named GIO fd 78 wrote 4096 bytes
(more data)
9943 208238 named RET sendmsg 7236/0x1c44
9943 208238 named CALL sendmsg(0x4e,0x7fffdedf4e30,0x20000<MSG_NOSIGNAL>)
9943 208238 named GIO fd 78 wrote 12 bytes
0x0000 0000 0000 0000 0004 0000 0003 |............|
9943 208238 named RET sendmsg 12/0xc
9943 208238 named CALL read(0x4e,0x7fffdedf4edc,0x4)
9943 208238 named GIO fd 78 read 4 bytes
"\0\0\0\0"
9943 208238 named RET read 4
9943 208238 named CALL read(0x4e,0x7fffdedf4edc,0x4)
9943 208238 named GIO fd 78 read 4 bytes
0x0000 0000 0004 |....|
9943 208238 named RET read 4
9943 208238 named CALL read(0x4e,0x7fffdedf4eb0,0x4)
9943 208238 named GIO fd 78 read 4 bytes
0x0000 0000 0005 |....|
9943 208238 named RET read 4
9943 208238 named CALL close(0x4e)
9943 208238 named RET close 0
9943 208238 named CALL madvise(0x802f79000,0x16000,MADV_FREE)
9943 208238 named RET madvise 0
9943 208238 named CALL madvise(0x801570000,0x1d000,MADV_FREE)
9943 208238 named RET madvise 0
9943 208238 named CALL madvise(0x8014c9000,0x5000,MADV_FREE)
9943 208238 named RET madvise 0
9943 208238 named CALL madvise(0x801526000,0x27000,MADV_FREE)
9943 208238 named RET madvise 0
9943 208238 named CALL madvise(0x80159c000,0x5e000,MADV_FREE)
9943 208238 named RET madvise 0
9943 208238 named CALL thr_exit(0x802102000)
9943 100117 named RET _umtx_op 0 **LOOKS LIKE IT WAS BLOCKED HERE**
9943 100117 named CALL __sysctl(0x7fffffffa2f0,0x2,0x7fffffffe400,0x7fffffffa2e8,0,0)
9943 100117 named SCTL "kern.hostname"
9943 100117 named RET __sysctl 0
9943 100117 named CALL getpid
9943 100117 named RET getpid 9943/0x26d7
9943 100117 named CALL sendto(0x3,0x7fffffffc400,0x66,0,0,0)
9943 100117 named GIO fd 3 wrote 102 bytes
"<141>1 2022-05-30T10:47:41.246758+00:00 elnuc named 9943 - - 2022-05-3\
0T10:47:41.246Z general: exiting"
9943 100117 named RET sendto 102/0x66
9943 100117 named CALL close(0x4)
9943 100117 named RET close 0
9943 100117 named CALL close(0x3)
9943 100117 named RET close 0
9943 100117 named CALL unlink(0x8020eba80)
9943 100117 named NAMI "/var/run/named/pid"
Possible fixes
(If you can, link to the line of code that might be responsible for the problem.)