Randomly getting an 'An error occurred at ReplicationManager.RetrieveStoreCheckpoint' error message when replicating the Garnet instance

[wessisaac]

Describe the bug

Randomly getting an 'An error occurred at ReplicationManager.RetrieveStoreCheckpoint' error message when replicating the Garnet instance.

When replicating a Garnet instance using Redis-cli or programmatically, I receive an 'OK' output, but replication does not occur. In the error log, I get the message: 'An error occurred at ReplicationManager.RetrieveStoreCheckpoint.'

Commands:
redis-cli -c -h 127.0.0.1 -p 6379 Cluster Replicate ff8f09782078336d22b570988dfaca602d097c6f
Ans: OK

redis-cli -h 127.0.0.1 -p 6380 cluster nodes
Ans: ff8f09782078336d22b570988dfaca602d097c6f 127.0.0.1:6380@16380,DUC-L155.ducontindia.local myself,master - 0 0 53 connected 0-16383
9dd6ee8dfc4817de91375c19522f682b2a77e1be 127.0.0.1:6379@16379,DUC-L155.ducontindia.local master - 638794782854197274 638794782854196345 90 connected

Error Log:

[000.2025-04-05 19:18:12.6720] (Trace) CLUSTER REPLICATE ff8f09782078336d22b570988dfaca602d097c6f
[000.2025-04-05 19:18:12.6721] (Trace) Success recover lock [ClusterReplicate]
[000.2025-04-05 19:18:12.6726] (Information) Initiating background checkpoint retrieval
[000.2025-04-05 19:18:12.6939] (Debug) [127.0.0.1:61344] [00981EB9] Disposing RespServerSession Id=20
[000.2025-04-05 19:18:12.6941] (Debug) [] [0040850F] Disposing RespServerSession Id=0
[000.2025-04-05 19:18:12.7099] (Information) <TsavoriteKV [main]> Index Checkpoint: b9b2d6f2-294c-4eff-bb9c-d00070ee2687
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> ******** Index Checkpoint Info for b9b2d6f2-294c-4eff-bb9c-d00070ee2687 ********
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Table Size: 2097152
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Main Table Size (in GB): 0.13421772799999998
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Num Buckets: 16
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> Index Checkpoint: b9b2d6f2-294c-4eff-bb9c-d00070ee2687
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> ******** Index Checkpoint Info for b9b2d6f2-294c-4eff-bb9c-d00070ee2687 ********
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> Table Size: 262144
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Main Table Size (in GB): 0.016777215999999998
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Num Buckets: 16
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Start Logical Address: 72
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Final Logical Address: 72
[000.2025-04-05 19:18:12.7752] (Information) <TsavoriteLog [aof]> ******* Recovered HybridLog Stats *******
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Head Address: 64
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Safe Head Address: 64
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> ReadOnly Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Safe ReadOnly Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Tail Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) Recovered AOF: begin address = 64, tail address = 3864
[000.2025-04-05 19:18:12.7753] (Information) InitiateReplicaSync: AOF BeginAddress:64 AOF TailAddress:3864
[000.2025-04-05 19:18:12.7771] (Debug) Accepted TCP connection from 127.0.0.1:61346
[000.2025-04-05 19:18:12.8055] (Error) An error occurred at ReplicationManager.RetrieveStoreCheckpoint
System.Exception: ReplicaSyncSession replicaAofTail 3864 < canServeFromAofAddress 10536
at Garnet.cluster.ReplicationManager.g__ReplicaSyncAttachTask|20_0() in //libs/cluster/Server/Replication/ReplicaOps/ReplicaReceiveCheckpoint.cs:line 143
[000.2025-04-05 19:18:12.8059] (Trace) EndRecovery [ClusterReplicate,NoRecovery]_

Garnet.conf

Garnet.txt

Steps to reproduce the bug

When replicating a Garnet instance using Redis-cli or programmatically, I receive an 'OK' output, but replication does not occur. In the error log, I get the message: 'An error occurred at ReplicationManager.RetrieveStoreCheckpoint.'

Commands:
redis-cli -c -h 127.0.0.1 -p 6379 Cluster Replicate ff8f09782078336d22b570988dfaca602d097c6f
Ans: OK

redis-cli -h 127.0.0.1 -p 6380 cluster nodes
Ans: ff8f09782078336d22b570988dfaca602d097c6f 127.0.0.1:6380@16380,DUC-L155.ducontindia.local myself,master - 0 0 53 connected 0-16383
9dd6ee8dfc4817de91375c19522f682b2a77e1be 127.0.0.1:6379@16379,DUC-L155.ducontindia.local master - 638794782854197274 638794782854196345 90 connected

Error Log:

[000.2025-04-05 19:18:12.6720] (Trace) CLUSTER REPLICATE ff8f09782078336d22b570988dfaca602d097c6f
[000.2025-04-05 19:18:12.6721] (Trace) Success recover lock [ClusterReplicate]
[000.2025-04-05 19:18:12.6726] (Information) Initiating background checkpoint retrieval
[000.2025-04-05 19:18:12.6939] (Debug) [127.0.0.1:61344] [00981EB9] Disposing RespServerSession Id=20
[000.2025-04-05 19:18:12.6941] (Debug) [] [0040850F] Disposing RespServerSession Id=0
[000.2025-04-05 19:18:12.7099] (Information) <TsavoriteKV [main]> Index Checkpoint: b9b2d6f2-294c-4eff-bb9c-d00070ee2687
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> ******** Index Checkpoint Info for b9b2d6f2-294c-4eff-bb9c-d00070ee2687 ********
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Table Size: 2097152
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Main Table Size (in GB): 0.13421772799999998
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Num Buckets: 16
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-05 19:18:12.7101] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> Index Checkpoint: b9b2d6f2-294c-4eff-bb9c-d00070ee2687
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> ******** Index Checkpoint Info for b9b2d6f2-294c-4eff-bb9c-d00070ee2687 ********
[000.2025-04-05 19:18:12.7215] (Information) <TsavoriteKV [obj]> Table Size: 262144
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Main Table Size (in GB): 0.016777215999999998
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Num Buckets: 16
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Start Logical Address: 72
[000.2025-04-05 19:18:12.7216] (Information) <TsavoriteKV [obj]> Final Logical Address: 72
[000.2025-04-05 19:18:12.7752] (Information) <TsavoriteLog [aof]> ******* Recovered HybridLog Stats *******
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Head Address: 64
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Safe Head Address: 64
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> ReadOnly Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Safe ReadOnly Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) <TsavoriteLog [aof]> Tail Address: 3864
[000.2025-04-05 19:18:12.7753] (Information) Recovered AOF: begin address = 64, tail address = 3864
[000.2025-04-05 19:18:12.7753] (Information) InitiateReplicaSync: AOF BeginAddress:64 AOF TailAddress:3864
[000.2025-04-05 19:18:12.7771] (Debug) Accepted TCP connection from 127.0.0.1:61346
[000.2025-04-05 19:18:12.8055] (Error) An error occurred at ReplicationManager.RetrieveStoreCheckpoint
System.Exception: ReplicaSyncSession replicaAofTail 3864 < canServeFromAofAddress 10536
at Garnet.cluster.ReplicationManager.g__ReplicaSyncAttachTask|20_0() in //libs/cluster/Server/Replication/ReplicaOps/ReplicaReceiveCheckpoint.cs:line 143
[000.2025-04-05 19:18:12.8059] (Trace) EndRecovery [ClusterReplicate,NoRecovery]_

Garnet.conf

Garnet.txt

Expected behavior

No response

Screenshots

No response

Release version

No response

IDE

No response

OS version

No response

Additional context

No response

[vazois]

Try disabling compaction and let us know if you keep experiencing the issue.

[wessisaac]

Try disabling compaction and let us know if you keep experiencing the issue.

I'm still facing the same issue randomly, even after disabling compaction.

Garnet.conf:
"CompactionType" : "None",

Error Log:
[000.2025-04-06 17:31:14.6072] (Trace) CLUSTER REPLICATE ff8f09782078336d22b570988dfaca602d097c6f
[000.2025-04-06 17:31:14.6075] (Trace) Success recover lock [ClusterReplicate]
[000.2025-04-06 17:31:14.6088] (Information) Initiating background checkpoint retrieval
[000.2025-04-06 17:31:14.6520] (Information) <TsavoriteKV [main]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.6520] (Information) <TsavoriteKV [main]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.6520] (Information) <TsavoriteKV [main]> Table Size: 2097152
[000.2025-04-06 17:31:14.6521] (Information) <TsavoriteKV [main]> Main Table Size (in GB): 0.13421772799999998
[000.2025-04-06 17:31:14.6521] (Information) <TsavoriteKV [main]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.6521] (Information) <TsavoriteKV [main]> Num Buckets: 16
[000.2025-04-06 17:31:14.6521] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-06 17:31:14.6521] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-06 17:31:14.6653] (Information) <TsavoriteKV [obj]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.6654] (Information) <TsavoriteKV [obj]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.6654] (Information) <TsavoriteKV [obj]> Table Size: 262144
[000.2025-04-06 17:31:14.6654] (Information) <TsavoriteKV [obj]> Main Table Size (in GB): 0.016777215999999998
[000.2025-04-06 17:31:14.6654] (Information) <TsavoriteKV [obj]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.6654] (Information) <TsavoriteKV [obj]> Num Buckets: 16
[000.2025-04-06 17:31:14.6655] (Information) <TsavoriteKV [obj]> Start Logical Address: 120
[000.2025-04-06 17:31:14.6655] (Information) <TsavoriteKV [obj]> Final Logical Address: 120
[000.2025-04-06 17:31:14.7249] (Information) <TsavoriteLog [aof]> ******* Recovered HybridLog Stats *******
[000.2025-04-06 17:31:14.7250] (Information) <TsavoriteLog [aof]> Head Address: 15352
[000.2025-04-06 17:31:14.7250] (Information) <TsavoriteLog [aof]> Safe Head Address: 15352
[000.2025-04-06 17:31:14.7251] (Information) <TsavoriteLog [aof]> ReadOnly Address: 22684
[000.2025-04-06 17:31:14.7251] (Information) <TsavoriteLog [aof]> Safe ReadOnly Address: 22684
[000.2025-04-06 17:31:14.7251] (Information) <TsavoriteLog [aof]> Tail Address: 22684
[000.2025-04-06 17:31:14.7259] (Information) Recovered AOF: begin address = 15352, tail address = 22684
[000.2025-04-06 17:31:14.7260] (Information) InitiateReplicaSync: AOF BeginAddress:15352 AOF TailAddress:22684
[000.2025-04-06 17:31:14.7275] (Debug) Accepted TCP connection from 127.0.0.1:54858
[000.2025-04-06 17:31:14.7282] (Debug) [127.0.0.1:54858] [0351A7BF] Starting RespServerSession Id=11
[000.2025-04-06 17:31:14.7283] (Debug) [] [02CD3EB4] Starting RespServerSession Id=0
[000.2025-04-06 17:31:14.7288] (Information) Replica Recover MainStore: 3>[0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6]
ObjectStore: 3>[0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6]
[000.2025-04-06 17:31:14.7289] (Information) <TsavoriteKV [main]> ********* Primary Recovery Information ********
[000.2025-04-06 17:31:14.7356] (Information) <TsavoriteKV [main]> ******** HybridLog Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.7357] (Information) <TsavoriteKV [main]> Version: 2
[000.2025-04-06 17:31:14.7357] (Information) <TsavoriteKV [main]> Next Version: 3
[000.2025-04-06 17:31:14.7357] (Information) <TsavoriteKV [main]> Is Snapshot?: True
[000.2025-04-06 17:31:14.7357] (Information) <TsavoriteKV [main]> Flushed LogicalAddress: 64
[000.2025-04-06 17:31:14.7357] (Information) <TsavoriteKV [main]> SnapshotStart Flushed LogicalAddress: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Snapshot Final Logical Address: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Head Address: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Begin Address: 64
[000.2025-04-06 17:31:14.7358] (Information) <TsavoriteKV [main]> Delta Tail Address: -1
[000.2025-04-06 17:31:14.7417] (Information) <TsavoriteKV [main]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.7418] (Information) <TsavoriteKV [main]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.7418] (Information) <TsavoriteKV [main]> Table Size: 2097152
[000.2025-04-06 17:31:14.7418] (Information) <TsavoriteKV [main]> Main Table Size (in GB): 0.13421772799999998
[000.2025-04-06 17:31:14.7418] (Information) <TsavoriteKV [main]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.7419] (Information) <TsavoriteKV [main]> Num Buckets: 16
[000.2025-04-06 17:31:14.7419] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-06 17:31:14.7419] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-06 17:31:14.7419] (Information) <TsavoriteKV [main]> Recovery requires disk segments in range [0--0]
[000.2025-04-06 17:31:14.7420] (Information) <TsavoriteKV [main]> Available segment range on device: [0---1]
[000.2025-04-06 17:31:14.7459] (Information) <TsavoriteKV [main]> ******* Recovered HybridLog Stats *******
[000.2025-04-06 17:31:14.7459] (Information) <TsavoriteKV [main]> Head Address: 64
[000.2025-04-06 17:31:14.7459] (Information) <TsavoriteKV [main]> Safe Head Address: 64
[000.2025-04-06 17:31:14.7460] (Information) <TsavoriteKV [main]> ReadOnly Address: 64
[000.2025-04-06 17:31:14.7460] (Information) <TsavoriteKV [main]> Safe ReadOnly Address: 64
[000.2025-04-06 17:31:14.7460] (Information) <TsavoriteKV [main]> Tail Address: 64
[000.2025-04-06 17:31:14.7462] (Information) <TsavoriteKV [obj]> ********* Primary Recovery Information ********
[000.2025-04-06 17:31:14.7553] (Information) <TsavoriteKV [obj]> ******** HybridLog Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.7554] (Information) <TsavoriteKV [obj]> Version: 2
[000.2025-04-06 17:31:14.7554] (Information) <TsavoriteKV [obj]> Next Version: 3
[000.2025-04-06 17:31:14.7554] (Information) <TsavoriteKV [obj]> Is Snapshot?: True
[000.2025-04-06 17:31:14.7554] (Information) <TsavoriteKV [obj]> Flushed LogicalAddress: 120
[000.2025-04-06 17:31:14.7554] (Information) <TsavoriteKV [obj]> SnapshotStart Flushed LogicalAddress: 120
[000.2025-04-06 17:31:14.7555] (Information) <TsavoriteKV [obj]> Start Logical Address: 120
[000.2025-04-06 17:31:14.7556] (Information) <TsavoriteKV [obj]> Final Logical Address: 120
[000.2025-04-06 17:31:14.7556] (Information) <TsavoriteKV [obj]> Snapshot Final Logical Address: 120
[000.2025-04-06 17:31:14.7557] (Information) <TsavoriteKV [obj]> Head Address: 120
[000.2025-04-06 17:31:14.7558] (Information) <TsavoriteKV [obj]> Begin Address: 120
[000.2025-04-06 17:31:14.7558] (Information) <TsavoriteKV [obj]> Delta Tail Address: -1
[000.2025-04-06 17:31:14.7631] (Information) <TsavoriteKV [obj]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.7631] (Information) <TsavoriteKV [obj]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.7631] (Information) <TsavoriteKV [obj]> Table Size: 262144
[000.2025-04-06 17:31:14.7632] (Information) <TsavoriteKV [obj]> Main Table Size (in GB): 0.016777215999999998
[000.2025-04-06 17:31:14.7632] (Information) <TsavoriteKV [obj]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.7632] (Information) <TsavoriteKV [obj]> Num Buckets: 16
[000.2025-04-06 17:31:14.7632] (Information) <TsavoriteKV [obj]> Start Logical Address: 120
[000.2025-04-06 17:31:14.7632] (Information) <TsavoriteKV [obj]> Final Logical Address: 120
[000.2025-04-06 17:31:14.7634] (Information) <TsavoriteKV [obj]> Recovery requires disk segments in range [0--0]
[000.2025-04-06 17:31:14.7634] (Information) <TsavoriteKV [obj]> Available segment range on device: [0---1]
[000.2025-04-06 17:31:14.7640] (Information) <TsavoriteKV [obj]> ******* Recovered HybridLog Stats *******
[000.2025-04-06 17:31:14.7640] (Information) <TsavoriteKV [obj]> Head Address: 120
[000.2025-04-06 17:31:14.7641] (Information) <TsavoriteKV [obj]> Safe Head Address: 120
[000.2025-04-06 17:31:14.7641] (Information) <TsavoriteKV [obj]> ReadOnly Address: 120
[000.2025-04-06 17:31:14.7641] (Information) <TsavoriteKV [obj]> Safe ReadOnly Address: 120
[000.2025-04-06 17:31:14.7641] (Information) <TsavoriteKV [obj]> Tail Address: 120
[000.2025-04-06 17:31:14.7643] (Information) ReplicaRecover: replay local AOF from 15352 until 19128
[000.2025-04-06 17:31:14.7644] (Debug) [] [03AA1014] Starting RespServerSession Id=0
[000.2025-04-06 17:31:14.7645] (Information) Begin AOF recovery
[000.2025-04-06 17:31:14.7646] (Information) Begin AOF replay
[000.2025-04-06 17:31:14.7651] (Error) An error occurred AofProcessor.RecoverReplay
Tsavorite.core.TsavoriteException: Invalid length of record found: 4194304 at address 18968
at Tsavorite.core.TsavoriteLogScanIterator.GetNextInternal(Int64& physicalAddress, Int32& entryLength, Int64& currentAddress, Int64& outNextAddress, Boolean& commitRecord, Boolean& onFrame) in //libs/storage/Tsavorite/cs/src/core/TsavoriteLog/TsavoriteLogIterator.cs:line 829
at Tsavorite.core.TsavoriteLogScanIterator.GetNext(MemoryPool1 pool, IMemoryOwner1& entry, Int32& entryLength, Int64& currentAddress, Int64& nextAddress) in //libs/storage/Tsavorite/cs/src/core/TsavoriteLog/TsavoriteLogIterator.cs:line 348
at Garnet.server.AofProcessor.RecoverReplay(Int64 untilAddress) in //libs/server/AOF/AofProcessor.cs:line 135
[000.2025-04-06 17:31:14.7652] (Debug) [] [03AA1014] Disposing RespServerSession Id=0
[000.2025-04-06 17:31:14.7652] (Information) Initializing AOF
[000.2025-04-06 17:31:14.7671] (Information) <TsavoriteLog [aof]> ******* Recovered HybridLog Stats *******
[000.2025-04-06 17:31:14.7672] (Information) <TsavoriteLog [aof]> Head Address: 15352
[000.2025-04-06 17:31:14.7672] (Information) <TsavoriteLog [aof]> Safe Head Address: 15352
[000.2025-04-06 17:31:14.7672] (Information) <TsavoriteLog [aof]> ReadOnly Address: 15352
[000.2025-04-06 17:31:14.7672] (Information) <TsavoriteLog [aof]> Safe ReadOnly Address: 15352
[000.2025-04-06 17:31:14.7673] (Information) <TsavoriteLog [aof]> Tail Address: 15352
[000.2025-04-06 17:31:14.7673] (Information) ReplicaRecover: ReplicaReplicationOffset = 0
[000.2025-04-06 17:31:14.7674] (Trace) Purge all except 3 0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6 3 0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.7699] (Information) Initializing CheckpointStore
[000.2025-04-06 17:31:14.7917] (Information) <TsavoriteKV [main]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> Table Size: 2097152
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> Main Table Size (in GB): 0.13421772799999998
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> Num Buckets: 16
[000.2025-04-06 17:31:14.7918] (Information) <TsavoriteKV [main]> Start Logical Address: 64
[000.2025-04-06 17:31:14.7919] (Information) <TsavoriteKV [main]> Final Logical Address: 64
[000.2025-04-06 17:31:14.8038] (Information) <TsavoriteKV [obj]> Index Checkpoint: 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.8038] (Information) <TsavoriteKV [obj]> ******** Index Checkpoint Info for 0766aa6d-c353-423c-8a58-6a3d395917f6 ********
[000.2025-04-06 17:31:14.8038] (Information) <TsavoriteKV [obj]> Table Size: 262144
[000.2025-04-06 17:31:14.8039] (Information) <TsavoriteKV [obj]> Main Table Size (in GB): 0.016777215999999998
[000.2025-04-06 17:31:14.8039] (Information) <TsavoriteKV [obj]> Overflow Table Size (in GB): 1.0239999999999999E-06
[000.2025-04-06 17:31:14.8039] (Information) <TsavoriteKV [obj]> Num Buckets: 16
[000.2025-04-06 17:31:14.8039] (Information) <TsavoriteKV [obj]> Start Logical Address: 120
[000.2025-04-06 17:31:14.8039] (Information) <TsavoriteKV [obj]> Final Logical Address: 120
[000.2025-04-06 17:31:14.8464] (Trace) Purge all except 3 0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6 3 0766aa6d-c353-423c-8a58-6a3d395917f6 0766aa6d-c353-423c-8a58-6a3d395917f6
[000.2025-04-06 17:31:14.8488] (Information) Updating ReplicationId
[000.2025-04-06 17:31:14.8489] (Trace) Flushing replication history C:\Program Files\Garnet\Data/cluster\replication.conf
[000.2025-04-06 17:31:14.8496] (Trace) Replication history flush completed C:\Program Files\Garnet\Data/cluster\replication.conf
[000.2025-04-06 17:31:14.8497] (Trace) EndRecovery [ClusterReplicate,CheckpointRecoveredAtReplica]
[000.2025-04-06 17:31:14.8975] (Error) An error occurred at ReplicationManager.RetrieveStoreCheckpoint
System.Exception: Failed syncing because replica requested truncated AOF address
at Garnet.cluster.ReplicationManager.g__ReplicaSyncAttachTask|20_0() in //libs/cluster/Server/Replication/ReplicaOps/ReplicaReceiveCheckpoint.cs:line 143
[000.2025-04-06 17:31:14.8979] (Trace) EndRecovery [CheckpointRecoveredAtReplica,NoRecovery]
[000.2025-04-06 17:31:14.9062] (Debug) [127.0.0.1:54858] [0351A7BF] Disposing RespServerSession Id=11
[000.2025-04-06 17:31:14.9063] (Debug) [] [02CD3EB4] Disposing RespServerSession Id=0

[vazois]

Unfortunately, the provided information is not enough to repro this issue. We have been running replication in prod and no such error has been reported yet. I would suggest trying the defaults.conf and enable the bare minimum for your repro to run (i.e. EnableCluster, EnableAof) with everything left in default and see if you are still experiencing it. Keep adding options until you hit the issue.

[wessisaac]

Unfortunately, the provided information is not enough to repro this issue. We have been running replication in prod and no such error has been reported yet. I would suggest trying the defaults.conf and enable the bare minimum for your repro to run (i.e. EnableCluster, EnableAof) with everything left in default and see if you are still experiencing it. Keep adding options until you hit the issue.

Hi Vazois, everything works properly in standalone mode with AOF, but in cluster mode, we encounter an AOF truncation error during failover when the master instance goes down. We are getting the exception, ' (Error) An error occurred AofProcessor.RecoverReplay Tsavorite.core.TsavoriteException: Invalid length of record found: 4194304 at address 18968 at Tsavorite.core.TsavoriteLogScanIterator.GetNextInternal(Int64& physicalAddress, Int32& entryLength, Int64& currentAddress, Int64& outNextAddress, Boolean& commitRecord, Boolean& onFrame) in //libs/storage/Tsavorite/cs/src/core/TsavoriteLog/TsavoriteLogIterator.cs:line 829 at Tsavorite.core.TsavoriteLogScanIterator.GetNext(MemoryPool1 pool, IMemoryOwner1& entry, Int32& entryLength, Int64& currentAddress, Int64& nextAddress) in //libs/storage/Tsavorite/cs/src/core/TsavoriteLog/TsavoriteLogIterator.cs:line 348' what is the solution for this kind of issue?

[badrishc]

You may be replicating operations that add fields that are larger than the AOF page size. Can you try increasing AofPageSize to say 32m and the AofMemorySize to 128m. Also make sure that primary and secondary have the same configuration parameters. Generally, you need to make sure the operations add fields that will fit in the configured page size of the AOF.

[badrishc]

Any update on this @wessisaac ?

[wessisaac]

Any update on this @wessisaac ?

It seems replication is now working without any issues after increasing the AOF page and memory sizes. However, after a cluster failover, duplicate values are still being inserted into the List key type.

[badrishc]

Closing until we can get a proper repro for this duplicate value claim. We've not seen anything like it. Feel free to reopen when you can show a sequence of commands that results in duplicates at secondary.