kvcache-ai / kvcache-ai/Mooncake

[Bug]: Store clients take ~2 minutes to reattach after a master failover, though promotion itself takes ~10s

Open
#3,740 3 comments 0 reactions 1 assignee Claimed by @Icedcoco View on GitHub
Dominant language
C++
Stars
6.6k
Forks
1.2k
Avg merge
3d 5h
Merged PRs (30d)
312

Description

### Bug Report

On `0.3.13` with `-enable_ha=true -enable_oplog=true -ha_backend_type=etcd`, master failover
itself works well: promotion is fast and **no metadata is lost** — this is a clear improvement
over `0.3.12.post1`. But the pool is unreadable for roughly two minutes afterwards, because the
store clients do not reattach for that long. The master serves an intact 200-object index to
nobody.

Reproduced twice, with near-identical timing both times.

### Setup

- Kubernetes, 1 etcd (v3.5.21), 2 `mooncake_master` (primary + hot standby), 3 `mooncake_client`
store nodes contributing 200 GiB each (600 GiB pool)
- Image: `docker.io/kvcacheai/mooncake:0.3.13`
- Master: `-enable_ha=true -ha_backend_type=etcd -enable_oplog=true -etcd_endpoints=:2379`
- Client: `-master_server_address=etcd://:2379 -protocol=rdma -global_segment_size=200GB`
- Workload: 200 objects × 4 MiB, seeded and verified by a small deterministic probe
- Failover triggered with `kubectl delete pod `

### What works

```
17:49:57.752 Promoting Standby to Primary. Applied seq_id: 206, lag: 0 entries
17:49:57.755 Standby promoted to Primary successfully
17:50:02.755 Starting serve phase...
17:50:02.778 Restored from standby: 200 objects, 2 segments, initial_seq_id=206
```

~4 s from pod deletion to promotion, ~10 s to serving, `lag=0` throughout, and a verify run
after both failovers found **200/200 objects present and intact**.

### What does not

The new primary serves an index it has no clients for:

```
17:50:02.7 new leader serving — Keys: 200, Clients: 0, Mem Storage 0 B / 0 B
17:50:30 verify -> present+intact = 0/200, missing = 200
~17:52 Clients: 2, Mem Storage 800.00 MB / 400.00 GB (~2 min after the kill)
```

So the metadata survived and the data survived, but for ~2 minutes every read fails.

### First cause: the view is published before the RPC port is bound

The new primary writes its `master_view` entry to etcd when it wins the election, then spends
~5 s in warmup before it binds `:50051`. Since #2484 made the client's view watch event-driven,
clients now wake up *inside* that window and connect to a port nobody is listening on. From a
store client (a different run of the same test):

```
17:46:10.229 master_client.cpp:361 Client not available
17:46:10.230 client_service.cpp:755 Failed to switch to leader 10.245.103.224:50051: RPC_FAIL
```

The new leader began serving 0.7 s later. This first failure looks like a straightforward
ordering problem: **publish the view after the RPC port is accepting connections, not before.**
Before #2484 the 200 ms/1 s polling cadence would usually have hidden it; making discovery fast
made the race reliable.

### Second, and the part we cannot explain: recovery then takes ~120 s

A single lost race should cost a retry, not two minutes. Reading v0.3.13, every retry path
looks like it should recover in seconds:

- `Client::LeaderMonitorThreadMain` (`client_service.cpp:720`) sleeps
`kErrorRetryInterval` = **1 s** after a failed `SwitchLeader`, then loops. It does not need a
fresh watch event to retry: `EtcdLeaderCoordinator::WaitForViewChange` re-reads the view at
the top of each iteration and returns `changed = true` whenever it differs from the version
the client last committed (`etcd_leader_coordinator.cpp:434-440`) — and a failed
`SwitchLeader` deliberately does not commit one.
- The ping thread reconnects independently after `max_ping_fail_count` = **3** failures at
`fail_ping_interval_ms` = **1000** (`client_service.cpp:4726,4730`), then remounts segments
when the master answers `NEED_REMOUNT`.

Either path should have the client back within single-digit seconds. We measured ~120 s, twice,
and could not determine which path stalls or why. `Clients: 0` on the master for the whole
window suggests pings are not landing rather than the switch never being retried, but we did
not confirm that.

Happy to run instrumented builds, raise client log verbosity, or test a patch — this is a test
cluster and the failover is a one-command reproduction.

### Expected

Promotion is ~10 s. Clients should reattach on that order, not 12× later.

### Suggested fixes

1. Bind the RPC port before publishing the `master_view` entry, so a client that reacts
immediately to the watch reaches a listening socket. This alone removes the trigger.
2. Independently, find out why the retry path takes ~120 s rather than ~1 s — a client that
loses the race for any other reason (a slow node, a network blip) hits the same stall.

### Related

- #2484 made the master-view watch event-driven. That change is good and we want it; it is what
turns this ordering window from unlikely into reliable.
- #2188, #2971, #3561 cover master-side metadata durability. This report is specifically about
the **client** side after a successful promotion — the metadata was fine in every run here.

### Before submitting a new issue...

- [x] Searched existing issues and read the documentation.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.