On FreeBSD the very first invocation of `dnsdist -c` fails with `Fatal error: EOF while reading message` after a dnsdist restart

[tykling]

• [X] This is not a support question, I have read about opensource and will send support questions to the IRC channel, Github Discussions or the mailing list.
• [X] I have read and understood the 'out in the open' support policy

• Program: dnsdist
• Issue type: Bug report

Short description

After restarting dnsdist the first time I run dnsdist -c it fails with an error instead of entering the dnsdist console.

Environment

• Operating system: FreeBSD (multiple versions, currently 13-STABLE as of january)
• Software version: dnsdist 1.9.0 (also observed in earlier versions)
• Software source: built by my own poudriere from FreeBSD ports with the following options:

  [tykling@poudriere2 ~]$ cat /usr/local/etc/poudriere.d/options/dns_dnsdist/options 
  # This file is auto-generated by 'make config'.
  # Options for dnsdist-1.5.0
  _OPTIONS_READ=dnsdist-1.5.0
  _FILE_COMPLETE_OPTIONS_LIST=DNSTAP SNMP LUA LUAJIT LUAJITOR GNUTLS OPENSSL CDB LMDB
  OPTIONS_FILE_UNSET+=DNSTAP
  OPTIONS_FILE_UNSET+=SNMP
  OPTIONS_FILE_SET+=LUA
  OPTIONS_FILE_UNSET+=LUAJIT
  OPTIONS_FILE_UNSET+=LUAJITOR
  OPTIONS_FILE_SET+=GNUTLS
  OPTIONS_FILE_SET+=OPENSSL
  OPTIONS_FILE_SET+=CDB
  OPTIONS_FILE_SET+=LMDB
  [tykling@poudriere2 ~]$ 

  These are the default options for the port https://www.freshports.org/dns/dnsdist and my buildlogs can be seen here https://poudriere.tyknet.dk/data/latest-per-pkg/dnsdist/

Steps to reproduce

The config doesn't appear to matter much but here is my dnsdist.conf:

-- Client listeners

addTLSLocal('0.0.0.0:853', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305'})
addTLSLocal('[::]:853', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305'})

addDOHLocal('0.0.0.0:443', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { "/", "/dns-query" }, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305', customResponseHeaders={ ["Strict-Transport-Security"]="max-age=31536000; includeSubDomains; preload" }})
addDOHLocal('[::]:443', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { "/", "/dns-query" }, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305', customResponseHeaders={ ["Strict-Transport-Security"]="max-age=31536000; includeSubDomains; preload" }})

addDOQLocal('0.0.0.0:853', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305'})
addDOQLocal('[::]:853', {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.rsa.crt', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-chain.ecdsa.crt'}, {'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.rsa.key', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-keypair.ecdsa.key'}, { ocspResponses={'/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.rsa.ocsp', '/usr/local/etc/certgrinder/certificates/deic-lgb.anycast.censurfridns.dk-response.ecdsa.ocsp'}, minTLSVersion='tls1.2', ciphers='ECDHE-ECDSA-AES128-GCM-SHA256,ECDHE-RSA-AES128-GCM-SHA256,ECDHE-ECDSA-AES256-GCM-SHA384,ECDHE-RSA-AES256-GCM-SHA384,ECDHE-ECDSA-CHACHA20-POLY1305,ECDHE-RSA-CHACHA20-POLY1305'})

-- Upstream DNS servers
-- backend
newServer ({
    address="::1",
    name="backend",
})

-- ACL
addACL('0.0.0.0/0')
addACL('::/0')

-- Cache
pc = newPacketCache(100000, {maxTTL=86400, minTTL=0, temporaryFailureTTL=60, staleTTL=60, dontAge=false})
getPool(""):setCache(pc)

-- Console management
controlSocket('127.0.0.1:5199')
controlSocket('[::1]:5199')
-- generate with: openssl rand 32 | base64
setKey("hunter12base64")
addConsoleACL("130.225.244.166/32")
addConsoleACL("fe80::5a9c:fcff:fe0a:e52f%vtnet0/128")

-- Web management
webserver("127.0.0.1:8083")
webserver("[::1]:8083")
setWebserverConfig({password="hunter12hash", apiKey="hunter12hash", acl="127.0.0.1,[::1]"})

-- custom config below here
map = { newDOHResponseMapEntry("^$", 307, "https://blog.uncensoreddns.org") }
dohFE = getDOHFrontend(0)
dohFE:setResponsesMap(map)
dohFE6 = getDOHFrontend(1)
dohFE6:setResponsesMap(map)

The issue looks like this:

[tykling@deic-lgb ~]$ sudo dnsdist -c
> quit
[tykling@deic-lgb ~]$ sudo supervisorctl restart dnsdist
dnsdist: stopped
dnsdist: started
[tykling@deic-lgb ~]$ sudo dnsdist -c
Fatal error: EOF while reading message
[tykling@deic-lgb ~]$ sudo dnsdist -c
> quit
[tykling@deic-lgb ~]$ sudo dnsdist -c
> quit
[tykling@deic-lgb ~]$ sudo supervisorctl restart dnsdist
dnsdist: stopped
dnsdist: started
[tykling@deic-lgb ~]$ sudo dnsdist -c
Fatal error: EOF while reading message
[tykling@deic-lgb ~]$ sudo dnsdist -c
> quit
[tykling@deic-lgb ~]$ 

Expected behaviour

To enter the dnsdist console every time

Actual behaviour

Fatal error: EOF while reading message

Other information

This is truss(1) output from a failing case:

[tykling@deic-lgb ~]$ sudo truss dnsdist -c
mmap(0x0,135168,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 58965437853696 (0x35a0f5fa3000)
mprotect(0x4e7af9758000,4096,PROT_READ)          = 0 (0x0)
issetugid()                                      = 0 (0x0)
sigfastblock(0x1,0x4e7af975a770)                 = 0 (0x0)
__sysctl("kern.ostype",2,0x4e7af975a0ca,0x35a0f5e44060,0x0,0) = 0 (0x0)
__sysctl("kern.hostname",2,0x4e7af975a1ca,0x35a0f5e44060,0x0,0) = 0 (0x0)
__sysctl("kern.osrelease",2,0x4e7af975a2ca,0x35a0f5e44060,0x0,0) = 0 (0x0)
__sysctl("kern.version",2,0x4e7af975a3ca,0x35a0f5e44060,0x0,0) = 0 (0x0)
__sysctl("hw.machine",2,0x4e7af975a4ca,0x35a0f5e44060,0x0,0) = 0 (0x0)
open("/etc/libmap.conf",O_RDONLY|O_CLOEXEC,036576460030) = 3 (0x3)
fstat(3,{ mode=-rw-r--r-- ,inode=511138,size=35,blksize=4096 }) = 0 (0x0)
............snip....................
read(5,"\M-Ve3\M^G",4)                           = 4 (0x4)
read(5,"\r\^V9\M^Z",4)                           = 4 (0x4)
read(5,"t\M-D\M-,\t",4)                          = 4 (0x4)
read(5,"\M^Q@\M-D\M-=",4)                        = 4 (0x4)
read(5,"\M-pQ\M-l\M-~",4)                        = 4 (0x4)
read(5,"\M^SH\M-S\M-N",4)                        = 4 (0x4)
close(5)                                         = 0 (0x0)
socket(PF_INET,SOCK_DGRAM|SOCK_CLOEXEC,0)        = 5 (0x5)
ioctl(5,SIOCGIFINDEX,0x35a0f5e43c20)             = 0 (0x0)
close(5)                                         = 0 (0x0)
madvise(0x35a1214ad200,91,MADV_NOCORE)           = 0 (0x0)
mlock(0x35a1214ad200,91)                         = 0 (0x0)
madvise(0x35a1215b76f0,32,MADV_NOCORE)           = 0 (0x0)
mlock(0x35a1215b76f0,32)                         = 0 (0x0)
madvise(0x35a0f5e43de1,0,MADV_CORE)              = 0 (0x0)
munlock(0x35a0f5e43de1,0)                        = 0 (0x0)
madvise(0x35a0f5e43de1,0,MADV_CORE)              = 0 (0x0)
munlock(0x35a0f5e43de1,0)                        = 0 (0x0)
madvise(0x35a1214ad200,91,MADV_NOCORE)           = 0 (0x0)
mlock(0x35a1214ad200,91)                         = 0 (0x0)
madvise(0x35a1215b77b0,32,MADV_NOCORE)           = 0 (0x0)
mlock(0x35a1215b77b0,32)                         = 0 (0x0)
madvise(0x35a0f5e43de1,0,MADV_CORE)              = 0 (0x0)
munlock(0x35a0f5e43de1,0)                        = 0 (0x0)
madvise(0x35a0f5e43de1,0,MADV_CORE)              = 0 (0x0)
munlock(0x35a0f5e43de1,0)                        = 0 (0x0)
lseek(4,0x0,SEEK_CUR)                            = 6254 (0x186e)
lseek(4,0x0,SEEK_SET)                            = 0 (0x0)
lseek(4,0x186e,SEEK_SET)                         = 6254 (0x186e)
close(4)                                         = 0 (0x0)
socket(PF_INET6,SOCK_STREAM,0)                   = 4 (0x4)
connect(4,{ AF_INET6 [::1]:5199 },28)            = 0 (0x0)
setsockopt(4,IPPROTO_TCP,TCP_NODELAY,0x35a0f5e4448c,4) = 0 (0x0)
getrandom("|\M-D2\M^S\M-<q\r\M^R\M^A\M-G\\"...,24,0) = 24 (0x18)
write(4,"|\M-D2\M^S\M-<q\r\M^R\M^A\M-G\\"...,24) = 24 (0x18)
read(4,0x35a0f5e447b0,24)                        ERR#54 'Connection reset by peer'
fstatat(AT_FDCWD,"/usr/share/nls/C/libc.cat",0x35a0f5e441e0,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/share/nls/libc/C",0x35a0f5e441e0,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/local/share/nls/C/libc.cat",0x35a0f5e441e0,0x0) ERR#2 'No such file or directory'
fstatat(AT_FDCWD,"/usr/local/share/nls/libc/C",0x35a0f5e441e0,0x0) ERR#2 'No such file or directory'
close(4)                                         = 0 (0x0)
fstat(1,{ mode=crw--w---- ,inode=100,size=0,blksize=4096 }) = 0 (0x0)
ioctl(1,TIOCGETA,0x35a0f5e44340)                 = 0 (0x0)
Fatal error: failed in readn2: Connection reset by peer
write(1,"Fatal error: failed in readn2: C"...,56) = 56 (0x38)
exit(0x1)
process exit, rval = 1
[tykling@deic-lgb ~]$ 

Looks like it fails writing right after getrandom(). dnsdist is serving requests just fine during this by the way.

This is a truss(1) of a working case:

............snip....................
read(5,"\M-IK\M-4\M-!",4)                        = 4 (0x4)           
read(5,"\^\\M-|\M^Z\M^H",4)                      = 4 (0x4)                        
read(5,"\M-/\M^I\M-rl",4)                        = 4 (0x4)                        
read(5,"\M^J\M-0\M-=1",4)                        = 4 (0x4)        
close(5)                                         = 0 (0x0)                      
socket(PF_INET,SOCK_DGRAM|SOCK_CLOEXEC,0)        = 5 (0x5)    
ioctl(5,SIOCGIFINDEX,0x13373b562b80)             = 0 (0x0)               
close(5)                                         = 0 (0x0)                
madvise(0x13376af57200,91,MADV_NOCORE)           = 0 (0x0)                                                                                                                 
mlock(0x13376af57200,91)                         = 0 (0x0)                                                                                                                                                                                                                                                                                             
madvise(0x13376b0616f0,32,MADV_NOCORE)           = 0 (0x0)                                                                                                                 
mlock(0x13376b0616f0,32)                         = 0 (0x0)                                                                                                                 
madvise(0x13373b562d41,0,MADV_CORE)              = 0 (0x0)                                                                                                                                                                                                                                                                                             
munlock(0x13373b562d41,0)                        = 0 (0x0)                                                                                                                 
madvise(0x13373b562d41,0,MADV_CORE)              = 0 (0x0)                                                                                                                 
munlock(0x13373b562d41,0)                        = 0 (0x0)                                                                                                                                                                                                                                                                                             
madvise(0x13376af57200,91,MADV_NOCORE)           = 0 (0x0)                                                                                                                 
mlock(0x13376af57200,91)                         = 0 (0x0)                                                                                                                 
madvise(0x13376b0617b0,32,MADV_NOCORE)           = 0 (0x0)                                                                                                                                                                                                                                                                                             
mlock(0x13376b0617b0,32)                         = 0 (0x0)                                                                                                                 
madvise(0x13373b562d41,0,MADV_CORE)              = 0 (0x0)                                                                                                                 
munlock(0x13373b562d41,0)                        = 0 (0x0)                                                                                                                                                                                                                                                                                             
madvise(0x13373b562d41,0,MADV_CORE)              = 0 (0x0)                                                                                                                 
munlock(0x13373b562d41,0)                        = 0 (0x0)                                                                                                                 
lseek(4,0x0,SEEK_CUR)                            = 6254 (0x186e)                                                                                                                                                                                                                                                                                       
lseek(4,0x0,SEEK_SET)                            = 0 (0x0)                                                                                                                 
lseek(4,0x186e,SEEK_SET)                         = 6254 (0x186e)                                                                                                           
close(4)                                         = 0 (0x0)                                                                                                                                                                                                                                                                                             
socket(PF_INET6,SOCK_STREAM,0)                   = 4 (0x4)                                                                                                                 
connect(4,{ AF_INET6 [::1]:5199 },28)            = 0 (0x0)                                                                                                                 
setsockopt(4,IPPROTO_TCP,TCP_NODELAY,0x13373b5633ec,4) = 0 (0x0)
getrandom("\M-h\M^J\M-wb\M-Xh%\a\M-E>q\M-.:"...,24,0) = 24 (0x18)
write(4,"\M-h\M^J\M-wb\M-Xh%\a\M-E>q\M-.:"...,24) = 24 (0x18)
read(4,"\M^S\M-SR\M-/\\\M-4_\^\\\cX\br"...,24)   = 24 (0x18)                                                                                                               
write(4,"\0\0\0\^P",4)                           = 4 (0x4)                                                                                                                                                                                                                                                                                             
write(4,"\M-&\M-~g\f\M^^WW\M-F\^AWz\M^YW!"...,16) = 16 (0x10)                                                                                                              
read(4,"\0\0\0\^P",4)                            = 4 (0x4)                                                                
............snip....................

[rgacogne]

That's a weird one! Nothing in the logs of the server (it would probably have to be in verbose mode to log anything interesting)?

[rgacogne]

Note to self: the getrandom call means that dnsdist has been built without libsodium, which might be a clue.

[tykling]

The servers are busy so I had to block clients in the firewall to see what is going on but there was indeed an interesting clue in the logs, when it fails dnsdist -v logs:

Control connection from [::1000:0:0:0]:43311 dropped because of ACL

Following runs work well and log a more expected message:

Got control connection from [::1]:64450

But how ::1 becomes ::1000:0:0:0 I have no idea...

[rgacogne]

oh, I might have an idea!