Hi everybody,
sorry for the long post, but I'm new to openLDAP, and I wish to provide as much information as possible in order to pinpoint the troublesome issue that is driving me nuts.
First of all, I installed openLDAP server with Berkeley DB on a machine running Ubuntu 8.04.2, using available packages from certified sources.
Following some details I think might be useful:
root@bob:/etc/ldap# uname -a
Linux bob 2.6.24-24-generic #1 SMP Wed Apr 15 15:54:25 UTC 2009 i686 GNU/Linux
These are slapd and bdb version info I get from syslog when starting slapd:
Jun 14 17:08:19 bob slapd[9475]: @(#) $OpenLDAP: slapd 2.4.9 (Aug 5 2008 20:18:55) $ ^Ibuildd@palmer:/build/buildd/openldap2.3-2.4.9/debian/build/servers/slapd
[...]
Jun 14 17:08:19 bob slapd[9475]: hdb_back_initialize: Sleepycat Software: Berkeley DB 4.2.52: (December 3, 2003)
After installation everything seemed to work fine, and I could populate and browse my LDAP directory with no problems.
Following some details I think may be useful to know:
some directives in slapd.conf:
[...]
loglevel stats
# Where the dynamically loaded modules are stored
modulepath /usr/lib/ldap
moduleload back_hdb
[...]
# Specific Backend Directives for hdb:
backend hdb
[...]
# Specific Directives for database #1, of type hdb:
database hdb
[...]
# Where the database file are physically stored for database #1
directory "/var/lib/ldap"
[...]
# The dbconfig settings are used to generate a DB_CONFIG file the first
# time slapd starts. They do NOT override existing an existing DB_CONFIG
# file. You should therefore change these settings in DB_CONFIG directly
# or remove DB_CONFIG and restart slapd for changes to take effect.
[...]
dbconfig set_cachesize 0 2097152 0
[...]
# Number of objects that can be locked at the same time.
dbconfig set_lk_max_objects 1500
# Number of locks (both requested and granted)
dbconfig set_lk_max_locks 1500
# Number of lockers
dbconfig set_lk_max_lockers 1500
[...]
# Save the time that the entry gets modified, for database #1
lastmod on
# Checkpoint the BerkeleyDB database periodically in case of system
# failure and to speed slapd shutdown.
checkpoint 512 30
this was the content of DB_CONFIG file after installation and first start of slapd:
root@bob:/var/lib/ldap# cat DB_CONFIG
set_cachesize 0 2097152 0
set_lk_max_objects 1500
set_lk_max_locks 1500
set_lk_max_lockers 1500
this was the structure of /var/lib/ldap (the timestamps refer to the last successful working recovery I made):
root@bob:/var/lib/ldap# l
total 816
-rw-r--r-- 1 openldap openldap 2048 2009-06-14 17:09 alock
-rw------- 1 openldap openldap 8192 2009-06-14 17:08 cn.bdb
-rw------- 1 openldap openldap 8192 2009-06-14 17:39 __db.001
-rw------- 1 openldap openldap 2629632 2009-06-14 17:39 __db.002
-rw------- 1 openldap openldap 1081344 2009-06-14 17:39 __db.003
-rw------- 1 openldap openldap 565248 2009-06-14 17:09 __db.004
-rw------- 1 openldap openldap 24576 2009-06-14 17:39 __db.005
-rw-r--r-- 1 openldap openldap 383 2009-06-14 17:07 DB_CONFIG
-rw------- 1 openldap openldap 8192 2009-06-14 17:39 dn2id.bdb
-rw------- 1 openldap openldap 81920 2009-06-14 17:39 id2entry.bdb
-rw------- 1 openldap openldap 142289 2009-06-14 17:39 log.0000000001
-rw------- 1 openldap openldap 8192 2009-06-14 17:08 objectClass.bdb
-rw------- 1 openldap openldap 8192 2009-06-14 17:08 uid.bdb
Problems rose when I tried to test some 'tweaks' with DB_CONFIG file.
In particular, I was trying to store log files and data files in separate directories, thinking this would greatly simplify the db backup process.
First thing I did, was adding some lines to DB_CONFIG, in order to specify data and log dirs (I also tweaked default values for log files and cache):
root@bob:/var/lib/ldap# cat DB_CONFIG
# Directory for the data files
set_data_dir /var/lib/ldap/bdbdata
set_cachesize 0 2097152 0
set_lk_max_objects 1500
set_lk_max_locks 1500
set_lk_max_lockers 1500
# Logging settings
# Max memory cache for db file name caching
set_lg_regionmax 1048576
# Size of memory cache to log data
set_lg_bsize 32768
# Maximum size of logfile
set_lg_max 262144
# Directory for the logfiles
set_lg_dir /var/lib/ldap/bdblogs
After that, I created the new dirs in /var/lib/ldap and set the ownerships:
root@bob:/var/lib/ldap# ls -l | grep bdb
drwxr-xr-x 2 openldap openldap 4096 2009-06-14 16:59 bdbdata
drwxr-xr-x 2 openldap openldap 4096 2009-06-14 17:07 bdblogs
Finally, changed loglevel from 'stats' to 'any' in slapd.conf, and restarted slapd: here comes the problems!
slapd couldn't restart and syslog shows problems regarding permissions to write:
Jun 14 18:10:43 bob slapd[9624]: slapd startup: initiated.
Jun 14 18:10:43 bob slapd[9624]: backend_startup_one: starting "cn=config"
Jun 14 18:10:43 bob slapd[9624]: config_back_db_open
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn=config"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn=module{0}"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn=schema"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn={0}core"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn={1}cosine"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn={2}nis"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "cn={3}inetorgperson"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "olcDatabase={-1}frontend"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "olcDatabase={0}config"
Jun 14 18:10:43 bob slapd[9624]: config_build_entry: "olcDatabase={1}hdb"
Jun 14 18:10:43 bob slapd[9624]: backend_startup_one: starting "dc=springfield,dc=edu"
Jun 14 18:10:43 bob slapd[9624]: hdb_db_open: "dc=springfield,dc=edu"
Jun 14 18:10:43 bob slapd[9624]: hdb_db_open: database "dc=springfield,dc=edu": dbenv_open(/var/lib/ldap).
Jun 14 18:10:43 bob kernel: [36914.145407] audit(1244995843.179:55): type=1503 operation="inode_create" requested_mask="w::" denied_mask="w::" name="/var/lib/ldap/bdbdata/__db.1.22d19" pid=9624 profile="/usr/sbin/slapd" namespace="default"
Jun 14 18:10:43 bob kernel: [36914.146448] audit(1244995843.179:56): type=1503 operation="inode_create" requested_mask="w::" denied_mask="w::" name="/var/lib/ldap/bdbdata/__db.1.22d19" pid=9624 profile="/usr/sbin/slapd" namespace="default"
Jun 14 18:10:43 bob kernel: [36914.147356] audit(1244995843.179:57): type=1503 operation="inode_create" requested_mask="w::" denied_mask="w::" name="/var/lib/ldap/bdbdata/__db.1.22d19" pid=9624 profile="/usr/sbin/slapd" namespace="default"
Jun 14 18:10:43 bob slapd[9624]: hdb_db_open: database "dc=springfield,dc=edu": db_open(/var/lib/ldap/id2entry.bdb) failed: Permission denied (13).
Jun 14 18:10:43 bob slapd[9624]: ====> bdb_cache_release_all
Jun 14 18:10:43 bob slapd[9624]: bdb(dc=springfield,dc=edu): dn2id.bdb: unable to flush: No such file or directory
Jun 14 18:10:43 bob slapd[9624]: bdb(dc=springfield,dc=edu): id2entry.bdb: unable to flush: No such file or directory
Jun 14 18:10:43 bob slapd[9624]: bdb(dc=springfield,dc=edu): txn_checkpoint: failed to flush the buffer cache No such file or directory
Jun 14 18:10:43 bob slapd[9624]: bdb_db_close: database "dc=springfield,dc=edu": txn_checkpoint failed: No such file or directory (2).
Jun 14 18:10:43 bob slapd[9624]: backend_startup_one: bi_db_open failed! (13)
Jun 14 18:10:43 bob slapd[9624]: slapd shutdown: initiated
Jun 14 18:10:43 bob slapd[9624]: ====> bdb_cache_release_all
Jun 14 18:10:43 bob slapd[9624]: bdb_db_close: database "dc=springfield,dc=edu": alock_close failed
Jun 14 18:10:43 bob slapd[9624]: slapd destroy: freeing system resources.
Jun 14 18:10:43 bob slapd[9624]: slapd stopped.
Jun 14 18:10:43 bob slapd[9624]: connections_destroy: nothing to destroy.
Fortunately, I previously made a backup of my BDB data files and logs; I followed the procedures stated in the Berkeley DB Reference Guide:
1. stop slapd
2. force a checkpoint with db4.2_checkpoint -1v
3. copy all .bdb files returned by db4.2_archive -s to backup location /backup (cp -p)
4. copy all log.XXXXXXXXXX files returned by db4.2_archive -l to backup location /backup (cp -p)
So, I tried another approach.
I assumed that, in case I had to do a recovery, I could do the following:
A. ensure slapd is stopped by issuing /etc/init.d/slapd stop
B. remove all .bdb, alock, __db.XXX and log.XXXXXXXXXX files from /var/lib/ldap
C. copy .bdb files from /backup to /var/lib/ldap/bdbdata (cp -p)
D. copy log.XXXXXXXXXX file from /backup to /var/lib/ldap/bdblogs (cp -p)
Now, the structure of my /var/lib/ldap dir is:
root@bob:/var/lib/ldap# ls -lR
.:
total 16
drwxr-xr-x 2 openldap openldap 4096 2009-06-14 18:25 bdbdata
drwxr-xr-x 2 openldap openldap 4096 2009-06-14 18:25 bdblogs
-rw-r--r-- 1 openldap openldap 412 2009-06-14 18:09 DB_CONFIG
./bdbdata:
total 116
-rw------- 1 openldap openldap 8192 2009-06-14 15:30 cn.bdb
-rw------- 1 openldap openldap 8192 2009-06-14 15:34 dn2id.bdb
-rw------- 1 openldap openldap 81920 2009-06-14 15:34 id2entry.bdb
-rw------- 1 openldap openldap 8192 2009-06-14 15:30 objectClass.bdb
-rw------- 1 openldap openldap 8192 2009-06-14 15:30 uid.bdb
./bdblogs:
total 144
-rw------- 1 openldap openldap 141201 2009-06-14 15:35 log.0000000001
E. Finally, cd to /var/lib/ldap and issue the recovery command (as root):
root@bob:/var/lib/ldap# db4.2_recover -cv -h /var/lib/ldap
db_recover: Finding last valid log LSN: file: 1 offset 141201
db_recover: Recovery starting from [1][28]
db_recover: Recovery complete at Sun Jun 14 18:27:17 2009
db_recover: Maximum transaction ID 80000044 Recovery checkpoint [1][141201]
Started slapd again but got the following error logs in syslog:
Jun 14 18:28:44 bob slapd[9676]: slapd startup: initiated.
Jun 14 18:28:44 bob slapd[9676]: backend_startup_one: starting "cn=config"
Jun 14 18:28:44 bob slapd[9676]: config_back_db_open
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn=config"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn=module{0}"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn=schema"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn={0}core"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn={1}cosine"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn={2}nis"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "cn={3}inetorgperson"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "olcDatabase={-1}frontend"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "olcDatabase={0}config"
Jun 14 18:28:44 bob slapd[9676]: config_build_entry: "olcDatabase={1}hdb"
Jun 14 18:28:44 bob slapd[9676]: backend_startup_one: starting "dc=springfield,dc=edu"
Jun 14 18:28:44 bob slapd[9676]: hdb_db_open: "dc=springfield,dc=edu"
Jun 14 18:28:44 bob slapd[9676]: hdb_db_open: database "dc=springfield,dc=edu": dbenv_open(/var/lib/ldap).
Jun 14 18:28:45 bob kernel: [37994.300390] audit(1244996925.048:58): type=1503 operation="inode_permission" requested_mask="r::" denied_mask="r::" name="/var/lib/ldap/bdblogs/" pid=9676 profile="/usr/sbin/slapd" namespace="default"
Jun 14 18:28:45 bob slapd[9676]: bdb(dc=springfield,dc=edu): /var/lib/ldap/bdblogs/log.0000000001: Permission denied
Jun 14 18:28:45 bob slapd[9676]: bdb(dc=springfield,dc=edu): PANIC: Permission denied
Jun 14 18:28:45 bob slapd[9676]: bdb(dc=springfield,dc=edu): PANIC: DB_RUNRECOVERY: Fatal error, run database recovery
Jun 14 18:28:45 bob slapd[9676]: hdb_db_open: database "dc=springfield,dc=edu" cannot be opened, err -30978. Restore from backup!
Jun 14 18:28:45 bob slapd[9676]: ====> bdb_cache_release_all
Jun 14 18:28:45 bob slapd[9676]: bdb(dc=springfield,dc=edu): txn_checkpoint interface requires an environment configured for the transaction subsystem
Jun 14 18:28:45 bob slapd[9676]: bdb_db_close: database "dc=springfield,dc=edu": txn_checkpoint failed: Invalid argument (22).
Jun 14 18:28:45 bob slapd[9676]: backend_startup_one: bi_db_open failed! (-30978)
Jun 14 18:28:45 bob slapd[9676]: slapd shutdown: initiated
Jun 14 18:28:45 bob slapd[9676]: ====> bdb_cache_release_all
Jun 14 18:28:45 bob slapd[9676]: bdb_db_close: database "dc=springfield,dc=edu": alock_close failed
Jun 14 18:28:45 bob slapd[9676]: slapd destroy: freeing system resources.
Jun 14 18:28:45 bob slapd[9676]: slapd stopped.
Jun 14 18:28:45 bob slapd[9676]: connections_destroy: nothing to destroy.
Thanks in advance for your patience.
I hope to hear from somebody willing to help me out of this situation.
P.S.: please note that, if I comment the set_data_dir and set_lg_dir in DB_CONFIG, place log.XXXXXXXXXX and .bdb files in /var/lib/ldap and run db4.2_recover -cv -h /var/lib/ldap again, I'm able to get slapd running.
