Thank you very much Ludwig,
Disabling referential integrity would not be an attractive workaround
in this implementation so I'm grateful for any assistance and happy to
help all I can.
I understand and we should make it work.
As far as I see we have three potential issues here.
Issue 1) the modrdn operation fails with err=1 and the message indicates
that it is the result of a failing plugin, and based on Alberto's
findings it is the referential integrity plugin. But we do not know why
it is failing. You grepped for modrdn in the errors log, is there more
logging which could give a hint ? Otherwise we need to find a pattern
which modrdns are failing and which are not, maybe also considering the
context when they fail (eg you said some are failing after one day) so
that we finally will be able to reproduce this reliably.
The modrdn operation and all the plugin operation triggered by it are
processed inside one transaction and if something fails the
operation/transaction is aborted and the state of the database should be
and should be seen as before the transaction started, but looks like it
is not the case, which leads to
Issue 2) after a failed modrdn ldapsearches can return incorrect
results. I can somehow reproduce this by enforcing the failure in gdb
and have opened this ticket to fix it:
The core problem of this issue that we have an entry cache which is not
properly cleared after the transaction abort, the cache operations are
not transacted. But this is a transient issue and after cache reload (eg
triggered by a restart) everything is consistent again.
This seems not to be the case for
Issue 3) "Restart does not resolve the residual incorrect uniqueMember
values in groups."
I did not expect this and it would be great if you could provide some
data to show the effect.
Thanks for your patience,
Ludwig
PS I will be on vacation next week, so I hope someone else will look
into it as well
Responses are in-line below.
Ludwig Krispenz wrote on 10/4/2018 12:23 AM:
> Hi Alberto, Luke,
>
> thanks for reporting the issue and tracking it down to the
> referential integrity plugin.
>
> I am investigating another issue where after a failing modrdn with
> err=1 there is an entry cache corruption, but was failing to
> reproduce locally.
> In a quick try with the referential integrity plugin enabled and
> moving a user to another subtree everything worked for me.
>
> So could you give me some more information.
> - did the failure occur consistently or randomly, did a restart help
> (ruling out entry cache issues)
The failure is random. Restart resolves some instances of dn-uid
mismatch, but not every instance. There are some differences in the
logged errors which might be related. Restart does not resolve the
residual incorrect uniqueMember values in groups.
> - did it fail for all modrdns or only specific users
Only some users, but I have been able to reproduce errors by creating
test users and not trying to rename them until the following day or
later. This led me to suspect a possible relationship to periodic
scripted tasks (such as group membership management) but I have not
been able to confirm any such relationship.
> - could you provide the referential integrity configuration from the
> dse.ldif
dn: cn=referential integrity postoperation,cn=plugins,cn=config
objectClass: top
objectClass: nsSlapdPlugin
objectClass: extensibleObject
cn: referential integrity postoperation
nsslapd-pluginPath: libreferint-plugin
nsslapd-pluginInitfunc: referint_postop_init
nsslapd-pluginType: betxnpostoperation
nsslapd-pluginEnabled: on
nsslapd-pluginprecedence: 40
referint-update-delay: 0
referint-logfile: /var/log/dirsrv/slapd-dirmaster/referint
referint-logchanges: 0
referint-membership-attr: member
referint-membership-attr: uniquemember
referint-membership-attr: owner
referint-membership-attr: seeAlso
nsslapd-plugin-depends-on-type: database
nsslapd-pluginId: referint
nsslapd-pluginVersion: 1.3.7.5
nsslapd-pluginVendor: 389 Project
nsslapd-pluginDescription: referential integrity plugin
modifiersName: cn=directory manager
modifyTimestamp: 20180321162105Z
> - and some information on the user group structure of the failing
> users/groups
Our DIT is fairly flat, as is evident from the DNs in the excerpts
below. The specific group in this example is our largest at about
11000 members, but not all of the affected entries have been members
of this group.
*Audit log excerpts:*
time: 20180925100009
dn: uid=lktestA,ou=People,o=state.ak.us
result: 0
changetype: add
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: inetOrgPerson
objectClass: soaOrgPerson
objectClass: inetLocalMailRecipient
stellentusertype: Internal
sn: lktestA
cn: lktestA
ou: Administration
l: Anchorage
uid: lktestA
creatorsName: uid=lk*****,ou=people,o=state.ak.us
modifiersName: uid=lk*****,ou=people,o=state.ak.us
createTimestamp: 20180925180009Z
modifyTimestamp: 20180925180009Z
...
time: 20180926070140
dn: cn=Statewide - Non Employees, ou=Groups, o=state.ak.us
result: 0
changetype: modify
add: uniqueMember
uniqueMember: uid=20180925mwmeienberg,ou=People,o=state.ak.us
uniqueMember: uid=dlnorthburg,ou=People,o=state.ak.us
uniqueMember: uid=dot.issd.cab,ou=People,o=state.ak.us
uniqueMember: uid=dot.issd.systems.eng,ou=People,o=state.ak.us
uniqueMember: uid=lktestA,ou=People,o=state.ak.us
uniqueMember: uid=lktestB,ou=People,o=state.ak.us
uniqueMember: uid=lktestCorup010,ou=People,o=state.ak.us
uniqueMember: uid=lktestcorup0200,ou=People,o=state.ak.us
uniqueMember: uid=lktestC,ou=People,o=state.ak.us
uniqueMember: uid=lktestD,ou=People,o=state.ak.us
uniqueMember: uid=lktestE,ou=People,o=state.ak.us
uniqueMember: uid=lktestF,ou=People,o=state.ak.us
uniqueMember: uid=lorussell,ou=People,o=state.ak.us
uniqueMember: uid=mplachinski,ou=People,o=state.ak.us
uniqueMember: uid=Rkitiona,ou=People,o=state.ak.us
uniqueMember: uid=ssaarsetharc,ou=People,o=state.ak.us
-
replace: modifiersname
modifiersname: uid=ak*****,ou=people,o=state.ak.us
-
replace: modifytimestamp
modifytimestamp: 20180926150140Z
-
*Access log excerpt:
*[27/Sep/2018:11:29:23.099860407 -0800] conn=175 fd=173 slot=173
connection from 10.*.*.2 to 10.*.*.3
[27/Sep/2018:11:29:23.100058246 -0800] conn=175 op=0 BIND
dn="uid=lk*****,ou=People,o=state.ak.us" method=128 version=3
[27/Sep/2018:11:29:23.100419707 -0800] conn=175 op=0 RESULT err=0
tag=97 nentries=0 etime=0.0000498496
dn="uid=lk*****,ou=people,o=state.ak.us"
[27/Sep/2018:11:29:23.100883691 -0800] conn=175 op=1 MODRDN
dn="uid=lktestA,ou=People,o=state.ak.us" newrdn="uid=lktestA1"
newsuperior="(null)"
[27/Sep/2018:11:29:32.010951183 -0800] conn=175 op=1 RESULT err=1
tag=109 nentries=0 etime=8.1089839667 csn=5bad2f93000000010000
[27/Sep/2018:11:29:32.011655447 -0800] conn=175 op=2 UNBIND
[27/Sep/2018:11:29:32.011669501 -0800] conn=175 op=2 fd=173 closed - U1
*Error log excerpts: *(since starting production use on 9 September,
converted from ds7)
> grep -i modrdn errors*
errors.20180907-002004:[10/Sep/2018:15:05:34.658791117 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180907-002004:[11/Sep/2018:11:28:21.168151469 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180907-002004:[12/Sep/2018:12:02:30.359474198 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180907-002004:[12/Sep/2018:12:38:32.159185135 -0800] - ERR -
ldbm_back_modrdn - entryrdn_rename_subtree failed (-30988); dn:
uid=bfishie00,ou=People,o=state.ak.us, newsrdn: (null),
dn_newsuperiordn: (null)
errors.20180914-115839:[17/Sep/2018:08:02:08.997495533 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180914-115839:[17/Sep/2018:11:22:48.235465642 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180914-115839:[17/Sep/2018:11:58:34.809217081 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180914-115839:[19/Sep/2018:15:16:15.960581907 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[24/Sep/2018:08:01:42.846771929 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[25/Sep/2018:09:00:47.780203196 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[26/Sep/2018:15:50:46.671324556 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[27/Sep/2018:10:36:35.122441609 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[27/Sep/2018:11:29:31.994645991 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[27/Sep/2018:11:42:14.074905249 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[28/Sep/2018:07:56:01.431044649 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[28/Sep/2018:07:56:40.192324627 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[28/Sep/2018:07:57:13.827975215 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors.20180924-080142:[28/Sep/2018:12:29:11.860652579 -0800] - ERR -
ldbm_back_modrdn - entryrdn_rename_subtree failed (-30988); dn:
uid=jlsmith5,ou=People,o=state.ak.us, newsrdn: (null),
dn_newsuperiordn: (null)
errors.20180924-080142:[28/Sep/2018:12:31:03.854724118 -0800] - ERR -
ldbm_back_modrdn - SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned
error but did not set SLAPI_RESULT_CODE
errors:[02/Oct/2018:13:24:59.342201280 -0800] - ERR - ldbm_back_modrdn
- SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned error but did not
set SLAPI_RESULT_CODE
errors:[02/Oct/2018:16:29:11.282793381 -0800] - ERR - ldbm_back_modrdn
- SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned error but did not
set SLAPI_RESULT_CODE
errors:[04/Oct/2018:10:03:34.536504456 -0800] - ERR - ldbm_back_modrdn
- SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned error but did not
set SLAPI_RESULT_CODE
I have noticed that many of our DNs contain ou=people (lower case p
instead of upper case P) and I have speculated about whether that
could cause problems somewhere.
> Thanks,
> Ludwig
>
> On 10/02/2018 03:41 PM, Alberto Viana wrote:
>> I had to disable this plugin to solve the problem (workaround) in my
>> master.
>>
>> My first guess to solve the problem is:
>>
>> Delete my agreements, my replication DB, and re-create everything,
>> and after that try to enable the plugin again. But I couldn't do it
>> so far...I will later in this month.
>>
>> On Fri, Sep 28, 2018 at 4:00 PM Kreuzenstein, Luke (OIT)
>> <luke.kreuzenstein(a)alaska.gov <mailto:luke.kreuzenstein@alaska.gov>>
>> wrote:
>>
>> >>> From: "Alberto Viana" <albertocrj(a)gmail.com
>> <mailto:albertocrj@gmail.com>>
>> >>> To: "General discussion list for the 389 Directory server
>> project."
>> <389-users(a)lists.fedoraproject.org
>> <mailto:389-users@lists.fedoraproject.org>>
>> >>> Sent: Tuesday, March 20, 2018 6:15:46 PM
>> >>> Subject: [389-users] error moving an user
>> >>>
>> >>> Hey Guys,
>> >>>
>> >>> 389 version: 389-Directory/1.3.7.4
>>
<
https://urldefense.proofpoint.com/v2/url?u=http-3A__1.3.7.4&d=DwMFaQ&...
>> B2017.255.1330
>> >>>
>> >>> I'm trying to move one of my users to another OU and I see
>> this kind of
>> >>> error:
>> >>>
>> >>> Error while moving entry
>> >>> - [LDAP: error code 1 - Operations Error]
>> >>> java.lang.Exception: [LDAP: error code 1 - Operations Error]
>> >>> at
>> >>>
>> >>>
>> >>> In the log I see:
>> >>>
>> >>> [20/Mar/2018:14:12:27.172553808 -0300] - ERR -
>> ldbm_back_modrdn -
>> >>> SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned error
>> but did
>> not set
>> >>> SLAPI_RESULT_CODE
>> >>>
>> >>> I thought that was related to my windows replication, but I
>> disabled it and
>> >>> I'm still getting the error.
>> >>>
>> >>> Any clues?
>> >>>
>> >>> _______________________________________________
>> >>> 389-users mailing list -- 389-users(a)lists.fedoraproject.org
>> <mailto:389-users@lists.fedoraproject.org>
>> >>> To unsubscribe send an email to
>> 389-users-leave(a)lists.fedoraproject.org
>> <mailto:389-users-leave@lists.fedoraproject.org>
>> >>>
>>
>> On Wed, Mar 21, 2018 at 12:00 PM, Simon Pichugin
>> <spichugi(a)redhat.com <mailto:spichugi@redhat.com>>
>> wrote:
>>
>> >> Hi,
>> >> could you please enable 16385 errorlog-level (16384
>> defaults and
>> 1 trace) just before the operation and send us the
>> /var/log/dirsrv/slapd-INSTNAME/errors:
>> >>
>> >> ldapmodify -h localhost -p 389 -D "cn=Directory
manager" -w
>> password << EOF
>> >> dn: cn=config
>> >> changetype: modify
>> >> replace: nsslapd-errorlog-level
>> >> nsslapd-errorlog-level: 16385
>> >> EOF
>> >>
>> >> Thanks,
>> >> Simon
>>
>> Alberto Viana wrote on 3/23/2018 8:08 AM:
>> > Simon,
>> >
>> > I was able to reproduce the problem in a new fresh install (I
>> just
>> imported my database), and It's related to "Referential Integrity
>> Postoperation Plugin" that I use in my environment. When I
>> disable it,
>> the moving works just fine.
>> >
>> > I have a single master, replication to one AD.
>> >
>> > I changed the log level, but it's really hard to find the
>> root cause.
>> >
>> > Do you want to take a look on it?
>> >
>> >
>> > Once it has some info about my tree, I'd prefer to send the
>> link to
>> download the file directly to you.
>> >
>> > Thanks.
>>
>> Was this issue ever resolved? I'm experiencing the same symptom
>> intermittently in a production environment but haven't managed to
>> reproduce it in my test environment. The DN gets updated but the
>> uid
>> (naming attribute) does not. Restarting slapd has helped in one
>> instance
>> (to apparently fix a corrupted entry) but not every instance.
>>
>> [27/Sep/2018:11:29:31.994645991 -0800] - ERR - ldbm_back_modrdn -
>> SLAPI_PLUGIN_BE_TXN_POST_MODRDN_FN plugin returned error but did
>> not set
>> SLAPI_RESULT_CODE
>>
>> It's a single master configuration with two consumer replicas
>> and about
>> 37000 entries.
>> The Referential Integrity Postoperation Plugin is enabled on the
>> master
>> only.
>>
>> using:
>> > rpm -qa | grep 389-ds-base
>> 389-ds-base-1.3.7.5-25.el7_5.x86_64
>> 389-ds-base-libs-1.3.7.5-25.el7_5.x86_64
>> > uname -a
>> Linux 3.10.0-862.11.6.el7.x86_64 #1 SMP Tue Aug 14
>> 21:49:04 UTC
>> 2018 x86_64 x86_64 x86_64 GNU/Linux
>>
>> _______________________________________________
>> 389-users mailing list -- 389-users(a)lists.fedoraproject.org
>> <mailto:389-users@lists.fedoraproject.org>
>> To unsubscribe send an email to
>> 389-users-leave(a)lists.fedoraproject.org
>> <mailto:389-users-leave@lists.fedoraproject.org>
>> Fedora Code of Conduct:
>>
https://getfedora.org/code-of-conduct.html
>>
<
https://urldefense.proofpoint.com/v2/url?u=https-3A__getfedora.org_code-2...
>> List Guidelines:
>>
https://fedoraproject.org/wiki/Mailing_list_guidelines
>>
<
https://urldefense.proofpoint.com/v2/url?u=https-3A__fedoraproject.org_wi...
>> List Archives:
>>
https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproje...
>>
<
https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.fedoraproject....
>>
>>
>>
>> _______________________________________________
>> 389-users mailing list --389-users(a)lists.fedoraproject.org
>> To unsubscribe send an email to389-users-leave(a)lists.fedoraproject.org
>> Fedora Code of
Conduct:https://getfedora.org/code-of-conduct.html
>> List
Guidelines:https://fedoraproject.org/wiki/Mailing_list_guidelines
>> List
Archives:https://lists.fedoraproject.org/archives/list/389-users@lists.fe...
>
> --
> Red Hat
GmbH,http://www.de.redhat.com/, Registered seat: Grasbrunn,
> Commercial register: Amtsgericht Muenchen, HRB 153243,
> Managing Directors: Charles Cachera, Michael Cunningham, Michael O'Neill, Eric
Shander
>
>
> _______________________________________________
> 389-users mailing list --389-users(a)lists.fedoraproject.org
> To unsubscribe send an email to389-users-leave(a)lists.fedoraproject.org
> Fedora Code of
Conduct:https://urldefense.proofpoint.com/v2/url?u=https-3A__getfedora.or...
> List
Guidelines:https://urldefense.proofpoint.com/v2/url?u=https-3A__fedorapro...
> List
Archives:https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.fedor...
_______________________________________________
389-users mailing list -- 389-users(a)lists.fedoraproject.org
To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org
Fedora Code of Conduct:
https://getfedora.org/code-of-conduct.html
List Guidelines:
https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedoraproject.org/archives/list/389-users@lists.fedoraproje... , Registered seat: Grasbrunn,
Commercial register: Amtsgericht Muenchen, HRB 153243,
Managing Directors: Charles Cachera, Michael Cunningham, Michael O'Neill, Eric
Shander