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.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

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