File can not be synced after delete the file in secondary volume when use geo-replication

[baleqin]

I use geo-replication to sync file form primary volume to secondary volume. The 1.txt file can be synced successfully, but after I delete 1.txt in secondary volume, I modified 1.txt in primary volume, the file is no longer synced, there is no 1.txt file in secondary volume.

I found out the log but can not understand why the 1.txt can not be synced.

[2022-07-01 07:25:30.989635] I [master(worker /gluster/data/v2):1525:crawl] _GMaster: slave's time [{stime=(1656660120, 0)}]
[2022-07-01 07:25:30.991064] D [master(worker /gluster/data/v2):1509:changelogs_batch_process] _GMaster: processing changes [{batch=['/var/lib/misc/gluster/gsyncd/v2_192.168.10.200_v2/gluster-data-v2/.processing/CHANGELOG.1656660327']}]
[2022-07-01 07:25:30.991204] D [master(worker /gluster/data/v2):1344:process] _GMaster: processing change [{changelog=/var/lib/misc/gluster/gsyncd/v2_192.168.10.200_v2/gluster-data-v2/.processing/CHANGELOG.1656660327}]
[2022-07-01 07:25:30.991420] D [master(worker /gluster/data/v2):1207:process_change] _GMaster: entries: []
[2022-07-01 07:25:30.992301] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/d3def21e-67fc-47e7-9c40-2e84c2eb444d'])}]
[2022-07-01 07:25:30.992419] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/d3def21e-67fc-47e7-9c40-2e84c2eb444d}]
[2022-07-01 07:25:31.234231] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/d3def21e-67fc-47e7-9c40-2e84c2eb444d
[2022-07-01 07:25:31.289985] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0557}, {num_files=1}, {job=2}, {return_code=0}]
[2022-07-01 07:25:31.290410] D [master(worker /gluster/data/v2):326:regjob] _GMaster: synced [{file=.gfid/d3def21e-67fc-47e7-9c40-2e84c2eb444d}]
[2022-07-01 07:25:31.293996] I [master(worker /gluster/data/v2):1439:process] _GMaster: Entry Time Taken [{MKD=0}, {MKN=0}, {LIN=0}, {SYM=0}, {REN=0}, {RMD=0}, {CRE=0}, {duration=0.0000}, {UNL=0}]
[2022-07-01 07:25:31.294150] I [master(worker /gluster/data/v2):1449:process] _GMaster: Data/Metadata Time Taken [{SETA=0}, {SETX=0}, {meta_duration=0.0000}, {data_duration=0.3019}, {DATA=1}, {XATT=0}]
[2022-07-01 07:25:31.294338] I [master(worker /gluster/data/v2):1459:process] _GMaster: Batch Completed [{changelog_end=1656660327}, {entry_stime=(1656657188, 0)}, {changelog_start=1656660327}, {stime=(1656660326, 0)}, {duration=0.3030}, {num_changelogs=1}, {mode=live_changelog}]

And in the case of successful normal synchronization, why is the log show changelogs could not be processed completely?

[2022-07-01 07:33:52.114356] I [master(worker /gluster/data/v2):1525:crawl] _GMaster: slave's time [{stime=(1656660326, 0)}]
[2022-07-01 07:33:52.115648] D [master(worker /gluster/data/v2):1509:changelogs_batch_process] _GMaster: processing changes [{batch=['/var/lib/misc/gluster/gsyncd/v2_192.168.10.200_v2/gluster-data-v2/.processing/CHANGELOG.1656660831']}]
[2022-07-01 07:33:52.115737] D [master(worker /gluster/data/v2):1344:process] _GMaster: processing change [{changelog=/var/lib/misc/gluster/gsyncd/v2_192.168.10.200_v2/gluster-data-v2/.processing/CHANGELOG.1656660831}]
[2022-07-01 07:33:52.115859] D [master(worker /gluster/data/v2):1207:process_change] _GMaster: entries: []
[2022-07-01 07:33:52.118195] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:52.118396] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:52.221373] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:52.302719] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0813}, {num_files=1}, {job=2}, {return_code=23}]
[2022-07-01 07:33:52.303479] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:52.806252] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:52.806478] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:52.863478] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:52.922723] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0592}, {num_files=1}, {job=3}, {return_code=23}]
[2022-07-01 07:33:52.923203] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:53.425409] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:53.425654] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:53.746274] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:53.811428] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0651}, {num_files=1}, {job=1}, {return_code=23}]
[2022-07-01 07:33:53.811961] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:54.314379] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:54.314589] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:54.426227] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:54.483727] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0575}, {num_files=1}, {job=3}, {return_code=23}]
[2022-07-01 07:33:54.484154] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:54.987428] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:54.987689] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:55.309290] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:55.373817] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0645}, {num_files=1}, {job=2}, {return_code=23}]
[2022-07-01 07:33:55.374392] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:55.878252] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:55.878489] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:55.986745] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:56.51489] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0647}, {num_files=1}, {job=3}, {return_code=23}]
[2022-07-01 07:33:56.52040] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:56.557259] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:56.557476] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:56.826297] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:56.885858] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0595}, {num_files=1}, {job=1}, {return_code=23}]
[2022-07-01 07:33:56.886395] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:57.390222] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:57.390403] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:57.555223] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:57.609081] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0537}, {num_files=1}, {job=3}, {return_code=23}]
[2022-07-01 07:33:57.609661] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:58.113343] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:58.113574] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:58.385359] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:58.443250] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0578}, {num_files=1}, {job=2}, {return_code=23}]
[2022-07-01 07:33:58.443810] W [master(worker /gluster/data/v2):1411:process] _GMaster: incomplete sync, retrying changelogs [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:58.947354] D [master(worker /gluster/data/v2):317:a_syncdata] _GMaster: files [{files=set(['.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d'])}]
[2022-07-01 07:33:58.947577] D [master(worker /gluster/data/v2):320:a_syncdata] _GMaster: candidate for syncing [{file=.gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d}]
[2022-07-01 07:33:59.115217] D [resource(worker /gluster/data/v2):1442:rsync] SSH: files: .gfid/bf0e1c57-cae9-42e8-828f-3ed8c9780f9d
[2022-07-01 07:33:59.171736] I [master(worker /gluster/data/v2):2013:syncjob] Syncer: Sync Time Taken [{duration=0.0565}, {num_files=1}, {job=3}, {return_code=23}]
[2022-07-01 07:33:59.172159] E [master(worker /gluster/data/v2):1390:process] _GMaster: changelogs could not be processed completely - moving on... [{files=['CHANGELOG.1656660831']}]
[2022-07-01 07:33:59.176740] I [master(worker /gluster/data/v2):1439:process] _GMaster: Entry Time Taken [{MKD=0}, {MKN=0}, {LIN=0}, {SYM=0}, {REN=0}, {RMD=0}, {CRE=0}, {duration=0.0000}, {UNL=0}]
[2022-07-01 07:33:59.176918] I [master(worker /gluster/data/v2):1449:process] _GMaster: Data/Metadata Time Taken [{SETA=0}, {SETX=0}, {meta_duration=0.0000}, {data_duration=1656660839.1769}, {DATA=0}, {XATT=0}]
[2022-07-01 07:33:59.177215] I [master(worker /gluster/data/v2):1459:process] _GMaster: Batch Completed [{changelog_end=1656660831}, {entry_stime=(1656657188, 0)}, {changelog_start=1656660831}, {stime=(1656660830, 0)}, {duration=7.0613}, {num_changelogs=1}, {mode=live_changelog}]

glusterfs version: glusterfs 9.5 OS: CentOS Linux release 7.9.2009 (Core)