Bug 1393007

Summary: ds9 backport 47411 - Replace substring search with plain search in referint plugin
Product: Red Hat Enterprise Linux 6 Reporter: Marcel Kolaja <mkolaja>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED ERRATA QA Contact: Viktor Ashirov <vashirov>
Severity: urgent Docs Contact:
Priority: urgent    
Version: 6.8CC: mkolaja, msauton, nhosoi, nkinder, rmeggins, sramling, tbordaz
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.2.11.15-85.el6_8 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.
Story Points: ---
Clone Of: 1391324 Environment:
Last Closed: 2017-01-10 17:07:58 UTC Type: ---
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: 1391324    
Bug Blocks:    

Description Marcel Kolaja 2016-11-08 16:45:01 UTC
This bug has been copied from bug #1391324 and has been proposed
to be backported to 6.8 z-stream (EUS).

Comment 4 Sankar Ramalingam 2016-11-28 12:42:01 UTC
[root@bkr-hv03-guest16 ~]# ldapmodify -x -p 1189 -h localhost -D "cn=Directory Manager" -w Secret123 << EOF
> dn: cn=referential integrity postoperation,cn=plugins,cn=config
> replace: nsslapd-pluginEnabled
> nsslapd-pluginEnabled: on
> -
> replace: nsslapd-logaccess
> nsslapd-logaccess: on
> EOF
modifying entry "cn=referential integrity postoperation,cn=plugins,cn=config"

[root@bkr-hv03-guest16 ~]# ldapmodify -x -p 1189 -h localhost -D "cn=Directory Manager" -w Secret123 << EOF
dn: cn=MemberOf Plugin,cn=plugins,cn=config
replace: nsslapd-pluginEnabled
nsslapd-pluginEnabled: on
-
replace: nsslapd-logaccess
nsslapd-logaccess: on
EOF

modifying entry "cn=MemberOf Plugin,cn=plugins,cn=config"

[root@bkr-hv03-guest16 MMR_WINSYNC]# ldapsearch -LLL -x -p 1189 -h localhost -D "cn=Directory Manager" -w Secret123 -b "cn=mydsgrp32,dc=passsync,dc=com"
dn: cn=mydsgrp32,dc=passsync,dc=com
member: uid=mynewusr6,ou=people,dc=passsync,dc=com
member: uid=mynewusr7,ou=people,dc=passsync,dc=com
member: uid=mynewusr8,ou=people,dc=passsync,dc=com
member: uid=mynewusr9,ou=people,dc=passsync,dc=com
uniqueMember: uid=mynewusr1,ou=people,dc=passsync,dc=com
uniqueMember: uid=mynewusr2,ou=people,dc=passsync,dc=com
uniqueMember: uid=mynewusr3,ou=people,dc=passsync,dc=com

[root@bkr-hv03-guest16 MMR_WINSYNC]# ldapmodify -x -p 1189 -h localhost -D "cn=Directory Manager" -w Secret123 << EOFdn: cn=config                             
replace: nsslapd-accesslog-level
nsslapd-accesslog-level: 260
EOF

modifying entry "cn=config"

[root@bkr-hv03-guest16 MMR_WINSYNC]# service dirsrv restart

[root@bkr-hv03-guest16 MMR_WINSYNC]# time PORT=1189; /usr/bin/ldapdelete -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 "uid=mynewusr7,ou=people,dc=passsync,dc=com"

real	0m0.000s
user	0m0.000s
sys	0m0.000s
[root@bkr-hv03-guest16 MMR_WINSYNC]# time PORT=1189; /usr/bin/ldapdelete -x -p $PORT -h localhost -D "cn=Directory Manager" -w Secret123 "uid=mydsusr9,ou=people,dc=passsync,dc=com"

real	0m0.000s
user	0m0.000s
sys	0m0.000s

[root@bkr-hv03-guest16 MMR_WINSYNC]# cat /var/log/dirsrv/slapd-M1/access |grep -i "uniquemember"[28/Nov/2016:07:39:09 -0500] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=mynewusr1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[28/Nov/2016:07:39:09 -0500] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(uniquemember=uid=mynewusr1,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[28/Nov/2016:07:39:09 -0500] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=mynewusr2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[28/Nov/2016:07:39:09 -0500] conn=Internal op=-1 SRCH base="dc=passsync,dc=com" scope=2 filter="(uniquemember=uid=mynewusr2,ou=people,dc=passsync,dc=com)" attrs="uniquemember"
[28/Nov/2016:07:39:09 -0500] conn=Internal op=-1 SRCH base="dc=example,dc=com" scope=2 filter="(uniquemember=uid=mynewusr3,ou=people,dc=passsync,dc=com)" attrs="uniquemember"

The above lines from access logs show that there are no substring searches performed. Hence, marking the bug as Verified.

[root@bkr-hv03-guest16 MMR_WINSYNC]# rpm -qa |grep -i 389-ds
389-ds-base-debuginfo-1.2.11.15-85.el6_8.x86_64
389-ds-base-libs-1.2.11.15-85.el6_8.x86_64
389-ds-base-1.2.11.15-85.el6_8.x86_64
389-ds-base-devel-1.2.11.15-85.el6_8.x86_64

Comment 5 Sankar Ramalingam 2016-11-28 13:12:29 UTC
I encountered these errors while verifying this bugzilla. Seems like a problem to me. Please advise.

==> /var/log/dirsrv/slapd-M1/errors <==
[28/Nov/2016:07:20:15 -0500] NSMMReplicationPlugin - agmt="cn=1189_to_2626_on_bkr-hv03-guest16.dsal.lab.eng.bos.redhat.com" (bkr-hv03-guest16:2626): Replication bind with SIMPLE auth resumed
[28/Nov/2016:07:20:21 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:25:22 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:30:23 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:35:06 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:35:13 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:39:09 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT
[28/Nov/2016:07:39:12 -0500] clcache_load_buffer_bulk - changelog record with csn (583c1f90000a08a40000) not found for DB_NEXT

Comment 6 thierry bordaz 2016-12-06 10:17:46 UTC
Sankar,

This message means that M1 has to start a replication session using an alternate csn than 583c1f90000a08a40000. In fact M1 failed to find 583c1f90000a08a40000 in its changelog.
This is not really a concern as use of alternate csn always existed. But considering this situation as a corner case it was preferred to systematically log it when it happens.

The fact that this message occurs several times means that 583c1f90000a08a40000 is not a transient starting point and no server in the topology managed to send it the others updates generated on replica 2212.

You can check on which replica is 2212 and find in its access logs the updates after 583c1f90000a08a40000.

Monitoring ruv of all replicas you could find who knows updates after 583c1f90000a08a40000 and understand why those replicas fail to send the further updates.

Comment 7 Sankar Ramalingam 2016-12-09 13:36:15 UTC
(In reply to thierry bordaz from comment #6)
> Sankar,
> 
> This message means that M1 has to start a replication session using an
> alternate csn than 583c1f90000a08a40000. In fact M1 failed to find
> 583c1f90000a08a40000 in its changelog.
> This is not really a concern as use of alternate csn always existed. But
> considering this situation as a corner case it was preferred to
> systematically log it when it happens.
> 
> The fact that this message occurs several times means that
> 583c1f90000a08a40000 is not a transient starting point and no server in the
> topology managed to send it the others updates generated on replica 2212.
> 
> You can check on which replica is 2212 and find in its access logs the
> updates after 583c1f90000a08a40000.
> 
> Monitoring ruv of all replicas you could find who knows updates after
> 583c1f90000a08a40000 and understand why those replicas fail to send the
> further updates.

Thanks Thierry!. I tried the same test case on a fresh RHEL-6.8z and RHEL-7.3z, but no luck to reproduce. Anyways, I will continue to observe my test mmr setup to check if this occurs again.

Comment 9 errata-xmlrpc 2017-01-10 17:07:58 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-0034.html