Bug 1314956

Summary: moving an entry cause next on-line init to skip entry has no parent, ending at line 0 of file "(bulk import)"
Product: Red Hat Enterprise Linux 7 Reporter: Marc Sauton <msauton>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED ERRATA QA Contact: Viktor Ashirov <vashirov>
Severity: high Docs Contact:
Priority: unspecified    
Version: 7.0CC: gparente, nhosoi, nkinder, pkundal, rmeggins
Target Milestone: rc   
Target Release: 7.3   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.3.5.9-1.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-03 20:40:01 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 2016-03-05 03:52:32 UTC
Description of problem:

There was a situation with a 2xMMR 1.2.11-15 master on RHEL 6, in which an on-line would not happen well as entries were mysteriously skipped with no apparent valid reason after trouble shooting schema and data:

in my testing, I got
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: Skipping entry "uid=user1,ou=someou,dc=example,dc=com" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: bad entry: ID 10016

in the customer environment, edited errors log samples:

[04/Mar/2016:16:14:51 -0500] - Bulk import: begin import on 'o=test'.
[04/Mar/2016:16:14:51 -0500] - Entry "dd=ccc,ou=ou1,ou=somedata,o=test" required attribute "objectclass" missing
[04/Mar/2016:16:14:51 -0500] - import example: WARNING: Skipping entry "dd=subou1,ou=ou2,ou=somedata,o=test" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:16:14:51 -0500] - import example: WARNING: Skipping entry "dd=xxx,ou=ou2,ou=somedata,o=test" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:16:14:51 -0500] - import example: WARNING: Skipping entry "dd=yyy,ou=ou2,ou=Ssomedata,o=test" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:16:14:51 -0500] - import example: WARNING: Skipping entry "dd=zzz,ou=ou1,ou=somedata,o=test" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:16:14:51 -0500] - import example: WARNING: Skipping entry "dd=aaa,ou=ou1,ou=somedata,o=test" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:16:14:51 -0500] - Entry "dd=tcoolApp,ou=ou4,ou=somedata,o=test" required attribute "objectclass" missing
[04/Mar/2016:16:14:51 -0500] - Entry "dd=PSWebApp,ou=ou4,ou=somedata,o=test" required attribute "objectclass" missing
..snip..

And the LDIF data and schema wer verified, and looked all correct (there is no errors from master1 using that same custom schema and data)

I could not verify (not received at this time) the customer's dbscan on master1 for the order of some of those entries.


this issue was added to port389 upstream ticket 48755 by Noriko H.:
https://fedorahosted.org/389/ticket/48755


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

reported and tested for this report with same version as the customer:
389-ds-base-1.2.11.15-69.el6_7.x86_64
but happens on all versions including branch


How reproducible:
on demand


Steps to Reproduce:

Noriko H. provided the test case scenario in the upstream ticket 48755, here a test of mine to verify:

1. Have system and 389-ds-base installed, configured and running with 2xMMR, shown here with suffix dc=example,dc=com


2. add a user entry, for example with DN uid=user1,ou=people,dc=example,dc=com

ldapmodify -xD "cn=directory manager" -w password << EOF
dn: uid=user1,ou=people,dc=example,dc=com
changetype: add
title: got promoted again 7
gidNumber: 10001
uidNumber: 10001
loginShell: /bin/bash
userPassword: password
objectClass: person
objectClass: organizationalPerson
objectClass: inetOrgPerson
objectClass: posixAccount
objectClass: top
objectClass: shadowAccount
mail: user1.com
sn: user1
cn: user1
uid: user1
homeDirectory: /home/guests/user1
telephoneNumber: +1 111 222 3333
facsimileTelephoneNumber: +1 111 222 3333
mobile: +1 111 222 3333
roomNumber: 0123456789
carLicense: 6ZBC246
displayName: somedisplayname texttexttext
givenName: somegivenname texttexttext
initials: someinitials
departmentNumber: 0123456789
employeeNumber: 0123456789
employeeType: full time texttexttext 
EOF

verify:
ldapsearch -LLLxD "cn=directory manager" -w password -b dc=example,dc=com uid=user1 dn
dn: uid=user1,ou=people,dc=example,dc=com


3. add a ou:

ldapmodify -xD "cn=directory manager" -w password << EOF
dn: ou=someou,dc=example,dc=com
changetype: add
ou: someou
objectClass: organizationalUnit
objectClass: top
EOF

verify:
ldapsearch -LLLxD "cn=directory manager" -w password -b dc=example,dc=com ou=someou dn
dn: ou=someou,dc=example,dc=com


4. now the trick to recreate the real scenario, move the test user entry to the test ou: 

ldapmodify -xD "cn=directory manager" -w password << EOF
dn: uid=user1,ou=people,dc=example,dc=com
changetype: modrdn
newrdn: uid=user1
deleteoldrdn: 0
newsuperior: ou=someou,dc=example,dc=com
EOF

verify:
ldapsearch -LLLxD "cn=directory manager" -w password -b dc=example,dc=com uid=user1 dn
dn: uid=user1,ou=someou,dc=example,dc=com


5. on master1, do online init to master2 of the db hosting the suffix dc=example,dc=com

6. on master2, review the errors log file
tail -f /var/log/dirsrv/slapd-m2/errors
and notice the 
import userRoot: WARNING: Skipping entry "uid=user1,ou=someou,dc=example,dc=com" which has no parent, ending at line 0 of file "(bulk import)"
import userRoot: WARNING: bad entry: ID 10016


Actual results:
[04/Mar/2016:18:12:34 -0800] NSMMReplicationPlugin - multimaster_be_state_change: replica dc=example,dc=com is going offline; disabling replication
[04/Mar/2016:18:12:35 -0800] - WARNING: Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: Skipping entry "uid=user1,ou=someou,dc=example,dc=com" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: bad entry: ID 10016
[04/Mar/2016:18:12:51 -0800] - import userRoot: Workers finished; cleaning up...
[04/Mar/2016:18:12:51 -0800] - import userRoot: Workers cleaned up.
[04/Mar/2016:18:12:51 -0800] - import userRoot: Indexing complete.  Post-processing...
[04/Mar/2016:18:12:51 -0800] - import userRoot: Generating numSubordinates complete.
[04/Mar/2016:18:12:51 -0800] - import userRoot: Flushing caches...
[04/Mar/2016:18:12:51 -0800] - import userRoot: Closing files...
[04/Mar/2016:18:13:47 -0800] - import userRoot: Import complete.  Processed 10018 entries (1 were skipped) in 72 seconds. (139.14 entries/sec)
[04/Mar/2016:18:13:47 -0800] NSMMReplicationPlugin - multimaster_be_state_change: replica dc=example,dc=com is coming online; enabling replication
[04/Mar/2016:18:13:47 -0800] NSMMReplicationPlugin - replica_reload_ruv: Warning: new data for replica dc=example,dc=com does not match the data in the changelog.
 Recreating the changelog file. This could affect replication with replica's  consumers in which case the consumers should be reinitialized.
[04/Mar/2016:18:13:47 -0800] NSMMReplicationPlugin - Need to create replication keep alive entry <cn=repl keep alive 20,dc=example,dc=com>
[04/Mar/2016:18:13:48 -0800] NSMMReplicationPlugin - add dn: cn=repl keep alive 20,dc=example,dc=com
objectclass: top
objectclass: ldapsubentry
objectclass: extensibleObject
cn: repl keep alive 20



Expected results:
no skipping entry


Additional info:

a test workaround using db2ldif.pl task while the LDAP services were running looked OK, there is apparently no need to shutdown the LDAP service for a db2ldif/ldif2db, there were no more errors like:
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: Skipping entry "uid=user1,ou=someou,dc=example,dc=com" which has no parent, ending at line 0 of file "(bulk import)"
[04/Mar/2016:18:12:49 -0800] - import userRoot: WARNING: bad entry: ID 10016

master1
/usr/lib64/dirsrv/slapd-m1/db2ldif.pl -D "cn=directory manager" -w password -n userroot -r -a /var/tmp/userroot.with.replication.metadata.ldif

scp /var/tmp/userroot.with.replication.metadata.ldif root@master2:/var/tmp/

master 2

chown nobody:nobody /var/tmp/userroot.with.replication.metadata.ldif
ls -lh /var/tmp/userroot.with.replication.metadata.ldif
-rw-------. 1 nobody nobody 21M Mar  4 18:24 /var/tmp/userroot.with.replication.metadata.ldif

/usr/lib64/dirsrv/slapd-m2/ldif2db.pl -D "cn=directory manager" -w password -n userroot -i /var/tmp/userroot.with.replication.metadata.ldif

no more skipped entries due to this issue.

Comment 2 Marc Sauton 2016-03-07 07:32:01 UTC
test notes

I also have the skipped entries in this scenario, which may be the customer's situation:

2xMMR on 389-ds-base-1.2.11.15-69.el6_7.x86_64

us01 / c=us,o=sps
with just:
dn: c=us,o=sps
dn: ou=someou1,c=us,o=sps
dn: ou=someou2,c=us,o=sps

spsclassroom02 / ou=spsclassroom,c=us,o=sps
with just:
dn: ou=spsclassroom,c=us,o=sps
dn: ou=someou1,ou=spsclassroom,c=us,o=sps
dn: ou=someou2,ou=spsclassroom,c=us,o=sps

then I created:
sps00 / o=sps
that backend and suffix has 105 entries from the customer data, with the associated custom schema.

in that scenario, everything "nearly" work, except the import with ldif2db.pl or ldif2db skip 8 entries, so the on-line init to m2 sends everything except those 8 skipped entries in m1.
modifying an entry on o=sps works, the changes were replicated from m1 to m2, replication is ok.

the problem is the skipped entries.

I havn't tried yet if I create o=sps first, then the other backend in sub suffixes.

Comment 6 Punit Kundal 2016-07-14 15:22:17 UTC
RHEL:
RHEL 7.3 x86_64 Server

DS builds:
[0 root@qeos-235 tickets]# rpm -qa | grep 389-ds-base
389-ds-base-1.3.5.10-3.el7.x86_64
389-ds-base-snmp-1.3.5.10-3.el7.x86_64
389-ds-base-libs-1.3.5.10-3.el7.x86_64

Steps performed:
1. Ran automated ticket 48755
[0 root@qeos-235 tickets]# py.test -v ticket48755_test.py 
========================== test session starts =================================
platform linux2 -- Python 2.7.5, pytest-2.9.2, py-1.4.31, pluggy-0.3.1 -- /usr/bin/python
cachedir: .cache
rootdir: /export/tests/tickets, inifile: 
plugins: html-1.9.0, cov-2.3.0
collected 1 items 

ticket48755_test.py::test_ticket48755 PASSED

==================== 1 passed in 62.60 seconds ================================

marking as verified.

Comment 8 errata-xmlrpc 2016-11-03 20:40:01 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://rhn.redhat.com/errata/RHSA-2016-2594.html