Bug 1391324 - ds9 backport 47411 - Replace substring search with plain search in referint plugin
Summary: ds9 backport 47411 - Replace substring search with plain search in referint p...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: 389-ds-base
Version: 6.8
Hardware: All
OS: Linux
urgent
urgent
Target Milestone: rc
: ---
Assignee: Noriko Hosoi
QA Contact: Viktor Ashirov
URL:
Whiteboard:
Depends On:
Blocks: 1393007
TreeView+ depends on / blocked
 
Reported: 2016-11-03 05:26 UTC by Marc Sauton
Modified: 2020-09-13 20:37 UTC (History)
6 users (show)

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.
Clone Of:
: 1393007 (view as bug list)
Environment:
Last Closed: 2017-03-21 10:23:47 UTC
Target Upstream Version:

Attachments (Terms of Use)
Add an attachment (proposed patch, testcase, etc.)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 748 0 None None None 2020-09-13 20:37:26 UTC
Red Hat Product Errata RHBA-2017:0667 0 normal SHIPPED_LIVE 389-ds-base bug fix update 2017-03-21 12:35:05 UTC

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
Note You need to log in before you can comment on or make changes to this bug.