[Opendnssec-user] signer process hangs after finishing the work

[Michael Braunoeder]

Hi,

I'm running a test setup to signed a copy of  ".AT" and 2 other 
subdomains of .at. The setup worked pretty fine (with the auditor 
disabled), but in the last 2 weeks a problem occured.

After signing .AT and executing the update notify command the signer 
process still keeps running and waits for something. The zone seems to 
be signed correctly and the reload of the signed zone works also without 
any problems.

The problem with the hanging signer processes occurs only with the 
.AT-zone (about 900000 delegations, ~92MB filesize), the smaller 
subdomains work fine.

I upgraded to the latest svn-trunk (on Monday) but the problem still 
remains.

The currently active processes:

root      2596  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root      5009  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root      6261     1  1 Nov30 ?        00:58:32 /usr/bin/python 
/usr/local/lib/opendnssec/signer/Engine.py
root      8792  6261  0 Nov30 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root      9221  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     12990  6261  0 Nov30 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     13991  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     16326  6261  0 Dec01 ?        00:00:04 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     17759  6261  0 Nov30 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     19542  6261  0 00:16 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     20095  6261  0 Nov30 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     21868  6261  0 02:16 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     23222  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     24197  6261  0 04:16 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     25556  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     27880  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     28886  6261  0 08:06 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     31215  6261  0 10:06 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r
root     32693  6261  0 Dec01 ?        00:00:00 
/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r


The logfile output of the last signer-run:

Dec  2 10:12:49 security ods-signerd: Run command: 
'/usr/local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p 
/var/opendnssec/tmp/at.signed -w /var/opendnssec/tmp/at.signed2 -r'
Dec  2 10:12:49 security ods-signerd: write to subp:
Dec  2 10:12:49 security ods-signerd: write to subp: :origin at
Dec  2 10:12:49 security ods-signerd: write to subp: :soa_ttl 3600
Dec  2 10:12:49 security ods-signerd: write to subp: :soa_minimum 3600
Dec  2 10:12:49 security ods-signerd: Run command: 
'/usr/local/libexec/opendnssec/get_serial -f /var/opendnssec/unsigned/at'
Dec  2 10:12:49 security ods-signerd: set serial to 2009120201
Dec  2 10:12:49 security ods-signerd: write to subp: :soa_serial 2009120201
Dec  2 10:12:49 security ods-signerd: write to subp: :soa_serial_keep 1
Dec  2 10:12:49 security ods-signerd: set nsec3 values
Dec  2 10:12:49 security ods-signerd: write to subp: :nsec3_algorithm 1
Dec  2 10:12:49 security ods-signerd: write to subp: :nsec3_iterations 5
Dec  2 10:12:49 security ods-signerd: write to subp: :nsec3_salt 
5cd9f134909fe613
Dec  2 10:12:49 security ods-signerd: write to subp: :expiration 
20091204091249
Dec  2 10:12:49 security ods-signerd: write to subp: :expiration_denial 
20091205091249
Dec  2 10:12:49 security ods-signerd: write to subp: :jitter 43200
Dec  2 10:12:49 security ods-signerd: write to subp: :inception 
20091202090749
Dec  2 10:12:49 security ods-signerd: write to subp: :refresh 20091203091249
Dec  2 10:12:49 security ods-signerd: write to subp: :refresh_denial 
20091204091249
Dec  2 10:12:49 security ods-signerd: use signature key: 
12ca55e86819887d4822d2364d2c3260
Dec  2 10:12:49 security ods-signerd: write to subp: :add_ksk 
12ca55e86819887d4822d2364d2c3260 7 257
Dec  2 10:12:49 security ods-signerd: use signature key: 
ee7e96b6b02d7b1d8f9ca9105054a7cd
Dec  2 10:12:49 security ods-signerd: write to subp: :add_zsk 
ee7e96b6b02d7b1d8f9ca9105054a7cd 7 256
Dec  2 10:14:22 security ods-signerd: signer stderr: signer: number of 
signatures created: 751 (8 rr/sec)
Dec  2 10:14:22 security ods-signerd: Created 751 new signatures
Dec  2 10:14:22 security ods-signerd: Run command: 
'/usr/local/libexec/opendnssec/finalizer -f /var/opendnssec/tmp/at.signed'
Dec  2 10:14:33 security ods-signerd: Output zone to 
/var/opendnssec/signed/at.signed
Dec  2 10:14:33 security ods-signerd: Run command: 
'/usr/local/libexec/opendnssec/get_serial -f 
/var/opendnssec/tmp/at.finalized'
Dec  2 10:14:33 security ods-signerd: Stored output serial: 2009120201
Dec  2 10:14:33 security ods-signerd: Running update notify 
command:/usr/sbin/rndc -s signed.labs.nic.at reload at
Dec  2 10:14:34 security ods-signerd: Update notify command has run
Dec  2 10:14:34 security ods-signerd: output: zone reload queued
Dec  2 10:14:34 security ods-signerd: worker 2 acquiring lock
Dec  2 10:14:34 security ods-signerd: worker 2 acquired lock
Dec  2 10:14:34 security ods-signerd: no task for worker 2, sleep for 
6751.39977288
Dec  2 10:14:34 security ods-signerd: worker 2 released lock by going to 
wait (for ttime)

Do you have any ideas how to solve this?

Best,
Michael