Skip to content

Flaky test: TestSingleBinaryWithMemberlistScaling (arm64) — scale-down convergence wait inherits a ~50s readiness backoff, too short for memberlist to repair a lost leave message #7801

Description

@CharlieTLe

Summary

TestSingleBinaryWithMemberlistScaling scales a single-binary memberlist cluster up to 30 instances and then tears it back down to 3, one instance at a time. After each s.Stop() it waits for every surviving instance to report the reduced memberlist_client_cluster_members_count (integration/integration_memberlist_single_binary_test.go:326-328):

// TODO(#4360): Remove this when issue is resolved.
//   Wait until memberlist for all nodes has recognised the instance left.
//   This means that we will not gossip tombstones to leaving nodes.
for _, c := range instances {
    require.NoError(t, c.WaitSumMetrics(e2e.Equals(float64(len(instances))), "memberlist_client_cluster_members_count"))
}

That wait has no timeout of its own. WaitSumMetrics polls with the service's generic retry backoff, which newSingleBinary sets to MinBackoff: 200ms, MaxBackoff: 500ms, MaxRetries: 100 (integration/integration_memberlist_single_binary_test.go:245-249) — a budget sized for container-readiness checks, worth ~50 s.

A departing instance's memberlist leave message is gossiped best-effort. When one survivor misses it, the only fast repair is memberlist's push/pull full-state sync, which runs every 30 s — so the wait gives the cluster one, at best two, guaranteed repair opportunities, and one of those can be spent trying to sync with the instance that just went away. Whenever a single leave message is lost, the wait times out and the test fails. This is not a product bug: losing a gossip message during an aggressive scale down is expected, and memberlist_client_cluster_members_count is the right metric — the wait budget is simply an order of magnitude too small for what it is waiting on.

Most recent occurrence

Failure excerpt

Job log excerpt (arm64, attempt 1)
18:10:41 Starting cortex-30
18:10:49 Stopping cortex-30
18:10:53 Stopping cortex-29
18:10:58 Stopping cortex-28
18:11:03 Stopping cortex-27
18:11:08 Stopping cortex-26
18:11:11 Stopping cortex-25
18:11:13 Stopping cortex-24
18:11:17 Stopping cortex-23
18:11:18 Stopping cortex-22
18:11:18 cortex-22: caller=grpc_logging.go:74 level=warn duration=1m28.733888998s method=/frontend.Frontend/Process err="queue is stopped" msg=gRPC
18:11:21 cortex-22: caller=log.go:115 level=error msg="error running cortex" err="failed services..."
18:11:21 Error response from daemon: No such container: e2e-cortex-test-cortex-22
18:11:26 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:31 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:36 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:42 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:46 cortex-3: caller=log.go:244 level=error msg="Push/Pull with cortex-22-e8b03be2 failed: dial tcp 172.18.0.24:8000: i/o timeout"
18:11:48 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:54 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:11:59 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
18:12:04 cortex-3: caller=tcp_transport.go:535 level=warn component="memberlist TCPTransport" msg="WriteTo failed" addr=172.18.0.24:8000 err="dial tcp 172.18.0.24:8000: i/o timeout"
    integration_memberlist_single_binary_test.go:327:
        	Error Trace:	/__w/cortex/cortex/integration/integration_memberlist_single_binary_test.go:327
        	Error:      	Received unexpected error:
        	            	unable to find metrics [memberlist_client_cluster_members_count] with expected values. Last error: <nil>. Last values: [22]
        	Test:       	TestSingleBinaryWithMemberlistScaling
--- FAIL: TestSingleBinaryWithMemberlistScaling (276.16s)

Root cause

Timeline reconstructed from the log:

  1. All 30 instances started and passed the sanity check (cortex_ring_members == 30, zero tombstones) before the scale down began at 18:10:49. cortex-22 was healthy and fully in the ring — the containers cortex-3 is failing to dial belong to an instance the test itself stopped, not to one that never came up.
  2. cortex-22 (172.18.0.24) was sent SIGTERM at 18:11:18.6 and its container was removed at 18:11:21.3. It shut down cleanly and logged no "broadcast messages left in queue" warning, so its leave message was emitted.
  3. At the failure point instances held cortex-1cortex-21, so the expected value was 21. cortex-1 and cortex-2 had already converged (the loop polls in order). cortex-3 reported 22 — its memberlist still counted cortex-22, i.e. exactly one node behind. memberlist_client_cluster_members_count is Memberlist.NumMembers() (pkg/ring/kv/memberlist/metrics.go:144-149), which counts everything not dead-or-left.
  4. cortex-3 logged Push/Pull with cortex-22-e8b03be2 failed at 18:11:46 — 28 s after cortex-22 died. Memberlist.pushPull() selects only peers in StateAlive (vendor/github.com/hashicorp/memberlist/state.go:633-639), so at that moment cortex-3 still had cortex-22 as alive: it had neither received the leave message nor yet suspected the node.
  5. The wait gave up at 18:12:06.78, 48.2 s after the stop — exactly the ~50 s the readiness backoff allows. PushPullInterval is 30 s, so cortex-3's next full-state sync was due around 18:12:16: the assertion missed the repair by roughly 10 seconds. A remote StateLeft is applied directly by mergeStatedeadNode (vendor/github.com/hashicorp/memberlist/state.go:1313-1315), so that sync would have fixed it.

Why the missed leave message is not repaired quickly, and why the alternatives are all slower than the wait budget:

  • Gossip (fast, best-effort). Retransmit budget is RetransmitMult * ceil(log10(N+1)) = 8 transmissions at 22 nodes, sent to GossipNodes (3) peers per 200 ms tick. During a rapid scale down, up to 8 recently-departed nodes are still in each survivor's gossip pool, because memberlist keeps gossiping to nodes dead for less than GossipToTheDeadTime (30 s) (vendor/github.com/hashicorp/memberlist/state.go:575-595). A large share of the retransmit budget is therefore spent on addresses that no longer exist.
  • Amplifier: blocking dials in the TCP transport. TCPTransport.WriteTo dials synchronously with -memberlist.packet-dial-timeout (default 5 s) and swallows the error (pkg/ring/kv/memberlist/tcp_transport.go:521-542). Docker blackholes traffic to a removed container's IP, so the dial ends in i/o timeout rather than connection refused and burns the full 5 s on memberlist's single gossip goroutine. The regular ~5 s cadence of the WriteTo failed lines above is exactly this. So each survivor's outbound gossip is repeatedly stalled for 5 s at a time during the scale down — which both delays its own tombstone dissemination and makes leave-message loss more likely.
  • Push/pull (reliable, 30 s). As above; and a sync attempt can pick the departed node itself and be wasted, as happened here.
  • Failure detection (slowest). Cortex sets ProbeInterval = 5s / ProbeTimeout = 2s (pkg/ring/kv/memberlist/memberlist_client.go, buildMemberlistConfig). probe() round-robins one peer per interval, so a given peer is probed roughly once every len(members) * 5s ≈ 110 s at 22 nodes. Once suspected, suspicionTimeout = SuspicionMult * log10(N+1) * ProbeInterval ≈ 27 s minimum, and the timer starts at SuspicionMaxTimeoutMult (6×) that value ≈ 160 s, shrinking only as other nodes confirm the suspicion. No confirmation ever arrives here, because every other node already recorded the leave and suspectNode ignores suspect messages for non-alive nodes (vendor/github.com/hashicorp/memberlist/state.go:1171-1174). Worst case is therefore ~270 s — five times the wait budget.

Introduced by: commit 03911b6 ("Fix integration TestSingleBinaryWithMemberlistScaling flaking.", #4361, July 2021), which added this wait as a workaround for #4360 and inherited the readiness backoff as its timeout. The mechanism is architecture-independent — the earlier reports #4289 and #4351 are from 2021, long before arm64 CI was added (#7068), and they hit the final tombstone assertion rather than this wait. arm64 only raises the probability: the runner starts containers ~6.3 s apart and runs 30 Cortex processes with GOMAXPROCS=4, so gossip goroutines are more contended.

Note also that the workaround only partially achieves its stated goal ("we will not gossip tombstones to leaving nodes"): memberlist keeps gossiping to a node for GossipToTheDeadTime (30 s) after it has been marked dead, so the departing node stays in the gossip pool well past the point where memberlist_client_cluster_members_count drops. Fully avoiding it would mean sleeping 30 s per scale-down step. #4360 remains the real fix.

Proposed fix

Keep the assertion and the metric — replace the inherited readiness-sized budget with an explicit one derived from PushPullInterval, so the wait covers several full-state-sync opportunities instead of one marginal window, and log which instances are still behind (mirroring the final tombstone assertion, which already does this and has "proven extremely useful"). Also treat a transient scrape error as "not converged yet" and retry, rather than failing immediately as WaitSumMetrics does.

Not addressed here, but worth separate consideration: the 5 s blocking dial to blackholed peers on memberlist's gossip goroutine (pkg/ring/kv/memberlist/tcp_transport.go). That is a real robustness weakness in production too — a handful of unreachable peers can stall a node's outbound gossip — but changing it is a product change, not a test fix.

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions