Lucas Kot-Zaniewski created SOLR-18480:
------------------------------------------
Summary: TLOG leader election stalls on a frozen old leader
Key: SOLR-18480
URL: https://issues.apache.org/jira/browse/SOLR-18480
Project: Solr
Issue Type: Bug
Reporter: Lucas Kot-Zaniewski
h2. Summary
TLOG leader election stalls for a flat ~60s when the outgoing leader freezes
rather than dies.
h2. Problem
When a TLOG replica wins an election,
{{ShardLeaderElectionContext.runLeaderProcess}} calls
{{zkController.stopReplicationFromLeader(coreName)}} inline on the election
thread
({{ShardLeaderElectionContext.java:254}}). The whole chain is synchronous and
unbounded:
{code}
ShardLeaderElectionContext:254 stopReplicationFromLeader
-> ZkController:1621 stopReplicationFromLeader (synchronized on
ReplicateFromLeader)
-> ReplicateFromLeader:189 stopReplication
-> ReplicationHandler:1496 shutdown()
startShutdownHook.preClose -> executorService.shutdown() //
no interrupt
startShutdownHook.postClose -> pollingIndexFetcher.destroy()
-> IndexFetcher.abortFetch() //
sets a flag only
-> IOUtils.closeQuietly(solrClient) //
no-op
ExecutorUtil.shutdownAndAwaitTermination(executorService) // <--
BLOCKS 60s (:1502)
{code}
If the old leader has _frozen_ rather than died, the follower's
{{indexFetcher}} poll thread is
parked inside an HTTP call to it, so the executor cannot terminate and the
election thread sits in
{{awaitTermination}} until the 60s deadline expires.
h2. Why nothing cuts it short
* {{IndexFetcher.abortFetch()}} ({{:1483}}) only sets {{volatile boolean stop}}
({{:173}}), which is
polled in exactly one place -- {{FileFetcher.fetchPackets}},
{{IndexFetcher.java:1669}} -- and never
during the network call.
* {{IndexFetcher.destroy()}} ({{:1990}}) closes a client derived from
{{UpdateShardHandler.getRecoveryOnlyHttpClient()}}, so {{closeClient == false}}
and
{{HttpJettySolrClient.close()}} skips {{httpClient.stop()/destroy()}}. No
socket is torn down.
* {{ExecutorUtil.shutdownAndAwaitTermination}} ({{ExecutorUtil.java:116}})
waits 60s, _then_ calls
{{shutdownNow()}}, then waits another 60s.
The unwind is ultimately driven by that {{shutdownNow()}} interrupt, not by any
socket timeout:
{{HttpJettySolrClient.request}} catches {{InterruptedException}} and calls
{{req.abort(abortCause)}}
in its {{finally}} ({{:531}}). The interrupt works -- it just arrives 60s too
late. Since
{{soTimeout}} defaults to 120s ({{IndexFetcher.java:286}}), the executor
deadline always fires
first, which is why the stall is a flat ~60s rather than tracking how long the
peer stays frozen.
h2. Evidence
Reproduced on {{main}} with a 2-node cluster, one shard of two TLOG replicas:
the leader's
{{/replication?command=indexversion}} response is held open while its ZooKeeper
session is expired,
so the survivor runs an election with a fetch already parked in the network
phase.
Election took 62,553 ms (9 runs, 62.54--62.60s). On the surviving replica's
election thread:
{code}
7843 ms ZkController tlog_..._replica_t1 stopping background
replication from leader
67850 ms ShardLeaderElectionContext Replaying tlog before become new leader
{code}
60,007 ms. The same code path completes in 111 ms during normal collection
creation.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
