Re: (ITS#8432) Never ending operation modifications with 3+ MMR nodes

[hyc@symas.com]

quanah@openldap.org wrote:
> Full_Name: Quanah Gibson-Mount
> Version: 2.4.44
> OS: Linux 2.6
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (75.111.52.177)
>
>
> In MMR node, when there is > 2 nodes, operations can get sent out endlessly.
>
> For example, we see this modification occur at 20160603194926.427963Z

You seem to have a large clock sync problem.
>
> Jun  3 14:49:22 ldap01 slapd[14014]: syncrepl_message_to_op: rid=100 be_modify
> cn=edge02e.zimbra.com,cn=servers,cn=zimbra (0)
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_sendresp: to=002,
> cookie=rid=100,sid=003
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_queue_csn: queueing 0x121c8680
> 20160603194926.417898Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_graduate_commit_csn: removing
> 0x9403600 20160527111854.508810Z#000000#004#000000

How did a CSN from 20160527 get queued on 20160603?

> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=102
> cookie=rid=102,sid=004,csn=20160603194926.417898Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: dsysyncrep2: rid=102 CSN too old, ignoring
> 20160603194926.417898Z#000000#001#000000
> (reqStart=20160603194922.988081Z,cn=accesslog)
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=101
> cookie=rid=101,sid=002,csn=20160603194926.417898Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=101 CSN too old, ignoring
> 20160603194926.417898Z#000000#001#000000
> (reqStart=20160603194931.992576Z,cn=accesslog)
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=100
> cookie=rid=100,sid=001,csn=20160603194926.427963Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_queue_csn: queueing 0x120c1c80
> 20160603194926.427963Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_matchops: skipping original sid
> 001
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_sendresp: to=004,
> cookie=rid=102,sid=003
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_sendresp: to=002,
> cookie=rid=100,sid=003
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_graduate_commit_csn: removing
> 0x93aae80 20160527095853.061949Z#000000#004#000000

And another one.

> Jun  3 14:49:22 ldap01 slapd[14014]: syncrepl_message_to_op: rid=100 be_modify
> cn=edge02e.zimbra.com,cn=servers,cn=zimbra (0)
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_queue_csn: queueing 0x1104d080
> 20160603194926.427963Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_graduate_commit_csn: removing
> 0xac25300 20160527084152.674596Z#000000#004#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=102
> cookie=rid=102,sid=004,nsn=20160603194926.427963Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=102 CSN too old, ignoring
> 20160603194926.427963Z#000000#001#000000
> (reqStart=20160603194922.996275Z,cn=accesslog)
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=100
> cookie=rid=100,sid=001,csn=20160603194926.433237Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_queue_csn: queueing 0x1116e600
> 20160603194926.433237Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_matchops: skipping origil l sid
> 001
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_sendresp: to=004,
> cookie=rid=102,sid=003
> Jun  3 14:49:22 ldap01 slapd[14014]: syncprov_sendresp: to=002,
> cookie=rid=100,sid=003
> Jun  3 14:49:22 ldap01 slapd[14014]: do_syncrep2: rid=101
> cookie=rid=101,sid=002
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_queue_csn: queueing 0xf0cf380
> 20160603194926.427963Z#000000#001#000000
> Jun  3 14:49:22 ldap01 slapd[14014]: slap_graduate_commit_csn: removing
> 0x122e2cc0 20160527095853.613262Z#000000#004#000000

And another. There are more in the rest of the output you pasted.

-- 
   -- Howard Chu
   CTO, Symas Corp.           http://www.symas.com
   Director, Highland Sun     http://highlandsun.com/hyc/
   Chief Architect, OpenLDAP  http://www.openldap.org/project/