Hi Francesco,

likely the files in /var/lib/ldap/ have the wrong owner (root?).

chown -R openldap:openldap /var/lib/ldap should solve Your problem.

Greetings Klaus

Francesco Cicolani wrote:

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.