Gil Ganz created CASSANDRA-21636:
------------------------------------
Summary: Node can remain DOWN forever after a single lost ECHO:
inflightEcho entry is never cleared on failure (regression introduced by
CASSANDRA-18866)
Key: CASSANDRA-21636
URL: https://issues.apache.org/jira/browse/CASSANDRA-21636
Project: Apache Cassandra
Issue Type: Bug
Components: Cluster/Gossip
Reporter: Gil Ganz
```
h2. Summary
Since CASSANDRA-18866 ("Node does not send multiple inflight echos", fix
versions 4.0.20 / 4.1.11 / 5.0.7 / 6.0), gossip no longer heals after a
transient network problem. A single failed ECHO_REQ/ECHO_RSP permanently
prevents an observer from ever marking a peer UP again: the
{{Gossiper.inflightEcho}} entry added by that change is removed only on echo
*success*, so after a failure every subsequent {{markAlive}} trigger is
silently skipped ("Skipping ECHO_REQ to {} since it is already inflight"). The
implicit retry-on-next-heartbeat loop that has healed lost echoes since
CASSANDRA-6590 (2014) still executes, but the stale entry turns it into a no-op.
The practical effect for us: on 4.1.5, when a packet-loss event ended, every
node saw every other node UP again within seconds. On 5.0.8, the same event
leaves nodes DOWN indefinitely with no self-recovery - repeatedly, in
day-to-day operation, we see up to half the cluster reporting dozens of nodes
DN across several datacenters after loss clears, and it takes multiple rounds
of {{nodetool disablegossip}} / {{enablegossip}} on many nodes to clear.
Without that manual intervention the phantom-DOWN state persists.
Any event that can lose an echo now wedges permanently, so we hit the same end
state from two everyday operations: transient packet loss, and *multiple node
restarts within a short window* (a rolling upgrade, but equally any routine
batch of restarts, or a node restarted a few times in a row) - the restarted
nodes' GossipStage backlogs drop echoes in both directions while the cluster is
churning.
h2. Environment
Seen on *multiple* production clusters, all upgraded 4.1.5 -> 5.0.8, all with
similar topology:
* 7 DCs spread around the world, dozens of nodes per DC (largest cluster
analyzed in depth: 251 nodes), inter-DC links subject to occasional packet loss.
* {{num_tokens}} ranging from 16 to 128 depending on DC/cluster;
GossipingPropertyFileSnitch; NetworkTopologyStrategy keyspaces replicated
across all DCs.
* {{internode_encryption: none}}, {{internode_timeout: true}},
{{request_timeout: 10000ms}} (default), storage_compatibility_mode CASSANDRA_4.
* No comparable incidents on the same clusters/topologies/procedures while on
4.1.5.
h2. Symptom
Two operational triggers, same wedge:
*(1) Transient packet loss / partial connectivity loss (the dominant one in
steady-state operation).* When a loss event ends, affected pairs never return
to UP on their own. Views are pairwise-asymmetric and often mutual: A sees B
down while C sees B fine, and B simultaneously sees A down. Recovery requires
{{disablegossip}}/{{enablegossip}} on the DN targets, frequently several rounds
across many nodes (see "Why multiple rounds are needed" below), and the set of
DN nodes spans multiple DCs.
*(2) Multiple node restarts within a short window* - a rolling upgrade or
restart, a batch/rack wave, or simply the same node bounced a few times in a
row. Here the echo loss is local rather than network: ECHO_REQ/ECHO_RSP are
handled on the single-threaded GossipStage with a {{request_timeout}} (10s)
expiry, and a restarting node's GossipStage is backlogged applying every peer's
state (251 endpoints x ~27,000 vnode tokens x 7 DCs x 9 keyspaces), so inbound
echoes expire in the stage queue and are dropped before {{EchoVerbHandler}}
runs.
A single restart on an otherwise quiet cluster is usually asymmetric and
survivable: observers fire their one echo into the peak of the restarted node's
backlog and lose it, while the restarted node's own echoes land on idle peers
and succeed - so the restarted node sees everyone UP and only the observers
wedge (which is why the restarted node's own {{nodetool status}} must never be
trusted as the check). Once several restarts overlap in time, both directions
are sending echoes into busy GossipStages and both directions wedge, so a
restarted node also ends up seeing dozens of peers DN. Restarting again does
not recover it: each new generation buys exactly one fresh echo per observer,
and on a still-churning cluster that one attempt is likely lost too, so
repeated restarts in a window tend to accumulate wedged pairs rather than clear
them. During our 4.1.5 -> 5.0.8 roll of the 251-node cluster, 12 nodes ended up
phantom-DN cluster-wide (one of them itself seeing 33 phantom-DN peers),
concentrated where restart parallelism was highest, with seeds over-represented.
In both cases, while a pair is wedged:
* Cassandra is fully up and serving on the "down" node;
* all four internode channels are established in both directions
({{successfully connected ... encryption = unencrypted}}, messaging version 12);
* gossip state keeps flowing: current generation, advancing heartbeat, schema
in agreement, on the very observers showing DN (gossip digests use
{{longTimeout}} = max(request_timeout, 5 min), so state survives where the 10s
echo does not);
* no {{is now DOWN}} is logged at the moment the node becomes
unreachable-forever; observers may log {{Node /X has restarted, now UP}}
(printed by {{handleMajorStateChange}} *before* the echo round-trip) and then
keep the node in UNREACHABLE.
Network causes were excluded for the persistent state (TCP connects both ways,
no TLS, PMTUD healthy, clocks in sync) - i.e. connectivity is healthy again and
the DN state still does not clear. TRACE logging on a wedged observer shows the
smoking gun repeating for the peer:
{code}
TRACE ... Gossiper.java - Skipping ECHO_REQ to /10.x.x.x:7000 since it is
already inflight
{code}
h2. Root cause (5.0.8 source)
{{Gossiper.markAlive}} (Gossiper.java:1435):
{code:java}
private void markAlive(final InetAddressAndPort addr, final EndpointState
localState)
{
localState.markDead();
EndpointState prevState = inflightEcho.put(addr, localState);
boolean sendEcho = !localState.equals(prevState);
if (sendEcho)
{
Message<NoPayload> echoMessage = Message.out(ECHO_REQ, noPayload);
RequestCallback echoHandler = msg ->
{
runInGossipStageBlocking(() -> {
EndpointState epState = inflightEcho.remove(addr);
if (epState != null)
realMarkAlive(addr, epState);
});
};
MessagingService.instance().sendWithCallback(echoMessage, addr,
echoHandler);
}
else
logger.trace("Skipping ECHO_REQ to {} since it is already inflight",
addr);
}
{code}
# The callback implements only the response case; {{invokeOnFailure()}}
defaults to false, so a failed or expired echo leaves the {{inflightEcho}}
entry in place forever.
# {{EndpointState}} does not override {{equals}}, and {{localState}} is the
*same* {{EndpointState}} object for the endpoint's whole generation (the
{{localEpStatePtr}} held in {{endpointStateMap}}). So every later {{markAlive}}
for that generation compares the object against itself, dedups, and skips. The
CASSANDRA-6590 heal loop is disabled.
# Nothing clears the entry once the peer is already DOWN. {{markDead ->
silentlyMarkDead}} does remove it (Gossiper.java:1506), but it is unreachable
in this state: {{convict()}} early-returns when the endpoint is not alive
(Gossiper.java:612), and {{markAlive}} itself starts with
{{localState.markDead()}}. {{clearUnsafe()}} is test-only.
# The only escape in normal operation is a *generation change* on the target,
which replaces the {{EndpointState}} object via {{handleMajorStateChange}} and
therefore breaks the identity dedup. That is exactly why restarting the target,
or {{disablegossip}}/{{enablegossip}} ({{forceNewerGeneration()}}), fixes it -
and why it grants only *one* fresh echo attempt per observer.
h3. How a packet-loss event arms the trap
# Loss starts. The failure detector convicts the peer -> {{markDead ->
silentlyMarkDead}} clears any inflight entry. Peer is DN; nothing stuck yet.
# Loss continues. The observer still learns newer heartbeats for that peer
*indirectly*, relayed by a third node whose path is intact (very likely with 7
DCs and partial loss). {{applyStateLocally}} then hits Gossiper.java:1751-1752:
{{if (!localEpStatePtr.isAlive() && !isDeadState(localEpStatePtr))
markAlive(ep, localEpStatePtr);}} -> one ECHO_REQ is sent into the lossy path
and fails -> {{inflightEcho}} entry now stuck, with no generation change to
ever clear it.
# Loss ends. Heartbeats resume directly, {{markAlive}} is called ~1/s, and
every call is skipped. The pair is DN forever. On 4.1.5 step 3 healed within
~1s because each heartbeat sent a fresh echo.
h3. Why multiple rounds of disablegossip/enablegossip are needed
{{disablegossip}} broadcasts shutdown -> observers run {{markAsShutdown ->
markDead -> silentlyMarkDead}}, clearing the stuck entry; {{enablegossip}}
calls {{forceNewerGeneration()}}, so every observer sends one fresh echo. If
any of those echoes fails (residual loss, or a busy GossipStage on a cluster
still churning), that observer is wedged again for the new generation - one
shot per generation, no retry. With dozens of wedged pairs across 7 DCs,
operators end up cycling the union of DN targets repeatedly until every pair
happens to win its single race.
h3. On CASSANDRA-18866's reasoning
That ticket's description states "there is no retry logic for failed ECHO
requests, but this is the case even both before and after". That is true only
for *explicit* retries: before 18866, the per-heartbeat re-send of ECHO in
{{markAlive}} was an implicit retry loop (the CASSANDRA-6590 mechanism). The
dedup removed it without replacement, converting every transient echo loss into
a permanent phantom-DOWN.
h2. Reproduction
*Minimal (network variant, 3 nodes, no scale needed):*
# 3-node cluster (A, B, C) on 5.0.7+ / 4.1.11+ / 4.0.20+.
# Drop internode traffic between A and B only, both directions ({{iptables -A
INPUT -s B -p tcp --dport 7000 -j DROP}} on A and symmetrically on B), leaving
both able to gossip with C. Hold it well past FD conviction plus
{{request_timeout}} (~60s): A and B mark each other DOWN, then each re-attempts
{{markAlive}} on the peer's C-relayed heartbeat and loses its single echo.
# Remove the rules. Connections re-establish, digests and heartbeats flow,
{{nodetool gossipinfo}} shows a fresh generation and advancing heartbeat for
the peer - and {{nodetool status}} keeps showing DN on both sides indefinitely.
TRACE on Gossiper prints {{Skipping ECHO_REQ ... already inflight}} once per
heartbeat.
# Same test on 4.1.5 (or any pre-18866 build): both nodes are UP within ~1s of
the rules being removed.
*Restart variant (needs scale, or an artificially stalled GossipStage):*
restart a node on a cluster where the GossipStage drain exceeds
{{request_timeout}} (100+ nodes with 128 vnodes and several NTS keyspaces
suffices). Observers send their single ECHO_REQ as soon as they learn the new
generation, i.e. into the peak of the restarted node's backlog; it expires
in-queue and is dropped. Those observers show the node DN forever. Restarting
several nodes within the same window (rack waves, a rolling upgrade, or one
node bounced repeatedly) wedges both directions at once and compounds:
probability scales with cluster size - each restart is N-1 independent echo
races, so even 2% per-race loss gives ~99% chance of at least one wedge per
restart at N=251, and a fleet-wide roll is ~N^2 races (~62k).
h2. Workarounds (validated in production)
* {{nodetool disablegossip && sleep 15 && nodetool enablegossip}} on the
phantom-DN *target*, repeated over the union of nodes seen DN from any vantage
point, until clean - see "Why multiple rounds are needed".
* Raising the echo budget live ({{nodetool settimeout misc 30000}}) makes
losses, and therefore new wedges, much rarer for the GossipStage-backlog
variant. It is a probability lever only: it cannot unwedge existing pairs, and
any loss longer than the budget - which is what a packet-loss event is - still
wedges permanently.
h2. Proposed fix
Keep the 18866 dedup (one echo in flight per peer) but clear the entry on
failure, so the existing heartbeat-driven path retries - restoring the
CASSANDRA-6590 guarantee:
{code:java}
RequestCallback<NoPayload> echoHandler = new RequestCallback<NoPayload>()
{
@Override
public void onResponse(Message<NoPayload> msg)
{
runInGossipStageBlocking(() -> {
EndpointState epState = inflightEcho.remove(addr);
if (epState != null)
realMarkAlive(addr, epState);
});
}
@Override
public boolean invokeOnFailure()
{
return true;
}
@Override
public void onFailure(InetAddressAndPort from, RequestFailureReason
failureReason)
{
// Unblock the retry that fires on the next received heartbeat for this
endpoint.
// Two-arg remove so a newer inflight entry (new EndpointState after a
// generation change) is not clobbered.
runInGossipStageBlocking(() -> inflightEcho.remove(addr, localState));
logger.trace("ECHO_REQ to {} failed ({}); will retry on next state
update", addr, failureReason);
}
};
{code}
This bounds echo traffic to at most one in flight per peer (preserving the
18543/18866 goal) while guaranteeing eventual UP-marking once connectivity
allows a round-trip within the timeout.
h2. Related
* CASSANDRA-18866 - introduced the inflightEcho dedup (4.0.20 / 4.1.11 / 5.0.7
/ 6.0)
* CASSANDRA-18845 / CASSANDRA-18854 - earlier attempt and rollback
* CASSANDRA-18543 - echo flooding / slow UP-marking that motivated the dedup
* CASSANDRA-6590 - original 2014 fix for "gossip does not heal after partition
at startup"; its heal mechanism is what the stuck entry disables
* CASSANDRA-9218 - GC-pause echo loss (another loss source that is now
permanent)
```
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
