Bug 1391324

Summary: ds9 backport 47411 - Replace substring search with plain search in referint plugin
Product: Red Hat Enterprise Linux 6 Reporter: Marc Sauton <msauton>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED ERRATA QA Contact: Viktor Ashirov <vashirov>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 6.8CC: jvilicic, mkolaja, msauton, nkinder, rmeggins, sramling
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.2.11.15-85.el6 Doc Type: Bug Fix
Doc Text:
Referential integrity plug-in used to use a substring search internally, which was unncecessary and slowed down the every update operation with the unacceptable delay. In the 4 update operations - add, modify, delete and modrdn, the substring search is necessary only for modrdn. The substring search is replaced with the exact search for the other 3 update operations. The fix eliminates the unnecessary delay and improves the update performance.
Story Points: ---
Clone Of:
: 1393007 (view as bug list) Environment:
Last Closed: 2017-03-21 10:23:47 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:
Bug Depends On:    
Bug Blocks: 1393007    

Description Marc Sauton 2016-11-03 05:26:26 UTC
Description of problem:

DEL and SRCH of an entry takes seconds when referential integrity plug-in is enabled because of substring searches

this was fixed in upstream 47411 for 389-ds-base-1.3.4 some time ago, but not in 1.2.11 on RHEL 6


Version-Release number of selected component (if applicable):
RHDS9 / RHEL 6 - 389-ds-base-1.2.11.15-74.el6.x86_64


How reproducible:


Steps to Reproduce:

1. have instance already configured

2. have some data, e.g. user entries and groups with uniqueMember: uid=...full-dn

dn: cn=group10,ou=groups,dc=example,dc=com
objectClass: top
objectClass: groupOfUniqueNames
cn: group10
uniqueMember: uid=guest101,ou=people,dc=example,dc=com
...
uniqueMember: uid=guest1000,ou=people,dc=example,dc=com

3. service dirsrv stop m1

4. vim /etc/dirsrv/slapd-m1/dse.ldif

5. add internal operation log and log for referential integrity plug-in

dn: cn=config
nsslapd-accesslog-level: 260

dn: cn=referential integrity postoperation,cn=plugins,cn=config
nsslapd-logAccess: on

dn: cn=MemberOf Plugin,cn=plugins,cn=config
nsslapd-logAccess: on

6. enable the ref. int. plug-in, kept defaults for plug-in arguments, but could have removed unecessary defaults slowing down internal searches with substrings.
dn: cn=referential integrity postoperation,cn=plugins,cn=config
nsslapd-pluginEnabled: on

7. service dirsrv start m1

8. verify ns-sladp is up:

lsof -p $(pidof ns-slapd) | grep tcmalloc
[root@m1 ~]#

lsof -i :389

9. prepare to get access log:
tail -f /var/log/dirsrv/slapd-m1/access

10. delete a user entry
ldapdelete -x -D cn=directory\ manager -w password -h 10.14.5.18  uid=guest999,ou=people,dc=example,dc=com


Actual results:

see the filters with substring searches like filter="(uniquemember=*uid=guest999,...

in house test:

[02/Nov/2016:23:02:30 -0700] conn=2 fd=65 slot=65 connection from 10.3.224.98 to 10.14.5.18
[02/Nov/2016:23:02:30 -0700] conn=2 op=0 BIND dn="cn=directory manager" method=128 version=3
[02/Nov/2016:23:02:30 -0700] conn=2 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager"
[02/Nov/2016:23:02:30 -0700] conn=2 op=1 DEL dn="uid=guest999,ou=people,dc=example,dc=com"
[02/Nov/2016:23:02:30 -0700] conn=2 op=1 RESULT err=0 tag=107 nentries=0 etime=0 csn=581ad2f6000000010000
[02/Nov/2016:23:02:30 -0700] conn=Internal op=-1 SRCH base="c=us,o=sps" scope=2 filter="(member=*uid=guest999,ou=people,dc=example,dc=com)" attrs="member"
[02/Nov/2016:23:02:30 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:30 -0700] conn=Internal op=-1 SRCH base="c=us,o=sps" scope=2 filter="(uniquemember=*uid=guest999,ou=people,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=U
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 SRCH base="c=us,o=sps" scope=2 filter="(owner=*uid=guest999,ou=people,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:23:02:31 -0700] conn=2 op=2 UNBIND
[02/Nov/2016:23:02:31 -0700] conn=2 op=2 fd=65 closed - U1
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 SRCH base="c=us,o=sps" scope=2 filter="(seeAlso=*uid=guest999,ou=people,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:31 -0700] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(member=*uid=guest999,ou=people,dc=example,dc=com)" attrs="member"
[02/Nov/2016:23:02:32 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=A
[02/Nov/2016:23:02:32 -0700] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=*uid=guest999,ou=people,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:23:02:34 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1 etime=2 notes=A
[02/Nov/2016:23:02:34 -0700] conn=Internal op=-1 MOD dn="cn=group10,ou=groups,dc=example,dc=com"
[02/Nov/2016:23:02:34 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 csn=581ad2fa000000010000
[02/Nov/2016:23:02:34 -0700] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(owner=*uid=guest999,ou=people,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:23:02:35 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=A
[02/Nov/2016:23:02:35 -0700] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(seeAlso=*uid=guest999,ou=people,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=2 notes=A
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(member=*uid=guest999,ou=people,dc=example,dc=com)" attrs="member"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(uniquemember=*uid=guest999,ou=people,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(owner=*uid=guest999,ou=people,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(seeAlso=*uid=guest999,ou=people,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=sps" scope=2 filter="(member=*uid=guest999,ou=people,dc=example,dc=com)" attrs="member"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=sps" scope=2 filter="(uniquemember=*uid=guest999,ou=people,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=sps" scope=2 filter="(owner=*uid=guest999,ou=people,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="o=sps" scope=2 filter="(seeAlso=*uid=guest999,ou=people,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="ou=spsclassroom,c=us,o=sps" scope=2 filter="(member=*uid=guest999,ou=people,dc=example,dc=com)" attrs="member"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="ou=spsclassroom,c=us,o=sps" scope=2 filter="(uniquemember=*uid=guest999,ou=people,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="ou=spsclassroom,c=us,o=sps" scope=2 filter="(owner=*uid=guest999,ou=people,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 SRCH base="ou=spsclassroom,c=us,o=sps" scope=2 filter="(seeAlso=*uid=guest999,ou=people,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:23:02:37 -0700] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U


customer logs, 2 samples a user that was deleted from rhdsm01(8.2) where there is no delay in replication and the RI plugin does not insert a * in the filter

[02/Nov/2016:16:32:05 -0400] conn=5 op=1 DEL dn="uid=1400599,ou=someou,dc=example,dc=com"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="ou=someou,dc=example,dc=com" scope=2 filter="(uniqueMember=uid=1400599,ou=someou,dc=example,dc=com)" attrs=ALL 
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(member=uid=1400599,ou=someou,dc=example,dc=com)" attrs="member"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=1400599,ou=someou,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(owner=uid=1400599,ou=someou,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(seeAlso=uid=1400599,ou=someou,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(memberuid=uid=1400599,ou=someou,dc=example,dc=com)" attrs="memberuid"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(member=uid=1400599,ou=someou,dc=example,dc=com)" attrs="member"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(uniquemember=uid=1400599,ou=someou,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(owner=uid=1400599,ou=someou,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(seeAlso=uid=1400599,ou=someou,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:16:32:06 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(memberuid=uid=1400599,ou=someou,dc=example,dc=com)" attrs="memberuid"

Here is a delete on rhdsm03 (9.1.2) where there is a delay in replication and RI plugin inserts a * in the filter:

[02/Nov/2016:16:30:06 -0400] conn=18 op=1 DEL dn="uid=1478869,ou=someou,dc=example,dc=com"
[02/Nov/2016:16:30:12 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(member=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="member"
[02/Nov/2016:16:32:00 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:16:32:12 -0400] conn=7 op=31 SRCH base="dc=example,dc=com" scope=2 filter="(uid=1478869)" attrs="objectClass"
[02/Nov/2016:16:33:55 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(owner=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:16:35:54 -0400] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(seeAlso=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:16:37:56 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(member=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="member"
[02/Nov/2016:16:37:56 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(uniquemember=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="uniquemember"
[02/Nov/2016:16:37:56 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(owner=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="owner"
[02/Nov/2016:16:37:56 -0400] conn=Internal op=-1 SRCH base="o=netscaperoot" scope=2 filter="(seeAlso=*uid=1478869,ou=someou,dc=example,dc=com)" attrs="seeAlso"
[02/Nov/2016:16:37:56 -0400] conn=Internal op=-1 SRCH base="ou=someou,dc=example,dc=com" scope=2 filter="(uniquemember=uid=1478869,ou=someou,dc=example,dc=com)" attrs=ALL 



Expected results:


Additional info:

Comment 1 Marc Sauton 2016-11-03 05:39:15 UTC
note about the in house test, the test VM had several suffixes for other tests, and the ref. int. plug-in did not have a scope configured , but that may be a 1.3.4 feature only

Comment 3 Marc Sauton 2016-11-03 19:55:04 UTC
GSS Approved Z-Stream for RHEL-6.8.z

Comment 11 Sankar Ramalingam 2016-11-08 10:23:12 UTC
1). 4 way MMR setup
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; SUFF="dc=passsync,dc=com"; for PORT in `echo "1189 1289 1389 1489"`; do /usr/bin/ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b $SUFF |grep -i dn: | wc -l ; done
10307
10307
10307
10307

2). Groups with uniqueMember and members
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=grpgrp1,ou=groups,dc=passsync,dc=com"
dn: cn=grpgrp1,ou=Groups,dc=passsync,dc=com
objectClass: top
objectClass: groupOfNames
objectClass: groupOfUniqueNames
cn: grpgrp1
uniqueMember: uid=usersnew1,ou=people,ou=groups,dc=passsync,dc=com
uniqueMember: uid=usersnew2,ou=people,ou=groups,dc=passsync,dc=com
uniqueMember: uid=usersnew3,ou=people,ou=groups,dc=passsync,dc=com
member: uid=usersnew1,ou=people,ou=groups,dc=passsync,dc=com
member: uid=usersnew2,ou=people,ou=groups,dc=passsync,dc=com
member: uid=usersnew3,ou=people,ou=groups,dc=passsync,dc=com

3). Enabling Memberof and Referential Integrity plugin
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=MemberOf Plugin,cn=plugins,cn=config" |grep -i nsslapd-pluginEnabled
nsslapd-pluginEnabled: on
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=referential integrity postoperation,cn=plugins,cn=config" |grep -i nsslapd-pluginEnabled
nsslapd-pluginEnabled: on

4). Setting nsslapd-logaccess: on for both plugins.
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=referential integrity postoperation,cn=plugins,cn=config" nsslapd-logaccess
dn: cn=referential integrity postoperation,cn=plugins,cn=config
nsslapd-logaccess: on

[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=MemberOf Plugin,cn=plugins,cn=config" nsslapd-logaccess
dn: cn=MemberOf Plugin,cn=plugins,cn=config
nsslapd-logaccess: on


5). Setting accesslog level to 260
[root@vm-idm-017 MMR_WINSYNC]# PORT=1189; /usr/bin/ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=config" |grep -i nsslapd-accesslog-level
nsslapd-accesslog-level: 260

6). Running ldapdelete to remove one of the uniquemember users
[root@vm-idm-017 MMR_WINSYNC]# time PORT=1189; /usr/bin/ldapdelete -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 "uid=usersnew3,ou=people,dc=passsync,dc=com"
real	0m0.000s
user	0m0.000s
sys	0m0.000s

7). Check access logs for substring searches with filters.


[root@vm-idm-017 MMR_WINSYNC]# tail -f /var/log/dirsrv/slapd-M1/access

[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(member=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="member"
[08/Nov/2016:15:48:19 +051800] conn=1 op=2 UNBIND
[08/Nov/2016:15:48:19 +051800] conn=1 op=2 fd=64 closed - U1
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(owner=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="owner"
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(seeAlso=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="seeAlso"
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:48:19 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(member=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="member"
[08/Nov/2016:15:48:20 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=A
[08/Nov/2016:15:48:20 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(uniquemember=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[08/Nov/2016:15:48:20 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=A
[08/Nov/2016:15:48:20 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(owner=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="owner"
[08/Nov/2016:15:48:21 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=A
[08/Nov/2016:15:48:21 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(seeAlso=*uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs="seeAlso"
[08/Nov/2016:15:48:22 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=1 notes=A
[08/Nov/2016:15:48:22 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(member=uid=usersnew1,ou=people,dc=passsync,dc=com)" attrs=ALL

It looks like the substring searches are still performed. However, I don't see any delay in the delete operations. Please confirm if this is something we need to check?

Comment 12 Sankar Ramalingam 2016-11-08 10:29:54 UTC
I removed the seeAlso and owner attributes from referential integrity plugin. However, I still see the substring searches in the access logs.

[08/Nov/2016:15:55:31 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(member=*uid=usersnew2,ou=people,dc=passsync,dc=com)" attrs="member"
[08/Nov/2016:15:55:31 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:55:31 +051800] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=*uid=usersnew2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[08/Nov/2016:15:55:31 +051800] conn=Internal op=-1 RESULT err=0 tag=48 nentries=0 etime=0 notes=U
[08/Nov/2016:15:55:31 +051800] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="

Comment 17 Marc Sauton 2016-11-08 19:31:53 UTC
for the comments 11 step 7 and comment 12
if you till see the filter with member=*uid like
filter="(member=*uid=usersnew2,ou=people,dc=passsync,dc=com)" attrs="member"
I would say it means either the fix is not in, or there was a problem with it.

but there may be something else in the test:

you have
dn: cn=grpgrp1,ou=Groups,dc=passsync,dc=com
...
uniqueMember: uid=usersnew3,ou=people,ou=groups,dc=passsync,dc=com

and this:
[root@vm-idm-017 MMR_WINSYNC]# time PORT=1189; /usr/bin/ldapdelete -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 "uid=usersnew3,ou=people,dc=passsync,dc=com"

shouldn't it be
[root@vm-idm-017 MMR_WINSYNC]# time PORT=1189; /usr/bin/ldapdelete -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 "uid=usersnew3,ou=people,ou=groups,dc=passsync,dc=com"
?
or the cn=grpgrp1,ou=Groups,dc=passsync,dc=com has unexpected uniqueMember DN's in the test?

Comment 19 Sankar Ramalingam 2016-11-22 08:03:38 UTC
Followed the same steps as comment #11 to verify against the latest RHEL-6.9 builds. 
Build tested:

[root@auto-hv-02-guest09 MMR_WINSYNC]# cat /var/log/dirsrv/slapd-M1/access |grep -i "uniquemember"[22/Nov/2016:02:56:38 -0500] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=mydsusr1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[22/Nov/2016:02:56:38 -0500] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(uniquemember=uid=mydsusr1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[22/Nov/2016:02:56:38 -0500] conn=Internal op=-1 SRCH base="o=test.com" scope=2 filter="(uniquemember=uid=mydsusr1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[22/Nov/2016:02:56:46 -0500] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=mydsusr2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[22/Nov/2016:02:56:46 -0500] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(uniquemember=uid=mydsusr2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[22/Nov/2016:02:56:46 -0500] conn=Internal op=-1 SRCH base="o=test.com" scope=2 filter="(uniquemember=uid=mydsusr2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"


[root@auto-hv-02-guest09 MMR_WINSYNC]# rpm -qa |grep -i 389-ds
389-ds-base-1.2.11.15-85.el6.x86_64
389-ds-base-libs-1.2.11.15-85.el6.x86_64

After deleting the user entries, I observed the access logs. There are no substring searches performed. Hence, marking the bug as Verified.

Comment 21 errata-xmlrpc 2017-03-21 10:23:47 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/RHBA-2017-0667.html