18 Říj
2018
18 Říj
'18
12:36
Hi Libor,
I don't know why the message appears three times. I was also wondering about
this. I had a quick look at a tcpdump and nsupdate does indeed send three requests:
12:27:57.973741 IP6 (flowlabel 0x5e7e8, hlim 64, next-header UDP (17) payload length: 37)
::1.5835 > ::1.53: [bad udp cksum 0x0038 -> 0x19f7!] 53303 update SOA? example.org.
(29)
12:27:57.976086 IP6 (flowlabel 0x0f4a8, hlim 64, next-header UDP (17) payload length: 37)
::1.53 > ::1.5835: [bad udp cksum 0x0038 -> 0x99f6!] 53303 update- q: SOA?
example.org. 0/0/0 (29)
12:27:57.976554 IP6 (flowlabel 0x5e7e8, hlim 64, next-header UDP (17) payload length: 65)
::1.5835 > ::1.53: [bad udp cksum 0x0054 -> 0x0d44!] 32688 update [2n] SOA?
example.org. ns: example.org. ANY [0s] A 192.12.0.1, example.org. [1m] A 127.0.0.1 (57)
12:27:57.989710 IP6 (flowlabel 0x0f4a8, hlim 64, next-header UDP (17) payload length: 37)
::1.53 > ::1.5835: [bad udp cksum 0x0038 -> 0xea7d!] 32688 update- q: SOA?
example.org. 0/0/0 (29)
12:27:57.989970 IP6 (flowlabel 0x5e7e8, hlim 64, next-header UDP (17) payload length: 37)
::1.5835 > ::1.53: [bad udp cksum 0x0038 -> 0xa04c!] 18914 update SOA? example.org.
(29)
12:27:57.992947 IP6 (flowlabel 0x0f4a8, hlim 64, next-header UDP (17) payload length: 37)
::1.53 > ::1.5835: [bad udp cksum 0x0038 -> 0x204c!] 18914 update- q: SOA?
example.org. 0/0/0 (29)
Here is a trimmed down version of my configuration file which shows the same
behavior:
$ head -v -n-1 /etc/knot/knot.conf
==> /etc/knot/knot.conf <==
server:
listen: 0.0.0.0@53
listen: ::@53
user: knot:knot
log:
- target: syslog
any: info
policy:
- id: default
algorithm: RSASHA256
ksk-size: 3248
zsk-size: 2432
nsec3: on
nsec3-iterations: 330
ksk-lifetime: 365d
cds-cdnskey-publish: none
acl:
- id: example.org
action: update
template:
- id: default
file: zones/%s
semantic-checks: on
serial-policy: unixtime
- id: signed
file: zones/%s
dnssec-policy: default
dnssec-signing: on
semantic-checks: on
serial-policy: unixtime
zone:
- domain: example.org
template: signed
file: zones_ddns/%s
zonefile-load: difference
$ head -v -n-1 example.org
==> example.org <==
example.org. 3600 SOA ns1.example.org. hostmaster.example.org 1530570453 3600
1200 3628800 60
example.org. 3600 NS ns1.example.org.
The problem with knot not responding to DDNS updates happened after a server
reboot or shortly after. I could see packets arriving at the server in
tcpdump, but knot didn't react to them and didn't log anything.
The log messages after the reboot where these:
Okt 15 21:12:24 server knotd[508]: info: [<zone>] zone will be loaded
Okt 15 21:12:24 server knotd[508]: info: [<zone>] DNSSEC, key, tag 36134, algorithm
RSASHA256, KSK, public, active
Okt 15 21:12:24 server knotd[508]: info: [<zone>] DNSSEC, key, tag 62508, algorithm
RSASHA256, public, active
Okt 15 21:12:24 server knotd[508]: info: [<zone>] DNSSEC, signing started
Okt 15 21:12:25 server knotd[508]: info: [<zone>] DNSSEC, successfully signed
Okt 15 21:12:25 server knotd[508]: info: [<zone>] loaded, serial 1539630745, 7076
bytes
Okt 15 21:12:25 server knotd[508]: info: [<zone>] DNSSEC, next signing at
2018-10-19T11:32:26
Okt 15 21:12:25 server knotd[508]: info: [<zone>] zone file updated, serial
1539336748 -> 1539630745
after my manual knot restart this got logged:
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] zone will be loaded
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] DNSSEC, key, tag 36134, algorithm
RSASHA256, KSK, public, active
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] DNSSEC, key, tag 62508, algorithm
RSASHA256, public, active
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] DNSSEC, signing started
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] DNSSEC, zone is up-to-date
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] loaded, serial 1539630745, 7076
bytes
Okt 16 15:25:32 server knotd[3033]: info: [<zone>] DNSSEC, next signing at
2018-10-19T11:32:26
I don't know if these log are useful, but I don't have much more information.
Thanks,
Maxi
On Donnerstag, 18. Oktober 2018 09:55:05 CEST libor.peltan wrote:
Hi Maxi,
thanks much for detailed report!
First, the 1970 time information is indeed a cosmetic bug. It's just a
dumb conversion of zero timestamp, in our semantics infinite future.
Please interpret it as "not scheduled" until we fix it.
However, it's not clear to me how this can ever happen. Next re-sign is
always planned based on ksk-lifetime, zsk-lifetime and/or
rrsig-lifetime. Could you please share also (at least) the policy
section of your configuration to check? I will also take a look on this
anyway.
The snippet of log you sent us looks also a little weird, but maybe you
know the explanation here, why did Knot receive DDNS three times in one
second, with just the middle one actually changing the zone. If you
think there is also a bug, please share more information to this,
otherwise ok.
Please let us know if the situation with not responding to DDNS appears
again.
Danke!
Libor
Dne 17.10.18 v 23:25 Maximilian Engelhardt napsal(a):
> Hi,
>
> I'm using a zone with DNSSEC signing enabled that is updated using DDNS.
>
> The update procedure is very simple and looks like this:
> ==> test_ddns.sh <==
> #! /bin/sh
>
> ZONE="example.org."
>
> cat << EOF | nsupdate
> server localhost
> zone ${ZONE}
>
> update delete ${ZONE} A
> update add ${ZONE} 60 IN A 127.0.0.1
>
> send
> quit
> EOF
>
> And the corresponding output in the knot log is this:
>
> Okt 17 22:58:46 backroad knotd[14134]: info: [example.org.] DDNS,
> processing 1 updates Okt 17 22:58:46 backroad knotd[14134]: info:
> [example.org.] DNSSEC, zone is up-to-date Okt 17 22:58:46 backroad
> knotd[14134]: info: [example.org.] DNSSEC, next signing at
> 1970-01-01T01:00:00 Okt 17 22:58:46 backroad knotd[14134]: info:
> [example.org.] DDNS, finished, no changes to the zone were made Okt 17
> 22:58:46 backroad knotd[14134]: info: [example.org.] DDNS, processing 1
> updates Okt 17 22:58:46 backroad knotd[14134]: info: [example.org.]
> DNSSEC, successfully signed Okt 17 22:58:46 backroad knotd[14134]: info:
> [example.org.] DNSSEC, next signing at 2018-10-24T22:58:46 Okt 17
> 22:58:46 backroad knotd[14134]: info: [example.org.] DDNS, update
> finished, serial 1539809849 -> 1539809926, 0.02 seconds Okt 17 22:58:46
> backroad knotd[14134]: info: [example.org.] DDNS, processing 1 updates
> Okt 17 22:58:46 backroad knotd[14134]: info: [example.org.] DNSSEC, zone
> is up-to-date Okt 17 22:58:46 backroad knotd[14134]: info: [example.org.]
> DNSSEC, next signing at 1970-01-01T01:00:00 Okt 17 22:58:46 backroad
> knotd[14134]: info: [example.org.] DDNS, finished, no changes to the zone
> were made Okt 17 22:58:46 backroad knotd[14134]: info: [example.org.]
> zone file updated, serial 1539809849 -> 1539809926
>
> I'm wondering if the "next signing at 1970-01-01T01:00:00" output is
> correct as this seems suspicious to me.
>
> Running "knotc zone-status example.org" gives the following output:
> [example.org.] role: master | serial: 1539809926 | transaction: none |
> freeze: no | refresh: not scheduled | update: not scheduled | expiration:
> not scheduled | journal flush: not scheduled | notify: not scheduled |
> DNSSEC re-sign: not scheduled | NSEC3 resalt: +29D23h53m28s | parent DS
> query: not scheduled
>
> Is this expected behavior or a bug in knot?
>
> I can give more information or create a proper bugreport if needed.
>
> I also recently had the problem that knot didn't respond to ddns updates
> until it was restarted. I don't know if this is related or a different
> problem, however I currently don't have more information about this.
>
> Thanks,
> Maxi