[Opendnssec-develop] performance
Patrik Wallström
Patrik.Wallstrom at iis.se
Fri Sep 11 19:31:11 UTC 2009
I am testing to sign a 1000 domains. Having found the major
performance issue in SoftHSM I found out that the signing of 1000
domains takes forever. I guess that there is a lot of sleeping going on.
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 6 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 6 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 6 released lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: Got task for worker 6
Sep 11 21:28:19 mask OpenDNSSEC signer engine: Worker 6 run task
Sep 11 21:28:19 mask OpenDNSSEC signer engine: Zone action to perform: 6
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 7 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 7 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 7,
sleep for 22.8428030014
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 7 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 8 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 8 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 8,
sleep for 22.8425970078
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 8 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 5 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 5 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 5,
sleep for 22.8424079418
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 5 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: Run command: '/usr/
local/libexec/opendnssec/signer -c /etc/opendnssec/conf.xml -p /var/
opendnssec/tmp/459manyzones.signed -w /var/opendnssec/tmp/
459manyzones.signed2 -r'
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 1 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 1 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 1,
sleep for 22.8420629501
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 1 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 3 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 3 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 3,
sleep for 22.8418889046
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 3 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 4 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 4 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 4,
sleep for 22.841711998
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 4 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 2 acquiring lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 2 acquired lock
Sep 11 21:28:19 mask OpenDNSSEC signer engine: no task for worker 2,
sleep for 22.8298828602
Sep 11 21:28:19 mask OpenDNSSEC signer engine: worker 2 released lock
by going to wait (for ttime)
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp:
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :origin
459manyzones
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :soa_ttl
3600
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to
subp: :soa_minimum 3600
Sep 11 21:28:19 mask OpenDNSSEC signer engine: set serial to 1252697299
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to
subp: :expiration 20090918192819
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to
subp: :expiration_denial 20090918192819
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :jitter
43200
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to
subp: :inception 20090911192319
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :refresh
20090915192819
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to
subp: :refresh_denial 20090915192819
Sep 11 21:28:19 mask OpenDNSSEC signer engine: use signature key:
a1724d88fbb45b1142ff5bdde3e3f385
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :add_ksk
a1724d88fbb45b1142ff5bdde3e3f385 7 257
Sep 11 21:28:19 mask OpenDNSSEC signer engine: use signature key:
53305ef26679e5467409d8fbe68e8b17
Sep 11 21:28:19 mask OpenDNSSEC signer engine: write to subp: :add_zsk
53305ef26679e5467409d8fbe68e8b17 7 256
Sep 11 21:28:20 mask communicated: INFO: Promoting ZSK from publish to
active as this is the first pass for the zone
Sep 11 21:28:21 mask communicated: WARNING: Making non-backed up ZSK
active, PLEASE make sure that you know the potential problems of using
keys which are not recoverable
Sep 11 21:28:22 mask keygend: /var/opendnssec/kasp.db.our_lock already
locked, sleep
Sep 11 21:28:25 mask OpenDNSSEC signer engine: signer stderr: signer:
number of signatures created: 1 (0 rr/sec)
Sep 11 21:28:25 mask OpenDNSSEC signer engine: No new signatures,
keeping zone
Sep 11 21:28:25 mask OpenDNSSEC signer engine: worker 6 acquiring lock
Sep 11 21:28:25 mask OpenDNSSEC signer engine: worker 6 acquired lock
Sep 11 21:28:25 mask OpenDNSSEC signer engine: no task for worker 6,
sleep for 16.4016799927
Sep 11 21:28:25 mask OpenDNSSEC signer engine: worker 6 released lock
by going to wait (for ttime)
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Received command:
'update 670manyzones'
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Zone 670manyzones locked
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Scheduling task to sign
zone 670manyzones at 1252678193.9 with resign time 7200
Sep 11 21:28:28 mask OpenDNSSEC signer engine: acquire cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: notify
Sep 11 21:28:28 mask OpenDNSSEC signer engine: release cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Releasing lock on zone
670manyzones
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Scheduling task to sign
zone 670manyzones at 1252678193.9 with resign time 7200
Sep 11 21:28:28 mask OpenDNSSEC signer engine: acquire cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: notify
Sep 11 21:28:28 mask OpenDNSSEC signer engine: release cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: acquire cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: notify
Sep 11 21:28:28 mask OpenDNSSEC signer engine: release cond
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Releasing lock on engine
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Sending response: Zone
now has config#012
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Done handling command
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Connection closed by peer
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 5 acquiring lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 5 acquired lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 5 released lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Got task for worker 5
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Worker 5 run task
Sep 11 21:28:28 mask OpenDNSSEC signer engine: Zone action to perform: 3
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 8 acquiring lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 3 acquiring lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 3 acquired lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: no task for worker 3,
sleep for 13.7042028904
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 3 released lock
by going to wait (for ttime)
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 1 acquiring lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 1 acquired lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: no task for worker 1,
sleep for 13.7039978504
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 1 released lock
by going to wait (for ttime)
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 7 acquiring lock
Sep 11 21:28:28 mask OpenDNSSEC signer engine: worker 7 acquired lock
So this is what I get timing wise:
-rw-r--r-- 1 root root 10591 2009-09-11 21:14 647manyzones
-rw-r--r-- 1 root root 10591 2009-09-11 21:14 648manyzones
-rw-r--r-- 1 root root 10588 2009-09-11 21:15 649manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:15 650manyzones
-rw-r--r-- 1 root root 10591 2009-09-11 21:16 651manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:17 652manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:17 653manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:18 654manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:19 655manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:19 656manyzones
-rw-r--r-- 1 root root 10617 2009-09-11 21:20 657manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:21 658manyzones
-rw-r--r-- 1 root root 10591 2009-09-11 21:21 659manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:22 660manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:23 661manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:23 662manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:24 663manyzones
-rw-r--r-- 1 root root 10617 2009-09-11 21:24 664manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:25 665manyzones
-rw-r--r-- 1 root root 10591 2009-09-11 21:26 666manyzones
-rw-r--r-- 1 root root 10617 2009-09-11 21:26 667manyzones
-rw-r--r-- 1 root root 10617 2009-09-11 21:27 668manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:28 669manyzones
-rw-r--r-- 1 root root 10618 2009-09-11 21:28 670manyzones
-rw-r--r-- 1 root root 10591 2009-09-11 21:29 671manyzones
1.5 domains per minute is not very good.
--
Patrik Wallström
Project Manager, R&D
.SE (Stiftelsen för Internetinfrastruktur)
E-mail: patrik.wallstrom at iis.se
Web: http://www.iis.se/
More information about the Opendnssec-develop
mailing list