(ITS#5709) slapd sync provider skips some objects

[sylvain.thomas@gmail.com]

Full_Name: Sylvain Thomas
Version: 2.4.11
OS: Linux 2.6 (Fedora)
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (145.242.11.3)


I have a test platform with one master and one simple replica.
I perform rapid write operations on the master through 8 parallel connections,
and I find that some objects are missing in the replica.
More investigation shows that the sync provider skips the objects if they are
processed faster than the preceding ones.

Below, I produce a sample log (sync + stats) of the problem.

In the sample log the object uid=5030708029E1 is not sent to the replica (no
call to syncprov_sendresp() ) but the object uid=50307080309A is sent.

.....
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: conn=331 op=1 ADD
dn="uid=50307080309A,ou=A,ou=9,ou=abonnes,ou=test,c=fr"
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: slap_queue_csn: queing 0xa2f6cac0
20080923080903.375249Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: conn=333 op=1 ADD
dn="uid=5030708029E1,ou=1,ou=E,ou=abonnes,ou=test,c=fr"
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: slap_queue_csn: queing 0xa14feac0
20080923080903.376369Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: conn=332 op=1 RESULT tag=105 err=0
text=
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: slap_graduate_commit_csn: removing
0x9179420 20080923080903.373805Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: syncprov_sendresp:
cookie=rid=003,csn=20080923080903.373805Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: conn=333 op=1 RESULT tag=105 err=0
text=
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: slap_graduate_commit_csn: removing
0x917b428 20080923080903.376369Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: conn=331 op=1 RESULT tag=105 err=0
text=
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: slap_graduate_commit_csn: removing
0xa242aa38 20080923080903.375249Z#000000#001#000000
Sep 23 10:09:03 ldap_mirror1 slapd[2020]: syncprov_sendresp:
cookie=rid=003,csn=20080923080903.375249Z#000000#001#000000
......

I think the reason is that the ADD request for uid=5030708029E1 is received
after that of uid=50307080309A, so it takes a bigger csn
(20080923080903.376369Z#000000#001#000000) but its processing takes less time
(slap_graduate_commit_csn() comes first).

I can provide a detailed log (loglevel -1) and any other information required.
The environment and the configuration files are the same as for ITS 5661, but I
do not use the mirror mode.
Thanks for your help

Best Regards
Sylvain Thomas