After an upgrade to Centos 7.3.1611 with “yum update", we started seeing the following messages in the logs:
May 30 14:26:25 inf01 ns-slapd[5518]: [30/May/2017:14:26:25.148480281 +0000] agmt="cn=masterAgreement1-inf02.prod.ecobee.com-pki-tomcat" (inf02:389) - Can't locate CSN 576b3674000704a60000 in the changelog (DB rc=-30988). If replication stops, the consumer may need to be reinitialized. May 30 14:26:25 inf01 ns-slapd[5518]: [30/May/2017:14:26:25.162720282 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=masterAgreement1-inf02.prod.ecobee.com-pki-tomcat" (inf02:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged May 30 14:26:25 inf01 ns-slapd[5518]: [30/May/2017:14:26:25.181943610 +0000] NSMMReplicationPlugin - agmt="cn=masterAgreement1-inf02.prod.ecobee.com-pki-tomcat" (inf02:389): Data required to update replica has been purged from the changelog. The replica must be reinitialized. May 30 14:26:27 inf01 ns-slapd[5518]: [30/May/2017:14:26:27.252986365 +0000] agmt="cn=cloneAgreement1-inf01.dev.ecobee.com-pki-tomcat" (inf01:389) - Can't locate CSN 576b3674000704a60000 in the changelog (DB rc=-30988). If replication stops, the consumer may need to be reinitialized.
We've tried resyncing with ipa-replica-manage re-initialize and ipa-csreplica-manage re-initialize (the commands report success, but the log errors continue), deleting dangling RUVs, cleaning up all stale RUVs, updating to the latest Centos 7, but the logs messages persist with a rate of few/s for several weeks by now.
ipa-replica-manage re-initialize
ipa-csreplica-manage re-initialize
I'm attaching the logs and the info on the config and state for further analysis.
Attaching the files:
@marikgoran I did not look into the attachment yet, but is it OK to make this bug public?
Thanks Petr. I only made it private because I wasn't sure I sanitized the logs properly and I would not want to expose too much of our internal information.
If there is a way to only make the attachment private, or if I can pass it to you out of band, by all means, I don't mind to make the ticket public as other folks may be affected by a similar issue/bug when reinitializing the replicas.
Metadata Update from @marikgoran: - Issue private status set to: False (was: True)
is the ticket still relevant. People who can help are @lkrispen or @tbordaz
We still have the problem, but if this is not assessed as bug, then I'll try to reach out to the folks mentioned on the irc channel to try to get some further assistance. Thanks
Replication was broken, At least from 30/May/2017:09:55:00
[30/May/2017:09:55:00.682825036 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=masterAgreement1-inf02.prod.<fqdn>-pki-tomcat" (inf02:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged [30/May/2017:09:55:04.912508185 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=cloneAgreement1-inf01.dev.<fqdn>-pki-tomcat" (inf01:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged up to [30/May/2017:14:28:02.187971504 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=masterAgreement1-inf02.prod.<fqdn>-pki-tomcat" (inf02:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged [30/May/2017:14:28:04.270083945 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=cloneAgreement1-inf01.dev.<fqdn>-pki-tomcat" (inf01:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged
Then the replica was reinitialized that cleared the changelog Likely to recover from the replication breakage. Unfortunately it cleared the changelog
[30/May/2017:14:28:08.954212151 +0000] import ipaca: Workers finished; cleaning up... [30/May/2017:14:28:09.168417339 +0000] import ipaca: Workers cleaned up. [30/May/2017:14:28:09.181555220 +0000] import ipaca: Indexing complete. Post-processing... [30/May/2017:14:28:09.198982674 +0000] import ipaca: Generating numsubordinates (this may take several minutes to complete)... [30/May/2017:14:28:09.233946138 +0000] import ipaca: Generating numSubordinates complete. [30/May/2017:14:28:09.290697521 +0000] import ipaca: Gathering ancestorid non-leaf IDs... [30/May/2017:14:28:09.308159355 +0000] import ipaca: Finished gathering ancestorid non-leaf IDs. [30/May/2017:14:28:09.336686080 +0000] import ipaca: Creating ancestorid index (new idl)... [30/May/2017:14:28:09.392229868 +0000] import ipaca: Created ancestorid index (new idl). [30/May/2017:14:28:09.414796651 +0000] import ipaca: Flushing caches... [30/May/2017:14:28:09.438229543 +0000] import ipaca: Closing files... [30/May/2017:14:28:09.986488728 +0000] import ipaca: Import complete. Processed 204 entries in 4 seconds. (51.00 entries/sec) [30/May/2017:14:28:10.015523216 +0000] ipa-topology-plugin - ipa_topo_be_state_change - backend ipaca is coming online; checking domain level and init shared topology [30/May/2017:14:28:10.040302146 +0000] NSMMReplicationPlugin - multimaster_be_state_change: replica o=ipaca is coming online; enabling replication [30/May/2017:14:28:10.119270558 +0000] NSMMReplicationPlugin - replica_reload_ruv: Warning: new data for replica o=ipaca does not match the data in the changelog.
Recreating the changelog file. This could affect replication with replica's consumers in which case the consumers should be reinitialized.
With an empty changelog the same error continue
[30/May/2017:14:33:10.283943413 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=masterAgreement1-inf02.prod.<fqdn>-pki-tomcat" (inf02:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged [30/May/2017:14:33:10.370855214 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=cloneAgreement1-inf01.dev.<fqdn>-pki-tomcat" (inf01:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged ... [30/May/2017:15:40:06.096661529 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=masterAgreement1-inf02.prod.<fqdn>-pki-tomcat" (inf02:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged [30/May/2017:15:40:06.144855924 +0000] NSMMReplicationPlugin - changelog program - agmt="cn=cloneAgreement1-inf01.dev.<fqdn>-pki-tomcat" (inf01:389): CSN 576b3674000704a60000 not found, we aren't as up to date, or we purged
RUV of inf01.dev. is behind inf01.prod.
RUV nsds50ruv: {replicageneration} 56460d57000000600000 nsds50ruv: {replica 1295 ldap://inf01.dev.<fqdn>:389} 576b31990002050f0000 576b34e8000a050f0000 nsds50ruv: {replica 1195 ldap://inf01.prod.<fqdn>:389} 565456df000004ab0000 57c6e66f000804ab0000 nsds50ruv: {replica 1095 ldap://inf02.prod.<fqdn>:389} 565453d4000004470000 58e53f20000004470000 nsds50ruv: {replica 1190 ldap://inf02.dev.<fqdn>:389} 576b3656000004a60000 5913735f000004a60000 dn: cn=cloneAgreement1-inf01.dev.<fqdn>-pki-tomcat,cn=replica,cn=o\3Dipaca nsds50ruv: {replicageneration} 56460d57000000600000 nsds50ruv: {replica 1190 ldap://inf02.dev.<fqdn>:389} 576b3656000004a60000 576b3674000704a60000 nsds50ruv: {replica 1295 ldap://inf01.dev.<fqdn>:389} 576b31990002050f0000 576d4c8b0002050f0000 nsds50ruv: {replica 1195 ldap://inf01.prod.<fqdn>:389} 565456df000004ab0000 57c6e66f000804ab0000 nsds50ruv: {replica 1095 ldap://inf02.prod.<fqdn>:389} 565453d4000004470000 58e53f20000004470000
That means that inf01.prod. should be able to update inf01.dev. with the updates it is missing
-In conclusion
At the end of the log (30/May/2017:15:40:06) replication was broken because of reinit done on 30/May/2017:14:28:08. That is normal behavior.
Next steps
To recover from this situation, a replica agreement should be created from inf01.prod. to inf01.dev. so that inf01.dev. will receive the missing updates and among them 576b3674000704a60000 that is the starting point of replication inf01.prod. -> inf01.dev.
Thank you, I'll close the issue now. I was expecting ipa-replica-manage re-initialize to setup the replica agreement as needed, but if this is expected then I'll try to recreate the replication with different steps.
Metadata Update from @marikgoran: - Issue status updated to: Closed (was: Open)