[Date Prev][Date Next] [Chronological] [Thread] [Top]

Odd delta-sync replication issue (OpenLDAP 2.3.41)



I have a replica spitting out the following error in its logs (master and replica running OpenLDAP 2.3.41):

Apr 11 13:28:03 123-ldap-3 slapd[21846]: syncrepl_message_to_op: rid 100 be_modify uid=xxxxx,ou=people,dc=123,dc=abc,dc=edu (20)

It's syncrepl cookie is:

contextCSN: 20080410145621Z#000000#00#000000

Looking at the accesslog on the master, I see (for this time period):

dn: reqStart=20080410145621.000001Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20080410145621.000001Z
reqEnd: 20080410145621.000003Z
reqType: modify
reqSession: 190486
reqAuthzID: uid=zimbra,cn=admins,cn=zimbra
reqDN: uid=xxxxx,ou=people,dc=123,dc=abc,dc=edu
reqResult: 0
reqMod: zimbraPasswordLockoutFailureTime:+ 20080410145621Z
reqMod: zimbraPasswordLockoutFailureTime:- 20080410145230Z
reqMod: entryCSN:= 20080410145621Z#000000#00#000000
reqMod: modifiersName:= uid=zimbra,cn=admins,cn=zimbra
reqMod: modifyTimestamp:= 20080410145621Z
entryUUID: 06ac9202-9b5a-102c-8816-1596598f2bf0
creatorsName: cn=accesslog
createTimestamp: 20080410145621Z
entryCSN: 20080410145621Z#000000#00#000000
modifiersName: cn=accesslog
modifyTimestamp: 20080410145621Z

dn: reqStart=20080410145621.000027Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20080410145621.000027Z
reqEnd: 20080410145621.000028Z
reqType: modify
reqSession: 190494
reqAuthzID: uid=zimbra,cn=admins,cn=zimbra
reqDN: uid=yyyy_07,ou=people,dc=123,dc=abc,dc=edu
reqResult: 0
reqMod: zimbraPasswordLockoutFailureTime:+ 20080410145621Z
reqMod: entryCSN:= 20080410145621Z#000001#00#000000
reqMod: modifiersName:= uid=zimbra,cn=admins,cn=zimbra
reqMod: modifyTimestamp:= 20080410145621Z
entryUUID: 06ee59c6-9b5a-102c-8817-1596598f2bf0
creatorsName: cn=accesslog
createTimestamp: 20080410145621Z
entryCSN: 20080410145621Z#000001#00#000000
modifiersName: cn=accesslog
modifyTimestamp: 20080410145621Z



So as I understand (delta)syncrepl, the replica knows it already received the update for uid=xxxxx, and yet it is still trying to process that update, rather than the next one for uid=yyyy_07.

The entry on the replica has:

dn: uid=xxxxx,ou=people,dc=123,dc=abc,dc=edu
zimbraPasswordLockoutFailureTime: 20080410145515Z
zimbraPasswordLockoutFailureTime: 20080410145516Z
zimbraPasswordLockoutFailureTime: 20080410145519Z
zimbraPasswordLockoutFailureTime: 20080410145539Z
zimbraPasswordLockoutFailureTime: 20080410145547Z
zimbraPasswordLockoutFailureTime: 20080410145548Z
zimbraPasswordLockoutFailureTime: 20080410145621Z


So it's clear that the update took on the replica. So why is it trying to re-replicate an event it already got, and *knows* it already got, since it updated its cookie?!


--Quanah


--

Quanah Gibson-Mount
Principal Software Engineer
Zimbra, Inc
--------------------
Zimbra ::  the leader in open source messaging and collaboration