[Opendnssec-user] OpenDNSSEC Signer hang on MacOS X -- how to troubleshoot

Carsten Strotmann (Men & Mice) carsten at menandmice.com
Wed Jul 28 11:31:09 UTC 2010 

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi Alex,

I tried to start the enforcerd and the signerd manually, but I get the
same issue. The Python process is hanging at 100% CPU.

When I start signerd, I get this error message back

pthread_cond_wait: Invalid argument

- -- Carsten

On 7/16/10 7:14 AM, Alex Dalitz wrote:
> I also have this problem with OSX. Not on any other OS though. The workaround is to manually start the enforcer, followed by the signer, on OSX.
> 
> HTH,
> 
> 
> Alex.
> 
> On 15 Jul 2010, at 18:39, Carsten Strotmann (Men & Mice) wrote:
> 
> Hello Matthijs,
> 
> I start OpenDNSSEC with
> 
> # /usr/local/sbin/ods-control start
> Starting signer engine...
> connecting to /var/run/opendnssec/engine.sock
> OpenDNSSEC signer engine version 1.1.1
> Zone list updated: 0 removed, 2 added, 0 updated
> running as pid 3180
> pthread_cond_wait: Invalid argument
> Starting enforcer...
> OpenDNSSEC ods-enforcerd started (version 1.1.1), pid 3184
> 
> 
> The process that is running away with 100% CPU on all cores is
> 0  3180     1   0   0:20.15 ??         1:19.20
> /opt/local/Library/Frameworks/Python.framework/Versions/2.6/Resources/Python.app/Contents/MacOS/Python
> /usr/local/lib/opendnssec/signer/Engine.py
> 
> I need to kill the process to stop it. ods-control stop or ods-signer
> stop will not work.
> 
> The log output is
> 
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Zone test.example.com locked
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Scheduling task to sign zone
> test.example.com at 1279215179.82 with resign time 7200
> Jul 15 19:32:59 jimbo ods-signerd[3177]: acquire cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: notify
> Jul 15 19:32:59 jimbo ods-signerd[3177]: release cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Releasing lock on zone
> test.example.com
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Scheduling task to sign zone
> test.example.com at 1279215179.82 with resign time 7200
> Jul 15 19:32:59 jimbo ods-signerd[3177]: acquire cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: notify
> Jul 15 19:32:59 jimbo ods-signerd[3177]: release cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Zone test.example.com added
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Zone newzone.example.com locked
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Scheduling task to sign zone
> newzone.example.com at 1279215179.82 with resign time 7200
> Jul 15 19:32:59 jimbo ods-signerd[3177]: acquire cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: notify
> Jul 15 19:32:59 jimbo ods-signerd[3177]: release cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Releasing lock on zone
> newzone.example.com
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Scheduling task to sign zone
> newzone.example.com at 1279215179.82 with resign time 7200
> Jul 15 19:32:59 jimbo ods-signerd[3177]: acquire cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: notify
> Jul 15 19:32:59 jimbo ods-signerd[3177]: release cond
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Zone newzone.example.com added
> Jul 15 19:32:59 jimbo ods-signerd[3177]: Run command:
> '/usr/local/libexec/opendnssec/zone_fetcher -c
> /etc/opendnssec/zonefetch.xml -z /etc/opendnssec/zonelist.xml -d -f local0'
> Jul 15 19:33:00 jimbo ods-signerd[3177]: opening socket:
> /var/run/opendnssec/engine.sock
> Jul 15 19:33:00 jimbo ods-signerd[3177]: Engine running
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 3 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 3 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 3 released lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Got task for worker 3
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Worker 3 run task
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Zone action to perform: 3
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 7 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 7 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 7 released lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Got task for worker 7
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Fetch zone:
> /var/lib/opendnssec/unsigned/test.example.com-zone.axfr
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 1 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 1 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 1, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Worker 7 run task
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 1 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 2 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 8 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Zone action to perform: 3
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Fetch zone:
> /var/lib/opendnssec/unsigned/newzone.example.com-zone.axfr
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 4 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 5 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 6 acquiring lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 2 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 2, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 2 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 8 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 8, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 8 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 4 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 4, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 4 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 5 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 5, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 5 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 6 acquired lock
> Jul 15 19:33:00 jimbo ods-signerd[3180]: no task for worker 6, sleep for 0
> Jul 15 19:33:00 jimbo ods-signerd[3180]: worker 6 released lock by going
> to wait (indef)
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Run command:
> '/usr/local/libexec/opendnssec/get_serial -f
> /var/lib/opendnssec/unsigned/test.example.com-zone'
> Jul 15 19:33:00 jimbo /usr/libexec/taskgated[3173]: no system signature
> for unsigned /usr/local/sbin/ods-enforcerd[3182]
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Run command:
> '/usr/local/libexec/opendnssec/get_serial -f
> /var/lib/opendnssec/unsigned/newzone.example.com-zone'
> Jul 15 19:33:00 jimbo ods-enforcerd[3182]: opendnssec-enforcer starting...
> Jul 15 19:33:00 jimbo ods-enforcerd[3182]: opendnssec-enforcer Parent
> exiting...
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: opendnssec-enforcer forked OK...
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Preprocessing signed zone:
> test.example.com
> Jul 15 19:33:00 jimbo ods-signerd[3180]: No signed zone yet
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Sorting zone: test.example.com
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: opendnssec-enforcer started
> (version 1.1.1), pid 3184
> Jul 15 19:33:00 jimbo ods-signerd[3180]: Run command:
> '/usr/local/libexec/opendnssec/quicksorter -o test.example.com. -f
> /var/lib/opendnssec/unsigned/test.example.com-zone -w
> /var/opendnssec/tmp/test.example.com.sorted -m 3600 -t 3600'
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: HSM opened successfully.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Reading config
> "/etc/opendnssec/conf.xml"
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Reading config schema
> "/usr/local/share/opendnssec/conf.rng"
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Communication Interval: 3600
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: No DS Submit command supplied
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: SQLite database set to:
> /var/opendnssec/kasp.db
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Log User set to: local0
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Switched log facility to: local0
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Connecting to Database...
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Policy default found.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Key sharing is Off.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Purging keys...
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: zonelist filename set to
> /etc/opendnssec/zonelist.xml.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Zone test.example.com found.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Policy for test.example.com
> set to default.
> Jul 15 19:33:00 jimbo ods-enforcerd[3184]: Config will be output to
> /var/opendnssec/signconf/test.example.com.xml.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: WARNING: KSK Retirement
> reached; please submit the new DS for test.example.com and use
> ods-ksmutil key ds-seen when the DS appears in the DNS.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: No change to:
> /var/opendnssec/signconf/test.example.com.xml
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: Zone newzone.example.com found.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: Policy for
> newzone.example.com set to default.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: Config will be output to
> /var/opendnssec/signconf/newzone.example.com.xml.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: WARNING: KSK Retirement
> reached; please submit the new DS for newzone.example.com and use
> ods-ksmutil key ds-seen when the DS appears in the DNS.
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: No change to:
> /var/opendnssec/signconf/newzone.example.com.xml
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: Disconnecting from Database...
> Jul 15 19:33:01 jimbo ods-enforcerd[3184]: Sleeping for 3600 seconds.
> 
> 
> -- Carsten
> 
> On 7/14/10 12:26 PM, Matthijs Mekking wrote:
>>>> Hi Carsten,
>>>>
>>>> Do you mean the ods-signer or ods-signerd (daemon)? The cause of this
>>>> issue in 1.0.0rc1 was usually because one of the signer tools was still
>>>> running.
>>>>
>>>> Unfortunately, the current version of the signer can not run in
>>>> foreground mode. Perhaps the output of ps can help you identify which
>>>> processes are still running.
>>>>
>>>> Best regards,
>>>>
>>>> Matthijs
>>>>
>>>> On 07/14/2010 12:08 PM, Carsten Strotmann (Men & Mice) wrote:
>>>>> Hi,
>>>>
>>>>> the ods-signer process (Python, OpenDNSSEC 1.1.0) sometimes hangs under
>>>>> MacOS X 10.6. No message in the syslog.
>>>>
>>>>> I've seen there was a similar issue fixed in 1.0.0rc1.
>>>>
>>>>> How can I troubleshoot this issue? Is there a way to start the signer
>>>>> process in foreground with debug messages?
>>>>
>>>>> -- Carsten
>>>> _______________________________________________
>>>> Opendnssec-user mailing list
>>>> Opendnssec-user at lists.opendnssec.org
>>>> https://lists.opendnssec.org/mailman/listinfo/opendnssec-user
> _______________________________________________
> Opendnssec-user mailing list
> Opendnssec-user at lists.opendnssec.org
> https://lists.opendnssec.org/mailman/listinfo/opendnssec-user
_______________________________________________
Opendnssec-user mailing list
Opendnssec-user at lists.opendnssec.org
https://lists.opendnssec.org/mailman/listinfo/opendnssec-user

-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.14 (Darwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkxQFPwACgkQElgUYvSqn/STNQCgn51AD5L5enEg+E7FnALes22Z
mHEAn1v98qV147HCgrjMYx8Kv3erv6L/
=4e3o
-----END PGP SIGNATURE-----

More information about the Opendnssec-user mailing list