Bug 1307152 - keep alive entries can break replication
keep alive entries can break replication
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: 389-ds-base (Show other bugs)
6.0
All Linux
urgent Severity urgent
: rc
: ---
Assigned To: Noriko Hosoi
Viktor Ashirov
Petr Bokoc
: ZStream
Depends On:
Blocks: 1309962
  Show dependency treegraph
 
Reported: 2016-02-12 15:56 EST by Noriko Hosoi
Modified: 2016-05-10 15:22 EDT (History)
8 users (show)

See Also:
Fixed In Version: 389-ds-base-1.2.11.15-73.el6
Doc Type: Bug Fix
Doc Text:
Unnecessary `keep alive` entries no longer cause missing 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 missing replication no longer occurs.
Story Points: ---
Clone Of:
: 1309962 (view as bug list)
Environment:
Last Closed: 2016-05-10 15:22:58 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Noriko Hosoi 2016-02-12 15:56:01 EST
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 17:35:36 EST
GSS Approved Z-Stream
Comment 7 Amita Sharma 2016-03-29 07:51:57 EDT
[root@ipaqa64vmd export]# rpm -qa | grep 389
389-ds-base-1.2.11.15-74.el6.x86_64
389-ds-base-libs-1.2.11.15-74.el6.x86_64
[root@ipaqa64vmd export]# cat /etc/redhat-release 
Red Hat Enterprise Linux Server release 6.8 Beta (Santiago)

Executed steps :: https://bugzilla.redhat.com/show_bug.cgi?id=1309962#c12

Keep alive entry is added on M1 by M2 after 100+ updates ::
[29/Mar/2016:07:42:20 -0400] NSMMReplicationPlugin - agmt="cn=M1_to_M2" (localhost:1389): replay_update: Sending add operation (dn="cn=repl keep alive 7,dc=example,dc=com" csn=56fa6829000100070000)
[29/Mar/2016:07:42:20 -0400] NSMMReplicationPlugin - agmt="cn=M1_to_M2" (localhost:1389): replay_update: Consumer successfully sent operation with csn 56fa6829000100070000
[29/Mar/2016:07:42:20 -0400] agmt="cn=M1_to_M2" (localhost:1389) - load=1 rec=2 csn=56fa6a1a000000070000
[29/Mar/2016:07:42:20 -0400] - repl5_inc_result_threadmain: read result for message_id 0
[29/Mar/2016:07:42:20 -0400] NSMMReplicationPlugin - agmt="cn=M1_to_M2" (localhost:1389): replay_update: Sending add operation (dn="uid=ami,dc=example,dc=com" csn=56fa6a1a000000070000)
[29/Mar/2016:07:42:20 -0400] - repl5_inc_result_threadmain: read result for message_id 5
[29/Mar/2016:07:42:20 -0400] - repl5_inc_result_threadmain: result 1, 68, 1, 5, (null)
[29/Mar

Hence VERIFIED
Comment 9 errata-xmlrpc 2016-05-10 15:22:58 EDT
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-2016-0737.html

Note You need to log in before you can comment on or make changes to this bug.