[Opendnssec-user] enforce zone looping?

[Dennis Baaten]

Here we go again. This is beginning to look like my personal mailing list. :-)

Yesterday, I got the following output. Notice the date of next transition: 2017-11-14 14:36:34.

***@traxotic [/var/lib/opendnssec/signconf]$ ods-enforcer key list --verbose | grep dennisbaaten
key list completed in 0 seconds.
dennisbaaten.com ZSK retire 2017-11-14 14:36:34 2048 8 ce3507796d7c176695bbfdc18f100fc6 SoftHSM 52924
dennisbaaten.com ZSK active 2017-11-14 14:36:34 2048 8 49bad7794a2e2c4d5f44755f33317982 SoftHSM 11619
dennisbaaten.com KSK active 2017-11-14 14:36:34 4096 8 f82e46fa26d4772c3b09db259aa41a30 SoftHSM 59792
dennisbaaten.com ZSK retire 2017-11-14 14:36:34 2048 8 75602642359504fa4d1decc0d7ab37e4 SoftHSM 40563
dennisbaaten.com KSK publish 2017-11-14 14:36:34 4096 8 27384557fb5980c2b8fff0139e0d76e9 SoftHSM 32179
dennisbaaten.com ZSK publish 2017-11-14 14:36:34 2048 8 925276e53f3ac23420b34ed5f24d4892 SoftHSM 58128

Today, at 14:36 nothing happened. I was an expecting a KSK 'ready' state and a request to upload the new public key to the registry.
In an attempt to clarify this, I checked syslog but I cannot find anything useful. ODS is however quite chatty (logging SQL statements and stuff), so it's easy to miss something.

But then I check the queue (ods-enforcer queue). Output below (I left out the tasks for other domains)

All worker threads idle.
There are 7 tasks scheduled.
It is now Tue Nov 14 18:20:20 2017 (1510680020 seconds since epoch)
Next task scheduled Tue Nov 14 18:20:32 2017 (1510680032 seconds since epoch)
On Tue Nov 14 18:20:34 2017 I will enforce zone dennisbaaten.com

According to this output, I was literally seconds away from the next task. So after 18:20:34 I checked again.

All worker threads idle.
There are 7 tasks scheduled.
It is now Tue Nov 14 18:20:54 2017 (1510680054 seconds since epoch)
Next task scheduled Tue Nov 14 18:21:32 2017 (1510680092 seconds since epoch)
On Tue Nov 14 18:21:34 2017 I will enforce zone dennisbaaten.com

The task had shifted 1 minute to the future. So after after a couple of minutes I checked again.

All worker threads idle.
There are 7 tasks scheduled.
It is now Tue Nov 14 18:24:37 2017 (1510680277 seconds since epoch)
Next task scheduled Tue Nov 14 18:25:32 2017 (1510680332 seconds since epoch)
On Tue Nov 14 18:25:34 2017 I will enforce zone dennisbaaten.com

Again the tasked has shifted to the future. This happens every minute and just keeps going. It looks like some kind of 'enforcement loop'.

Any thoughts?

--
Dennis

[Yuri Schaeffer]

Post by Dennis Baaten
Again the tasked has shifted to the future. This happens every minute and just keeps going. It looks like some kind of 'enforcement loop'.
Any thoughts?

Yes. Not a loop but a 1 minute backoff. It seems to want to do something
but fails so it schedules a retry in a minute. Suspects are a database
connection that gone away, isn't writeable or the HSM not reachable etc.
I'm afraid you have to go over the logs.

Note: You can change the verbosity of the running daemon with
ods-enforcer verbosity

//Yuri

[Dennis Baaten]

Going through the logs and found the problem:
ods-enforcerd: [enforcer] updateZone Ready for transition but key material not backed up yet

after a 'ods-ksmutil backup prepare' and a 'ods-enforcer backup commit' (and a ods restart) it worked, and I got an e-mail with the new KSK key.

--Dennis

[Yuri Schaeffer]

Post by Dennis Baaten
after a 'ods-ksmutil backup prepare'

ods-ksmutil is part of OpenDNSSEC 1.4 and no longer exists in 2.1...

Post by Dennis Baaten
and a 'ods-enforcer backup commit' (and a ods restart) it worked, and I got an e-mail with the new KSK key.

Good.

//Yuri

PS. It seems you are only telling OpenDNSSEC you backed up the key
without doing so (on your HSM). If you don't actually care for backups
remove the <RequireBackup/> from the OpenDNSSEC configuration.