Bug 1076729
| Summary: | Continuous add/delete of an entry in MMR setup causes entryrdn-index conflict | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | Milan Kubík <mkubik> |
| Component: | 389-ds-base | Assignee: | Noriko Hosoi <nhosoi> |
| Status: | CLOSED ERRATA | QA Contact: | Viktor Ashirov <vashirov> |
| Severity: | unspecified | Docs Contact: | |
| Priority: | medium | ||
| Version: | 7.0 | CC: | amsharma, nkinder, rmeggins |
| Target Milestone: | rc | ||
| Target Release: | 7.1 | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | 389-ds-base-1.3.3.1-1.el7 | Doc Type: | Bug Fix |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2015-03-05 09:34:02 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: | |||
Milan Kubík wrote: > I ran into this problem trying to verify #1074084. How to verify: https://bugzilla.redhat.com/show_bug.cgi?id=1074084#c2 (although it is very simple...) M1 :: [12/Jan/2015:13:46:21 +051800] conn=243 fd=66 slot=66 connection from ::1 to ::1 [12/Jan/2015:13:46:21 +051800] conn=243 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [12/Jan/2015:13:46:21 +051800] conn=243 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager" [12/Jan/2015:13:46:21 +051800] conn=243 op=1 ADD dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:21 +051800] conn=243 op=1 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000500010000 [12/Jan/2015:13:46:21 +051800] conn=243 op=2 UNBIND [12/Jan/2015:13:46:21 +051800] conn=243 op=2 fd=66 closed - U1 [12/Jan/2015:13:46:21 +051800] conn=244 fd=66 slot=66 connection from ::1 to ::1 [12/Jan/2015:13:46:21 +051800] conn=244 op=0 BIND dn="cn=Directory Manager" method=128 version=3 [12/Jan/2015:13:46:21 +051800] conn=244 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager" [12/Jan/2015:13:46:21 +051800] conn=244 op=1 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:22 +051800] conn=244 op=1 RESULT err=0 tag=107 nentries=0 etime=1 csn=54b382d6000600010000 [12/Jan/2015:13:46:22 +051800] conn=244 op=2 UNBIND [12/Jan/2015:13:46:22 +051800] conn=244 op=2 fd=66 closed - U1 [12/Jan/2015:13:46:22 +051800] conn=49 op=21 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:22 +051800] conn=49 op=21 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:23 +051800] conn=48 op=203 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:23 +051800] conn=48 op=203 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:23 +051800] conn=48 op=204 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:23 +051800] conn=48 op=204 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:23 +051800] conn=48 op=205 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=205 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d5000400020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=206 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=206 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d5000500020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=207 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=207 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d5000700020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=208 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=208 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000000020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=209 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=209 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000100020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=210 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=48 op=210 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000200020000 [12/Jan/2015:13:46:23 +051800] conn=48 op=211 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:24 +051800] conn=48 op=211 RESULT err=0 tag=107 nentries=0 etime=1 csn=54b382d6000300020000 [12/Jan/2015:13:46:24 +051800] conn=48 op=212 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:24 +051800] conn=48 op=212 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000400020000 [12/Jan/2015:13:46:24 +051800] conn=48 op=213 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:24 +051800] conn=48 op=213 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000500020000 [12/Jan/2015:13:46:24 +051800] conn=48 op=214 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:24 +051800] conn=48 op=214 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000600020000 [12/Jan/2015:13:46:24 +051800] conn=48 op=215 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:24 +051800] conn=48 op=215 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d7000000020000 [12/Jan/2015:13:46:25 +051800] conn=49 op=23 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:25 +051800] conn=49 op=23 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:26 +051800] conn=48 op=217 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:26 +051800] conn=48 op=217 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:28 +051800] conn=49 op=24 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:28 +051800] conn=49 op=24 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:28 +051800] conn=49 op=25 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:28 +051800] conn=49 op=25 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:47:27 +051800] conn=48 op=218 UNBIND [12/Jan/2015:13:47:27 +051800] conn=48 op=218 fd=64 closed - U1 [12/Jan/2015:13:47:29 +051800] conn=49 op=27 UNBIND [12/Jan/2015:13:47:29 +051800] conn=49 op=27 fd=65 closed - U1 M2 :: === [12/Jan/2015:13:46:23 +051800] conn=46 op=205 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=205 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d5000500010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=206 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=206 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d5000600010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=207 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=207 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000000010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=208 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=208 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000100010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=209 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=209 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000200010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=210 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=210 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000300010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=211 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=211 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000400010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=212 ADD dn="uid=amita,ou=People,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=212 RESULT err=0 tag=105 nentries=0 etime=0 csn=54b382d6000500010000 [12/Jan/2015:13:46:23 +051800] conn=46 op=213 DEL dn="uid=amita,ou=people,dc=example,dc=com" [12/Jan/2015:13:46:23 +051800] conn=46 op=213 RESULT err=0 tag=107 nentries=0 etime=0 csn=54b382d6000600010000 [12/Jan/2015:13:46:25 +051800] conn=48 op=24 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:25 +051800] conn=48 op=24 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:26 +051800] conn=46 op=215 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:26 +051800] conn=46 op=215 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:27 +051800] conn=46 op=216 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:27 +051800] conn=46 op=216 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:27 +051800] conn=46 op=217 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:27 +051800] conn=46 op=217 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:27 +051800] conn=48 op=26 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [12/Jan/2015:13:46:27 +051800] conn=48 op=26 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:46:27 +051800] conn=48 op=27 EXT oid="2.16.840.1.113730.3.5.5" name="Netscape Replication End Session" [12/Jan/2015:13:46:27 +051800] conn=48 op=27 RESULT err=0 tag=120 nentries=0 etime=0 [12/Jan/2015:13:47:27 +051800] conn=48 op=28 UNBIND [12/Jan/2015:13:47:27 +051800] conn=48 op=28 fd=66 closed - U1 [12/Jan/2015:13:47:28 +051800] conn=46 op=218 UNBIND [12/Jan/2015:13:47:28 +051800] conn=46 op=218 fd=64 closed - U1 No error found, hence marking as VERIFIED. 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-2015-0416.html |
Description of problem: I ran into this problem trying to verify #1074084. When I tried to run a script that adds and deletes an entry on all masters repeatedly to create a conflict and nsuniqueid entry one of the servers got into the state which can be seen in this log excerpt: [14/Mar/2014:05:53:54 -0400] - slapd started. Listening on All Interfaces port 2389 for LDAP requests [14/Mar/2014:05:59:29 -0400] entryrdn-index - _entryrdn_insert_key: Same DN (dn: uid=range_user12,ou=People,dc=example,dc=com) is already in the entryrdn file with different ID 4383. Expected ID is 4384. [14/Mar/2014:05:59:29 -0400] - database index operation failed BAD 1031, err=9999 Unknown error 9999 [14/Mar/2014:05:59:29 -0400] - add: attempt to index 4384 failed (rc=9999) [14/Mar/2014:05:59:30 -0400] conn=200 op=477 csn=5322d301000700070000 - Annotated DN nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef+uid=range_user12,ou=People,dc=example,dc=com has naming conflict [14/Mar/2014:05:59:30 -0400] conn=200 op=479 csn=5322d302000000070000 - Annotated DN nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef,nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef+uid=range_user12,ou=People,dc=example,dc=com has naming conflict [14/Mar/2014:05:59:30 -0400] ldbm_back_delete - Attempt to Tombstone again a tombstone entry uid=range_user12,ou=people,dc=example,dc=com [14/Mar/2014:05:59:30 -0400] NSMMReplicationPlugin - IsValidOperation: NULL operation CSN [14/Mar/2014:05:59:30 -0400] NSMMReplicationPlugin - write_changelog_and_ruv: can't add a change for uid=range_user12,ou=people,dc=example,dc=com (uniqid: 3fb02ccc-ab5f11e3-9f529539-057f01ef, optype: 32) to changelog csn [14/Mar/2014:05:59:30 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code [14/Mar/2014:05:59:30 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code but did not set SLAPI_RESULT_CODE [14/Mar/2014:05:59:31 -0400] ldbm_back_delete - Attempt to Tombstone again a tombstone entry uid=range_user12,ou=people,dc=example,dc=com [14/Mar/2014:05:59:31 -0400] NSMMReplicationPlugin - IsValidOperation: NULL operation CSN [14/Mar/2014:05:59:31 -0400] NSMMReplicationPlugin - write_changelog_and_ruv: can't add a change for uid=range_user12,ou=people,dc=example,dc=com (uniqid: 3fb02ccc-ab5f11e3-9f529539-057f01ef, optype: 32) to changelog csn [14/Mar/2014:05:59:31 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code [14/Mar/2014:05:59:31 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code but did not set SLAPI_RESULT_CODE ... [14/Mar/2014:06:00:06 -0400] conn=202 op=76 csn=5322d296000600090000 - Annotated DN nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef,nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef+uid=range_user12,ou=People,dc=example,dc=com has naming conflict [14/Mar/2014:06:00:06 -0400] conn=202 op=78 csn=5322d296000800090000 - Annotated DN nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef,nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef+uid=range_user12,ou=People,dc=example,dc=com has naming conflict ... [14/Mar/2014:06:00:13 -0400] conn=202 op=416 csn=5322d302000100090000 - Annotated DN nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef,nsuniqueid=3fb02ccc-ab5f11e3-9f529539-057f01ef+uid=range_user12,ou=People,dc=example,dc=com has naming conflict [14/Mar/2014:06:00:27 -0400] ldbm_back_delete - Attempt to Tombstone again a tombstone entry uid=range_user12,ou=people,dc=example,dc=com [14/Mar/2014:06:00:27 -0400] NSMMReplicationPlugin - IsValidOperation: NULL operation CSN [14/Mar/2014:06:00:27 -0400] NSMMReplicationPlugin - write_changelog_and_ruv: can't add a change for uid=range_user12,ou=people,dc=example,dc=com (uniqid: 3fb02ccc-ab5f11e3-9f529539-057f01ef, optype: 32) to changelog csn [14/Mar/2014:06:00:27 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code [14/Mar/2014:06:00:27 -0400] - SLAPI_PLUGIN_BE_TXN_POST_DELETE_FN plugin returned error code but did not set SLAPI_RESULT_CODE There seems to be a problem with entryrdn-index that causes (?) a cascade of other problems (deleting tombstone entry, invalid CSN operation, corrupted changelog). Version-Release number of selected component (if applicable): 389-ds-base-1.3.1.6-24.el7 How reproducible: always Steps to Reproduce: 1. Set up MMR environment. 2. Continuously add and delete an entry on all masters, trying to create conflicts and nsuniqueid entries. Actual results: After some time the entry is no longer replicated on the affected server. Also the entry is not searchable, add operation fails and reports the entry being present, delete operation fails. Expected results: The conflict in entryrdn index does not occur. Additional info: Possible blocker for bugzilla #1074084. Probably a race condition.