Bug 1654438

Summary: dsctl db2index creates NO backup files
Product: Red Hat Enterprise Linux 8 Reporter: Marc Sauton <msauton>
Component: 389-ds-baseAssignee: mreynolds
Status: CLOSED CURRENTRELEASE QA Contact: RHDS QE <ds-qe-bugs>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 8.1CC: lkrispen, nkinder, rmeggins, spichugi, tbordaz, vashirov
Target Milestone: rc   
Target Release: 8.2   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.4.2.4-1.module+el8.2.0+4699+cf2da360 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-12-16 21:35:49 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Marc Sauton 2018-11-28 19:29:08 UTC
Description of problem:

dsctl db2index creates NO backup files/sub-directories under /var/lib/dirsrv/slapd-localhost/bak/
and 1 error:
ERR - dblayer_copyfile - Failed to open source file (null)/DBVERSION by "No such file or directory"


Version-Release number of selected component (if applicable):

Red Hat Enterprise Linux release 8.0 Beta (Ootpa)
389-ds-base-1.4.0.19-2.module+el8+1+36e60e1d.x86_64
python3-lib389-1.4.0.19-2.module+el8+1+36e60e1d.noarch


How reproducible:
always


Steps to Reproduce:

1. create a 389 instance:

cat << EOF > ~/instance.inf
[general]
[slapd]
root_password = password
[backend-userroot]
sample_entries = yes
suffix = dc=example,dc=com
EOF

dscreate from-file ~/instance.inf


2. stop 389 instance:

dsctl localhost stop
Instance "localhost" has been stopped


3. do a re-index:

dsctl localhost db2index userRoot
[28/Nov/2018:14:22:22.571825156 -0500] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[28/Nov/2018:14:22:22.575922198 -0500] - INFO - check_and_set_import_cache - pagesize: 4096, available bytes 1485524992, process usage 22114304 
[28/Nov/2018:14:22:22.576267710 -0500] - INFO - check_and_set_import_cache - Import allocates 580283KB import cache.
[28/Nov/2018:14:22:22.577036509 -0500] - INFO - dblayer_copy_directory - Backing up file 0 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/DBVERSION)
[28/Nov/2018:14:22:22.577454614 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/DBVERSION to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/DBVERSION
[28/Nov/2018:14:22:22.577716544 -0500] - INFO - dblayer_copy_directory - Backing up file 1 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/id2entry.db)
[28/Nov/2018:14:22:22.578006662 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/id2entry.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/id2entry.db
[28/Nov/2018:14:22:22.578288331 -0500] - INFO - dblayer_copy_directory - Backing up file 2 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/entryrdn.db)
[28/Nov/2018:14:22:22.578553435 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/entryrdn.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/entryrdn.db
[28/Nov/2018:14:22:22.578831912 -0500] - INFO - dblayer_copy_directory - Backing up file 3 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/nsuniqueid.db)
[28/Nov/2018:14:22:22.579114804 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/nsuniqueid.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/nsuniqueid.db
[28/Nov/2018:14:22:22.579358112 -0500] - INFO - dblayer_copy_directory - Backing up file 4 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/objectclass.db)
[28/Nov/2018:14:22:22.579636505 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/objectclass.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/objectclass.db
[28/Nov/2018:14:22:22.579904926 -0500] - INFO - dblayer_copy_directory - Backing up file 5 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/ancestorid.db)
[28/Nov/2018:14:22:22.580162147 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/ancestorid.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/ancestorid.db
[28/Nov/2018:14:22:22.580504655 -0500] - INFO - dblayer_copy_directory - Backing up file 6 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/aci.db)
[28/Nov/2018:14:22:22.580822079 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/aci.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/aci.db
[28/Nov/2018:14:22:22.581100407 -0500] - INFO - dblayer_copy_directory - Backing up file 7 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/cn.db)
[28/Nov/2018:14:22:22.581404728 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/cn.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/cn.db
[28/Nov/2018:14:22:22.581673516 -0500] - INFO - dblayer_copy_directory - Backing up file 8 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/parentid.db)
[28/Nov/2018:14:22:22.581960938 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/parentid.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/parentid.db
[28/Nov/2018:14:22:22.582246270 -0500] - INFO - dblayer_copy_directory - Backing up file 9 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/numsubordinates.db)
[28/Nov/2018:14:22:22.582505524 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/numsubordinates.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/numsubordinates.db
[28/Nov/2018:14:22:22.582816172 -0500] - INFO - dblayer_copy_directory - Backing up file 10 (/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/uid.db)
[28/Nov/2018:14:22:22.583175318 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/userroot/uid.db to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/uid.db
[28/Nov/2018:14:22:22.583697302 -0500] - INFO - upgradedb_core - userroot: Start upgradedb.
[28/Nov/2018:14:22:22.584013274 -0500] - INFO - dblayer_instance_start - Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
[28/Nov/2018:14:22:22.599522230 -0500] - INFO - import_main_offline - reindex userroot: Index buffering enabled with bucket size 100
[28/Nov/2018:14:22:23.301451480 -0500] - INFO - import_monitor_threads - reindex userroot: Workers finished; cleaning up...
[28/Nov/2018:14:22:23.502264161 -0500] - INFO - import_monitor_threads - reindex userroot: Workers cleaned up.
[28/Nov/2018:14:22:23.502775051 -0500] - INFO - import_main_offline - reindex userroot: Cleaning up producer thread...
[28/Nov/2018:14:22:23.503034592 -0500] - INFO - import_main_offline - reindex userroot: Indexing complete.  Post-processing...
[28/Nov/2018:14:22:23.503331204 -0500] - INFO - import_main_offline - reindex userroot: Generating numsubordinates (this may take several minutes to complete)...
[28/Nov/2018:14:22:23.503584861 -0500] - INFO - import_main_offline - reindex userroot: Generating numSubordinates complete.
[28/Nov/2018:14:22:23.503887567 -0500] - INFO - ldbm_get_nonleaf_ids - reindex userroot: Gathering ancestorid non-leaf IDs...
[28/Nov/2018:14:22:23.504164521 -0500] - INFO - ldbm_get_nonleaf_ids - reindex userroot: Finished gathering ancestorid non-leaf IDs.
[28/Nov/2018:14:22:23.504961246 -0500] - INFO - ldbm_ancestorid_new_idl_create_index - reindex userroot: Creating ancestorid index (new idl)...
[28/Nov/2018:14:22:23.505299700 -0500] - INFO - ldbm_ancestorid_new_idl_create_index - reindex userroot: Created ancestorid index (new idl).
[28/Nov/2018:14:22:23.505548020 -0500] - INFO - import_main_offline - reindex userroot: Flushing caches...
[28/Nov/2018:14:22:23.505786370 -0500] - INFO - import_main_offline - reindex userroot: Closing files...
[28/Nov/2018:14:22:23.509944085 -0500] - INFO - dblayer_pre_close - All database threads now stopped
[28/Nov/2018:14:22:23.510353970 -0500] - INFO - import_main_offline - reindex userroot: Reindexing complete.  Processed 14 entries in 1 seconds. (14.00 entries/sec)
[28/Nov/2018:14:22:23.510913213 -0500] - INFO - dblayer_copyfile - Copying /var/lib/dirsrv/slapd-localhost/db/log.0000000001 to /var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/log.0000000001
[28/Nov/2018:14:22:23.517555488 -0500] - WARN - dblayer_get_home_dir - Db home directory is not set. Possibly nsslapd-directory (optionally nsslapd-db-home-directory) is missing in the config file.
[28/Nov/2018:14:22:23.517951485 -0500] - ERR - dblayer_copyfile - Failed to open source file (null)/DBVERSION by "No such file or directory"
[28/Nov/2018:14:22:23.518254512 -0500] - INFO - dblayer_pre_close - All database threads now stopped
db2index successful


Actual results:

NO backup, missing all userroot db files from this example:
ls -la /var/lib/dirsrv/slapd-localhost/bak/
total 0
drwxr-xr-x. 2 dirsrv dirsrv  6 Nov 28 14:22 .
drwxr-xr-x. 5 dirsrv dirsrv 39 Nov 28 14:19 ..

and 1 error:
ERR - dblayer_copyfile - Failed to open source file (null)/DBVERSION by "No such file or directory"


Expected results:
should see the subdirectory as indicated in the errors log, missing:
/var/lib/dirsrv/slapd-localhost/bak/reindex_2018-11-28T14:22:22.452560/userroot/


Additional info:

Comment 1 Marc Sauton 2018-11-28 19:47:37 UTC
side note: db2bak works just fine as expected ( dsctl localhost db2bak )

Comment 2 mreynolds 2018-11-28 20:08:04 UTC
When you use db2index and do not specify any attributes dsctl (and the old db2index script) calls "ns-slapd upgradedb" which does the reimport of the database, and a backup.  The old db2index tool also generates the exact same log messages and errors.  But...  The reindexing does correctly complete.  So really everything is working except for confusing log messages in the errors log.