Replication broken after backup restore with freeipa configuration

[progier389]

Issue Description
Replication never synchronize after DS restore from a previous backup

Package Version and Platform:

• Platform: Fedora
• Package and version: 3.0.0

Steps to Reproduce
Steps to reproduce the behavior:

1. setup a freeipa server and a freeipa replica
2. (on server) dsconf IPA-TEST backup create
3. (on server) kinit admin
4. (on server) ipa user-add test1_supplier --first test --last user
5. (on replica) kinit admin
6. (on replica) ipa user-add test1_replica --first test --last user
7. Wait until replication is in sync
8. dsconf IPA-TEST backup restore /var/lib/dirsrv/slapd-IPA-TEST/bak/IPA-TEST-*
9. Wait a few minutes to let the time for the replica to replay its changes toward the server
10. dsctl IPA-TEST healthcheck
11. See Error: The replication agreement (metoipareplica.ipa.test) under "dc=ipa,dc=test" is not in synchronization.

Expected results
Replication should be able to synchronize

Additional context
dsconf IPA-TEST repl get-ruv --suffix dc=ipa,dc=test
Show that the server maxcsn is higher than the replica one.

[progier389]

After dumping both changelog, I think that the csn that blocked the replication is:
dbid: 65a51d7f000000040000
encrypted: no
replgen: 1705319604 Mon Jan 15 12:53:24 2024
csn: 65a51d7f000000040000
uniqueid: 00000000-00000000-00000000-00000000
dn: cn=start iteration
operation: delete

Which looks like a dummy operation. Why are we creating operation entries when the changelog is not empty ?

[tbordaz]

I wonder if it is not just to log the oldest change in the CL for a given replica. Dummy entry to be the first one(s) per replicaID (replica_log_ruv_elements_nolock).

[progier389]

I was also thinking that theses entries are used to created to have a starting point for the changelog iterator when (re)initializing a changelog or joining a new replica, but as you said, in this case should be the first CSN in the changelog for a given replica id.
That is not the case here: there a lot of csn with same RID that precede this one. For example:

There is for example
dbid: 65a51d69000000040000
encrypted: no
replgen: 1705319489 Mon Jan 15 12:51:29 2024
csn: 65a51d69000000040000
uniqueid: 5ce75a81-b39c11ee-91abeac6-9ecf5fb1
dn: uid=test3_master,cn=users,cn=accounts,dc=ipa,dc=test
operation: modify
memberOf: cn=ipausers,cn=groups,cn=accounts,dc=ipa,dc=test
modifiersname: cn=MemberOf Plugin,cn=plugins,cn=config
modifytimestamp: 20240115115129Z
entryusn: 10296

BTW: dummy entry getting created why they should not could be the root cause of the bug because they will prevent the other server to replay the missing changes (Guess I will have to dig the code. )
But I have a second concern, since memberof plugin generates internal modify operation (as seen above)
it could also prevent the other replica to resync the server
I wonder if the problem is not a backend state one. restored server should stay in referral on update mode until an admin explicitly switch it back to normal mode once replication is in sync, and I have the feeling that it is not the case ...

[progier389]

Apparently referral on update is only be set while a total update is in progress (Otherwise consumer5_set_mapping_tree_state_for_replica reset it when a replication session occurs)
So it is not changed after a restore (neither in bdb nor mdb mode)

[tbordaz]

IIRC we were discussing (and possibly implemented) a mechanism to switch a replica referral_on_update after a restore. This was to prevent the replica to generate a CSN before being in sync with updates that it generated itself after the backup.
Could such mechanism contribute to this ticket ?

[progier389]

I do not know, as I am not yet sure of the root cause of the problem. Something that puzzle me is why the freeipa test pass with bdb. Apparently Referral on update behavior is the same in both cases.

BTW: I found when the dummy operation get created:
#0 0x00007f32f6f4ae88 in replica_log_start_iteration () from target:/usr/lib64/dirsrv/plugins/libreplication-plugin.so
#1 0x00007f32f6f4dafd in ruv_enumerate_elements () from target:/usr/lib64/dirsrv/plugins/libreplication-plugin.so
#2 0x00007f32f6f48c27 in replica_reload_ruv () from target:/usr/lib64/dirsrv/plugins/libreplication-plugin.so
#3 0x00007f32f6f48c7c in replica_enable_replication () from target:/usr/lib64/dirsrv/plugins/libreplication-plugin.so
#4 0x00007f32fb9046b7 in mtn_be_state_change () from target:/usr/lib64/dirsrv/libslapd.so.0
#5 0x00007f32fb914079 in mtn_internal_be_set_state () from target:/usr/lib64/dirsrv/libslapd.so.0
#6 0x00007f32f71f9e9c in ldbm_back_archive2ldbm () from target:/usr/lib64/dirsrv/plugins/libback-ldbm.so
#7 0x00007f32fb961b4d in task_restore_thread () from target:/usr/lib64/dirsrv/libslapd.so.0
#8 0x00007f32fbb82739 in _pt_root (arg=0x7f2de2e94c80) at ../../../../nspr/pr/src/pthreads/ptthread.c:201
#9 0x00007f32fb6ae947 in start_thread (arg=) at pthread_create.c:444
#10 0x00007f32fb734860 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
But once again I do not understand why mdb would have an impact ...

[progier389]

So far I found several problems:

1. A bug in _cl5CICbInit so the cl RUV was badly build (impact both bdb and lmdb ) and leads to recreate the changelog
2. A bug dbmdb_back_ctrl so in case [1] the changelog was not cleared (but starting iteration dummy csn was still created) This one impacts only lmdb.
3. Replication keep alive get created before the replica get back in sync (creating missing csn)
4. memberof plugin creates csn before the replica get back in sync (creating missing csn)

I intend to fix [1] and [2] in a PR (as they are fast fix)
For [3] and [4] we will have to think how we handle the "replica is re-syncing" state (by re-sync I mean waiting until the other suppliers replays changes originally done on that replica after a restore or an import)

[progier389]

While creating the CI testcase I also found another reason to get in trouble when the backup is done on line the changelog RUVs are not updated (because the db is copied on fly without stopping the backends) so at restore time the changelog get a new generation and is recreated). I will do an offline backup to avoid this problem. I wonder if we should not stop the backend cleanly for the backup (or at least have the option to do it ...)

[droideck]

I intend to fix [1] and [2] in a PR (as they are fast fix) For [3] and [4] we will have to think how we handle the "replica is re-syncing" state (by re-sync I mean waiting until the other suppliers replays changes originally done on that replica after a restore or an import)

I don't have much experience with our replication code, but out of curiosity, as for the solution... Is it possible to have some kind of flag that will indicate "replica is re-syncing"? And, of course, the flag should be accessible to others to whom it's important not to start their work "too soon".

[progier389]

@droideck, that is one of the ideas, the hard thing is to determine that the server has to resync, (ideally we have to wait that all suppliers that target the replica have attempted to open a replication session and check if their maxcsn for this replica is not greater than the local one (which means that we have to left the server in Referral on update mode at startup until a bit more longer than the maximum backoff timer (i.e 5 Minutes)
Anyway I plan to open another issue for that part of the job as it will likely generates discussion ...