retroCL may miss some update if internal add fails

[389-ds-bot]

Cloned from Pagure issue: https://pagure.io/389-ds-base/issue/47802

• Created at 2014-05-12 15:50:39 by tbordaz (@tbordaz)
• Closed as Duplicate
• Assigned to mreynolds (@mreynolds389)

---

retrocl_postob returns success (0) even if write_replog_db fails. So if RetroCL is enabled, it is called in postop of a MODIFY (for example). The changenumber is not written in 'cn=changelog' (in case of internal failure), but the original MODIFY succeeds.

So an update is written in the original database but not in the cn=changelog.

I reproduce this attaching a debugger and making 'write_replog_db' fail.

I was testing a fix for https://fedorahosted.org/389/ticket/47797. The fix, is to catch a DB_DEADLOCK and prevent a deadlock that is quite easy to reproduce with freeipa unit tests. This fix allows an internal ADD to fail if it encounters a DB_DEADLOCK. The consequence is that the update of the retroCL fails but not the original MOD.

#
# 1rst update on an entry without simulating a failure in retroCL
#
ldapmodify  -h localhost -p 44389 -D "cn=directory manager" -w password 
dn: cn=new_account0,cn=staged user,dc=example,dc=com
changetype: modify 
replace: description
description: val1

modifying entry "cn=new_account0,cn=staged user,dc=example,dc=com"


#
# the update is in cn=changelog
#
ldapsearch -LLL -h localhost -p 44389 -D "cn=directory manager" -w password -b "cn=changelog" "(changenumber>=1)"
dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account0,cn=staged user,dc=example,dc=com
changeTime: 20140512084901Z
changeType: modify
changes:: cmVwbGFjZTogZGVzY3JpcHRpb24KZGVzY3JpcHRpb246IHZhbDEKLQpyZXBsYWNlOiBt
 b2RpZmllcnNuYW1lCm1vZGlmaWVyc25hbWU6IGNuPWRpcmVjdG9yeSBtYW5hZ2VyCi0KcmVwbGFjZ
 TogbW9kaWZ5dGltZXN0YW1wCm1vZGlmeXRpbWVzdGFtcDogMjAxNDA1MTIwODQ5MDFaCi0KAA==

#
# 2nd update on the entry simulating a failure in RetrocCL add
#
ldapmodify  -h localhost -p 44389 -D "cn=directory manager" -w password 
dn: cn=new_account0,cn=staged user,dc=example,dc=com
changetype: modify
replace: description
description: val2

modifying entry "cn=new_account0,cn=staged user,dc=example,dc=com"


#
# only the first update is in the changelog
#
ldapsearch -LLL -h localhost -p 44389 -D "cn=directory manager" -w password -b "cn=changelog" "(changenumber>=1)"
dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account0,cn=staged user,dc=example,dc=com
changeTime: 20140512084901Z
changeType: modify
changes:: cmVwbGFjZTogZGVzY3JpcHRpb24KZGVzY3JpcHRpb246IHZhbDEKLQpyZXBsYWNlOiBt
 b2RpZmllcnNuYW1lCm1vZGlmaWVyc25hbWU6IGNuPWRpcmVjdG9yeSBtYW5hZ2VyCi0KcmVwbGFjZ
 TogbW9kaWZ5dGltZXN0YW1wCm1vZGlmeXRpbWVzdGFtcDogMjAxNDA1MTIwODQ5MDFaCi0KAA==

#
# 3rd update without simulating retrocl add failure
#
ldapmodify  -h localhost -p 44389 -D "cn=directory manager" -w password 
dn: cn=new_account0,cn=staged user,dc=example,dc=com
changetype: modify
add: description
description: val3

modifying entry "cn=new_account0,cn=staged user,dc=example,dc=com"

#
# only 1rst and 3rd update are in retroCL
#
 ldapsearch -LLL -h localhost -p 44389 -D "cn=directory manager" -w password -b "cn=changelog" "(changenumber>=1)"
dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account0,cn=staged user,dc=example,dc=com
changeTime: 20140512084901Z
changeType: modify
changes:: cmVwbGFjZTogZGVzY3JpcHRpb24KZGVzY3JpcHRpb246IHZhbDEKLQpyZXBsYWNlOiBt
 b2RpZmllcnNuYW1lCm1vZGlmaWVyc25hbWU6IGNuPWRpcmVjdG9yeSBtYW5hZ2VyCi0KcmVwbGFjZ
 TogbW9kaWZ5dGltZXN0YW1wCm1vZGlmeXRpbWVzdGFtcDogMjAxNDA1MTIwODQ5MDFaCi0KAA==

dn: changenumber=2,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 2
targetDn: cn=new_account0,cn=staged user,dc=example,dc=com
changeTime: 20140512091822Z
changeType: modify
changes:: YWRkOiBkZXNjcmlwdGlvbgpkZXNjcmlwdGlvbjogdmFsMwotCnJlcGxhY2U6IG1vZGlm
 aWVyc25hbWUKbW9kaWZpZXJzbmFtZTogY249ZGlyZWN0b3J5IG1hbmFnZXIKLQpyZXBsYWNlOiBtb
 2RpZnl0aW1lc3RhbXAKbW9kaWZ5dGltZXN0YW1wOiAyMDE0MDUxMjA5MTgyMloKLQoA


#
# this although the entry contains the 3 updates
#
ldapsearch -LLL -h localhost -p 44389 -D "cn=directory manager" -w password -b "cn=new_account0,cn=staged user,dc=example,dc=com"
dn: cn=new_account0,cn=staged user,dc=example,dc=com
description: val2
description: val3
objectClass: top
objectClass: person
sn: new_account0
cn: new_account0

[389-ds-bot]

Comment from tbordaz (@tbordaz) at 2014-05-19 22:31:07

The previous test case can be confusing as we may think some updates are skipped because some values are replaced.

Here a more direct test case:

• add val1 => changelog contains 1 entry
• add val2 (with failure trigger in retro-cl update) => changelog contains 1 entry
• add val3 => changelog contains 2 entries but the target entry contains the 3 values

# The entry contains no description attribute
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "dc=example,dc=com" cn=new_account2
dn: cn=new_account2,cn=staged user,dc=example,dc=com
objectClass: top
objectClass: person
sn: new_account2
cn: new_account2


# no entry in the changelog
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "cn=changelog"
dn: cn=changelog
objectClass: top
objectClass: nsContainer
cn: changelog





# add 'val1' without failure during addition of the update in changelog
ldapmodify -h localhost -p 45389 -D "cn=directory manager" -w password
dn: cn=new_account2,cn=staged user,dc=example,dc=com
changetype: modify
add: description
description: val1

modifying entry "cn=new_account2,cn=staged user,dc=example,dc=com"


# changelog contains 1 update
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "cn=changelog"
dn: cn=changelog
objectClass: top
objectClass: nsContainer
cn: changelog

dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account2,cn=staged user,dc=example,dc=com
changeTime: 20140519161359Z
changeType: modify
changes:: YWRkOiBkZXNjcmlwdGlvbgpkZXNjcmlwdGlvbjogdmFsMQotCnJlcGxhY2U6IG1vZGlm
 aWVyc25hbWUKbW9kaWZpZXJzbmFtZTogY249ZGlyZWN0b3J5IG1hbmFnZXIKLQpyZXBsYWNlOiBtb
 2RpZnl0aW1lc3RhbXAKbW9kaWZ5dGltZXN0YW1wOiAyMDE0MDUxOTE2MTM1OVoKLQoA


# the entry  contains val1 (normal) 
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "dc=example,dc=com" cn=new_account2
dn: cn=new_account2,cn=staged user,dc=example,dc=com
description: val1
objectClass: top
objectClass: person
sn: new_account2
cn: new_account2




# add 'val2' but trigger failure in changelog update (with debugger) 
ldapmodify -h localhost -p 45389 -D "cn=directory manager" -w passworddn: cn=new_account2,cn=staged user,dc=example,dc=com
changetype: modify
add: description
description: val2

modifying entry "cn=new_account2,cn=staged user,dc=example,dc=com"


# the entry contains the 2 values
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "dc=example,dc=com" cn=new_account2
dn: cn=new_account2,cn=staged user,dc=example,dc=com
description: val1
description: val2
objectClass: top
objectClass: person
sn: new_account2
cn: new_account2


# BUT the changelog contains only 1 update
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "cn=changelog"dn: cn=changelog
objectClass: top
objectClass: nsContainer
cn: changelog

dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account2,cn=staged user,dc=example,dc=com
changeTime: 20140519161359Z
changeType: modify
changes:: YWRkOiBkZXNjcmlwdGlvbgpkZXNjcmlwdGlvbjogdmFsMQotCnJlcGxhY2U6IG1vZGlm
 aWVyc25hbWUKbW9kaWZpZXJzbmFtZTogY249ZGlyZWN0b3J5IG1hbmFnZXIKLQpyZXBsYWNlOiBtb
 2RpZnl0aW1lc3RhbXAKbW9kaWZ5dGltZXN0YW1wOiAyMDE0MDUxOTE2MTM1OVoKLQoA






# add 'val3' without failure during update of the changelog
ldapmodify -h localhost -p 45389 -D "cn=directory manager" -w passworddn: cn=new_account2,cn=staged user,dc=example,dc=com
changetype: modify
add: description
description: val3

modifying entry "cn=new_account2,cn=staged user,dc=example,dc=com"


# the entry contains the 3 values
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "dc=example,dc=com" cn=new_account2
dn: cn=new_account2,cn=staged user,dc=example,dc=com
description: val1
description: val2
description: val3
objectClass: top
objectClass: person
sn: new_account2
cn: new_account2



# THe changelog only contains the update 'val1' and 'val2'
ldapsearch -LLL -h localhost -p 45389 -D "cn=directory manager" -w password -b "cn=changelog"dn: cn=changelog
objectClass: top
objectClass: nsContainer
cn: changelog

dn: changenumber=1,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 1
targetDn: cn=new_account2,cn=staged user,dc=example,dc=com
changeTime: 20140519161359Z
changeType: modify
changes:: YWRkOiBkZXNjcmlwdGlvbgpkZXNjcmlwdGlvbjogdmFsMQotCnJlcGxhY2U6IG1vZGlm
 aWVyc25hbWUKbW9kaWZpZXJzbmFtZTogY249ZGlyZWN0b3J5IG1hbmFnZXIKLQpyZXBsYWNlOiBtb
 2RpZnl0aW1lc3RhbXAKbW9kaWZ5dGltZXN0YW1wOiAyMDE0MDUxOTE2MTM1OVoKLQoA

dn: changenumber=2,cn=changelog
objectClass: top
objectClass: changelogentry
changeNumber: 2
targetDn: cn=new_account2,cn=staged user,dc=example,dc=com
changeTime: 20140519162113Z
changeType: modify
changes:: YWRkOiBkZXNjcmlwdGlvbgpkZXNjcmlwdGlvbjogdmFsMwotCnJlcGxhY2U6IG1vZGlm
 aWVyc25hbWUKbW9kaWZpZXJzbmFtZTogY249ZGlyZWN0b3J5IG1hbmFnZXIKLQpyZXBsYWNlOiBtb
 2RpZnl0aW1lc3RhbXAKbW9kaWZ5dGltZXN0YW1wOiAyMDE0MDUxOTE2MjExM1oKLQoA

[389-ds-bot]

Comment from mreynolds (@mreynolds389) at 2014-06-23 22:59:20

This has been addressed via ticket: https://fedorahosted.org/389/ticket/47810

Verified that if a retrocl update fails, so does the originating operation.

[389-ds-bot]

Comment from mreynolds (@mreynolds389) at 2017-02-11 23:00:10

Metadata Update from @mreynolds389:

• Issue assigned to mreynolds389
• Issue set to the milestone: 1.3.2.18