[Opendnssec-user] Date of next transition: now

Discussion:

Gerhard Schmidt

2018-01-08 06:43:23 UTC

Hi,

I have some problems with opendnssec.
I'm running opendnssec 2.1.0 since late 2016. I have about 20 domains
configured and all have the same problem.

The KSK and ZSK of every domain shows as next transition date now. The
KSK keys should have a transition till 2020.

I have the output of one of the domains attached.

Please point me to what I've done wrong and how I fix this.

Regards
Estartu

Yuri Schaeffer

2018-01-08 10:44:55 UTC

Permalink

Hi Estartu,

Post by Gerhard Schmidt
The KSK and ZSK of every domain shows as next transition date now. The
KSK keys should have a transition till 2020.

The transition time is a remnant of OpenDNSSEC 1.4. Currently it means
something need to happen to this zone not specifically a key. If it says
*now* something might be blocking the enforcer. I advice to look through
the logs.

Could you provide the output of 'ods-enfocer queue'? It will tell us the
Enforcers schedule.

//Yuri

Gerhard Schmidt

2018-01-08 13:17:01 UTC

Permalink

Post by Yuri Schaeffer
Hi Estartu,

Post by Gerhard Schmidt
The KSK and ZSK of every domain shows as next transition date now. The
KSK keys should have a transition till 2020.

The transition time is a remnant of OpenDNSSEC 1.4. Currently it means
something need to happen to this zone not specifically a key. If it says
*now* something might be blocking the enforcer. I advice to look through
the logs.
Could you provide the output of 'ods-enfocer queue'? It will tell us the
Enforcers schedule.

ods-enforcer queue reports.

All worker threads idle.
There is 1 task scheduled.
It is now Mon Jan 8 14:01:54 2018 (1515416514 seconds since epoch)
Next task scheduled Wed Mar 28 15:49:26 2018 (1522244966 seconds since
epoch)
On Wed Mar 28 15:49:26 2018 I will resalt zone default

I've scanned the logfiles and didn't see any obvious error messages.

Regards Estartu

Yuri Schaeffer

2018-01-08 14:48:24 UTC

Permalink

Post by Gerhard Schmidt
All worker threads idle.
There is 1 task scheduled.
It is now Mon Jan 8 14:01:54 2018 (1515416514 seconds since epoch)
Next task scheduled Wed Mar 28 15:49:26 2018 (1522244966 seconds since
epoch)
On Wed Mar 28 15:49:26 2018 I will resalt zone default

At this point I do not know how this have happened but the problem is
clear. The enforce tasks for the zones are no longer scheduled. I
believe you can do 'ods-enforcer enforce --all' to get them back in the
queue. Alternatively restarting ods-enforcerd will work as well.

In normal operation this will only happen when the enforcer concludes no
more (automated) work needs to be done for a zone -ever-. This means
zones are only re-evaluated on user input. This should only be possible
if you configured manual rollover for both KSK and ZSK. In that case the
timestamp thing is a fluke (which we need to address). Can that be the case?

//Yuri

Gerhard Schmidt

2018-01-22 13:39:09 UTC

Permalink

Post by Yuri Schaeffer

At this point I do not know how this have happened but the problem is
clear. The enforce tasks for the zones are no longer scheduled. I
believe you can do 'ods-enforcer enforce --all' to get them back in the
queue. Alternatively restarting ods-enforcerd will work as well.
In normal operation this will only happen when the enforcer concludes no
more (automated) work needs to be done for a zone -ever-. This means
zones are only re-evaluated on user input. This should only be possible
if you configured manual rollover for both KSK and ZSK. In that case the
timestamp thing is a fluke (which we need to address). Can that be the case?
//Yuri

after restart i got this from eds-enforcer queue.
All worker threads idle.
There are 15 tasks scheduled.
It is now Mon Jan 8 14:31:58 2018 (1515418318 seconds since epoch)
Next task scheduled Mon Jan 22 14:13:19 2018 (1516626799 seconds since
epoch)
On Mon Jan 22 14:13:19 2018 I will enforce zone augusta.de
On Wed Mar 28 15:49:26 2018 I will resalt zone default
ods-enforcer key list reports now
augusta.de KSK active 2018-01-22 14:13:19
augusta.de ZSK retire 2018-01-22 14:13:19
augusta.de ZSK active 2018-01-22 14:13:19
but after that time there will be now again. Done this twice sine end
november 2017.
they all user default profile with
<KSK>
<Algorithm length="4096">10</Algorithm>
<Lifetime>P5Y</Lifetime>
<Repository>SoftHSM</Repository>
</KSK>
<ZSK>
<Algorithm length="1024">10</Algorithm>
<Lifetime>P90D</Lifetime>
<Repository>SoftHSM</Repository>
</ZSK>

HI again,

i pinpointed the problem in the logs.

Jan 22 14:13:19 inga ods-enforcerd: DB prepare SQL SELECT zone.id,
zone.rev, zone.policyId, zone.name, zone.signconfNeedsWriting,
zone.signconfPath, zone.nextChange, zone.ttlEndDs, zone.ttlEndDk,
zone.ttlEndRs, zone.rollKskNow, zone.rollZskNow, zone.rollCskNow,
zone.inputAdapterType, zone.inputAdapterUri, zone.outputAdapterType,
zone.outputAdapterUri, zone.nextKskRoll, zone.nextZskRoll,
zone.nextCskRoll FROM zone WHERE zone.name = ?
Jan 22 14:13:19 inga ods-enforcerd: DB prepare Err 2006: MySQL server
has gone away
Jan 22 14:13:19 inga ods-enforcerd: [enforce_task] Could not find zone
augusta.de in database
Jan 22 14:13:19 inga kernel: Jan 22 14:13:19 inga ods-enforcerd:
[enforce_task] Could not find zone augusta.de in database

MySQL doesn't keep the connection living for week. After 28800 seconds
of inactivity the connection is closed. So OpenDNSSec should close the
connection an reopen in before it's needed or do a query at least every
28800 seconds or retry the select with a new connection if the open one
failed.

The actual timeout value can be found with
show variables where Variable_name = 'interactive_timeout';
+---------------------+-------+
| Variable_name | Value |
+---------------------+-------+
| interactive_timeout | 28800 |
+---------------------+-------+

Regards
Estartu

Berry A.W. van Halderen

2018-01-22 13:44:23 UTC

Permalink

Post by Gerhard Schmidt

Post by Yuri Schaeffer

At this point I do not know how this have happened but the problem is
clear. The enforce tasks for the zones are no longer scheduled. I
believe you can do 'ods-enforcer enforce --all' to get them back in the
queue. Alternatively restarting ods-enforcerd will work as well.
In normal operation this will only happen when the enforcer concludes no
more (automated) work needs to be done for a zone -ever-. This means
zones are only re-evaluated on user input. This should only be possible
if you configured manual rollover for both KSK and ZSK. In that case the
timestamp thing is a fluke (which we need to address). Can that be the case?
//Yuri

HI again,
i pinpointed the problem in the logs.
Jan 22 14:13:19 inga ods-enforcerd: DB prepare SQL SELECT zone.id,
zone.rev, zone.policyId, zone.name, zone.signconfNeedsWriting,
zone.signconfPath, zone.nextChange, zone.ttlEndDs, zone.ttlEndDk,
zone.ttlEndRs, zone.rollKskNow, zone.rollZskNow, zone.rollCskNow,
zone.inputAdapterType, zone.inputAdapterUri, zone.outputAdapterType,
zone.outputAdapterUri, zone.nextKskRoll, zone.nextZskRoll,
zone.nextCskRoll FROM zone WHERE zone.name = ?
Jan 22 14:13:19 inga ods-enforcerd: DB prepare Err 2006: MySQL server
has gone away
Jan 22 14:13:19 inga ods-enforcerd: [enforce_task] Could not find zone
augusta.de in database
[enforce_task] Could not find zone augusta.de in database
MySQL doesn't keep the connection living for week. After 28800 seconds
of inactivity the connection is closed. So OpenDNSSec should close the
connection an reopen in before it's needed or do a query at least every
28800 seconds or retry the select with a new connection if the open one
failed.

Great, if that is indeed the problem, and I find it very believable.
The normal way would be to perform a query every once in a while to keep
the connection alive, but we might need to consider to perform such a
query before a enforce task runs because of the current set-up.

Thank you very much for sifting through the logs.

\Berry