Bug 1307151

Summary: keep alive entries can break replication
Product: Red Hat Enterprise Linux 7 Reporter: Noriko Hosoi <nhosoi>
Component: 389-ds-baseAssignee: Noriko Hosoi <nhosoi>
Status: CLOSED ERRATA QA Contact: Viktor Ashirov <vashirov>
Severity: urgent Docs Contact: Petr Bokoc <pbokoc>
Priority: urgent    
Version: 7.3CC: ekeck, mkolaja, msauton, nkinder, pbokoc, rmeggins
Target Milestone: rcKeywords: ZStream
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: 389-ds-base-1.3.5.2-1.el7 Doc Type: Bug Fix
Doc Text:
Keep-alive entries no longer break replication Previously, a keep-alive entry was being created at too many opportunities during replication, potentially causing a race condition when adding the entry to the replica changelog and resulting in operations being dropped from the replication. With this update, unnecessary keep-alive entry creation has been eliminated, and keep-alive entries no longer cause missing operations during replication.
Story Points: ---
Clone Of:
: 1309963 (view as bug list) Environment:
Last Closed: 2016-11-03 20:39:31 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
Bug Depends On:    
Bug Blocks: 1309963    

Description Noriko Hosoi 2016-02-12 20:53:43 UTC
This bug is created as a clone of upstream ticket:
https://fedorahosted.org/389/ticket/48445

There is a scenario where the added keep alive entry is in the database but is missing from the changelog. When this entry is updated the replication of the MOD fails because the ADD of the entry is not replicated.

It looks like the changelog is recreated just after adding the keep alive entry

[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - Need to create replication keep alive entry <cn=repl keep alive 3,dc=abc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com>
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - add dn: cn=repl keep alive 3,dc=abc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com
objectclass: top
objectclass: ldapsubentry
objectclass: extensibleObject
cn: repl keep alive 3
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - ruv_add_csn_inprogress: successfully inserted csn 56ab4413000100030000 into pending list
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName: no DB object found for database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: semaphore /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d.sema
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: maxConcurrentWrites=2
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetEntryCount: 0 changes for replica 2abae513-c67611e5-b4f3d71a-a8c5143d
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5AddDBFile: Added new DB object 55a280d8fb30
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBOpenFileByReplicaName: created new DB object 55a280d8fb30
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName: found DB object 55a280d8fb30 for database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - ruv_update_ruv: successfully committed csn 56ab4413000100030000
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - conn=0 op=0 repl="dc=abc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com": Released replica held by locking_purl=conn=5 id=5
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - replica_enable_replication: replica dc=abc,dc=idm,dc=lab,dc=eng,dc=brq,dc=redhat,dc=com is relinquished
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): No linger to cancel on the connection
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): Disconnected from the consumer
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): State: start -> ready_to_acquire_replica
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): Trying non-secure slapi_ldap_init_ext
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): binddn = ,  passwd =
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): Unable to acquire replica: permission denied. The bind dn "" does not have permission to supply replication updates to the replica. Will retry later.
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): Beginning linger on the connection
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - agmt="cn=meTovm-058-073.abc.idm.lab.eng.brq.redhat.com" (vm-058-073:389): State: ready_to_acquire_replica -> start_backoff
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetDBFile: found DB object 55a280d8fb30 for database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBDeleteFile: removed DB object 55a280d8fb30
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBCloseFile: Closing database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBCloseFile: Closed the changelog database handle for /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db (rc: 0)
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBCloseFile: removing the changelog /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db (flag 256)
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBCloseFile: Deleted the changelog database file /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4413000000030000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName: no DB object found for database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d_56ab4397000000040000.db
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: semaphore /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-a8c5143d.sema
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5NewDBFile: maxConcurrentWrites=2
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetEntryCount: 0 changes for replica 2abae513-c67611e5-b4f3d71a-a8c5143d
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5AddDBFile: Added new DB object 7f02342026d0
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5DBOpenFileByReplicaName: created new DB object 7f02342026d0
[29/Jan/2016:11:50:59 +0100] NSMMReplicationPlugin - changelog program - _cl5GetDBFileByReplicaName: found DB object 7f02342026d0 for database /var/lib/dirsrv/slapd-ABC-IDM-LAB-ENG-BRQ-REDHAT-COM/cldb/2abae513-c67611e5-b4f3d71a-

Comment 1 Marc Sauton 2016-02-12 22:36:12 UTC
GSS Approved Z-Stream

Comment 6 Mike McCune 2016-03-28 23:13:32 UTC
This bug was accidentally moved from POST to MODIFIED via an error in automation, please see mmccune@redhat.com with any questions

Comment 10 errata-xmlrpc 2016-11-03 20:39:31 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