(ITS#3592) slurpd attribute filtering results in lost replication events

[lucca@csun.edu]

Full_Name: Matthew Backes
Version: 2.2.23
OS: MacOS 10.3.8
URL: 
Submission from: (NULL) (130.166.10.156)


At least some cases of attribute filtering in combination with (somewhat
pathologically) rapidfire modifications to the same object can result in dropped
replication events.

The events make it into slurpd's private replog but periodically some are
shadowed by other changes and get dropped without appearing in the replicas or
reject logs.

In all known cases, the dropped events came in a stream of changes involving the
same dn, targets, and timestamp, but the targets were for Unfiltered replication
stanzas in slapd.conf.  (Our filtering was limited to stripping operational
attributes to create "fake" masters, mostly useful for testing purposes)

Example "normal" stanza:
replica
       host=crow.csun.edu:389
       binddn=...
       bindmethod=simple
       credentials=...

Example "fake master" stanza:
replica
       host=crow.csun.edu:2389
       binddn=...
       bindmethod=simple
       credentials=...
       attr!=structuralObjectClass,entryUUID,creatorsName,modifiersName,createTimeStamp,modifyTimeStamp,entryCSN,subschemaSubentry,hasSu
bordinates

Example sequence of replication events that caused trouble:

# writing to the normal replicas... with no change but operationals??
replica: peregrine.csun.edu:389
replica: crow.csun.edu:389
replica: jay.csun.edu:389
time: 1110328981
dn: uid=...,ou=People,ou=Auth,o=CSUN
changetype: modify
replace: entryCSN
entryCSN: 20050309004301Z#000001#00#000000
-
replace: modifiersName
modifiersName: cn=rmwd write,ou=Proxies,ou=Auth,o=CSUN
-
replace: modifyTimestamp
modifyTimestamp: 20050309004301Z
-

# Mysterious series of blank lines in the replog (4 lines, rather than the usual
1)



# writing to normal replicas with the real changes--this gets dropped
replica: peregrine.csun.edu:389
replica: crow.csun.edu:389
replica: jay.csun.edu:389
time: 1110328981
dn: uid=...,ou=People,ou=Auth,o=CSUN
changetype: modify
replace: userPassword
userPassword:: ...
-
replace: csunEduPersonAccountStatus
csunEduPersonAccountStatus: active
-
replace: csunEduPersonOldPassword
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
-
replace: entryCSN
entryCSN: 20050309004301Z#000002#00#000000
-
replace: modifiersName
modifiersName: cn=rmwd write,ou=Proxies,ou=Auth,o=CSUN
-
replace: modifyTimestamp
modifyTimestamp: 20050309004301Z
-

# one replication event for each fake-master target
replica: crow.csun.edu:2389
time: 1110328981
dn: uid=...,ou=People,ou=Auth,o=CSUN
changetype: modify
replace: userPassword
userPassword:: ...
-
replace: csunEduPersonAccountStatus
csunEduPersonAccountStatus: active
-
replace: csunEduPersonOldPassword
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
csunEduPersonOldPassword: ...
-

Obviously "..." refers to various values which might be sensitive and hopefully
not relevant.

Disabling the attribute filtering in slapd was insufficient to avoid the
problem.  After disabling the filtering, I also had to restart slurpd in order
to stop dropping events.