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

Re: Fwd: CSN too old, ignoring - and therefore not syncing



I'm facing a similar problem.
I'm testing N-way multimaster replication with OpenLDAP 2.4.13.

I'm able to successfully import data into an instance and have my two masters to sync correctly but then when I try to add a new entry in one of the two masters, I'm getting strange messages :

let's say we have m1 & m2 (m1 & m2 are on the same server): 
I initial import data into m1, it is successfully imported into m2 (at least it looks like it).
Then I'm trying to add an entry on m2 (cn=adrien-externe.futschik@edfgdf.fr,ou=personnes,o=edfgdf,c=fr). I'm getting strange message on m1 & m2 :

m1 log :(repetitively)
[...]
Entry ou=administrateurs,o=gazdefrance,c=fr CSN 20081224125950.481561Z#000000#001#000000 older or equal to ctx 20081224125950.481561Z#000000#001#000000
Entry cn=adrien-externe.futschik@edfgdf.fr,ou=personnes,o=edfgdf,c=fr changed by peer, ignored
syncprov_search_response: cookie=rid=004,sid=002,csn=20081224125950.481561Z#000000#001#000000;20081224130148.522455Z#000000#002#000000
do_syncrep2: rid=005 LDAP_RES_SEARCH_RESULT
[...]


m2 log : (repetitively)
[...]
master where I added an entry :
do_syncrep2: rid=004 LDAP_RES_INTERMEDIATE - SYNC_ID_SET
do_syncrep2: rid=004 LDAP_RES_SEARCH_RESULT
do_syncrep2: cookie=rid=004,sid=002,csn=20081224125950.481561Z#000000#001#000000;20081224130148.522455Z#000000#002#000000
[...]

Is this a bug ? Am-I doing something wrong ?

If I add the same entry to m1 and not m2 I get the following messages :

on m2 :
syncrepl_entry: rid=004 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD)
syncrepl_entry: rid=004 be_search (0)
syncrepl_entry: rid=004 cn=adrien-externe.futschik@edfgdf.fr,ou=personnes,o=edfgdf,c=fr
<= bdb_equality_candidates: (entryCSN) not indexed
<= bdb_inequality_candidates: (entryCSN) not indexed
<= bdb_inequality_candidates: (entryCSN) not indexed
syncprov_search_response: cookie=rid=005,sid=001,csn=20081224132158.749532Z#000000#001#000000
syncrepl_entry: rid=004 be_add (0)
do_syncrep2: rid=004 LDAP_RES_SEARCH_RESULT
do_syncrep2: cookie=rid=004,sid=002,csn=20081224132238.790862Z#000000#001#000000
<= bdb_inequality_candidates: (entryCSN) not indexed
nonpresent_callback: rid=004 present UUID 96268508-6609-102d-9d8e-9742e72db399, dn c=fr
nonpresent_callback: rid=004 present UUID 962af700-6609-102d-9d8f-9742e72db399, dn o=edfgdf,c=fr
nonpresent_callback: rid=004 present UUID 962bd698-6609-102d-9d90-9742e72db399, dn ou=personnes,o=edfgdf,c=fr
nonpresent_callback: rid=004 present UUID 962c00b4-6609-102d-9d91-9742e72db399, dn ou=appli,o=edfgdf,c=fr
nonpresent_callback: rid=004 present UUID 962c2634-6609-102d-9d92-9742e72db399, dn ou=groupes,o=edfgdf,c=fr
nonpresent_callback: rid=004 present UUID 962ca492-6609-102d-9d93-9742e72db399, dn ou=administrateurs,o=edfgdf,c=fr
nonpresent_callback: rid=004 present UUID 962cce90-6609-102d-9d94-9742e72db399, dn o=edf,c=fr
nonpresent_callback: rid=004 present UUID 962d7138-6609-102d-9d95-9742e72db399, dn ou=personnes,o=edf,c=fr
nonpresent_callback: rid=004 present UUID 962d96f4-6609-102d-9d96-9742e72db399, dn ou=appli,o=edf,c=fr
nonpresent_callback: rid=004 present UUID 962deafa-6609-102d-9d97-9742e72db399, dn ou=groupes,o=edf,c=fr
nonpresent_callback: rid=004 present UUID 962ef026-6609-102d-9d98-9742e72db399, dn ou=administrateurs,o=edf,c=fr
nonpresent_callback: rid=004 present UUID 962f156a-6609-102d-9d99-9742e72db399, dn o=gazdefrance,c=fr
nonpresent_callback: rid=004 present UUID 962fca8c-6609-102d-9d9a-9742e72db399, dn ou=personnes,o=gazdefrance,c=fr
nonpresent_callback: rid=004 present UUID 962fef76-6609-102d-9d9b-9742e72db399, dn ou=appli,o=gazdefrance,c=fr
nonpresent_callback: rid=004 present UUID 9630106e-6609-102d-9d9c-9742e72db399, dn ou=groupes,o=gazdefrance,c=fr
nonpresent_callback: rid=004 present UUID 9630bfa0-6609-102d-9d9d-9742e72db399, dn ou=administrateurs,o=gazdefrance,c=fr
nonpresent_callback: rid=004 present UUID ae0e93d6-6609-102d-9d9e-9742e72db399, dn cn=adrien-externe.futschik@edfgdf.fr,ou=personnes,o=edfgdf,c=fr
slap_queue_csn: queing 0x843fef0 20081224132238.790862Z#000000#001#000000
slap_graduate_commit_csn: removing 0x83d6410 20081224132238.790862Z#000000#001#000000

on m1 :
slap_queue_csn: queing 0x1df3860 20081224132238.790862Z#000000#001#000000
slap_graduate_commit_csn: removing 0x9703700 20081224132238.790862Z#000000#001#000000
<= bdb_equality_candidates: (entryCSN) not indexed
<= bdb_inequality_candidates: (entryCSN) not indexed
Entry ou=administrateurs,o=gazdefrance,c=fr CSN 20081224132158.749532Z#000000#001#000000 older or equal to ctx 20081224132158.749532Z#000000#001#000000
syncprov_search_response: cookie=rid=004,sid=002,csn=20081224132238.790862Z#000000#001#000000
do_syncrep2: rid=005 LDAP_RES_INTERMEDIATE - SYNC_ID_SET
do_syncrep2: rid=005 LDAP_RES_SEARCH_RESULT
do_syncrep2: cookie=rid=005,sid=001,csn=20081224132158.749532Z#000000#001#000000

Here is the entry I'm adding :

dn: cn=adrien-externe.futschik@edfgdf.fr,ou=personnes,o=edfgdf, c=fr
objectclass: top
objectclass: person
objectclass: organizationalPerson
objectclass: inetorgPerson
objectclass: ditPerson
cn: adrien-externe.futschik@edfgdf.fr
sn: Futschik
givenName: Adrien
uid: adrien-externe.futschik@edfgdf.fr
mail: adrien-externe.futschik@edfgdf.fr
telephonenumber: 0123456789
userpassword: {SSHA}GuU6CMRoOxp9EA1ANafzuRUXADKlBA0r
allowedServices: appli20

pretty simple isn't it ? What's going wrong ?

Adrien

========================================
 Message date : Dec 23 2008, 07:39 PM
 From : "Gavin Henry" <gavin.henry@gmail.com>
 To : openldap-technical@openldap.org
 Copy to : 
 Subject : Fwd: CSN too old, ignoring - and therefore not syncing
 
 ---------- Forwarded message ----------
 From: Pat Riehecky <prieheck@iwu.edu>
 Date: Tue, 23 Dec 2008 12:34:33 -0600
 Subject: Re: CSN too old, ignoring - and therefore not syncing
 To: Gavin Henry <gavin.henry@gmail.com>
 
 On Tue, 2008-12-23 at 18:28 +0000, Gavin Henry wrote:
 > Where did you read that those were needed anyway? If it was the admin
 > guide then I need to fix it ;-)
 >
 > Gavin.
 
 I have no idea where I found those at... I know it wasn't the (recent)
 admin guide.  It may have been from around the 2.4.8 release, but that
 is long gone...
 
 Pat
 
 >
 > On 23/12/2008, Pat Riehecky <prieheck@iwu.edu> wrote:
 > > On Tue, 2008-12-23 at 15:55 +0000, Gavin Henry wrote:
 > >> Try dropping nopresent and reloadhint relating to ITS5669. You only
 > >> need these two syncprov settings on an accesslog db.
 > >>
 > >> Gavin.
 > >
 > > Thanks, that did the job!
 > >
 > > Pat
 > >
 > >>
 > >> On 23/12/2008, Pat Riehecky <prieheck@iwu.edu> wrote:
 > >> > On Tue, 2008-12-23 at 11:45 +0000, Gavin Henry wrote:
 > >> >> Can you post your config somewhere?
 > >> >
 > >> >
 > >> > allow bind_v2
 > >> >
 > >> > include         /etc/ldap/schema/core.schema
 > >> > include         /etc/ldap/schema/cosine.schema
 > >> > include         /etc/ldap/schema/nis.schema
 > >> > include         /etc/ldap/schema/inetorgperson.schema
 > >> > include		/etc/ldap/schema/samba.schema
 > >> > include		/etc/ldap/schema/eduperson-200412.schema
 > >> > include		/etc/ldap/schema/hdb.schema
 > >> > include		/etc/ldap/schema/IWU.schema
 > >> >
 > >> > pidfile         /var/run/slapd/slapd.pid
 > >> > argsfile        /var/run/slapd/slapd.args
 > >> >
 > >> > modulepath	/usr/lib/ldap
 > >> > moduleload	back_hdb
 > >> > moduleload	back_monitor
 > >> > moduleload	memberof
 > >> > moduleload	syncprov
 > >> > moduleload	smbk5pwd
 > >> >
 > >> > tool-threads 2
 > >> > sizelimit 500
 > >> > idletimeout 7200
 > >> >
 > >> > TLSCACertificateFile /etc/ldap/ssl/IWU.crt
 > >> > TLSCertificateFile /etc/ldap/ssl/ldap.iwu.edu.crt
 > >> > TLSCertificateKeyFile /etc/ldap/ssl/ldap.iwu.edu.key
 > >> > TLSVerifyClient allow
 > >> >
 > >> > localSSF 160
 > >> > security ssf=1 update_ssf=128 simple_bind=112
 > >> > sasl-secprops noanonymous
 > >> >
 > >> > access to dn.base="" by * read
 > >> > access to dn.base="cn=Subschema" by * read
 > >> >
 > >> > backend		hdb
 > >> > database        hdb
 > >> >
 > >> > overlay memberof
 > >> > overlay smbk5pwd
 > >> > overlay syncprov
 > >> >
 > >> > smbk5pwd-enable samba
 > >> > smbk5pwd-enable krb5
 > >> > smbk5pwd-must-change 0
 > >> >
 > >> > syncprov-checkpoint 100 10
 > >> > syncprov-sessionlog 200
 > >> > syncprov-nopresent TRUE
 > >> > syncprov-reloadhint TRUE
 > >> >
 > >> > suffix          "dc=iwu,dc=edu"
 > >> >
 > >> > rootdn          "cn=admin,dc=iwu,dc=edu"
 > >> > rootpw		{redacted}
 > >> >
 > >> > authz-regexp "uidNumber=0\\\
 > >> > +gidNumber=.*,cn=peercred,cn=external,cn=auth"
 > >> >           	"cn=ldapi,dc=iwu,dc=edu"
 > >> > authz-regexp "gidNumber=.*\\\
 > >> > +uidNumber=0,cn=peercred,cn=external,cn=auth"
 > >> >           	"cn=ldapi,dc=iwu,dc=edu"
 > >> >
 > >> > authz-regexp "uid=(.+),cn=.+,cn=auth" "uid=$1,ou=People,dc=iwu,dc=edu"
 > >> >
 > >> > directory       "/var/lib/ldap/"
 > >> >
 > >> > dbconfig set_cachesize 0 62914560 0
 > >> > dbconfig set_lk_max_objects 1500
 > >> > dbconfig set_lk_max_locks 1500
 > >> > dbconfig set_lk_max_lockers 1500
 > >> >
 > >> > # Make sure to do a nightly slapcat
 > >> > dbconfig set_flags DB_LOG_AUTOREMOVE
 > >> >
 > >> > index   objectClass             eq,pres
 > >> > index   default                 eq,sub,pres
 > >> > index   mail                    eq,sub,pres
 > >> > index   sn                      eq,sub,pres
 > >> > index   cn                      eq,sub,pres
 > >> > index   displayName             eq,sub,pres
 > >> > index   gecos                   eq,sub,pres
 > >> > index   uid                     eq,sub,pres
 > >> > index   memberUid               eq,sub,pres
 > >> > index   uidNumber               eq,pres
 > >> > index   gidNumber               eq,pres
 > >> > index   entryCSN                eq,pres
 > >> > index   entryUUID               eq,pres
 > >> > index   uniqueMember            eq,pres
 > >> > index	userPassword		eq,pres
 > >> > index   krb5PrincipalName       eq,pres
 > >> > index   krb5PrincipalRealm      eq,pres
 > >> > index   sambaDomainName         eq,pres
 > >> > index   sambaSID                eq,pres
 > >> > index   sambaPrimaryGroupSID    eq,pres
 > >> > index	sambaSIDList		eq,pres
 > >> >
 > >> > lastmod         on
 > >> >
 > >> > checkpoint      256 15
 > >> >
 > >> > password-hash {SSHA}
 > >> >
 > >> > limits dn.exact="cn=admin,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> > limits dn.exact="cn=ldapi,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> > limits dn.exact="cn=sambaadmin,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> > limits dn.exact="cn=mirror,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> > limits dn.exact="cn=freeradius,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > 	by dn.exact="cn=ldapi,dc=iwu,dc=edu" write
 > >> > 	by dn.exact="cn=sambaadmin,dc=iwu,dc=edu" write
 > >> > 	by dn.exact="cn=mirror,dc=iwu,dc=edu"  read
 > >> > 	by dn.exact="cn=freeradius,dc=iwu,dc=edu"  read
 > >> > 	by * break
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > attrs=userPassword,shadowLastChange,sambaLMPassword,sambaNTPassword,krb5Key
 > >> >         by anonymous auth
 > >> >         by self write
 > >> >         by dn.exact="cn=passwordmanager,dc=iwu,dc=edu" write
 > >> > 	by users auth
 > >> >         by * break
 > >> >
 > >> > access to dn.exact="cn=ldapi,dc=iwu,dc=edu" by * none
 > >> > access to dn.exact="cn=sambaadmin,dc=iwu,dc=edu" by * none
 > >> > access to dn.exact="cn=mirror,dc=iwu,dc=edu" by * none
 > >> > access to dn.exact="cn=freeradius,dc=iwu,dc=edu" by * none
 > >> > access to dn.exact="cn=passwordmanager,dc=iwu,dc=edu" by * none
 > >> > access to dn.exact="cn=admin,dc=iwu,dc=edu" by * none
 > >> >
 > >> > access to dn.regex="uid=.*\$,ou=People,dc=iwu,dc=edu" by self read by *
 > >> > none
 > >> > access to dn.sub="ou=Computers,dc=iwu,dc=edu" by self read by * none
 > >> > access to dn.sub="ou=Idmap,dc=iwu,dc=edu" by self read by * none
 > >> > access to dn.exact="sambaDomainName=IWU.EDU,dc=iwu,dc=edu" by self read
 > >> > by * none
 > >> > access to dn.exact="uid=Administrator,ou=People,dc=iwu,dc=edu" by self
 > >> > read by * none
 > >> > access to dn.exact="uid=root,ou=People,dc=iwu,dc=edu" by self read by *
 > >> > none
 > >> >
 > >> > access to
 > >> > dn.regex="krb5PrincipalName=.*@IWU.EDU,ou=People,dc=iwu,dc=edu" by self
 > >> > read by * none
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > attrs=telephoneNumber,mobileTelephoneNumber,homePostalAddress,streetAddress,physicalDeliveryOfficeName,roomNumber,preferredLanguage,localityName,postOfficeBox,postalCode,stateOrProvinceName
 > >> >    by self write
 > >> >    by users read
 > >> >    by anonymous none
 > >> >    by * break
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > attrs=krb5PrincipalName,krb5MaxLife,krb5MaxRenew,krb5KDCFlags,krb5KeyVersionNumber
 > >> >     by self read
 > >> >     by anonymous none
 > >> >     by * break
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > attrs=sambaPrimaryGroupSID,sambaSID,sambaAlgorithmicRidBase,sambaNextRid
 > >> >     by * none
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu"
 > >> > attrs=sambaPwdCanChange,sambaLogonTime,sambaLogoffTime,sambaAcctFlags,sambaPasswordHistory,sambaPwdLastSet,sambaGroupType,sambaPwdMustChange,sambaKickoffTime,sambaLockoutThreshold,sambaForceLogoff,sambaRefuseMachinePwdChange,sambaLockoutObservationWindow,sambaLockoutDuration,sambaMinPwdAge,sambaMaxPwdAge,sambaLogonToChgPwd,sambaPwdHistoryLength,sambaMinPwdLength
 > >> >     by self read
 > >> >     by anonymous none
 > >> >     by * break
 > >> >
 > >> > access to dn.sub="dc=iwu,dc=edu" by * read
 > >> >
 > >> > serverID 1
 > >> >
 > >> > syncrepl rid=2
 > >> >          provider=ldap://ldap2.iwu.edu/
 > >> >          schemachecking=off
 > >> >          searchbase="dc=iwu,dc=edu"
 > >> >          scope=sub
 > >> >          type=refreshAndPersist
 > >> >          binddn="cn=mirror,dc=iwu,dc=edu"
 > >> >          credentials={redacted}
 > >> >          bindmethod=simple
 > >> >          starttls=yes
 > >> >          tls_cert=/etc/ldap/ssl/ldap.iwu.edu.crt
 > >> >          tls_key=/etc/ldap/ssl/ldap.iwu.edu.key
 > >> >          tls_cacert=/etc/ldap/ssl/IWU.crt
 > >> >          tls_reqcert=try
 > >> >          interval=00:00:00:30
 > >> >          retry="15 +"
 > >> >          timeout=1
 > >> >          timelimit=unlimited
 > >> >          sizelimit=unlimited
 > >> >
 > >> > mirrormode on
 > >> >
 > >> > ###############################
 > >> > database monitor
 > >> > limits dn.exact="cn=admin,dc=iwu,dc=edu" size.hard=unlimited
 > >> > time.hard=unlimited size.soft=unlimited time.soft=unlimited
 > >> >
 > >> > access to dn.exact="cn=Monitor"
 > >> > 	by dn.exact="cn=admin,dc=iwu,dc=edu" read
 > >> > 	by * none
 > >> >
 > >> > access to dn.subtree="cn=Monitor"
 > >> > 	by dn.exact="cn=admin,dc=iwu,dc=edu" read
 > >> > 	by * none
 > >> >
 > >> >
 > >> >>
 > >> >> On 22/12/2008, Pat Riehecky <prieheck@iwu.edu> wrote:
 > >> >> > Here is the quick and dirty what I am trying to do:
 > >> >> >
 > >> >> > ldap1 and ldap2 are supposed to be in MultiMaster.  They are time
 > >> >> > synced
 > >> >> > to pool.ntp.org and each other (if they drift I would rather they
 > >> >> > sorta
 > >> >> > drift together, but pool should be keeping that in check).
 > >> >> >
 > >> >> > Right now I am just beating them up to see how 2.4.13 performs. (So
 > >> >> > far
 > >> >> > VERY well, minus this little problem)
 > >> >> >
 > >> >> > I have a rather small ldif (41 entries) that just wont sync (I'm
 > >> >> > starting small).  Debug gives me
 > >> >> >
 > >> >> > ber_scanf fmt (m}) ber:
 > >> >> > ber_dump: buf=0xb806f120 ptr=0xb806f137 end=0xb806f175 len=62
 > >> >> >   0000:  00 3c 72 69 64 3d 30 30  31 2c 73 69 64 3d 30
 > >> >> > 30   .<rid=001,sid=00
 > >> >> >   0010:  32 2c 63 73 6e 3d 32 30  30 38 31 32 32 32 31 37
 > >> >> > 2,csn=2008122217
 > >> >> >   0020:  34 37 32 31 2e 38 35 35  39 30 34 5a 23 30 30 30
 > >> >> > 4721.855904Z#000
 > >> >> >   0030:  30 30 30 23 30 30 31 23  30 30 30 30 30 30
 > >> >> > 000#001#000000
 > >> >> > do_syncrep2:
 > >> >> > cookie=rid=001,sid=002,csn=20081222174721.855904Z#000000#001#000000
 > >> >> > do_syncrep2: rid=001 CSN too old, ignoring
 > >> >> > 20081222174721.855904Z#000000#001#000000
 > >> >> > ldap_msgfree
 > >> >> >
 > >> >> > I am not exactly sure how it gotten to be "too old."  The ldif I am
 > >> >> > importing is not the result of a slapcat or anything that would
 > >> >> > preserve
 > >> >> > the CSN or UUID attributes (not that syncrepl uses UUID). I am
 > >> >> > loading
 > >> >> > one single file with ldapadd which, in my understanding, sets up the
 > >> >> > CSN
 > >> >> > and wouldn't let me import one anyway.
 > >> >> >
 > >> >> > Each server has no entries until I load the one, so there shouldn't
 > >> >> > be
 > >> >> > any weird stale CSNs causing this.  They are "sync'ed" almost
 > >> >> > instantly
 > >> >> > after the one system is loaded - I just don't have everything.
 > >> >> >
 > >> >> > After a sync:
 > >> >> > ldap1 - slapcat |grep dn: |wc -l = 41
 > >> >> > ldap2 - slapcat |grep dn: |wc -l = 18
 > >> >> >
 > >> >> > Right now I can get them in sync with a slapcat/slapadd, but when the
 > >> >> > go
 > >> >> > into production I wont be able to say for certain which one is
 > >> >> > authoritative.  That is the purpose of multi-master....
 > >> >> >
 > >> >> > OpenLDAP 2.4.13, built by me (passed all tests) on Ubuntu Linux 32
 > >> >> > bit
 > >> >> >
 > >> >> > Any ideas as to what I can do to stop this from happening?
 > >> >> >
 > >> >> > Pat
 > >> >> >
 > >> >> >
 > >> >> >
 > >> >> >
 > >> >>
 > >> >
 > >> >
 > >>
 > >
 > >
 >
 
 
 -- 
 Sent from my mobile device
 
 http://www.suretecsystems.com/services/openldap/
 
 


Adrien Futschik