RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1235387 - Slow replication when deleting large quantities of multi-valued attributes
Summary: Slow replication when deleting large quantities of multi-valued attributes
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: 389-ds-base
Version: 7.0
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Noriko Hosoi
QA Contact: Viktor Ashirov
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-06-24 16:48 UTC by Noriko Hosoi
Modified: 2020-09-13 21:25 UTC (History)
3 users (show)

Fixed In Version: 389-ds-base-1.3.4.0-2.el7
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-11-19 11:42:45 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github 389ds 389-ds-base issues 1526 0 None closed Slow replication when deleting large quantities of multi-valued attributes 2020-10-06 12:01:23 UTC
Red Hat Product Errata RHBA-2015:2351 0 normal SHIPPED_LIVE 389-ds-base bug fix and enhancement update 2015-11-19 10:28:44 UTC

Description Noriko Hosoi 2015-06-24 16:48:02 UTC 
This bug is created as a clone of upstream ticket:
https://fedorahosted.org/389/ticket/48195

We write to our directory via Java API. When changing our groups the ModificationItems are lists of distinguished names of users. 

There is no problem when we add new uniqueMembers to our groups, but deleting them takes much too long on the second (replicated) master. (example deleting 850 members from 86000 takes 159 seconds on dldap02).

dldap01
[01/Jun/2015:13:44:47 +0200] conn=141407 op=3 MOD dn="cn=TSNMAIL-VerteilerZugriff,cn=TSNMAIL,cn=Applications,ou=Groups,ou=TSN-AD,dc=tirol+gvOuId=AT:L7:LVN:000001,dc=gv,dc=at"
[01/Jun/2015:13:44:48 +0200] conn=141407 op=3 RESULT err=0 tag=103 nentries=0 etime=0.858000 csn=556c45b0000000010000

dldap02
[01/Jun/2015:13:44:48 +0200] conn=141354 op=4 MOD dn="cn=TSNMAIL-VerteilerZugriff,cn=TSNMAIL,cn=Applications,ou=Groups,ou=TSN-AD,dc=tirol+gvOuId=AT:L7:LVN:000001,dc=gv,dc=at"
[01/Jun/2015:13:47:28 +0200] conn=141354 op=4 RESULT err=0 tag=103 nentries=0 etime=159.670000 csn=556c45b0000000010000

I found a closed ticket (#346) with some simmilarities, maybe the problem still exists in a multimaster replication environment when deleting attributes. Logging shows millions of calls to plugin_call_syntax_filter_ava uniqueMember=gvGid=AT:L7:TSN:i.weitlaner,ou=People,ou=TSN-AD,dc=tirol+gvOuId=AT:L7:LVN:000001,dc=gv,dc=at ?
Comment 2 Sankar Ramalingam 2015-09-19 08:55:41 UTC 
Enabled memberOf plugin and added a group with 90000 members in group. Then, added/deleted about 100 users as member/uniquemember to the group.

[root@dhcp35-196 ~]# PORT=1289; ldapsearch -LLL -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=MemberOf Plugin,cn=plugins,cn=config" "memberofgroupattr"
dn: cn=MemberOf Plugin,cn=plugins,cn=config
memberofgroupattr: member
memberofgroupattr: uniquemember

[root@dhcp35-196 export]# ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com" |grep -i member: |wc -l
90000

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f 100addmember.ldif
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	1m24.197s
user	0m0.009s
sys	0m0.007s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f 100delmember.ldif
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	0m5.059s
user	0m0.003s
sys	0m0.008s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f 100uinqmemadd.ldif modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	1m23.539s
user	0m0.005s
sys	0m0.014s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f 100uinqmemdel.ldif 
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	1m24.492s
user	0m0.006s
sys	0m0.017s


Another set of delete/add member/uniquemember attribute to groups.

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100addmember.ldif 
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	1m21.672s
user	0m0.007s
sys	0m0.023s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100delmember.ldif 
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	0m4.045s
user	0m0.004s
sys	0m0.005s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100uinqmemadd.ldif 
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	1m45.207s
user	0m0.010s
sys	0m0.019s

[root@dhcp35-196 export]# PORT=1189; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100uinqmemdel.ldif 
modifying entry "cn=grpC,ou=groups,dc=nestgrpsuff,dc=com"

real	0m49.638s
user	0m0.005s
sys	0m0.017s

-----
It takes about 90secs on an average to add or delete about 120 member/uniquemember attributes. I checked this only on Master.
-----

[root@dhcp35-196 export]# cat New100delmember.ldif |head -5
dn: cn=grpC,ou=groups,dc=nestgrpsuff,dc=com
delete: member
member: uid=usrC59879,ou=people,dc=nestgrpsuff,dc=com
member: uid=usrC59880,ou=people,dc=nestgrpsuff,dc=com
member: uid=usrC59881,ou=people,dc=nestgrpsuff,dc=com

[root@dhcp35-196 export]# cat New100addmember.ldif |head -5
dn: cn=grpC,ou=groups,dc=nestgrpsuff,dc=com
add: member
member: uid=usrB59879,ou=people,dc=nestgrpsuff,dc=com
member: uid=usrB59880,ou=people,dc=nestgrpsuff,dc=com
member: uid=usrB59881,ou=people,dc=nestgrpsuff,dc=com

[root@dhcp35-196 export]# cat New100uinqmemadd.ldif |head -5
dn: cn=grpC,ou=groups,dc=nestgrpsuff,dc=com
add: uniquemember
uniquemember: uid=usrB49879,ou=people,dc=nestgrpsuff,dc=com
uniquemember: uid=usrB49880,ou=people,dc=nestgrpsuff,dc=com
uniquemember: uid=usrB49881,ou=people,dc=nestgrpsuff,dc=com

[root@dhcp35-196 export]# cat New100uinqmemdel.ldif |head -5
dn: cn=grpC,ou=groups,dc=nestgrpsuff,dc=com
delete: uniquemember
uniquemember: uid=usrB49879,ou=people,dc=nestgrpsuff,dc=com
uniquemember: uid=usrB49880,ou=people,dc=nestgrpsuff,dc=com
uniquemember: uid=usrB49881,ou=people,dc=nestgrpsuff,dc=com
Comment 3 Viktor Ashirov 2015-09-21 17:07:30 UTC 
Updating on behalf of Sankar (bz was down).

For adding 122 users with uniquemember attribute:

[root@dhcp35-196 export]# PORT="1189";ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l ; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100uinqmemadd.ldif
90017
modifying entry "cn=grpC,ou=groups,dc=grpmembers,dc=com"

real	0m35.561s
user	0m0.005s
sys	0m0.003s

[root@dhcp35-196 ~]# ncount=0; PORT="1289";Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l`; while [ $Count -ne 90139 ]; do Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l` ; sleep 1; ncount=`expr $ncount + 1`; echo "Total wait time is $ncount" ; done
--
--
Total wait time is 36
[root@dhcp35-196 ~]#

For deleting 122 users with uniquemember attribute:

[root@dhcp35-196 export]# PORT="1189";ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l ; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100uinqmemdel.ldif 
90139
modifying entry "cn=grpC,ou=groups,dc=grpmembers,dc=com"

real	0m5.225s
user	0m0.002s
sys	0m0.003s

[root@dhcp35-196 ~]# ncount=0; PORT="1289";Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l`; while [ $Count -ne 90017 ]; do Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l` ; sleep 1; ncount=`expr $ncount + 1`; echo "Total wait time is $ncount" ; done
--
--
Total wait time is 5
[root@dhcp35-196 ~]# 

For adding 122 users with member attribute:

[root@dhcp35-196 export]# PORT="1189";ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpB,ou=groups,dc=grpmembers,dc=com" "member" |wc -l ; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100addmember.ldif 
90017
modifying entry "cn=grpB,ou=groups,dc=grpmembers,dc=com"

real	0m37.067s
user	0m0.005s
sys	0m0.004s

[root@dhcp35-196 ~]# ncount=0; PORT="1289";Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l`; while [ $Count -ne 90139 ]; do Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpC,ou=groups,dc=grpmembers,dc=com" "uniquemember" |wc -l` ; sleep 1; ncount=`expr $ncount + 1`; echo "Total wait time is $ncount" ; done
--
--
Total wait time is 39
[root@dhcp35-196 ~]# 


For deleting 244 users with member attribute:

[root@dhcp35-196 export]# PORT="1189";ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpB,ou=groups,dc=grpmembers,dc=com" "member" |wc -l ; time ldapmodify -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -f New100delmember.ldif 
89895
modifying entry "cn=grpB,ou=groups,dc=grpmembers,dc=com"

real	0m41.023s
user	0m0.008s
sys	0m0.004s


[root@dhcp35-196 ~]# ncount=0; PORT="1289";Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpB,ou=groups,dc=grpmembers,dc=com" "member" |wc -l`; while [ $Count -ne 89651 ]; do Count=`ldapsearch -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=GrpB,ou=groups,dc=grpmembers,dc=com" "member" |wc -l` ; sleep 1; ncount=`expr $ncount + 1`; echo "Total wait time is $ncount" ; done
--
--
Total wait time is 43


The data above shows that... to synchronize the member/uniquemember attribute add/delete operations to replica is taking almost the same time as the master. Hence, marking the bug as Verified.

Build  tested:

[root@dhcp35-196 ~]# rpm -qa |grep -i 389-ds
389-ds-base-libs-1.3.4.0-15.el7.x86_64
389-ds-base-1.3.4.0-15.el7.x86_64
Comment 4 errata-xmlrpc 2015-11-19 11:42:45 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-2015-2351.html
Note You need to log in before you can comment on or make changes to this bug.