Hello,
Thanks for HINFO case. Here's another one.
I experience the following problem.
- Query signed RR results NOERROR.
- Resign the zone on authoritative server.
- Query same RR results NOERROR.
- Invoke unbound-control flush.
- Query same RR results SERVFAIL.
- After some interval, I'm not sure but it may be $TTL of
the zone, it results NOERROR again.
Though the following result is produced with stub-zone:
hack, same problem occurs on global domain, too.
What is wrong?
# zonedata before signing
$TTL 1m
@ IN SOA ns.example.jp. hostmaster.example.jp. (
0 ; overridden by dnssec-signzone
15m
10m
4w
15m)
$INCLUDE ksk.key
$INCLUDE zsk.key
2m NS ns.example.jp.
ns 3m A 10.2.0.18
foo 4m A 10.20.30.40
# output of dig and unbound-control
Script started on Thu Jan 15 14:53:04 2009
kohi@vm1[1]% /usr/bin/su
Password:
vm1# dig @127.0.0.1 version.bind txt chaos
; <<>> DiG 9.4.2-P2 <<>> @127.0.0.1 version.bind txt chaos
; (1 server found)
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 17415
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0
;; QUESTION SECTION:
;version.bind. CH TXT
;; ANSWER SECTION:
version.bind. 0 CH TXT "unbound 1.2.0"
;; Query time: 0 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jan 15 14:53:32 2009
;; MSG SIZE rcvd: 56
vm1# dig +dnssec @127.0.0.1 foo.example.jp
; <<>> DiG 9.4.2-P2 <<>> +dnssec @127.0.0.1 foo.example.jp
; (1 server found)
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 14367
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 2, ADDITIONAL: 3
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
;; QUESTION SECTION:
;foo.example.jp. IN A
;; ANSWER SECTION:
foo.example.jp. 240 IN A 10.20.30.40
foo.example.jp. 240 IN RRSIG A 5 3 240 20090301044615 20090115044615 59520 example.jp. G93MjniWgY2rW2s375NbrBDOLrh0CqmH47BrxKTvX1ElqPyxrq7oE9Vu UJjDASLI1c03/i4Yj73w/Ubbb+SlXpqhcn37RsO5TryjU3y37aQBqZrB DZnFLNUY3pYu6Wci
;; AUTHORITY SECTION:
example.jp. 120 IN NS ns.example.jp.
example.jp. 120 IN RRSIG NS 5 2 120 20090301044615 20090115044615 59520 example.jp. fUWtaLmZlBEjEUgDA9wQcS0dJThrVDPNbaSfpD3xg4KoRLZlB4KJhh0D N1H/ou4RNtx4iwk66qVr4XFJJyNwz2NFQHIM0J5TF5oG43Yb/ynLGO+E U4h7pKQiuXoBcGEz
;; ADDITIONAL SECTION:
ns.example.jp. 180 IN A 10.2.0.18
ns.example.jp. 180 IN RRSIG A 5 3 180 20090301044615 20090115044615 59520 example.jp. QwGJ9c5lsJCPgI8tswiVqCidX+n4bchBDttN3jPTjY0ddf1PCeeXNJQn mcH0WwamG6eC9nJu1jeSeHS5J07VoSAxadCbq15jn0SSI57cT5OT95i1 R5qWJPg6fT5u4dZM
;; Query time: 146 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jan 15 14:53:46 2009
;; MSG SIZE rcvd: 506
# It's O.K.
# resign at the authoritative server.
vm1# dig +dnssec @127.0.0.1 foo.example.jp
; <<>> DiG 9.4.2-P2 <<>> +dnssec @127.0.0.1 foo.example.jp
; (1 server found)
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 34057
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 2, ADDITIONAL: 3
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
;; QUESTION SECTION:
;foo.example.jp. IN A
;; ANSWER SECTION:
foo.example.jp. 209 IN A 10.20.30.40
foo.example.jp. 209 IN RRSIG A 5 3 240 20090301044615 20090115044615 59520 example.jp. G93MjniWgY2rW2s375NbrBDOLrh0CqmH47BrxKTvX1ElqPyxrq7oE9Vu UJjDASLI1c03/i4Yj73w/Ubbb+SlXpqhcn37RsO5TryjU3y37aQBqZrB DZnFLNUY3pYu6Wci
;; AUTHORITY SECTION:
example.jp. 89 IN NS ns.example.jp.
example.jp. 89 IN RRSIG NS 5 2 120 20090301044615 20090115044615 59520 example.jp. fUWtaLmZlBEjEUgDA9wQcS0dJThrVDPNbaSfpD3xg4KoRLZlB4KJhh0D N1H/ou4RNtx4iwk66qVr4XFJJyNwz2NFQHIM0J5TF5oG43Yb/ynLGO+E U4h7pKQiuXoBcGEz
;; ADDITIONAL SECTION:
ns.example.jp. 149 IN A 10.2.0.18
ns.example.jp. 149 IN RRSIG A 5 3 180 20090301044615 20090115044615 59520 example.jp. QwGJ9c5lsJCPgI8tswiVqCidX+n4bchBDttN3jPTjY0ddf1PCeeXNJQn mcH0WwamG6eC9nJu1jeSeHS5J07VoSAxadCbq15jn0SSI57cT5OT95i1 R5qWJPg6fT5u4dZM
;; Query time: 0 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jan 15 14:54:17 2009
;; MSG SIZE rcvd: 506
# It' s still O.K.
vm1# /proj/unbound-1.2.0/sbin/unbound-control flush foo.example.jp
ok
vm1# dig +dnssec @127.0.0.1 foo.example.jp
; <<>> DiG 9.4.2-P2 <<>> +dnssec @127.0.0.1 foo.example.jp
; (1 server found)
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 29411
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
;; QUESTION SECTION:
;foo.example.jp. IN A
;; Query time: 2 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jan 15 14:54:46 2009
;; MSG SIZE rcvd: 43
# Oops!
vm1# sleep 60; dig +dnssec @127.0.0.1 foo.example.jp
; <<>> DiG 9.4.2-P2 <<>> +dnssec @127.0.0.1 foo.example.jp
; (1 server found)
;; global options: printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 1711
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 2, ADDITIONAL: 3
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 4096
;; QUESTION SECTION:
;foo.example.jp. IN A
;; ANSWER SECTION:
foo.example.jp. 240 IN A 10.20.30.40
foo.example.jp. 240 IN RRSIG A 5 3 240 20090301045359 20090115045359 16236 example.jp. ZZORs2cPenp0750acuVnQwA26Y1/dtm0HD2BWMdspX3fM5BhTcMlwp8j C88TU7Q5ifGc65/2c0bNjWFn+Nn6OfXIEWuFYYiKM3EZXLQxFZPxBWUD pBXyJ3U2THlmmM2l
;; AUTHORITY SECTION:
example.jp. 120 IN NS ns.example.jp.
example.jp. 120 IN RRSIG NS 5 2 120 20090301045359 20090115045359 16236 example.jp. lSma+vDcxytZoVU8qgtv1xvNKwg4PF53gUh8/Q38wM9C3jmHopwLOaRP x6d+8v/mbqM7TsFnI/XAIhKrV4v0DiuwsmgPy2/9oVGYFu0dnBuUt3Kw YeEJTEKGvbvYJQNe
;; ADDITIONAL SECTION:
ns.example.jp. 180 IN A 10.2.0.18
ns.example.jp. 180 IN RRSIG A 5 3 180 20090301045359 20090115045359 16236 example.jp. O3i7lhtKVXw2l7KPsoy7ODRUFyYc8IrQlNAuNVYit+T9owBXQtl4CTsB 6FFeP1hjnRc0LiMLQOWhCitzPzz7kBJZCzpHgJnj6/NXXaex+B+crJLx Q4cDrtGqgFkmfQ9N
;; Query time: 3 msec
;; SERVER: 127.0.0.1#53(127.0.0.1)
;; WHEN: Thu Jan 15 14:56:01 2009
;; MSG SIZE rcvd: 506
# It comes back.
vm1# exit
exit
kohi@vm1[2]% exit
Script done on Thu Jan 15 14:56:05 2009
# output of unbound
Script started on Thu Jan 15 14:52:50 2009
kohi@vm1[1]% /usr/bin/su
Password:
vm1# /proj/unbound-1.2.0/sbin/unbound -dv
[1231998797] unbound[29635:0] notice: Start of unbound 1.2.0.
[1231998797] unbound[29635:0] notice: init module 0: validator
[1231998797] unbound[29635:0] notice: init module 1: iterator
[1231998797] unbound[29635:0] notice: openssl has no entropy, seeding with time and pid
[1231998797] unbound[29635:0] info: start of service (unbound 1.2.0).
# invoke dig which results NOERROR
[1231998826] unbound[29635:0] info: resolving <foo.example.jp. A IN>
[1231998826] unbound[29635:0] info: priming . IN NS
[1231998826] unbound[29635:0] info: response for <. NS IN>
[1231998826] unbound[29635:0] info: reply from <.> 192.203.230.10#53
[1231998826] unbound[29635:0] info: query response was ANSWER
[1231998826] unbound[29635:0] info: priming successful for <. NS IN>
[1231998826] unbound[29635:0] info: use stub <example.jp. NS IN>
[1231998826] unbound[29635:0] info: response for <foo.example.jp. A IN>
[1231998826] unbound[29635:0] info: reply from <example.jp.> 10.2.0.18#53
[1231998826] unbound[29635:0] info: query response was ANSWER
[1231998826] unbound[29635:0] info: prime trust anchor
[1231998826] unbound[29635:0] info: resolving <example.jp. DNSKEY IN>
[1231998826] unbound[29635:0] info: use stub <example.jp. NS IN>
[1231998826] unbound[29635:0] info: response for <example.jp. DNSKEY IN>
[1231998826] unbound[29635:0] info: reply from <example.jp.> 10.2.0.18#53
[1231998826] unbound[29635:0] info: query response was ANSWER
[1231998826] unbound[29635:0] info: validate keys with anchor(DNSKEY): sec_status_secure
[1231998826] unbound[29635:0] info: Successfully primed trust anchor <example.jp. DNSKEY IN>
[1231998826] unbound[29635:0] info: validate(positive): sec_status_secure
[1231998826] unbound[29635:0] info: validation success <foo.example.jp. A IN>
# resign at the authoritative server
# invoke dig once here, which results NOERROR,
# but no explanation is generated with single -v
# unbound-control flush
[1231998876] unbound[29635:0] info: control cmd: flush foo.example.jp
# invoke dig which results SERVFAIL
[1231998886] unbound[29635:0] info: resolving <foo.example.jp. A IN>
[1231998886] unbound[29635:0] info: use stub <example.jp. NS IN>
[1231998886] unbound[29635:0] info: response for <foo.example.jp. A IN>
[1231998886] unbound[29635:0] info: reply from <example.jp.> 10.2.0.18#53
[1231998886] unbound[29635:0] info: query response was ANSWER
[1231998886] unbound[29635:0] info: Validate: message contains bad rrsets
# approx 1min interval
# invoke dig which results NOERROR
[1231998961] unbound[29635:0] info: resolving <foo.example.jp. A IN>
[1231998961] unbound[29635:0] info: use stub <example.jp. NS IN>
[1231998961] unbound[29635:0] info: response for <foo.example.jp. A IN>
[1231998961] unbound[29635:0] info: reply from <example.jp.> 10.2.0.18#53
[1231998961] unbound[29635:0] info: query response was ANSWER
[1231998961] unbound[29635:0] info: prime trust anchor
[1231998961] unbound[29635:0] info: resolving <example.jp. DNSKEY IN>
[1231998961] unbound[29635:0] info: use stub <example.jp. NS IN>
[1231998961] unbound[29635:0] info: response for <example.jp. DNSKEY IN>
[1231998961] unbound[29635:0] info: reply from <example.jp.> 10.2.0.18#53
[1231998961] unbound[29635:0] info: query response was ANSWER
[1231998961] unbound[29635:0] info: validate keys with anchor(DNSKEY): sec_status_secure
[1231998961] unbound[29635:0] info: Successfully primed trust anchor <example.jp. DNSKEY IN>
[1231998961] unbound[29635:0] info: validate(positive): sec_status_secure
[1231998961] unbound[29635:0] info: validation success <foo.example.jp. A IN>
^C[1231998967] unbound[29635:0] info: service stopped (unbound 1.2.0).
[1231998967] unbound[29635:0] info: server stats for thread 0: 5 queries, 2 answers from cache, 3 recursions
[1231998967] unbound[29635:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0
[1231998967] unbound[29635:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 3 recursion replies sent, 0 replies dropped, 0 states jostled out
[1231998967] unbound[29635:0] info: average recursion processing time 0.049181 sec
[1231998967] unbound[29635:0] info: histogram of recursion processing times
[1231998967] unbound[29635:0] info: [25%]=0 median[50%]=0 [75%]=0
[1231998967] unbound[29635:0] info: lower(secs) upper(secs) recursions
[1231998967] unbound[29635:0] info: 0.001024 0.002048 2
[1231998967] unbound[29635:0] info: 0.131072 0.262144 1
vm1# exit
exit
kohi@vm1[2]% exit
Script done on Thu Jan 15 14:56:09 2009
Thanks in advance.
Koh-ichi Ito