broken trust chain

Josef Moellers jmoellers at suse.de
Tue Sep 29 07:14:24 UTC 2020


On 28.09.20 16:35, Jeremy C. Reed wrote:
> Let's get more logging. Enable more debugging in named.

It is already running with -d 5

> What made named think that name should be DNSSEC signed in the first 
> place?

Because the default is "dnssec-validation yes" and there is no other
directive.
Also, in 3 out of 4 test runs it works flawlessly ("Key 20326 for zone .
acceptance timer complete: key now trusted"), in the one case in 4 it
complains about "No DNSKEY RRSIGs found for '.'"

> 
> Do you only have the problem resolving the single name and it doesn't 
> happen every time?

It happens every time when the error message about the DNSKEY RRSIGs is
issued and it does not happen at all when the message about the trusted
key is issued.
And it is independent upon the name searched for:

sles12-sp4:~ # dig @192.168.122.1 www.google.com +short
216.58.208.36
sles12-sp4:~ # dig @localhost www.google.com +short
sles12-sp4:~ #

> Does the problem ever happen without using your forwarders?

No:

sles12-sp4:~ # dig @192.168.122.1 www.suse.de +short
redirector.suse.com.
fra-alb-p-redirector-01-1686471185.eu-central-1.elb.amazonaws.com.
18.157.240.156
52.28.35.86
sles12-sp4:~ # dig @localhost www.suse.de +short
sles12-sp4:~ #

> Also do the query with delv -d99 and record that verbose output.

;; socket 0x7ff2a4000010: created

;; socket 0x7ff2a4000010 0.0.0.0#57450: bound

;; dispatchmgr 0x7ff2a3ffb010: dns_dispatch_createudp: Created UDP
dispatch for 0.0.0.0#0 with socket fd 20
;; dispatchmgr 0x7ff2a3ffb010: created UDP dispatcher 0x22536f0

;; dispatch 0x22536f0: created task 0x7ff2a3fef1a0

;; dispatch 0x22536f0: created socket 0x7ff2a4000010

;; socket 0x7ff2a4000270: created

;; socket 0x7ff2a4000270 ::#39765: bound

;; dispatchmgr 0x7ff2a3ffb010: dns_dispatch_createudp: Created UDP
dispatch for ::#0 with socket fd 21
;; dispatchmgr 0x7ff2a3ffb010: created UDP dispatcher 0x2253120
;; dispatch 0x2253120: created task 0x7ff2a3fef268
;; dispatch 0x2253120: created socket 0x7ff2a4000270
;; adb: task-exclusive mode unavailable, initializing table sizes to 49193

;; dns_requestmgr_create
;; dns_requestmgr_create: 0x7ff2a4021010
;; dns_requestmgr_whenshutdown
;; socket 0x7ff2a3ead010: created
;; socket 0x7ff2a3ead010 0.0.0.0#40118: bound
;; dispatchmgr 0x7ff2a3ea7010: dns_dispatch_createudp: Created UDP
dispatch for 0.0.0.0#0 with socket fd 22
;; dispatchmgr 0x7ff2a3ea7010: created UDP dispatcher 0x3968290
;; dispatch 0x3968290: created task 0x7ff2a3ea0268
;; dispatch 0x3968290: created socket 0x7ff2a3ead010
;; socket 0x7ff2a3ead270: created
;; socket 0x7ff2a3ead270 ::#54166: bound
;; dispatchmgr 0x7ff2a3ea7010: dns_dispatch_createudp: Created UDP
dispatch for ::#0 with socket fd 23
;; dispatchmgr 0x7ff2a3ea7010: created UDP dispatcher 0x3967cc0
;; dispatch 0x3967cc0: created task 0x7ff2a3ea0330
;; dispatch 0x3967cc0: created socket 0x7ff2a3ead270
;; adb: task-exclusive mode unavailable, initializing table sizes to 49193

;; dns_requestmgr_create
;; dns_requestmgr_create: 0x7ff2a3ed1010
;; dns_requestmgr_whenshutdown
;; fetch: localhost/A
;; log_ns_ttl: fctx 0x4fd6ca0: fctx_create: localhost (in '.'?): 0 0
;; findaddrinfo: new entry 0x7ff29cadf128
;; findaddrinfo: new entry 0x7ff29cadf010
;; dispatch 0x3968290 response 0x7ff2a3edbe98 217.0.43.1#53: attached to
task 0x7ff2a3ea0970
;; socket 0x7ff2a3ead010: socket_recv: event 0x7ff2a3edc6f0 -> task
0x7ff2a3ea0268
;; sending packet to 217.0.43.1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  52687
;; flags: rd; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
; COOKIE: fb39bcd1c3e747d5
;; QUESTION SECTION:
;localhost.                     IN      A


;; sockmgr 0x7ff2a3ea1f30: watcher got message -3 for socket 22
;; sockmgr 0x7ff2a3ea1f30: watcher got message -2 for socket -1
;; fetch: localhost/AAAA
;; log_ns_ttl: fctx 0x4fd9140: fctx_create: localhost (in '.'?): 0 0
;; findaddrinfo: found entry 0x7ff29cadf128
;; findaddrinfo: found entry 0x7ff29cadf010
;; dispatch 0x3968290 response 0x7ff2a3edbda0 217.0.43.1#53: attached to
task 0x7ff2a3ea0970
;; sending packet to 217.0.43.1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  50536
;; flags: rd; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
; COOKIE: fb39bcd1c3e747d5
;; QUESTION SECTION:
;localhost.                     IN      AAAA


;; socket 0x7ff2a3ead010: dispatch_recv:  event 0x7ff2a3edc6f0 -> task
0x7ff2a3ea0268
;; socket 0x7ff2a3ead010: internal_recv: task 0x7ff2a3ea0268 got event
0x7ff2a3ead0d8
;; socket 0x7ff2a3ead010 217.0.43.1#53: packet received correctly
;; socket 0x7ff2a3ead010: processing cmsg 0x7ff29e387c50
;; socket 0x7ff2a3ead010: processing cmsg 0x7ff29e387c70
;; dispatch 0x3968290: got packet: requests 2, buffers 1, recvs 1
;; dispatch 0x3968290: got valid DNS message header, /QR 1, id 52687
;; dispatch 0x3968290: search for response in bucket 6561: found
;; dispatch 0x3968290 response 0x7ff2a3edbe98 217.0.43.1#53: [a] Sent
event 0x7ff2a3eac9e8 buffer 0x7ff298021ac0 len 4096 to task 0x7ff2a3ea0970
;; socket 0x7ff2a3ead010: socket_recv: event 0x7ff2a3edc590 -> task
0x7ff2a3ea0268
;; received packet from 217.0.43.1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  52687
;; flags: qr rd ra; QUESTION: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
;; QUESTION SECTION:
;localhost.                     IN      A

;; ANSWER SECTION:
;localhost.             86400   IN      A       127.0.0.1


;; log_ns_ttl: fctx 0x4fd6ca0: answer_response: localhost (in '.'?): 0 0
;; dispatch 0x3968290 response 0x7ff2a3edbe98 217.0.43.1#53: detaching
from task 0x7ff2a3ea0970
;; dispatch 0x3968290: detach: refcount 5
;; sockmgr 0x7ff2a3ea1f30: watcher got message -3 for socket 22
;; sockmgr 0x7ff2a3ea1f30: watcher got message -2 for socket -1
;; socket 0x7ff2a3ead010: dispatch_recv:  event 0x7ff2a3edc590 -> task
0x7ff2a3ea0268
;; socket 0x7ff2a3ead010: internal_recv: task 0x7ff2a3ea0268 got event
0x7ff2a3ead0d8
;; socket 0x7ff2a3ead010 217.0.43.1#53: packet received correctly
;; socket 0x7ff2a3ead010: processing cmsg 0x7ff29e387c50
;; socket 0x7ff2a3ead010: processing cmsg 0x7ff29e387c70
;; dispatch 0x3968290: got packet: requests 1, buffers 1, recvs 1
;; dispatch 0x3968290: got valid DNS message header, /QR 1, id 50536
;; dispatch 0x3968290: search for response in bucket 4142: found
;; dispatch 0x3968290 response 0x7ff2a3edbda0 217.0.43.1#53: [a] Sent
event 0x7ff2a3eac9e8 buffer 0x7ff298020ab0 len 4096 to task 0x7ff2a3ea0970
;; socket 0x7ff2a3ead010: socket_recv: event 0x7ff2a3edc6f0 -> task
0x7ff2a3ea0268
;; received packet from 217.0.43.1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  50536
;; flags: qr rd ra; QUESTION: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
;; QUESTION SECTION:
;localhost.                     IN      AAAA

;; ANSWER SECTION:
;localhost.             86400   IN      AAAA    ::1


;; log_ns_ttl: fctx 0x4fd9140: answer_response: localhost (in '.'?): 0 0
;; dispatch 0x3968290 response 0x7ff2a3edbda0 217.0.43.1#53: detaching
from task 0x7ff2a3ea0970
;; dispatch 0x3968290: detach: refcount 3
;; sockmgr 0x7ff2a3ea1f30: watcher got message -3 for socket 22
;; sockmgr 0x7ff2a3ea1f30: watcher got message -2 for socket -1
;; dns_requestmgr_shutdown: 0x7ff2a3ed1010
;; send_shutdown_events: 0x7ff2a3ed1010
;; dispatch 0x3968290: detach: refcount 2
;; dispatch 0x3967cc0: detach: refcount 2
;; dispatchmgr 0x7ff2a3ea7010: destroy_mgr_ok: shuttingdown=1,
listnonempty=1, depool=2, rpool=0, dpool=2
;; dispatchmgr 0x7ff2a3ea7010: destroy: killit=0
;; dispatch 0x3968290: detach: refcount 1
;; dispatch 0x3967cc0: detach: refcount 1
;; dns_requestmgr_detach: 0x7ff2a3ed1010: eref 0 iref 0
;; mgr_destroy
;; dispatch 0x3968290: detach: refcount 0
;; dispatch 0x3967cc0: detach: refcount 0
;; dispatch 0x3968290: got packet: requests 0, buffers 1, recvs 1
;; dispatch 0x3968290: shutting down; detaching from sock
0x7ff2a3ead010, task 0x7ff2a3ea0268
;; socket 0x7ff2a3ead010: destroying
;; sockmgr 0x7ff2a3ea1f30: watcher got message -5 for socket 22
;; sockmgr 0x7ff2a3ea1f30: watcher got message -2 for socket -1
;; dispatchmgr 0x7ff2a3ea7010: destroy_mgr_ok: shuttingdown=1,
listnonempty=1, depool=1, rpool=0, dpool=1
;; dispatch 0x3967cc0: shutting down; detaching from sock
0x7ff2a3ead270, task 0x7ff2a3ea0330
;; socket 0x7ff2a3ead270: destroying
;; sockmgr 0x7ff2a3ea1f30: watcher got message -5 for socket 23
;; sockmgr 0x7ff2a3ea1f30: watcher got message -2 for socket -1
;; dispatchmgr 0x7ff2a3ea7010: destroy_mgr_ok: shuttingdown=1,
listnonempty=0, depool=0, rpool=0, dpool=0
;; sockmgr 0x7ff2a3ea1f30: watcher got message -1 for socket 0
;; sockmgr 0x7ff2a3ea1f30: watcher exiting
;; adding trust anchor .
;; fetch: www.suse.de/A
;; log_ns_ttl: fctx 0x38fac90: fctx_create: www.suse.de (in '.'?): 0 0
;; findaddrinfo: new entry 0x7ff2a3f48128
;; findaddrinfo: new entry 0x7ff2a3f48010
;; dispatch 0x22536f0 response 0x38c0b08 127.0.0.1#53: attached to task
0x7ff2a401c970
;; socket 0x7ff2a4000010: socket_recv: event 0x38c1360 -> task
0x7ff2a3fef1a0
;; sending packet to 127.0.0.1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  45107
;; flags: rd; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
; COOKIE: fbbf2d870fd1a427
;; QUESTION SECTION:
;www.suse.de.                   IN      A


;; sockmgr 0x7ff2a3ff0f30: watcher got message -3 for socket 20
;; sockmgr 0x7ff2a3ff0f30: watcher got message -2 for socket -1
;; socket 0x7ff2a4000010: dispatch_recv:  event 0x38c1360 -> task
0x7ff2a3fef1a0
;; socket 0x7ff2a4000010: internal_recv: task 0x7ff2a3fef1a0 got event
0x7ff2a40000d8
;; socket 0x7ff2a4000010 127.0.0.1#53: packet received correctly
;; socket 0x7ff2a4000010: processing cmsg 0x7ff2a0250c50
;; socket 0x7ff2a4000010: processing cmsg 0x7ff2a0250c70
;; dispatch 0x22536f0: got packet: requests 1, buffers 1, recvs 1
;; dispatch 0x22536f0: got valid DNS message header, /QR 1, id 45107
;; dispatch 0x22536f0: search for response in bucket 10407: found
;; dispatch 0x22536f0 response 0x38c0b08 127.0.0.1#53: [a] Sent event
0x7ff2a3fff9e8 buffer 0x7ff298021ac0 len 4096 to task 0x7ff2a401c970
;; socket 0x7ff2a4000010: socket_recv: event 0x38c1200 -> task
0x7ff2a3fef1a0
;; received packet from 127.0.0.1#53
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id:  45107
;; flags: qr rd ra; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
; COOKIE: fbbf2d870fd1a427a559e12a5f72de0d1f7d573673bd484f
;; QUESTION SECTION:
;www.suse.de.                   IN      A


;; dispatch 0x22536f0 response 0x38c0b08 127.0.0.1#53: detaching from
task 0x7ff2a401c970
;; dispatch 0x22536f0: detach: refcount 3
;; dispatch 0x2253120 response 0x38c0b08 ::1#53: attached to task
0x7ff2a401c970
;; socket 0x7ff2a4000270: socket_recv: event 0x38c2a40 -> task
0x7ff2a3fef268
;; sending packet to ::1#53
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  58627
;; flags: rd; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
; COOKIE: 07a6fee537d54a89
;; QUESTION SECTION:
;www.suse.de.                   IN      A


;; sockmgr 0x7ff2a3ff0f30: watcher got message -3 for socket 20
;; sockmgr 0x7ff2a3ff0f30: watcher got message -3 for socket 21
;; sockmgr 0x7ff2a3ff0f30: watcher got message -2 for socket -1
;; socket 0x7ff2a4000270: dispatch_recv:  event 0x38c2a40 -> task
0x7ff2a3fef268
;; socket 0x7ff2a4000270: internal_recv: task 0x7ff2a3fef268 got event
0x7ff2a4000338
;; socket 0x7ff2a4000270 ::1#53: packet received correctly
;; socket 0x7ff2a4000270: processing cmsg 0x7ff2a0250c50
;; socket 0x7ff2a4000270: processing cmsg 0x7ff2a0250c70
;; socket 0x7ff2a4000270: interface received on ifindex 1
;; socket 0x7ff2a4000270: processing cmsg 0x7ff2a0250c98
;; dispatch 0x2253120: got packet: requests 1, buffers 2, recvs 1
;; dispatch 0x2253120: got valid DNS message header, /QR 1, id 58627
;; dispatch 0x2253120: search for response in bucket 14157: found
;; dispatch 0x2253120 response 0x38c0b08 ::1#53: [a] Sent event
0x7ff2a3fff9e8 buffer 0x7ff298021ac0 len 4096 to task 0x7ff2a401c970
;; socket 0x7ff2a4000270: socket_recv: event 0x38c28e0 -> task
0x7ff2a3fef268
;; received packet from ::1#53
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id:  58627
;; flags: qr rd ra; QUESTION: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
; COOKIE: 07a6fee537d54a89e5d496475f72de0d19ecfdc75acdcb42
;; QUESTION SECTION:
;www.suse.de.                   IN      A


;; dispatch 0x2253120 response 0x38c0b08 ::1#53: detaching from task
0x7ff2a401c970
;; dispatch 0x2253120: detach: refcount 3
;; findaddrinfo: found entry 0x7ff2a3f48128
;; findaddrinfo: found entry 0x7ff2a3f48010
;; resolution failed: SERVFAIL
;; dns_requestmgr_shutdown: 0x7ff2a4021010
;; send_shutdown_events: 0x7ff2a4021010
;; dispatch 0x22536f0: detach: refcount 2
;; dispatch 0x2253120: detach: refcount 2
;; dispatchmgr 0x7ff2a3ffb010: destroy_mgr_ok: shuttingdown=1,
listnonempty=1, depool=2, rpool=0, dpool=2
;; dispatchmgr 0x7ff2a3ffb010: destroy: killit=0
;; sockmgr 0x7ff2a3ff0f30: watcher got message -3 for socket 21
;; sockmgr 0x7ff2a3ff0f30: watcher got message -2 for socket -1
;; dispatch 0x22536f0: detach: refcount 1
;; dispatch 0x2253120: detach: refcount 1
;; dns_requestmgr_detach: 0x7ff2a4021010: eref 0 iref 0
;; mgr_destroy
;; dispatch 0x22536f0: detach: refcount 0
;; dispatch 0x2253120: detach: refcount 0
;; calling free_rbtdb(.)
;; done free_rbtdb(.)
;; dispatch 0x22536f0: got packet: requests 0, buffers 2, recvs 1
;; dispatch 0x22536f0: shutting down; detaching from sock
0x7ff2a4000010, task 0x7ff2a3fef1a0
;; socket 0x7ff2a4000010: destroying
;; sockmgr 0x7ff2a3ff0f30: watcher got message -5 for socket 20
;; sockmgr 0x7ff2a3ff0f30: watcher got message -2 for socket -1
;; dispatchmgr 0x7ff2a3ffb010: destroy_mgr_ok: shuttingdown=1,
listnonempty=1, depool=1, rpool=0, dpool=1
;; dispatch 0x2253120: got packet: requests 0, buffers 1, recvs 1
;; dispatch 0x2253120: shutting down; detaching from sock
0x7ff2a4000270, task 0x7ff2a3fef268
;; socket 0x7ff2a4000270: destroying
;; sockmgr 0x7ff2a3ff0f30: watcher got message -5 for socket 21
;; sockmgr 0x7ff2a3ff0f30: watcher got message -2 for socket -1
;; dispatchmgr 0x7ff2a3ffb010: destroy_mgr_ok: shuttingdown=1,
listnonempty=0, depool=0, rpool=0, dpool=0
;; sockmgr 0x7ff2a3ff0f30: watcher got message -1 for socket 0
;; sockmgr 0x7ff2a3ff0f30: watcher exiting


-- 
SUSE Software Solutions Germany GmbH
Maxfeldstr. 5
90409 Nürnberg
Germany

(HRB 36809, AG Nürnberg)
Geschäftsführer: Felix Imendörffer


More information about the bind-workers mailing list