> the ods-enforcer daemon loops, periodically looking for things > which need to be done / scheduled. Inside its service loop it > has this piece of code: > > log_msg(config, LOG_INFO, "Connecting to Database..."); > kaspConnect(config, &dbhandle); > > followed by misleadingly-indented code (that's a minor issue). > > However... What happens if an administrator just happens to run > "ods-ksmutil key list ..." at exactly that time when the enforcer > wants to connect to the database? This is what the log can tell: > > Dec 8 08:32:43 hugin ods-enforcerd: Connecting to Database... > Dec 8 08:32:43 hugin ods-enforcerd: ERROR: error executing SQL - database is > locked > > and this time it looks like ods-enforcerd really means that this > is an error, because kaspConnect() doesn't return an error but > does an exit() if connecting to the database fails:
Another variant of this problem of database locking just happened to me. On the hourly run, the enforcer logged: Mar 18 07:30:03 hugin ods-enforcerd: HSM connection open. Mar 18 07:30:03 hugin ods-enforcerd: Reading config "/usr/pkg/etc/opendnssec/conf.xml" Mar 18 07:30:03 hugin ods-enforcerd: Reading config schema "/usr/pkg/share/opendnssec/conf.rng" Mar 18 07:30:03 hugin ods-enforcerd: Communication Interval: 3600 Mar 18 07:30:03 hugin ods-enforcerd: No DS Submit command supplied Mar 18 07:30:03 hugin ods-enforcerd: SQLite database set to: /var/db/opendnssec/kasp.db Mar 18 07:30:03 hugin ods-enforcerd: Log User set to: local0 Mar 18 07:30:03 hugin ods-enforcerd: Switched log facility to: local0 Mar 18 07:30:03 hugin ods-enforcerd: Connecting to Database... Mar 18 07:30:03 hugin ods-enforcerd: Policy default found. Mar 18 07:30:03 hugin ods-enforcerd: Key sharing is Off. Mar 18 07:30:03 hugin ods-enforcerd: 369 zone(s) found on policy "default" Mar 18 07:30:04 hugin ods-enforcerd: Predict we need 369 KSKs Mar 18 07:30:04 hugin ods-enforcerd: Have 369 KSK keys in queue Mar 18 07:30:04 hugin ods-enforcerd: Need 0 new KSK keys Mar 18 07:30:04 hugin ods-enforcerd: No new KSKs need to be created. Mar 18 07:30:04 hugin ods-enforcerd: Predict we need 369 new ZSK keys Mar 18 07:30:04 hugin ods-enforcerd: Have 369 ZSK keys in queue Mar 18 07:30:04 hugin ods-enforcerd: Need 0 new ZSK keys Mar 18 07:30:04 hugin ods-enforcerd: No new ZSKs need to be created. Mar 18 07:30:04 hugin ods-enforcerd: Purging keys... Mar 18 07:30:04 hugin ods-enforcerd: zonelist filename set to /usr/pkg/etc/opendnssec/zonelist.xml. Mar 18 07:30:04 hugin ods-enforcerd: Zone 156.193.in-addr.arpa found. Mar 18 07:30:04 hugin ods-enforcerd: Policy for 156.193.in-addr.arpa set to default. Mar 18 07:30:04 hugin ods-enforcerd: Config will be output to /var/opendnssec/signconf/156.193.in-addr.arpa.xml. Mar 18 07:30:04 hugin ods-enforcerd: No change to: /var/opendnssec/signconf/156.193.in-addr.arpa.xml Mar 18 07:30:04 hugin ods-enforcerd: Zone 157.193.in-addr.arpa found. Mar 18 07:30:04 hugin ods-enforcerd: Policy for 157.193.in-addr.arpa set to default. Mar 18 07:30:04 hugin ods-enforcerd: Config will be output to /var/opendnssec/signconf/157.193.in-addr.arpa.xml. Mar 18 07:30:04 hugin ods-enforcerd: ERROR: error executing SQL - database is locked Mar 18 07:30:04 hugin ods-enforcerd: No change to: /var/opendnssec/signconf/157.193.in-addr.arpa.xml and then subseqently apparently for every zone: Mar 18 07:30:04 hugin ods-enforcerd: Zone 91.78.in-addr.arpa found. Mar 18 07:30:04 hugin ods-enforcerd: Policy for 91.78.in-addr.arpa set to default. Mar 18 07:30:04 hugin ods-enforcerd: Config will be output to /var/opendnssec/signconf/91.78.in-addr.arpa.xml. Mar 18 07:30:04 hugin ods-enforcerd: ERROR: error executing SQL - cannot start a transaction within a transaction Mar 18 07:30:04 hugin ods-enforcerd: ERROR: database operation failed - cannot start a transaction within a transaction Mar 18 07:30:04 hugin ods-enforcerd: KsmRequestKeys returned: 71691 Mar 18 07:30:04 hugin ods-enforcerd: Signconf not written for 91.78.in-addr.arpa and then on the next hourly run it appears to have stumbled in its own feet: Mar 18 08:32:11 hugin ods-enforcerd: HSM connection open. Mar 18 08:32:11 hugin ods-enforcerd: Reading config "/usr/pkg/etc/opendnssec/con f.xml" Mar 18 08:32:11 hugin ods-enforcerd: Reading config schema "/usr/pkg/share/opend nssec/conf.rng" Mar 18 08:32:11 hugin ods-enforcerd: Communication Interval: 3600 Mar 18 08:32:11 hugin ods-enforcerd: No DS Submit command supplied Mar 18 08:32:11 hugin ods-enforcerd: SQLite database set to: /var/db/opendnssec/ kasp.db Mar 18 08:32:11 hugin ods-enforcerd: Log User set to: local0 Mar 18 08:32:11 hugin ods-enforcerd: Switched log facility to: local0 Mar 18 08:32:11 hugin ods-enforcerd: Connecting to Database... Mar 18 08:32:11 hugin ods-enforcerd: ERROR: error executing SQL - database is lo cked which is an instance of the problem quoted above, and which will cause the enforcer to exit(-1). I suspect once again that what caused this problem was that one of my scripts which runs periodically e.g. to list all the zones handled by OpenDNSSEC via "ods-ksmutil zone list" ran at about the same time, causing the initial problem, because the script which ran from cron produced this output, submitted at 07:31:00: 'ods-ksmutil zone list' failed, retrying 'ods-ksmutil zone list' failed, retrying ERROR: error executing SQL - database is locked 'ods-ksmutil zone list' failed, retrying ERROR: error executing SQL - database is locked 'ods-ksmutil zone list' failed, retrying ERROR: error executing SQL - database is locked 'ods-ksmutil zone list' failed, retrying ERROR: error executing SQL - database is locked 'ods-ksmutil zone list' failed, giving up I'm not sure what caused the first ods-ksmutil failure in this script, there's apparently no error message attached in the above output, although the "sh -x" output from the script lists all 6 identical error messages. Just restarting the enforcer appears to at least temporarily have restored my OpenDNSSEC installation to working order. Regards, - Håvard _______________________________________________ Opendnssec-user mailing list [email protected] https://lists.opendnssec.org/mailman/listinfo/opendnssec-user
