1451460 – error messages during ldif2db after enabling encryption on an attribute

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1451460 - error messages during ldif2db after enabling encryption on an attribute

Summary: error messages during ldif2db after enabling encryption on an attribute

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 7
Classification:	Red Hat
Component:	389-ds-base
Sub Component:
Version:	7.4
Hardware:	Unspecified
OS:	Unspecified
Priority:	high
Severity:	urgent
Target Milestone:	rc
Target Release:	7.7
Assignee:	Simon Pichugin
QA Contact:	RHDS QE
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	1454955
TreeView+	depends on / blocked

Reported:	2017-05-16 16:58 UTC by Roshni
Modified:	2020-09-13 22:17 UTC (History)
CC List:	10 users (show)
Fixed In Version:	389-ds-base-1.3.9.1-1.el7
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2019-08-06 12:58:23 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
error during ldif2db (66.79 KB, text/plain) 2017-05-18 21:35 UTC, Roshni	no flags	Details
View All

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Github	389ds 389-ds-base issues 3204	0	None	closed	Add a verbose option to the backup tools	2021-02-01 13:21:51 UTC
Red Hat Product Errata	RHBA-2019:2152	0	None	None	None	2019-08-06 12:58:42 UTC

Description Roshni 2017-05-16 16:58:53 UTC

Description of problem:
ldif2db fails after enabling encryption on an attribute

Version-Release number of selected component (if applicable):
389-ds-base-1.3.6.1-13.el7.x86_64

How reproducible:
always

Steps to Reproduce:

1. Setup admin ldap instance.

2. Run the attached file to enable TLS.

3. Install CA and enabled AES ciphers in server.xml

5. db2ldif -n pki-ca-rpattath-May18-CA -E -a /tmp/dbout-new.ldif -s
"o=pki-ca-rpattath-May18-CA"

6. deleted this entry cn=AES,cn=encrypted attribute
keys,cn=userRoot,cn=ldbm database,cn=plugins,cn=config (otherwise I was
not able to restart the ldap server after replacing the temp CA with
permanent CA)

7. Stop ldap server

8. replace the temporary CA and Server Cert with permanent certs.

9. start the server

10. Using redhat-idm-console I added uid as the encrypted attribute

11. ldif2db -n pki-ca-rpattath-May18-CA -E -i /tmp/dbout-new.ldif

Actual results:
[root@nocp1 ~]# ldif2db -n pki-ca-rpattath-May18-CA -E -i /tmp/dbout-new.ldif
importing data ...
[16/May/2017:12:45:43.854816925 -0400] - WARN - Security Initialization - SSL alert: Sending pin request to SVRCore. You may need to run systemd-tty-ask-password-agent to provide the password.
[16/May/2017:12:45:43.875194130 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[16/May/2017:12:45:43.899250305 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[16/May/2017:12:45:43.924208695 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[16/May/2017:12:45:43.948293361 -0400] - INFO - dblayer_start - Resizing db cache size: 106812211 -> 61694672
[16/May/2017:12:45:44.142120383 -0400] - DEBUG - ldbm_usn_init - backend: userRoot
[16/May/2017:12:45:44.156122310 -0400] - DEBUG - ldbm_usn_init - backend: NetscapeRoot
[16/May/2017:12:45:44.168495501 -0400] - DEBUG - ldbm_usn_init - backend: pki-ca-rpattath-May18-CA
[16/May/2017:12:45:44.179779052 -0400] - INFO - dblayer_pre_close - All database threads now stopped
[16/May/2017:12:45:44.194173987 -0400] - INFO - dblayer_start - Resizing db cache size: 106812211 -> 61694672
[16/May/2017:12:45:44.226457076 -0400] - INFO - dblayer_instance_start - Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
[16/May/2017:12:45:44.240297554 -0400] - INFO - check_and_set_import_cache - pagesize: 4096, available bytes 267780096, process usage 21745664 
[16/May/2017:12:45:44.251842551 -0400] - INFO - check_and_set_import_cache - Import allocates 104601KB import cache.
[16/May/2017:12:45:44.312104634 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.323786779 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.335706908 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.347728152 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.359592137 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.371518970 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.383606693 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.395437717 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.407424605 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.419410654 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.431340838 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.443285827 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.455398969 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.467332226 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.479143698 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.491281978 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.509076838 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.520991660 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.533007597 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.544902587 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.556834447 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.568871333 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.580745653 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.598687996 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.610698346 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.622593895 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.634554526 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.646563480 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.658466011 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.676373997 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.688384627 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.700290510 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.712257007 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.724270988 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.736153967 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.748122140 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.760105955 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.772028877 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.783964648 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.795981143 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.807900434 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.819863020 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.831916387 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.843768640 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.855723405 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.867727889 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.879631259 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.891573175 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.909548757 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.921473635 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.933409127 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.945430091 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.957322009 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.969287388 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.981306397 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:44.993197756 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.005157269 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.017157843 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.029067637 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.041016257 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.053041412 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.070890181 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.082858075 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.094872894 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.106762018 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.118730191 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.130717078 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.142646425 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.154604541 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.166587797 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.184482655 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.196429041 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.208431011 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.220334102 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.232297805 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.244338322 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.256207894 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.268171597 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.280154015 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.292116880 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.315961328 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.327987879 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.339872255 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.351840427 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.363844912 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.375747164 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.387710588 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.399735743 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.411620398 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.423565386 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.435567078 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.447500614 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.459438340 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.471449808 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.483341167 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.495307663 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.507309634 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.519218311 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.537126297 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.549138882 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.567033181 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.578969511 -0400] - DEBUG - _entryrdn_index_read - Suffix "o=pki-ca-rpattath-may18-ca" not found: BDB0073 DB_NOTFOUND: No matching key/data pair found(-30988)
[16/May/2017:12:45:45.595580877 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Beginning import job...
[16/May/2017:12:45:45.609016057 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Index buffering enabled with bucket size 33
[16/May/2017:12:45:45.810728380 -0400] - INFO - import_producer - import pki-ca-rpattath-May18-CA: Processing file "/tmp/dbout-new.ldif"
[16/May/2017:12:45:45.838076382 -0400] - INFO - import_producer - import pki-ca-rpattath-May18-CA: Finished scanning file "/tmp/dbout-new.ldif" (58 entries)
[16/May/2017:12:45:46.043304271 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'CA-nocp1.idm.lab.eng.rdu2.redhat.com-20443' (42)
[16/May/2017:12:45:46.069621569 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'caadmin' (7)
[16/May/2017:12:45:46.100071179 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'pkidbuser' (9)
[16/May/2017:12:45:46.369962730 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'ca-nocp1.idm.lab.eng.rdu2.redhat.com-20443' (42)
[16/May/2017:12:45:46.382106038 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'caadmin' (7)
[16/May/2017:12:45:46.393953264 -0400] - DEBUG - _back_crypt_crypto_op - Encrypt 'pkidbuser' (9)
[16/May/2017:12:45:46.825788739 -0400] - INFO - import_monitor_threads - import pki-ca-rpattath-May18-CA: Workers finished; cleaning up...
[16/May/2017:12:45:47.039386835 -0400] - INFO - import_monitor_threads - import pki-ca-rpattath-May18-CA: Workers cleaned up.
[16/May/2017:12:45:47.054061372 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Cleaning up producer thread...
[16/May/2017:12:45:47.066015020 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Indexing complete.  Post-processing...
[16/May/2017:12:45:47.077983751 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Generating numsubordinates (this may take several minutes to complete)...
[16/May/2017:12:45:47.109890592 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Generating numSubordinates complete.
[16/May/2017:12:45:47.126089956 -0400] - INFO - ldbm_get_nonleaf_ids - import pki-ca-rpattath-May18-CA: Gathering ancestorid non-leaf IDs...
[16/May/2017:12:45:47.138010644 -0400] - INFO - ldbm_get_nonleaf_ids - import pki-ca-rpattath-May18-CA: Finished gathering ancestorid non-leaf IDs.
[16/May/2017:12:45:47.168155791 -0400] - INFO - ldbm_ancestorid_new_idl_create_index - import pki-ca-rpattath-May18-CA: Creating ancestorid index (new idl)...
[16/May/2017:12:45:47.180649929 -0400] - INFO - ldbm_ancestorid_new_idl_create_index - import pki-ca-rpattath-May18-CA: Created ancestorid index (new idl).
[16/May/2017:12:45:47.191975099 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Flushing caches...
[16/May/2017:12:45:47.203940199 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Closing files...
[16/May/2017:12:45:47.853950206 -0400] - INFO - dblayer_pre_close - All database threads now stopped
[16/May/2017:12:45:47.862678785 -0400] - INFO - import_main_offline - import pki-ca-rpattath-May18-CA: Import complete.  Processed 58 entries in 2 seconds. (29.00 entries/sec)

Expected results:


Additional info:

Comment 3 Noriko Hosoi 2017-05-16 17:13:22 UTC

Hi Roshni, 

Could you attach the dbout-new.ldif to this bug?

5. db2ldif -n pki-ca-rpattath-May18-CA -E -a /tmp/dbout-new.ldif -s
"o=pki-ca-rpattath-May18-CA"


And the steps 6 through 8 do not look correct to me...

Before the step 6, could you disable SSL/startTLS?  Plus instead of "8. replace the ...", enable SSL/startTLS with the permanent certs?

6. deleted this entry cn=AES,cn=encrypted attribute
keys,cn=userRoot,cn=ldbm database,cn=plugins,cn=config (otherwise I was
not able to restart the ldap server after replacing the temp CA with
permanent CA)

7. Stop ldap server

8. replace the temporary CA and Server Cert with permanent certs.


Also, if you are on Console, you may want to try this GUI.
https://access.redhat.com/documentation/en-us/red_hat_directory_server/10/html/administration_guide/managing-certs#renewing-certs

Comment 4 Roshni 2017-05-17 13:25:32 UTC

Found the actual issue is https://bugzilla.redhat.com/show_bug.cgi?id=1451494. So closing this bug.

Comment 5 Noriko Hosoi 2017-05-17 16:18:55 UTC

Thanks for the update, Roshini!

Comment 6 Roshni 2017-05-18 21:34:47 UTC

Reopening the bug because eventhough attribute encryption and ldif2db were successful, noticed the messages in the attachment.

Comment 7 Roshni 2017-05-18 21:35:24 UTC

Created attachment 1280246 [details]
error during ldif2db

Comment 8 mreynolds 2017-05-24 20:47:11 UTC

Two issues here:

[1] If you use "-q" with ldif2db/db2ldif it will not log those DEBUG messages.

[2] Are you concerned about:

[17/May/2017:10:23:50.320813265 -0400] - ERR - attrcrypt_cipher_init - No symmetric key found for cipher AES in backend CC-NonTMS-LDAP, attempting to create one...
[17/May/2017:10:23:50.371331841 -0400] - ERR - attrcrypt_cipher_init - No symmetric key found for cipher 3DES in backend CC-NonTMS-LDAP, attempting to create one...

These actually should not be errors (ERR), but NOTICE.


Was it [1] or [2], or both that you were concerned about?

Comment 9 Roshni 2017-05-24 21:55:43 UTC

(In reply to mreynolds from comment #8)
> Two issues here:
> 
> [1] If you use "-q" with ldif2db/db2ldif it will not log those DEBUG
> messages.
> 
> [2] Are you concerned about:
> 
> [17/May/2017:10:23:50.320813265 -0400] - ERR - attrcrypt_cipher_init - No
> symmetric key found for cipher AES in backend CC-NonTMS-LDAP, attempting to
> create one...
> [17/May/2017:10:23:50.371331841 -0400] - ERR - attrcrypt_cipher_init - No
> symmetric key found for cipher 3DES in backend CC-NonTMS-LDAP, attempting to
> create one...
> 
> These actually should not be errors (ERR), but NOTICE.
> 
> 
> Was it [1] or [2], or both that you were concerned about?
I was concerned about [1] because I was not able to understand what those messages meant. For [2] I knew why those messages were shown. Will the doc have to be updated to use -q to not see those DEBUG messages?

Comment 10 mreynolds 2017-05-24 23:23:29 UTC

(In reply to Roshni from comment #9)
> > Was it [1] or [2], or both that you were concerned about?
> I was concerned about [1] because I was not able to understand what those
> messages meant. For [2] I knew why those messages were shown. Will the doc
> have to be updated to use -q to not see those DEBUG messages?

Well it is documented.  "-q" is quiet mode.  It is in the docs, usage, and man page.  These DEBUG messages have always been present as far as I know.  

That being said I don't think they should be logged/displayed by default.  It should be "quiet" by default, and use a verbose option to turn it on.  But since this has always been the behavior, I think we can push this out to 7.5 (or 8)

Comment 11 Roshni 2017-05-25 17:27:50 UTC

(In reply to mreynolds from comment #10)
> (In reply to Roshni from comment #9)
> > > Was it [1] or [2], or both that you were concerned about?
> > I was concerned about [1] because I was not able to understand what those
> > messages meant. For [2] I knew why those messages were shown. Will the doc
> > have to be updated to use -q to not see those DEBUG messages?
> 
> Well it is documented.  "-q" is quiet mode.  It is in the docs, usage, and
> man page.  These DEBUG messages have always been present as far as I know.  
> 
> That being said I don't think they should be logged/displayed by default. 
> It should be "quiet" by default, and use a verbose option to turn it on. 
> But since this has always been the behavior, I think we can push this out to
> 7.5 (or 8)

So do we need a bug for this and [2] in comment 8 ?

Comment 12 mreynolds 2017-05-25 17:32:15 UTC

(In reply to Roshni from comment #11)
> (In reply to mreynolds from comment #10)
> > (In reply to Roshni from comment #9)
> > > > Was it [1] or [2], or both that you were concerned about?
> > > I was concerned about [1] because I was not able to understand what those
> > > messages meant. For [2] I knew why those messages were shown. Will the doc
> > > have to be updated to use -q to not see those DEBUG messages?
> > 
> > Well it is documented.  "-q" is quiet mode.  It is in the docs, usage, and
> > man page.  These DEBUG messages have always been present as far as I know.  
> > 
> > That being said I don't think they should be logged/displayed by default. 
> > It should be "quiet" by default, and use a verbose option to turn it on. 
> > But since this has always been the behavior, I think we can push this out to
> > 7.5 (or 8)
> 
> So do we need a bug for this and [2] in comment 8 ?

We need to open a RFE to remove the "-q" option, and be "quiet' by default, and to add a "verbose" option.  I would set the version to RHEL 7.5 (although it won't be until RHEL 8 that we actually address it)

Comment 13 eg 2018-04-09 15:59:19 UTC

RHDS 9 does *not* require a -q option to not log debugging messages.  We did not see this output until we were loading our data into RHDS 10 this morning.

I would therefore state that this is definitely a bug, because it's not expected or reasonable behavior.

Comment 14 eg 2018-04-09 16:11:43 UTC

More detail: -q also suppresses the output that had been included before when doing an import.  So I would not suggest removing the -q option, just require a -v option to log/produce the DEBUG output.

Comment 15 mreynolds 2018-04-09 16:17:04 UTC

Reopening to evaluate regression in behavior.

Comment 17 Simon Pichugin 2019-01-10 12:06:35 UTC

Upstream issue - https://pagure.io/389-ds-base/issue/50145

Comment 19 bsmejkal 2019-05-07 08:53:32 UTC

Build tested:
389-ds-base-1.3.9.1-5.el7.x86_64

db2ldif, ldif2db, db2bak and bak2db scripts now contain verbose option to display DEBUG messages.

1) # db2ldif --help
...
-V                - Verbose output
...

# db2ldif -Z test -n userRoot -s dc=example,dc=com -a /tmp/userRoot.ldif
Exported ldif file: /tmp/userRoot.ldif
ldiffile: /tmp/userRoot.ldif

# db2ldif -Z test -n userRoot -s dc=example,dc=com -a /tmp/userRoot.ldif -V
Exported ldif file: /tmp/userRoot.ldif
ldiffile: /tmp/userRoot.ldif
[06/May/2019:04:18:14.484980689 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[06/May/2019:04:18:14.497231211 -0400] - INFO - ldbm_back_ldbm2ldif - export userRoot: Processed 9 entries (100%).
[06/May/2019:04:18:14.498092567 -0400] - INFO - dblayer_pre_close - All database threads now stopped


2) # ldif2db --help
...
-V                - Verbose output
...

# ldif2db -Z test -n userRoot -s dc=example,dc=com -i /tmp/userRoot.ldif
importing data ...
#

# ldif2db -Z test -n userRoot -s dc=example,dc=com -i /tmp/userRoot.ldif -V
importing data ...
[06/May/2019:04:33:37.807225227 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[06/May/2019:04:33:37.818503144 -0400] - INFO - dblayer_instance_start - Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
[06/May/2019:04:33:37.819716225 -0400] - INFO - check_and_set_import_cache - pagesize: 4096, available bytes 1601572864, process usage 22863872 
[06/May/2019:04:33:37.820267088 -0400] - INFO - check_and_set_import_cache - Import allocates 625614KB import cache.
[06/May/2019:04:33:37.843633007 -0400] - INFO - import_main_offline - import userRoot: Beginning import job...
...

(skipped some messages because of length)

...
[06/May/2019:04:33:38.761923077 -0400] - INFO - dblayer_pre_close - All database threads now stopped
[06/May/2019:04:33:38.762728453 -0400] - INFO - import_main_offline - import userRoot: Import complete.  Processed 9 entries in 1 seconds. (9.00 entries/sec)


3) # db2bak --help
...
-V                - Verbose output
...

# db2bak -Z test
Back up directory: /var/lib/dirsrv/slapd-test/bak/test-2019_05_06_04_43_01

# db2bak -Z test -V
Back up directory: /var/lib/dirsrv/slapd-test/bak/test-2019_05_06_04_43_13
[06/May/2019:04:43:14.012136512 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[06/May/2019:04:43:14.022638127 -0400] - INFO - dblayer_copy_directory - Backing up file 1 (/var/lib/dirsrv/slapd-test/bak/test-2019_05_06_04_43_13/userRoot/entryrdn.db)
...

(skipped some messages because of length)

...
[06/May/2019:04:43:14.056350406 -0400] - INFO - dblayer_pre_close - All database threads now stopped


4) # bak2db --help
...
-V                - Verbose output
...

# bak2db /var/lib/dirsrv/slapd-test/bak/test-2019_05_06_04_43_46 -Z test
#

# bak2db /var/lib/dirsrv/slapd-test/bak/test-2019_05_06_04_43_46 -Z test -V
[06/May/2019:04:48:43.079721313 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[06/May/2019:04:48:43.088835243 -0400] - INFO - dblayer_delete_transaction_logs - Deleting log file: (/var/lib/dirsrv/slapd-test/db/log.0000000001)
[06/May/2019:04:48:43.090990509 -0400] - INFO - dblayer_copy_directory - Restoring file 1 (/var/lib/dirsrv/slapd-test/db/userRoot/entryrdn.db)
...

(skipped some messages because of length)

...
[06/May/2019:04:48:43.135418802 -0400] - INFO - dblayer_pre_close - All database threads now stopped
#


Marking as VERIFIED.

Comment 21 errata-xmlrpc 2019-08-06 12:58:23 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:2152

Note You need to log in before you can comment on or make changes to this bug.