----- Mail original -----
De: "Ivanov Andrey (M.)"
<andrey.ivanov(a)polytechnique.fr>
À: "General discussion list for the 389 Directory server project."
<389-users(a)lists.fedoraproject.org>
Envoyé: Mercredi 12 Novembre 2014 18:52:44
Objet: [389-users] 389ds v.1.3.2.24 replication deadlocks/retry count
exceeded
Hi,
I've continued testing 389ds v.1.3.2.24 on CentOS 7. I really
have an
impression that everything works fine (plugins etc) but the replication
seems to be a little fragile. Both of the tickets i've already opened
concern replication partially or completely
(
https://fedorahosted.org/389/ticket/47942 and
https://fedorahosted.org/389/ticket/47950).
Here is another issue with replication :
i have two servers with multi-master agreements on each of them (the same
configuration as in ticket
https://fedorahosted.org/389/ticket/47942).
We add/delete a lot of groups (943, to be exact). Each group may
contain a
large number of referenced entries, up to ~250 (uniqueMember: dn). MemberOf
plugin is activated and works fine. Referential integrity plugin is also
activated but of course it is of any sense only when deleting groups (or
renaming them). It goes on for a long time (20-30 minutes or more). Some
time after the beginning of the operations (typically 5-8 minutes) we have
replication erros and inconsistency of the replica concerning the entries
mentioned in error log.
When adding and deleting groups the supplier is ok. Howevere the
consumer has
several (from one to four or five) groupe deletions/adds that are not
replicated. The error on the supplier:
[12/Nov/2014:16:46:42 +0100] NSMMReplicationPlugin -
agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
fa90219d-6a8211e4-a42c901a-94623bee, CSN 546380d6000000020000): Operations
error (1). Will retry later.
[12/Nov/2014:16:47:55 +0100] NSMMReplicationPlugin - agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
1e5367ae-6a8311e4-a42c901a-94623bee, CSN 54638125000000020000): Operations
error (1). Will retry later.
[12/Nov/2014:16:53:14 +0100] NSMMReplicationPlugin - agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
f4e70b85-6a8311e4-a42c901a-94623bee, CSN 54638260000000020000): Operations
error (1). Will retry later.
[12/Nov/2014:16:55:12 +0100] NSMMReplicationPlugin - agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
3c6d978a-6a8411e4-a42c901a-94623bee, CSN 546382d6000400020000): Operations
error (1). Will retry later.
[12/Nov/2014:16:56:31 +0100] NSMMReplicationPlugin - agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
6030dd93-6a8411e4-a42c901a-94623bee, CSN 54638325000000020000): Operations
error (1). Will retry later.
[12/Nov/2014:16:57:22 +0100] NSMMReplicationPlugin - agmt="cn=Replication
from ldap-edev.polytechnique.fr to ldap-model.polytechnique.fr"
(ldap-model:636): Consumer failed to replay change (uniqueid
83f42395-6a8411e4-a42c901a-94623bee, CSN 5463835d000000020000): Operations
error (1). Will retry later.
The corresponding errors on the consumer seem to hint deadlocks in
these
cases:
[12/Nov/2014:16:46:41 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=546380d6000000020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:46:41 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(546380d6000000020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:46:41 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=LAN452ESP-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: fa90219d-6a8211e4-a42c901a-94623bee, optype: 16) to changelog csn
546380d6000000020000
[12/Nov/2014:16:47:54 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=54638125000000020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:47:54 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(54638125000000020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:47:54 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=LAN472EFLE-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: 1e5367ae-6a8311e4-a42c901a-94623bee, optype: 16) to changelog csn
54638125000000020000
[12/Nov/2014:16:53:13 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=54638260000000020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:53:13 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(54638260000000020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:53:13 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=MAT471-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: f4e70b85-6a8311e4-a42c901a-94623bee, optype: 16) to changelog csn
54638260000000020000
[12/Nov/2014:16:55:11 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=546382d6000400020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:55:11 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(546382d6000400020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:55:11 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=MEC592-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: 3c6d978a-6a8411e4-a42c901a-94623bee, optype: 16) to changelog csn
546382d6000400020000
[12/Nov/2014:16:56:29 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=54638325000000020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:56:29 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(54638325000000020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:56:29 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=PHY566-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: 6030dd93-6a8411e4-a42c901a-94623bee, optype: 16) to changelog csn
54638325000000020000
[12/Nov/2014:16:57:20 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: retry (49) the transaction (csn=5463835d000000020000)
failed (rc=-30993 (BDB0068 DB_LOCK_DEADLOCK: Locker killed to resolve a
deadlock))
[12/Nov/2014:16:57:20 +0100] NSMMReplicationPlugin - changelog program -
_cl5WriteOperationTxn: failed to write entry with csn
(5463835d000000020000); db error - -30993 BDB0068 DB_LOCK_DEADLOCK: Locker
killed to resolve a deadlock
[12/Nov/2014:16:57:20 +0100] NSMMReplicationPlugin - write_changelog_and_ruv:
can't add a change for
cn=PHY651K-2014,ou=2014,ou=Cours,ou=Enseignement,ou=Groupes,dc=id,dc=polytechnique,dc=edu
(uniqid: 83f42395-6a8411e4-a42c901a-94623bee, optype: 16) to changelog csn
5463835d000000020000
Each time the failed group entries are different.
The replication agreements look liek this :
0 cn=Replication from ldap-edev.polytechnique.fr to
ldap-model.polytechnique.fr,cn=replica,cn=dc\\3Did\\2Cdc\\3Dpolytechnique\\2Cdc\\3Dedu,cn=mapping
tree,cn=config
objectClass: top
objectClass: nsDS5ReplicationAgreement
cn: Replication from ldap-edev.polytechnique.fr to
ldap-model.polytechnique.fr
description: Replication agreement from server ldap-edev.polytechnique.fr to
server ldap-model.polytechnique.fr
nsDS5ReplicaHost: ldap-model.polytechnique.fr
nsDS5ReplicaRoot: dc=id,dc=polytechnique,dc=edu
nsDS5ReplicaPort: 636
nsDS5ReplicaTransportInfo: SSL
nsDS5ReplicaBindDN: cn=RepliX,cn=config
nsDS5ReplicaBindMethod: simple
nsDS5ReplicatedAttributeList: (objectclass=*) $ EXCLUDE entryusn memberOf
nsDS5ReplicatedAttributeListTotal: (objectclass=*) $ EXCLUDE entryusn
nsds5ReplicaStripAttrs: modifiersName modifyTimestamp internalModifiersName
internalModifyTimestamp internalCreatorsname
nsds5replicaBusyWaitTime: 3
nsds5replicaTimeout: 30
nsDS5ReplicaCredentials: {DES}...
nsds5ReplicaEnabled: on
nsds50ruv: {replicageneration} 54636df3000000020000
nsds50ruv: {replica 1 ldap://ldap-model.polytechnique.fr:389}
54637b3c000000010000 54637dce000000010000
nsds50ruv: {replica 2 ldap://ldap-edev.polytechnique.fr:389}
54636ffe000000020000 54637d2d000000020000
nsruvReplicaLastModified: {replica 1 ldap://ldap-model.polytechnique.fr:389}
00000000
nsruvReplicaLastModified: {replica 2 ldap://ldap-edev.polytechnique.fr:389}
00000000
nsds5replicareapactive: 0
nsds5replicaLastUpdateStart: 20141112173922Z
nsds5replicaLastUpdateEnd: 20141112173922Z
nsds5replicaChangesSentSinceStartup: 2:1899/21484
nsds5replicaLastUpdateStatus: 0 Replica acquired successfully: Incremental
update succeeded
nsds5replicaUpdateInProgress: FALSE
nsds5replicaLastInitStart: 0
nsds5replicaLastInitEnd: 0
I've made a ticket concerning this problem
(
https://fedorahosted.org/389/ticket/47410)
The ticket for this problem is of course
https://fedorahosted.org/389/ticket/47954, not
the one i've written in the original mail.
Another problem when doing these tests, with replication agreements
suspended
is the following message in the error log:
12/Nov/2014:16:15:35 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:38 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:40 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:43 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:45 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:47 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:50 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:52 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:55 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:57 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:15:59 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:02 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:04 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:06 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:09 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:11 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:14 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:17 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:19 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:22 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:16:24 +0100] - Retry count exceeded in modify
...
(it goes on for approx 5 minutes)
[12/Nov/2014:16:20:31 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:20:33 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:20:36 +0100] - Retry count exceeded in modify
[12/Nov/2014:16:20:42 +0100] - Retry count exceeded in modify
During these error messages the server doe snot consume CPU but it is
does
not allow any changes to continue. Do i need to open another ticket for this
second problem?
Thank you!
Regards,
Andrey
--
389 users mailing list
389-users(a)lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/389-users