Re: (ITS#6195) Replications with 2.3.43 master to 2.4.16 slave is failing

[quanah@zimbra.com]

--On Thursday, July 02, 2009 10:15 PM +0000 whm@stanford.edu wrote:

> It looks like there is an attempt to remove objectclass=posixaccount
> without removing gecos at the same time.

The slapd -d -1 output of this system is quite interesting.  First, here's 
the changelogs from the master.  Note that there are *two* of them.  In the 
first one, "gecos" is deleted:

dn: reqStart=20090702070150.000014Z,cn=accesslog
objectClass: auditModify
reqStart: 20090702070150.000014Z
reqEnd: 20090702070150.000016Z
reqType: modify
reqSession: 12280
reqAuthzID: cn=slog-accounts,cn=service,cn=applications,dc=stanford,dc=edu
reqDN: uid=acyen,cn=Accounts,dc=Stanford,dc=edu
reqResult: 0
reqMod: gecos:-
reqMod: cn:-
reqMod: description:-
reqMod: loginShell:-
reqMod: uidNumber:-
reqMod: gidNumber:-
reqMod: homeDirectory:-
reqMod: objectClass:= suPtsService
reqMod: objectClass:= suAccount
reqMod: objectClass:= suOperational
reqMod: objectClass:= suAfsService
reqMod: objectClass:= suEmailService
reqMod: objectClass:= suLelandService
reqMod: objectClass:= suDialinService
reqMod: objectClass:= suKerberosService
reqMod: objectClass:= suSeasService
reqMod: suAfsStatus:= frozen
reqMod: suSeasStatus:= frozen
reqMod: suEmailStatus:= frozen
reqMod: suLelandStatus:= frozen
reqMod: suIdentifies:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=S
 tanford,dc=edu
reqMod: seeAlso:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=Stanfo
 rd,dc=edu
reqMod: owner:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=Stanford
 ,dc=edu
reqMod: suDialinStatus:= frozen
reqMod: suPtsStatus:= frozen
reqMod: suDescription:= XXXXXXX
reqMod: entryCSN:= 20090702070150Z#000002#00#000000
reqMod: modifiersName:= 
cn=slog-accounts,cn=service,cn=applications,dc=stanfor
 d,dc=edu
reqMod: modifyTimestamp:= 20090702070150Z

So, you can see gecos is clearly deleted here.  In fact, it is the very 
first thing deleted.  The second change is where things are failing:

dn: reqStart=20090702075511.000006Z,cn=accesslog
objectClass: auditModify
reqStart: 20090702075511.000006Z
reqEnd: 20090702075511.000007Z
reqType: modify
reqSession: 13583
reqAuthzID: cn=slog-accounts,cn=service,cn=applications,dc=stanford,dc=edu
reqDN: uid=acyen,cn=Accounts,dc=Stanford,dc=edu
reqResult: 0
reqMod: krb5PrincipalName:-
reqMod: suKrb4Name:-
reqMod: suKerberosStatus:-
reqMod: objectClass:= suPtsService
reqMod: objectClass:= suAccount
reqMod: objectClass:= suOperational
reqMod: objectClass:= suAfsService
reqMod: objectClass:= suEmailService
reqMod: objectClass:= suLelandService
reqMod: objectClass:= suDialinService
reqMod: objectClass:= suSeasService
reqMod: suIdentifies:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=S
 tanford,dc=edu
reqMod: seeAlso:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=Stanfo
 rd,dc=edu
reqMod: owner:= 
suRegID=85ddc8aaf61311d2ae662436000baa77,cn=People,dc=Stanford
 ,dc=edu
reqMod: suDescription:= XXXXXXX
reqMod: suService:= dialin
reqMod: suService:= afs
reqMod: suService:= leland
reqMod: suService:= email
reqMod: suService:= pts
reqMod: suService:= seas
reqMod: suAccountStatus:= inactive
reqMod: entryCSN:= 20090702075511Z#000000#00#000000
reqMod: modifiersName:= 
cn=slog-accounts,cn=service,cn=applications,dc=stanfor
 d,dc=edu
reqMod: modifyTimestamp:= 20090702075511Z

Now, the replica was loaded from an LDIF taken on 2009/07/01, so it should 
have taken both of these changes just fine:

dn: dc=stanford,dc=edu
objectClass: dcObject
objectClass: organization
o: Stanford University
dc: stanford
l: Palo Alto
structuralObjectClass: organization
entryUUID: e67c08ca-adc9-102a-8f07-03156481d080
creatorsName: cn=manager,dc=stanford,dc=edu
modifiersName: cn=manager,dc=stanford,dc=edu
createTimestamp: 20060722123236Z
modifyTimestamp: 20060722123236Z
contextCSN: 20090701110754Z#000000#00#000000


The slapd -d -1 log shows it is clearly processing the second change and 
failing there:

  0000:  82 04 37 04 2c 72 65 71  53 74 61 72 74 3d 32 30   ..7.,reqStart=20
  0010:  30 39 30 37 30 32 30 37  35 35 31 31 2e 30 30 30   090702075511.000
  0020:  30 30 36 5a 2c 63 6e 3d  61 63 63 65 73 73 6c 6f   006Z,cn=accesslo
  0030:  67 30 82 04 05 30 13 04  07 72 65 71 54 79 70 65   g0...0...reqType
  0040:  31 08 04 06 6d 6f 64 69  66 79 30 33 04 05 72 65   1...modify03..re
  0050:  71 44 4e 31 2a 04 28 75  69 64 3d 61 63 79 65 6e   qDN1*.(uid=acyen
  0060:  2c 63 6e 3d 41 63 63 6f  75 6e 74 73 2c 64 63 3d   ,cn=Accounts,dc=
  0070:  53 74 61 6e 66 6f 72 64  2c 64 63 3d 65 64 75 30   Stanford,dc=edu0
  0080:  82 03 87 04 06 72 65 71  4d 6f 64 31 82 03 7b 04   .....reqMod1..{.
  0090:  13 6b 72 62 35 50 72 69  6e 63 69 70 61 6c 4e 61   .krb5PrincipalNa
  00a0:  6d 65 3a 2d 04 0c 73 75  4b 72 62 34 4e 61 6d 65   me:-..suKrb4Name
  00b0:  3a 2d 04 12 73 75 4b 65  72 62 65 72 6f 73 53 74   :-..suKerberosSt
  00c0:  61 74 75 73 3a 2d 04 1a  6f 62 6a 65 63 74 43 6c   atus:-..objectCl
  00d0:  61 73 73 3a 3d 20 73 75  50 74 73 53 65 72 76 69   ass:= suPtsServi
  00e0:  63 65 04 17 6f 62 6a 65  63 74 43 6c 61 73 73 3a   ce..objectClass:
  00f0:  3d 20 73 75 41 63 63 6f  75 6e 74 04 1b 6f 62 6a   = suAccount..obj
  0100:  65 63 74 43 6c 61 73 73  3a 3d 20 73 75 4f 70 65   ectClass:= suOpe
  0110:  72 61 74 69 6f 6e 61 6c  04 1a 6f 62 6a 65 63 74   rational..object
  0120:  43 6c 61 73 73 3a 3d 20  73 75 41 66 73 53 65 72   Class:= suAfsSer


(etc).

bdb_modify_internal: 0x00074e3f: uid=acyen,cn=accounts,dc=stanford,dc=edu
<= acl_access_allowed: granted to database root
bdb_modify_internal: delete krb5PrincipalName
bdb_modify_internal: delete suKrb4Name
bdb_modify_internal: delete suKerberosStatus
bdb_modify_internal: replace objectClass
bdb_modify_internal: replace suIdentifies
bdb_modify_internal: replace seeAlso
bdb_modify_internal: replace owner
bdb_modify_internal: replace suDescription
bdb_modify_internal: replace suService
bdb_modify_internal: replace suAccountStatus
bdb_modify_internal: replace entryCSN
bdb_modify_internal: replace modifiersName
bdb_modify_internal: replace modifyTimestamp
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suPtsService"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suAccount"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suOperational"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suAfsService"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suEmailService"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suLelandService"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suDialinService"
oc_check_required entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), 
objectClass "suSeasService"
oc_check_allowed type "suSeasSunetID"
oc_check_allowed type "suDialinStatus"
oc_check_allowed type "suCreateAgent"
oc_check_allowed type "suEmailAdmin"
oc_check_allowed type "suSeasUriRouteTo"
oc_check_allowed type "suName"
oc_check_allowed type "uid"
oc_check_allowed type "suNameLF"
oc_check_allowed type "suSeasStatus"
oc_check_allowed type "suEntryStatus"
oc_check_allowed type "suSeasLocal"
oc_check_allowed type "suEmailAccountType"
oc_check_allowed type "suAfsStatus"
oc_check_allowed type "suEmailStatus"
oc_check_allowed type "suMailDrop"
oc_check_allowed type "suCreateAPI"
oc_check_allowed type "suPtsStatus"
oc_check_allowed type "suLelandStatus"
oc_check_allowed type "structuralObjectClass"
oc_check_allowed type "entryUUID"
oc_check_allowed type "creatorsName"
oc_check_allowed type "createTimestamp"
oc_check_allowed type "gecos"
Entry (uid=acyen,cn=accounts,dc=stanford,dc=edu), attribute 'gecos' not 
allowed
entry failed schema check: attribute 'gecos' not allowed
hdb_modify: modify failed (65)


So, it appears to me that even though it must have at some point accepted 
the first change, the entry on the server is not truly updated to reflect 
that for some reason?  That, or it "skipped" that change for reasons 
unknown to me.

--Quanah
--

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