[Opendnssec-user] zone sign after upgrading to 1.3.1

[Göran Bengtson]

On Mon, 12 Sep 2011, Matthijs Mekking wrote:

> From: Matthijs Mekking <matthijs at NLnetLabs.nl>
> To: Göran Bengtson <goeran at chalmers.se>
> Cc: "opendnssec-user at lists.opendnssec.org"
>     <opendnssec-user at lists.opendnssec.org>
> Message-ID: <4E6E18AF.3020302 at nlnetlabs.nl>
> Date: Mon, 12 Sep 2011 16:35:27 +0200
> Subject: Re: [Opendnssec-user] zone sign after upgrading to 1.3.1
> 
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> Hi,
>
> On 09/12/2011 03:58 PM, Göran Bengtson wrote:
>> I tried an upgrade from 1.3.0 to 1.3.1. on a RedHat Enterprise 5.7 system
>> today and now zone transfer or explicit sign commands fail to trigger
>> a zone sign.
>>
>> After increasing the verbosity the logs say:
>> Sep 12 11:48:51 ns-test ods-signerd: [fifo] unable to push item: max cap
>> reached
>
> This is a verbose debug message. All RRsets are pushed on a queue for
> signing. However, the queue has limited space. If you see this, RRsets
> are put on the queue faster than that they can be signed (which is logical).
>
>> I tried increasing FIFOQ_MAX_COUNT in signer/src/scheduler/fifoq.h from
>> 1000
>> to 10000 and that got rid of that message, but the zones are still not
>> signed
>> (at least not all the times they should be).  Later, when working on 10-15
>> zones the max cap reached message turned up again and  I also find
>> "ods-signerd: [fifo] popped item, count=9999" messages supporting the
>> conclusion that the fifo is full.  Is 1000 or 10000 really too small, or
>> is there another problem behind this?
>
> The value for FIFOQ_MAX_COUNT is not the cause here.
>
>> More logs below. A guess is some race conditions (maybe between threads).
>> What does "no valid signconf.xml for zone chalmers.se yet" indicate?
>> The file is present and as far as I can se valid.
>
> It means that the signer has not yet read a valid signer configuration
> (or it least it thinks it has not).
>
> I think I know what is going on here. The signer can update the signer
> configuration in two different code paths: Through ods-signer update
> <zone> (or adding a fresh zone), or through the backup files. In the
> latter case, the 'I have a valid signconf' flag is not set.
>
> The patch below should fix this, or do

It did. Thanks!

 			/ Göran

>
>> touch signconf/<zone>.xml
>> ods-signer update <zone>
>
> Thanks for your report.
>
> Best regards,
>  Matthijs
>
>
> Modified: branches/OpenDNSSEC-1.3/signer/src/signer/zone.c
> ===================================================================
> - --- branches/OpenDNSSEC-1.3/signer/src/signer/zone.c	2011-09-12 10:30:33
> UTC (rev 5610)
> +++ branches/OpenDNSSEC-1.3/signer/src/signer/zone.c	2011-09-12 14:15:58
> UTC (rev 5611)
> @@ -954,6 +954,7 @@
>
>         /* all ok */
>         zone->zonedata->initialized = 1;
> +        zone->prepared = 1;
>         if (zone->stats) {
>             lock_basic_lock(&zone->stats->stats_lock);
>             stats_clear(zone->stats);
> @@ -992,6 +993,7 @@
>             zone->zonedata->outbound_serial = outbound;
>             /* all ok */
>             zone->zonedata->initialized = 1;
> +            zone->prepared = 1;
>             if (zone->stats) {
>                 lock_basic_lock(&zone->stats->stats_lock);
>                 stats_clear(zone->stats);
>
>
>
>> Anyone seen this before?
>>
>> Sep 12 12:15:23 ns-test ods-signerd: [cmdhandler] done handling command
>> verbosity 7[11]
>> Sep 12 12:16:54 ns-test ods-signerd: zone fetcher received NOTIFY for
>> zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: zone fetcher transferred zone
>> chalmers.se serial 2011091207 successfully
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] 1 clients in progress...
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] accept client 15
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] received command sign
>> chalmers.se[16]
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] sign zone command
>> Sep 12 12:16:54 ns-test ods-signerd: [scheduler] unschedule task [sign]
>> for zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] reschedule task for
>> zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [scheduler] schedule task [read]
>> for zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] zone chalmers.se
>> scheduled for immediate re-sign
>> Sep 12 12:16:54 ns-test ods-signerd: [engine] wake up workers
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [scheduler] pop task for zone
>> chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [scheduler] unschedule task [read]
>> for zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] start working on zone
>> chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] perform task [read] for
>> zone chalmers.se at 1315822614
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] read zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] no valid signconf.xml
>> for zone chalmers.se yet
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] continue task [sign]
>> for zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] finished working on
>> zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [scheduler] schedule task [sign]
>> for zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [task] On Mon Sep 12 13:16:54 2011
>> I will [sign] zone chalmers.se
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[1]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[2]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[3]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[2]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[3]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[4]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[2]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[4]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[5]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[3]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[5]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[6]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[4]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[6]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[7]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[5]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[7]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[8]] wake up
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[6]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[8]] report for duty
>> Sep 12 12:16:54 ns-test ods-signerd: [cmdhandler] done handling command
>> sign chalmers.se[16]
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[7]] nothing to do
>> Sep 12 12:16:54 ns-test ods-signerd: [worker[8]] nothing to do
>> Sep 12 12:17:35 ns-test ods-signerd: [cmdhandler] 1 clients in progress...
>> Sep 12 12:17:35 ns-test ods-signerd: [cmdhandler] accept client 15
>> Sep 12 12:17:35 ns-test ods-signerd: [cmdhandler] received command
>> verbosity 0[11]
>> Sep 12 12:17:35 ns-test ods-signerd: [cmdhandler] verbosity command
>> Sep 12 12:17:35 ns-test ods-signerd: [log] switching log to syslog
>> verbosity 0 (log level 2)
>>
>> _______________________________________________
>> Opendnssec-user mailing list
>> Opendnssec-user at lists.opendnssec.org
>> https://lists.opendnssec.org/mailman/listinfo/opendnssec-user
>
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v1.4.11 (GNU/Linux)
> Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
>
> iQEcBAEBAgAGBQJObhivAAoJEA8yVCPsQCW5+bIIANa8IjnlMVJo+8Pxy90NnRdk
> 97FJy/XbsyCO9nhV46LcfVjcpO67GO7WEjzebIkdqVjR2Oo8Eb9pqphoX05MxRIP
> Xl/cYm0hS3b6xVKNhVz0Zp1kETCKlokW/QjpBXB16yhNEViCDUxAvM3YRBcoiO3D
> YgbI2L1Zf5LfeG2BS+zhlTjpYGPWYeK3+zdSY3MHTSQP2u9Iu6cQhn3TIwNjNFvA
> aKPIYlo7/iwV0brcvuCubIO41vVYN4hwUcDCl8343IUJfDMtNWadm4T2pKqfXCSB
> 7mZGQ7FN2dDgHF+EjlmYRLRL1msjxDSui6l/+z0ILtwkmoJHIi7H9AMbqsIICog=
> =6buH
> -----END PGP SIGNATURE-----