Checkpoint fails with `InvalidOperationException` in `ListObject.DoSerialize` under concurrent LIST mutation, then never completes ("checkpoint already in progress")
Open
@TedHartMS is already working on this.
Since Sep 15, 2026.
- Dominant language
- C#
- Stars
- 12k
- Forks
- 703
- Avg merge
- 2d 19h
- Merged PRs (30d)
- 36
Description
Describe the bug
Summary
When LIST values are being mutated while a snapshot checkpoint is flushing, the checkpoint fails with InvalidOperationException: Collection was modified after the enumerator was instantiated. After one or two such failures, the checkpoint pipeline stops entirely. The next Initiating checkpoint never completes and never logs an error, every subsequent BGSAVE returns ERR checkpoint already in progress, and the process stays in that state until restarted.
Because checkpoints are what truncate the AOF, the AOF then grows without bound. Nothing signals to the application that persistence has stopped working.
After observing this in normal operation, we created a small console program to see whether it could be reproduced in isolation. It reproduces on a clean, stock instance in about 12 seconds. That program is attached, but the original observations below came from the ordinary running of our application, not from the test harness.
Observed Issue
Environment
- Garnet 2.1.5, 64-bit
- .NET 10.0.10, Win32NT, X64
- Windows on VMware ESXi 8.0 U2, 4 vCPU, 8 GB RAM
- Running as a Windows service via
Garnet.Worker.exe
Configuration (non-default options)
"LogMemorySize": "512m", // PageSize left at default 16m
"IndexMemorySize": "1m",
"SegmentSize": "64m",
"EnableStorageTier": true,
"LogDir": "C:/Program Files/Garnet/data",
"CheckpointDir": "C:/Program Files/Garnet/checkpoints",
"CompactionType": "Lookup",
"CompactionMaxSegments": 4,
"EnableAOF": true,
"AofMemorySize": "64m",
"AofSegmentSize": "64m",
"AofSizeLimit": "256m",
"AofSizeLimitEnforceFrequencySecs": 15,
"EnableRevivification": true,
"Recover": true,
"MaxDatabases": 1
Workload
Client continuously mutating Redis LIST values. Lists hold on the order of 5,000 entries each and are updated entry by entry, and lists are periodically deleted and recreated, so list mutation is close to constant. No BGSAVE or SAVE is issued by the application. Checkpoints are triggered entirely by AofSizeLimit, which the write volume reaches about every 7 minutes.
Bug
Most checkpoints complete normally, roughly every 7 minutes:
09::31::57 info: StoreWrapper[0] Enforcing AOF size limit currentAofSize: 271122428 > AofSizeLimit: 268435456
09::31::57 info: StoreWrapper[0] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
09::31::57 info: StoreWrapper[0] Completed checkpoint for DB ID: 0
09::38::57 info: StoreWrapper[0] Enforcing AOF size limit currentAofSize: 270419944 > AofSizeLimit: 268435456
09::38::57 info: StoreWrapper[0] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
09::38::57 info: StoreWrapper[0] Completed checkpoint for DB ID: 0
09::45::57 info: StoreWrapper[0] Enforcing AOF size limit currentAofSize: 270976216 > AofSizeLimit: 268435456
09::45::57 info: StoreWrapper[0] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
09::45::57 info: StoreWrapper[0] Completed checkpoint for DB ID: 0
Then one fails:
09::52::58 info: StoreWrapper[0] Enforcing AOF size limit currentAofSize: 270529228 > AofSizeLimit: 268435456
09::52::58 info: StoreWrapper[0] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
09::52::58 fail: TsavoriteKV [main][0] AsyncFlushPagesForSnapshot failed while flushing snapshot pages from 0 to 1
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
09::52::58 fail: StateMachineDriver[0] State machine task 'SnapshotCheckpointSMTaskHybridLogFlushed' faulted
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
09::52::58 fail: StateMachineDriver[0] Exception in state machine
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
09::52::58 fail: StoreWrapper[0] Checkpointing threw exception, DB ID: 0
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
at Tsavorite.core.StateMachineDriver.RunAsync(...)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 194
at Garnet.server.DatabaseManagerBase.InitiateCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 530
at Garnet.server.DatabaseManagerBase.TakeCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 196
09::53::13 info: StoreWrapper[0] Enforcing AOF size limit currentAofSize: 279961864 > AofSizeLimit: 268435456
09::53::13 info: StoreWrapper[0] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
info: Microsoft.Hosting.Lifetime[0]
Application is shutting down...
09::57::47 dbug: Session[0] [127.0.0.1:58276] [031A06BC] Disposing RespServerSession Id=18
09::57::47 dbug: Session[0] [127.0.0.1:61349] [02CE8245] Disposing RespServerSession Id=13
09::57::47 dbug: Session[0] [127.0.0.1:58204] [0045A1A5] Disposing RespServerSession Id=15
09::57::47 dbug: Session[0] [127.0.0.1:58275] [0220A7A8] Disposing RespServerSession Id=17
09::57::47 dbug: Session[0] [127.0.0.1:58205] [03FDBC62] Disposing RespServerSession Id=16
09::57::47 dbug: Session[0] [127.0.0.1:60504] [00BB9C73] Disposing RespServerSession Id=9
09::57::47 dbug: Session[0] [127.0.0.1:60027] [0353662B] Disposing RespServerSession Id=10
09::57::47 dbug: Session[0] [127.0.0.1:58303] [01BF9EA4] Disposing RespServerSession Id=19
09::57::47 dbug: Session[0] [127.0.0.1:61348] [03AD1FE9] Disposing RespServerSession Id=12
09::57::47 dbug: Session[0] [127.0.0.1:58304] [006AACF1] Disposing RespServerSession Id=20
09::57::47 dbug: Session[0] [127.0.0.1:60560] [03C09FDF] Disposing RespServerSession Id=14
After the failure, no checkpoint ever completes again. The size-limit task retries 15 seconds later, logs Initiating checkpoint, and nothing follows. We left it running and eventually stopped the service about four and a half minutes later, still with no completion:
AOF stops being truncated.
On another occasion we let it keep running after the failure. The AOF directory grew to 33 files totaling roughly 1.5 GB against a 256 MB AofSizeLimit. Segment numbering starts in the high 80s, so truncation had been working normally until this point. (Screenshot attached.)
CPU rises and stays elevated.
After the failure, Garnet settles at a sustained ~25% on this 4-vCPU machine and stays there indefinitely. Restarting the process is the only remedy we have found. (Screenshot attached.)
Possible data inconsistencies.
We are separately investigating what looks like corrupted or missing data after restarting and recovering following these events. That is unconfirmed and we are not claiming a connection, but we mention it because recovery depends on these checkpoints.
Full Log: GarnetCheckpointFailLog.txt
Steps to reproduce the bug
To check whether this was specific to our deployment, we created a small StackExchange.Redis console program (attached).
The program: ListMutator.zip
- Creates 10 LIST keys of 5,000 entries each, roughly 1.2 KB per entry (~57 MB total).
- Mutates them continuously from 32 concurrent tasks using
LSETwith slightly jittered value sizes, plus occasionalRPUSH. - Deletes and refills one list every 10 seconds.
- Issues
BGSAVEevery 2 seconds, standing in for theAofSizeLimittrigger so checkpoints happen every few seconds instead of every few minutes. - Polls
LASTSAVEandINFO STOREto detect when checkpoints stop completing.
Run against Garnet 2.1.5 on 6379 using the same configuration as the deployment above, with TLS and ACL disabled, MaxDatabases: 2, and LogLevel: Debug. All store, checkpoint, AOF, and revivification settings are identical. The instance started completely clean (No Hybrid Log found for recovery, 0 records replayed), so no prior state carried over.
It got stuck soon after:
02::21::26 info: Session[0] [127.0.0.1:65391] [039103E1] Initiating checkpoint; full = True, type = Snapshot, dbId = 0
02::21::26 dbug: Session[0] [] [03352504] Starting RespServerSession Id=3
02::21::26 dbug: Session[0] [] [03352504] Disposing RespServerSession Id=3
02::21::26 info: Session[0] [127.0.0.1:65391] [039103E1] Completed checkpoint for DB ID: 0
02::21::28 info: Session[0] [127.0.0.1:65391] [039103E1] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
02::21::28 dbug: Session[0] [] [03CBA339] Starting RespServerSession Id=4
02::21::28 dbug: Session[0] [] [03CBA339] Disposing RespServerSession Id=4
02::21::28 info: Session[0] [127.0.0.1:65391] [039103E1] Completed checkpoint for DB ID: 0
02::21::30 info: Session[0] [127.0.0.1:65391] [039103E1] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
02::21::30 fail: TsavoriteKV [main][0] AsyncFlushPagesForSnapshot failed while flushing snapshot pages from 0 to 1
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
02::21::30 fail: StateMachineDriver[0] State machine task 'SnapshotCheckpointSMTaskHybridLogFlushed' faulted
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
02::21::30 fail: StateMachineDriver[0] Exception in state machine
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
02::21::30 fail: Session[0] [127.0.0.1:65391] [039103E1] Checkpointing threw exception, DB ID: 0
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
at Tsavorite.core.StateMachineDriver.RunAsync(...)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 194
at Garnet.server.DatabaseManagerBase.InitiateCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 530
at Garnet.server.DatabaseManagerBase.TakeCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 196
02::21::32 info: Session[0] [127.0.0.1:65391] [039103E1] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
02::21::32 fail: TsavoriteKV [main][0] AsyncFlushPagesForSnapshot failed while flushing snapshot pages from 0 to 1
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
02::21::32 fail: StateMachineDriver[0] State machine task 'SnapshotCheckpointSMTaskHybridLogFlushed' faulted
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
02::21::32 fail: StateMachineDriver[0] Exception in state machine
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
02::21::32 fail: Session[0] [127.0.0.1:65391] [039103E1] Checkpointing threw exception, DB ID: 0
System.InvalidOperationException: Collection was modified after the enumerator was instantiated.
at Garnet.server.ListObject.DoSerialize(BinaryWriter writer)
in /_/libs/server/Objects/List/ListObject.cs:line 116
at Tsavorite.core.HeapObjectBase.Serialize(BinaryWriter writer)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/HeapObjectBase.cs:line 67
at Garnet.server.GarnetObjectSerializer.SerializeInternal(BinaryWriter binaryWriter, IGarnetObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 127
at Garnet.server.GarnetObjectSerializer.Serialize(IHeapObject obj)
in /_/libs/server/Objects/Types/GarnetObjectSerializer.cs:line 120
at Tsavorite.core.ObjectLogWriter`1.DoSerialize(IHeapObject valueObject)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 323
at Tsavorite.core.ObjectLogWriter`1.WriteRecordObjects(...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectSerialization/ObjectLogWriter.cs:line 118
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsync[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 968
at Tsavorite.core.ObjectAllocatorImpl`1.WriteAsyncToDeviceForSnapshot[TContext](...)
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/ObjectAllocatorImpl.cs:line 707
at Tsavorite.core.AllocatorBase`2.<>c__DisplayClass146_0.<AsyncFlushPagesForSnapshot>g__FlushRunner|0()
in /_/libs/storage/Tsavorite/cs/src/core/Allocator/AllocatorBase.cs:line 2369
--- End of stack trace from previous location ---
at Tsavorite.core.StateMachineDriver.ProcessWaitingListAsync(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 316
at Tsavorite.core.StateMachineDriver.RunStateMachine(CancellationToken token)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 335
at Tsavorite.core.StateMachineDriver.RunAsync(...)
in /_/libs/storage/Tsavorite/cs/src/core/Index/Checkpointing/StateMachineDriver.cs:line 194
at Garnet.server.DatabaseManagerBase.InitiateCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 530
at Garnet.server.DatabaseManagerBase.TakeCheckpointAsync(...)
in /_/libs/server/Databases/DatabaseManagerBase.cs:line 196
02::21::34 info: Session[0] [127.0.0.1:65391] [039103E1] Initiating checkpoint; full = False, type = Snapshot, dbId = 0
02::24::50 dbug: Session[0] [127.0.0.1:65391] [039103E1] Disposing RespServerSession Id=1
02::24::50 dbug: Session[0] [127.0.0.1:65392] [026AC6F7] Disposing RespServerSession Id=2
Two checkpoints complete normally, two fail with the exception, and the fifth at 02:21:34 produces no completion and no error at all. The log stays silent for the remaining 3m16s until the client disconnects.
Client-side over the same period:
[00:00:05] mutations=75,161 (15,032/s) bgsave=2 lastSave=0s ago version=3/2 tail=1224
[00:00:10] mutations=163,640 (17,696/s) bgsave=4 lastSave=0s ago version=5/2 tail=1864
[bgsave] RedisServerException: ERR checkpoint already in progress
[00:00:15] mutations=235,957 (14,463/s) bgsave=5 lastSave=5s ago version=6/2 tail=2264
[bgsave] RedisServerException: ERR checkpoint already in progress
[00:00:20] mutations=326,906 (18,190/s) bgsave=5 lastSave=10s ago version=6/2 tail=2264
...
[00:03:02] mutations=1,998,188 (8,531/s) bgsave=5 lastSave=173s ago version=6/2 tail=2304
'version' is (CurrentVersion/LastCheckpointedVersion) from INFO STORE. LastCheckpointedVersion stops at 2, the second and final checkpoint to complete. CurrentVersion advances once per attempt to 6 and then stops, since no further attempt is accepted.
Expected behavior
Checkpoints continue to complete while LIST values are being mutated concurrently, and the AOF continues to be truncated at the configured limit.
Screenshots
No response
Release version
v2.1.5
IDE
No response
OS version
Windows Server 2025
Additional context
We observed this after the issue had naturally occurred during our testing. When using the repro program, CPU usage after the issue was much higher.
This shows the broken AOF file truncation:
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Assessment
This issue has not been assessed yet.