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

(ITS#6473) delta-syncrepl "replicates" entries with unknown schema elements



Full_Name: Quanah Gibson-Mount
Version: 2.3.43
OS: Linux 2.6
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (75.111.45.108)


Recent discrepancies on client replica systems that were 100% reproducible
showed that when using delta-syncrepl, it is easy to get a master/replica out of
sync in the following scenario when using slapd.conf:

A) Stop the master
B) update the master with a schema that adds an additional attribute
C) Start the master
D) Modify an existing entry on the master, setting the new attribute with a
value

The replica will update its database with the event, but ignoring the new
attribute and the value set for it, incorrectly updating its CSN.  Instead of
accepting the replication event, it should stop replication until its schema is
updated to match that of the master.

Master log of the modification:

dn: reqStart=20100213000511.000002Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20100213000511.000002Z
reqEnd: 20100213000511.000003Z
reqType: modify
reqSession: 3
reqAuthzID: uid=zimbra,cn=admins,cn=zimbra
reqDN: cn=config,cn=zimbra
reqResult: 0
reqMod: zimbraMailUseDirectBuffers:= FALSE
reqMod: entryCSN:= 20100213000511Z#000000#00#000000
reqMod: modifiersName:= uid=zimbra,cn=admins,cn=zimbra
reqMod: modifyTimestamp:= 20100213000511Z
entryUUID: 328fcc94-ac7f-102e-8753-251cf08bb530
creatorsName: cn=accesslog
createTimestamp: 20100213000511Z
entryCSN: 20100213000511Z#000000#00#000000
modifiersName: cn=accesslog
modifyTimestamp: 20100213000511Z

On the replica, we see:

ber_scanf fmt ({ml{) ber:
ber_dump: buf=0x9f811c0 ptr=0x9f811c3 end=0x9f81375 len=434
  0000:  64 82 01 49 04 2c 72 65  71 53 74 61 72 74 3d 32   d..I.,reqStart=2
  0010:  30 31 30 30 32 31 33 30  30 30 35 31 31 2e 30 30   0100213000511.00
  0020:  30 30 30 32 5a 2c 63 6e  3d 61 63 63 65 73 73 6c   0002Z,cn=accessl
  0030:  6f 67 30 82 01 17 30 13  04 07 72 65 71 54 79 70   og0...0...reqTyp
  0040:  65 31 08 04 06 6d 6f 64  69 66 79 30 1e 04 05 72   e1...modify0...r
  0050:  65 71 44 4e 31 15 04 13  63 6e 3d 63 6f 6e 66 69   eqDN1...cn=confi
  0060:  67 2c 63 6e 3d 7a 69 6d  62 72 61 30 81 af 04 06   g,cn=zimbra0....
  0070:  72 65 71 4d 6f 64 31 81  a4 04 22 7a 69 6d 62 72   reqMod1..."zimbr
  0080:  61 4d 61 69 6c 55 73 65  44 69 72 65 63 74 42 75   aMailUseDirectBu
  0090:  66 66 65 72 73 3a 3d 20  46 41 4c 53 45 04 2b 65   ffers:= FALSE.+e
  00a0:  6e 74 72 79 43 53 4e 3a  3d 20 32 30 31 30 30 32   ntryCSN:= 201002
  00b0:  31 33 30 30 30 35 31 31  5a 23 30 30 30 30 30 30   13000511Z#000000
  00c0:  23 30 30 23 30 30 30 30  30 30 04 2e 6d 6f 64 69   #00#000000..modi
  00d0:  66 69 65 72 73 4e 61 6d  65 3a 3d 20 75 69 64 3d   fiersName:= uid=
  00e0:  7a 69 6d 62 72 61 2c 63  6e 3d 61 64 6d 69 6e 73   zimbra,cn=admins
  00f0:  2c 63 6e 3d 7a 69 6d 62  72 61 04 21 6d 6f 64 69   ,cn=zimbra.!modi
  0100:  66 79 54 69 6d 65 73 74  61 6d 70 3a 3d 20 32 30   fyTimestamp:= 20
  0110:  31 30 30 32 31 33 30 30  30 35 31 31 5a 30 2e 04   100213000511Z0..
  0120:  08 65 6e 74 72 79 43 53  4e 31 22 04 20 32 30 31   .entryCSN1". 201
  0130:  30 30 32 31 33 30 30 30  35 31 31 5a 23 30 30 30   00213000511Z#000
  0140:  30 30 30 23 30 30 23 30  30 30 30 30 30 a0 63 30   000#00#000000.c0
  0150:  61 04 18 31 2e 33 2e 36  2e 31 2e 34 2e 31 2e 34   a..1.3.6.1.4.1.4
  0160:  32 30 33 2e 31 2e 39 2e  31 2e 32 04 45 30 43 0a   203.1.9.1.2.E0C.
  0170:  01 01 04 10 32 8f cc 94  ac 7f 10 2e 87 53 25 1c   ....2........S%.
  0180:  f0 8b b5 30 04 2c 63 73  6e 3d 32 30 31 30 30 32   ...0.,csn=201002
  0190:  31 33 30 30 30 35 31 31  5a 23 30 30 30 30 30 30   13000511Z#000000
  01a0:  23 30 30 23 30 30 30 30  30 30 2c 72 69 64 3d 31   #00#000000,rid=1
  01b0:  30 30                                              00
ldap_get_attribute_ber
ber_scanf fmt ({mM}) ber:
ber_dump: buf=0x9f811c0 ptr=0x9f811f9 end=0x9f81310 len=279
  0000:  30 13 04 07 72 65 71 54  79 70 65 31 08 04 06 6d   0...reqType1...m
  0010:  6f 64 69 66 79 30 1e 04  05 72 65 71 44 4e 31 15   odify0...reqDN1.
  0020:  04 13 63 6e 3d 63 6f 6e  66 69 67 2c 63 6e 3d 7a   ..cn=config,cn=z
  0030:  69 6d 62 72 61 30 81 af  04 06 72 65 71 4d 6f 64   imbra0....reqMod
  0040:  31 81 a4 04 22 7a 69 6d  62 72 61 4d 61 69 6c 55   1..."zimbraMailU
  0050:  73 65 44 69 72 65 63 74  42 75 66 66 65 72 73 3a   seDirectBuffers:
  0060:  3d 20 46 41 4c 53 45 04  2b 65 6e 74 72 79 43 53   = FALSE.+entryCS
  0070:  4e 3a 3d 20 32 30 31 30  30 32 31 33 30 30 30 35   N:= 201002130005
  0080:  31 31 5a 23 30 30 30 30  30 30 23 30 30 23 30 30   11Z#000000#00#00
  0090:  30 30 30 30 04 2e 6d 6f  64 69 66 69 65 72 73 4e   0000..modifiersN
  00a0:  61 6d 65 3a 3d 20 75 69  64 3d 7a 69 6d 62 72 61   ame:= uid=zimbra
  00b0:  2c 63 6e 3d 61 64 6d 69  6e 73 2c 63 6e 3d 7a 69   ,cn=admins,cn=zi
  00c0:  6d 62 72 61 04 21 6d 6f  64 69 66 79 54 69 6d 65   mbra.!modifyTime
  00d0:  73 74 61 6d 70 3a 3d 20  32 30 31 30 30 32 31 33   stamp:= 20100213
  00e0:  30 30 30 35 31 31 5a 30  2e 04 08 65 6e 74 72 79   000511Z0...entry
  00f0:  43 53 4e 31 22 04 20 32  30 31 30 30 32 31 33 30   CSN1". 201002130
  0100:  30 30 35 31 31 5a 23 30  30 30 30 30 30 23 30 30   00511Z#000000#00
  0110:  23 30 30 30 30 30 30                               #000000
ldap_get_attribute_ber
ber_scanf fmt ({mM}) ber:
ber_dump: buf=0x9f811c0 ptr=0x9f8120e end=0x9f81310 len=258
  0000:  00 1e 04 05 72 65 71 44  4e 31 15 04 13 63 6e 3d   ....reqDN1...cn=
  0010:  63 6f 6e 66 69 67 2c 63  6e 3d 7a 69 6d 62 72 61   config,cn=zimbra
  0020:  30 81 af 04 06 72 65 71  4d 6f 64 31 81 a4 04 22   0....reqMod1..."
  0030:  7a 69 6d 62 72 61 4d 61  69 6c 55 73 65 44 69 72   zimbraMailUseDir
  0040:  65 63 74 42 75 66 66 65  72 73 3a 3d 20 46 41 4c   ectBuffers:= FAL
  0050:  53 45 04 2b 65 6e 74 72  79 43 53 4e 3a 3d 20 32   SE.+entryCSN:= 2
  0060:  30 31 30 30 32 31 33 30  30 30 35 31 31 5a 23 30   0100213000511Z#0
  0070:  30 30 30 30 30 23 30 30  23 30 30 30 30 30 30 04   00000#00#000000.
  0080:  2e 6d 6f 64 69 66 69 65  72 73 4e 61 6d 65 3a 3d   .modifiersName:=
  0090:  20 75 69 64 3d 7a 69 6d  62 72 61 2c 63 6e 3d 61    uid=zimbra,cn=a
  00a0:  64 6d 69 6e 73 2c 63 6e  3d 7a 69 6d 62 72 61 04   dmins,cn=zimbra.
  00b0:  21 6d 6f 64 69 66 79 54  69 6d 65 73 74 61 6d 70   !modifyTimestamp
  00c0:  3a 3d 20 32 30 31 30 30  32 31 33 30 30 30 35 31   := 2010021300051
  00d0:  31 5a 30 2e 04 08 65 6e  74 72 79 43 53 4e 31 22   1Z0...entryCSN1"
  00e0:  04 20 32 30 31 30 30 32  31 33 30 30 30 35 31 31   . 20100213000511
  00f0:  5a 23 30 30 30 30 30 30  23 30 30 23 30 30 30 30   Z#000000#00#0000
  0100:  30 30                                              00
>>> dnPrettyNormal: <cn=config,cn=zimbra>
=> ldap_bv2dn(cn=config,cn=zimbra,0)
<= ldap_bv2dn(cn=config,cn=zimbra)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=config,cn=zimbra)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(cn=config,cn=zimbra)=0
<<< dnPrettyNormal: <cn=config,cn=zimbra>, <cn=config,cn=zimbra>
ldap_get_attribute_ber
ber_scanf fmt ({mM}) ber:
ber_dump: buf=0x9f811c0 ptr=0x9f8122e end=0x9f81310 len=226
  0000:  00 81 af 04 06 72 65 71  4d 6f 64 31 81 a4 04 22   .....reqMod1..."
  0010:  7a 69 6d 62 72 61 4d 61  69 6c 55 73 65 44 69 72   zimbraMailUseDir
  0020:  65 63 74 42 75 66 66 65  72 73 3a 3d 20 46 41 4c   ectBuffers:= FAL
  0030:  53 45 04 2b 65 6e 74 72  79 43 53 4e 3a 3d 20 32   SE.+entryCSN:= 2
  0040:  30 31 30 30 32 31 33 30  30 30 35 31 31 5a 23 30   0100213000511Z#0
  0050:  30 30 30 30 30 23 30 30  23 30 30 30 30 30 30 04   00000#00#000000.
  0060:  2e 6d 6f 64 69 66 69 65  72 73 4e 61 6d 65 3a 3d   .modifiersName:=
  0070:  20 75 69 64 3d 7a 69 6d  62 72 61 2c 63 6e 3d 61    uid=zimbra,cn=a
  0080:  64 6d 69 6e 73 2c 63 6e  3d 7a 69 6d 62 72 61 04   dmins,cn=zimbra.
  0090:  21 6d 6f 64 69 66 79 54  69 6d 65 73 74 61 6d 70   !modifyTimestamp
  00a0:  3a 3d 20 32 30 31 30 30  32 31 33 30 30 30 35 31   := 2010021300051
  00b0:  31 5a 30 2e 04 08 65 6e  74 72 79 43 53 4e 31 22   1Z0...entryCSN1"
  00c0:  04 20 32 30 31 30 30 32  31 33 30 30 30 35 31 31   . 20100213000511
  00d0:  5a 23 30 30 30 30 30 30  23 30 30 23 30 30 30 30   Z#000000#00#0000
  00e0:  30 30                                              00
ldap_get_attribute_ber
ber_scanf fmt ({mM}) ber:
ber_dump: buf=0x9f811c0 ptr=0x9f812e0 end=0x9f81310 len=48
  0000:  00 2e 04 08 65 6e 74 72  79 43 53 4e 31 22 04 20   ....entryCSN1".
  0010:  32 30 31 30 30 32 31 33  30 30 30 35 31 31 5a 23   20100213000511Z#
  0020:  30 30 30 30 30 30 23 30  30 23 30 30 30 30 30 30   000000#00#000000
ldap_get_attribute_ber
>>> dnPretty: <uid=zimbra,cn=admins,cn=zimbra>
=> ldap_bv2dn(uid=zimbra,cn=admins,cn=zimbra,0)
<= ldap_bv2dn(uid=zimbra,cn=admins,cn=zimbra)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=zimbra,cn=admins,cn=zimbra)=0
<<< dnPretty: <uid=zimbra,cn=admins,cn=zimbra>
>>> dnNormalize: <uid=zimbra,cn=admins,cn=zimbra>
=> ldap_bv2dn(uid=zimbra,cn=admins,cn=zimbra,0)
<= ldap_bv2dn(uid=zimbra,cn=admins,cn=zimbra)=0
=> ldap_dn2bv(272)
<= ldap_dn2bv(uid=zimbra,cn=admins,cn=zimbra)=0
<<< dnNormalize: <uid=zimbra,cn=admins,cn=zimbra>
bdb_modify: cn=config,cn=zimbra
bdb_dn2entry("cn=config,cn=zimbra")
bdb_modify_internal: 0x0000000c: cn=config,cn=zimbra
<= acl_access_allowed: granted to database root
bdb_modify_internal: replace entryCSN
bdb_modify_internal: replace modifiersName
bdb_modify_internal: replace modifyTimestamp
=> key_change(DELETE,c)
bdb_idl_delete_key: c
<= key_change 0
=> key_change(ADD,c)
bdb_idl_insert_key: c
<= key_change 0
=> entry_encode(0x0000000c): cn=config,cn=zimbra
bdb_modify: updated id=0000000c dn="cn=config,cn=zimbra"
send_ldap_result: conn=-1 op=0 p=0
send_ldap_result: err=0 matched="" text=""
syncrepl_message_to_op: rid 100 be_modify cn=config,cn=zimbra (0)
bdb_modify:
bdb_dn2entry("")
bdb_modify_internal: 0x00000000:
<= acl_access_allowed: granted to database root
bdb_modify_internal: replace contextCSN
=> entry_encode(0x00000000):
bdb_modify: updated id=00000000 dn=""
send_ldap_result: conn=-1 op=0 p=0
send_ldap_result: err=0 matched="" text=""
ldap_msgfree


As you can see, the replica *clearly* sees the attribute in question, but fails
to throw an error, and simply updates the database with all of the other changes
(entryCSN, etc) then updates the contextCSN.