up vote 0 down vote favorite
share [g+] share [fb]

My openldap-2.4.21 server died I so checked the syslog messages and found logs reporting a corrupt db which I tried to fix by issuing:

$ /usr/bin/db4.8_recover -v -h /var/lib/ldap/
Finding last valid log LSN: file: 69 offset 120
Recovery starting from [68][84]
Recovery complete at Mon Nov  7 10:32:54 2011
Maximum transaction ID 80015fb4 Recovery checkpoint [70][28]

After that I tried to start slapd which failed because of an Unacceptable log file. That issue never happened to me before, db4.*_recover could always fix issues. What I know is that the ldap utils got upgraded from db4.7 to db4.8 recently.

$ /etc/init.d/slapd start

$ tail -f /var/log/syslog

Nov  7 10:33:08 server slapd[4083]: @(#) $OpenLDAP: slapd 2.4.21 (Jun  2 2011 19:36:19) $#012#011buildd@allspice:/build/buildd/openldap-2.4.21/debian/build/servers/slapd
Nov  7 10:33:08 server slapd[4084]: hdb_db_open: database "dc=example,dc=org": unclean shutdown detected; attempting recovery.
Nov  7 10:33:08 server slapd[4084]: bdb(dc=example,dc=org): Unacceptable log file /var/lib/ldap/log.0000000067: unsupported log version 15
Nov  7 10:33:08 server slapd[4084]: bdb(dc=example,dc=org): Invalid log file: log.0000000067: Invalid argument
Nov  7 10:33:08 server slapd[4084]: bdb(dc=example,dc=org): PANIC: Invalid argument
Nov  7 10:33:08 server slapd[4084]: bdb(dc=example,dc=org): unable to join the environment
Nov  7 10:33:08 server slapd[4084]: hdb_db_open: database "dc=example,dc=org" cannot be recovered, err -30974. Restore from backup!
Nov  7 10:33:08 server slapd[4084]: bdb(dc=example,dc=org): txn_checkpoint interface requires an environment configured for the transaction subsystem
Nov  7 10:33:08 server slapd[4084]: bdb_db_close: database "dc=example,dc=org": txn_checkpoint failed: Invalid argument (22).
Nov  7 10:33:08 server slapd[4084]: backend_startup_one (type=hdb, suffix="dc=example,dc=org"): bi_db_open failed! (-30974)
Nov  7 10:33:08 server slapd[4084]: bdb_db_close: database "dc=example,dc=org": alock_close failed
Nov  7 10:33:08 server slapd[4084]: slapd stopped.

If I look at the offending log file it seems properly created (same size and correct permissions)

$ ls -lh /var/lib/ldap

-rw-r----- 1 openldap openldap  10M 2011-11-07 08:50 log.0000000065
-rw-r----- 1 openldap openldap  10M 2011-11-07 10:12 log.0000000066
-rw-r----- 1 openldap openldap  10M 2011-11-07 10:17 log.0000000067
-rw-r----- 1 openldap openldap  10M 2011-11-07 10:27 log.0000000068
-rw-r----- 1 openldap openldap  10M 2011-11-07 10:27 log.0000000069
-rw------- 1 openldap openldap  30M 2011-10-28 10:30 mail.bdb
-rw------- 1 openldap openldap 2.5M 2011-10-28 10:30 objectClass.bdb
-rw------- 1 openldap openldap  18M 2011-10-28 10:30 sn.bdb
-rw------- 1 openldap openldap 2.2M 2011-10-28 10:30 uid.bdb

Q1: How can I fix the unacceptable log file problem?

I've tried to read the log files using db4.8_printlog -h /var/lib/ldap and so far it's been running for 1 hour displaying all the logged transactions. I'll update the question if it throws an error.

Also, when I run the db_recovery utility several times in a row WITHOUT restarting slapd in the meantime I see the last valid log file changing every time which I was not expecting

$ /usr/bin/db*.*_recover -v -h /var/lib/ldap/
Finding last valid log LSN: file: 71 offset 120
Recovery starting from [70][84]
Recovery complete at Mon Nov  7 10:41:15 2011
Maximum transaction ID 80015fb4 Recovery checkpoint [72][28]

$ /usr/bin/db*.*_recover -v -h /var/lib/ldap/
Finding last valid log LSN: file: 72 offset 120
Recovery starting from [71][84]
Recovery complete at Mon Nov  7 10:43:31 2011
Maximum transaction ID 80015fb4 Recovery checkpoint [73][28]

Q2: Is that normal to see the last valid log file changing for every db recovery (without slapd being used at all)?

link|improve this question
81% accept rate
Have you tried file /var/lib/ldap/log.* to see if your log files have conflicting DB versions? Over the years I've also seen similar problems with several different programs using BerkeleyDB, not only with OpenLDAP. BDB can be a bit painful sometimes. – Janne Pikkarainen Nov 7 '11 at 12:31
Logs files prior to log.0000000064 have version 14. Subsequent logs have version 15. This doesn't explain why it fails on log.0000000067 and not log.0000000064. – user64204 Nov 7 '11 at 14:06
feedback

1 Answer

up vote 1 down vote accepted

You'd better use the utilities which shipped in the OpenLDAP package:

$ rpm -ql openldap-servers | grep db_
/usr/sbin/slapd_db_archive
/usr/sbin/slapd_db_checkpoint
/usr/sbin/slapd_db_deadlock
/usr/sbin/slapd_db_dump
/usr/sbin/slapd_db_hotbackup
/usr/sbin/slapd_db_load
/usr/sbin/slapd_db_printlog
/usr/sbin/slapd_db_recover
/usr/sbin/slapd_db_stat
/usr/sbin/slapd_db_upgrade
/usr/sbin/slapd_db_verify

instead of from the db4-utils package:

/usr/bin/db_archive
/usr/bin/db_checkpoint
/usr/bin/db_deadlock
/usr/bin/db_dump
/usr/bin/db_dump185
/usr/bin/db_load
/usr/bin/db_printlog
/usr/bin/db_recover
/usr/bin/db_stat
/usr/bin/db_upgrade
/usr/bin/db_verify
link|improve this answer
Do you recommend a particular version for openldap-servers? – user64204 Nov 7 '11 at 14:04
No. But notice that the version of BerkeleyDB which is built in OpenLDAP maybe different from the external package (often older than). It is why it has complained about the "unsupported log version 15". – quanta Nov 7 '11 at 23:48
Thanks. My point is, if the issue was strictly related to unsupported log version 15, why didn't db_recover fail on log.0000000064 which is the first log to have version 15 (i.e. why did it only fail 3 logs later on log.0000000067)? – user64204 Nov 8 '11 at 7:27
feedback

Your Answer

 
or
required, but never shown
discard

Not the answer you're looking for? Browse other questions tagged or ask your own question.