Bug 1316731

Summary: syncrepl search returning error 329; plugin sending a bad error code
Product: Red Hat Enterprise Linux 7 Reporter: Amy Farley <afarley>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED ERRATA QA Contact: Viktor Ashirov <vashirov>
Severity: high Docs Contact:
Priority: high    
Version: 7.2CC: gparente, kbanerje, lkrispen, nhosoi, nkinder, pspacek, rmeggins
Target Milestone: rc   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.3.5.9-1.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-03 20:40:24 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:
Embargoed:

Comment 3 Petr Spacek 2016-06-28 09:02:13 UTC
As far as I can tell this is a directory server issue. I guess that LDAP intermediate message from the syncrepl plugin is logged as "result" with a weird error code:

[07/Mar/2016:03:37:01 -0800] conn=93893 op=3 SRCH base="cn=dns,dc=example,dc=net" scope=2 filter="(|(objectClass=idnsConfigObject)(objectClass=idnsZone)(objectClass=idnsForwardZone)(objectClass=idnsRecord))" attrs=ALL
[07/Mar/2016:03:37:02 -0800] conn=93893 op=3 RESULT err=329 tag=121 nentries=0 etime=1

Comment 6 Noriko Hosoi 2016-06-28 19:54:05 UTC
Upstream ticket:
https://fedorahosted.org/389/ticket/48904

Comment 8 Noriko Hosoi 2016-06-28 20:07:16 UTC
Upstream ticket:
https://fedorahosted.org/389/ticket/48904

Comment 13 Viktor Ashirov 2016-09-20 16:30:01 UTC
Build tested:
389-ds-base-1.3.5.10-11.el7.x86_64
(rebuilt with -O0 so GDB would work)

[0] Setup DS
[1] Enable Content Synchronization and Retro Changelog plugins
# ldapmodify  -D "cn=Directory Manager" -w Secret123 
dn: cn=Content Synchronization,cn=plugins,cn=config
changetype: modify
replace: nsslapd-pluginEnabled
nsslapd-pluginEnabled: on
-

dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
changetype: modify
replace: nsslapd-pluginEnabled
nsslapd-pluginEnabled: on
-
modifying entry "cn=Content Synchronization,cn=plugins,cn=config"


modifying entry "cn=Retro Changelog Plugin,cn=plugins,cn=config"

# ldapmodify  -D "cn=Directory Manager" -w Secret123 
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
changetype: modify
add: nsslapd-attribute
nsslapd-attribute: nsuniqueid:targetUniqueId
-

modifying entry "cn=Retro Changelog Plugin,cn=plugins,cn=config"

[2] Restart DS:
# restart-dirsrv 
Restarting instance "rhel7ds"

[3] Add test entry:
# ldapmodify  -D "cn=Directory Manager" -w Secret123 
dn: uid=cso_test,ou=People,dc=example,dc=com
changetype: add
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: inetorgperson
uid: cso_test
sn: cso_test
cn: cso_test

adding new entry "uid=cso_test,ou=People,dc=example,dc=com"

[4] Attach GDB:
# gdb -p $(pidof ns-slapd)
...
(gdb) b result.c:258
Breakpoint 1 at 0x7f0ab84005dc: file ldap/servers/slapd/result.c, line 258.
(gdb) c
Continuing.

[5] On a second terminal run ldapsearch with syncrepl cookie:
ldapsearch -h localhost:389 -D "cn=Directory Manager" -w Secret123 -b dc=example,dc=com -LLL -E sync=rp/"rhel7ds.brq.redhat.com:389#cn=directory manager:dc=example,dc=com:(objectClass=*)#1"
dn: uid=cso_test,ou=People,dc=example,dc=com
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: inetorgperson
uid: cso_test
sn: cso_test
cn: cso_test

SyncInfo Received

[6] GDB hit breakpoint:
Breakpoint 1, send_ldap_intermediate (pb=0x7f0a967fba70, ectrls=0x7f0a967f6cd8, responseName=0x7f0aad041ec4 "1.3.6.1.4.1.4203.1.9.1.4", 
    responseValue=0x7f0a700014d0) at ldap/servers/slapd/result.c:258
258		if (rc == LBER_ERROR) {
(gdb) p rc
$1 = 124
(gdb) set rc=-1
(gdb) p rc
$2 = -1
(gdb) c
Continuing.

[7] In the access log:
# tail -n 5 /var/log/dirsrv/slapd-rhel7ds/access
[20/Sep/2016:18:24:34.965377012 +0200] conn=2 fd=64 slot=64 connection from ::1 to ::1
[20/Sep/2016:18:24:34.965465691 +0200] conn=2 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[20/Sep/2016:18:24:34.965529863 +0200] conn=2 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=directory manager"
[20/Sep/2016:18:24:34.965639129 +0200] conn=2 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(objectClass=*)" attrs=ALL
[20/Sep/2016:18:25:44.659441272 +0200] conn=2 op=1 RESULT err=1 tag=121 nentries=0 etime=0

err=1, because rc was set to LDAP_OPERATIONS_ERROR.

Marking as VERIFIED.

Comment 15 errata-xmlrpc 2016-11-03 20:40:24 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/RHSA-2016-2594.html