kvcache-ai / kvcache-ai/Mooncake
[Bug] Snapshot restore reports success but drops every object: ApplySnapshotState evicts on restored (already-expired) leases, and every test skips that path (v0.3.13)
- Dominant language
- C++
- Stars
- 6.6k
- Forks
- 1.2k
- Avg merge
- 3d 5h
- Merged PRs (30d)
- 312
Description
### Bug Report
On v0.3.13, a non-HA master with `enable_snapshot` + `enable_snapshot_restore` writes correct snapshots, reads one back after a restart, logs **`Successfully restored state from snapshot`** — and comes up with **zero objects**. No error, no warning.
The snapshot is not at fault. The objects are decoded and then erased by the post-restore cleanup pass in `ApplySnapshotState`, because restored read leases are wall-clock deadlines that are always expired by the time a master finishes restarting. The only way to skip that pass is an env var that exists **only in the snapshot unit tests**, which is why CI does not catch it.
### Environment
- `docker.io/kvcacheai/mooncake:0.3.13`
- Single master, `-enable_ha=false`, `enable_oplog` off
- `-enable_snapshot=true -enable_snapshot_restore=true -snapshot_interval_seconds=60 -snapshot_object_store_type=local -snapshot_catalog_store_type=embedded`, `MOONCAKE_SNAPSHOT_LOCAL_PATH=/snapshots` on a node-local persistent path
- 3 store clients, 3 x 200 GiB memory segments, `replica_num=1`
- `default_kv_lease_ttl` at its default (10000 ms)
### Repro
1. Start the master with the flags above.
2. Write 300 x 4 MiB objects. `master_key_count` = 300.
3. Wait for at least one snapshot interval. Snapshots are written correctly — `Snapshots: Success=6, Fail=0`, retention honoured, a forked child per snapshot:
```
I local_file_snapshot_object_store.cpp:47] LocalFileSnapshotObjectStore initialized with path: "/snapshots"
I master_snapshot_manager.cpp:65] [MasterSnapshotManager] Started
I master_snapshot_manager.cpp:97] [Snapshot] snapshot_thread started
```
```
/snapshots/mooncake_master_snapshot//20260828_074040_060/
metadata segments task_manager manifest.txt descriptor.txt
/snapshots/mooncake_master_snapshot//latest.txt
```
4. Restart the master and let the store clients reattach.
### What happens
```
I [Restore] Backend info: LocalFileSnapshotObjectStore: base_path=/snapshots
I master_service.cpp:11594] Restored Replica::next_id_ to 301
I [Restore] Total allocated size after restore: 0
I [Restore] Total capacity size after restore: 644245094400
I [Restore] Successfully restored state from snapshot: 20260828_074040_060
```
`master_key_count` goes **300 -> 0** and stays 0 for the 160 s we watched, with all three clients reattached and full capacity back. Segments restore fine. Only the objects are gone, and the master reports success.
### The objects were in the snapshot and were decoded
`MasterSnapshotCodec` documents its `metadata` payload as "Metadata shards (objects, replicas, tenant state)". Payload sizes make the before/after unambiguous:
```
20260828_074040_060 metadata = 48,462 B segments = 151,413 B <- taken at keys=300
20260828_074147_596 metadata = 48 B segments = 151,503 B <- taken after, at keys=0
```
The restore read **exactly** `074040_060`, the 48 KB one. `Restored Replica::next_id_ to 301` proves the metadata deserializer ran and saw all 300 replicas. So encode is fine and decode is fine.
### Root cause: the post-restore cleanup evicts everything on expired leases
`MasterService::ApplySnapshotState` (`master_service.cpp:9583`) runs a cleanup pass immediately after decode:
```cpp
const bool skip_cleanup =
std::getenv("MOONCAKE_MASTER_SERVICE_SNAPSHOT_TEST_SKIP_CLEANUP");
if (!skip_cleanup) {
auto cleanup_now = now;
...
if (it->second.HasDiffRepStatus(ReplicaStatus::COMPLETE) ||
it->second.IsLeaseExpired(cleanup_now)) {
it = EraseMetadata(tenant_state, it, tenant_it->first);
}
...
}
```
`now` is `std::chrono::system_clock::now()`, taken in `RestoreState` at restart time. And `lease_timeout` is persisted as an **absolute epoch timestamp** and restored verbatim — `MetadataSerializer::SerializeMetadata` packs `metadata.lease_timeout.time_since_epoch()` (`master_service.cpp:11763`) and `DeserializeMetadata` reads it straight back (`master_service.cpp:11830`). It is never re-based on restore. The deadline therefore comes from before the snapshot was taken, and `default_kv_lease_ttl` defaults to **10000 ms** (`types.h:84`). A master restart — pod termination, scheduling, bind, snapshot download, decode — takes far longer than 10 seconds in any real deployment, and the snapshot itself is up to `snapshot_interval_seconds` old before that. So **every restored object is lease-expired at `cleanup_now` and every one of them is erased.**
The `Rebuild allocated memory metrics` loop then runs over what survived, which is nothing, hence `Total allocated size after restore: 0`. `RestoreState` sees `ApplySnapshotState` return success and logs `Successfully restored state from snapshot`.
**Why CI does not catch it:** `MOONCAKE_MASTER_SERVICE_SNAPSHOT_TEST_SKIP_CLEANUP` appears in exactly two files in the tree, both tests:
```
mooncake-store/tests/ha/snapshot/master_service_test_for_snapshot_base.h
mooncake-store/tests/ha/snapshot/master_service_ssd_test_for_snapshot.cpp
```
Every snapshot restore test disables the code path that destroys the restored state in production. The feature is only ever tested with the failing step turned off.
### What we would like
1. **Do not apply wall-clock lease expiry to restored objects.** A lease is a liveness hint for readers, not durability state. Re-granting `default_kv_lease_ttl` from `now` on restore, or skipping the lease check during restore entirely, would both give the intended behaviour.
2. **Do not report success when the restore produced zero objects out of a non-empty snapshot.** At minimum log a `WARNING` with decoded-vs-surviving counts; `Successfully restored state from snapshot` alongside `Total allocated size after restore: 0` is actively misleading.
3. **Cover the cleanup path in tests.** A restore test with a snapshot older than `default_kv_lease_ttl` and `skip_cleanup` unset would have caught this. As written, the env var makes the test suite structurally unable to see the bug.
### A second defect underneath
Even with the above fixed, ten seconds after restore `client_ttl=10` expires the restored segments' clients and unmounts all three (`action=unmount_expired_mem_segment`) while the live store pods re-register as new clients. A restored index would need segment identity to survive that churn to be usable.
### Operational note
A non-HA master does not publish `master_view`, so store clients cannot use `-master_server_address=etcd://...` and must be pointed at the master's address directly. Worth a line in the snapshot docs, since the non-HA path is the only one where snapshots are written at all today (see #3561).
Contributor guide
Research direction
Start in master_service.cpp at MasterService::ApplySnapshotState and RestoreState, then read MetadataSerializer::SerializeMetadata and DeserializeMetadata to trace lease deadlines through restore. Compare the cleanup behavior with the snapshot tests in tests/ha/snapshot/master_service_test_for_snapshot_base.h and master_service_ssd_test_for_snapshot.cpp, first with the skip-cleanup environment variable unset. Done means the cleanup path is covered and a non-empty snapshot does not restore as an apparently successful empty state.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- cpp
- Domain
- distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Active
- Clarity
- Mostly clear
- Newbie friendliness
- 52/100