Amrit Sarkar created SOLR-18525:
-----------------------------------
Summary: Core create hangs forever if its replica is removed from
cluster state during registration
Key: SOLR-18525
URL: https://issues.apache.org/jira/browse/SOLR-18525
Project: Solr
Issue Type: Bug
Components: SolrCloud
Affects Versions: 10.0, 9.10, 9.9, 9.11, 9.10.1
Reporter: Amrit Sarkar
If a replica is removed from state.json while the node hosting it is still
inside {{CoreContainer.create}} for that core, the create never returns and the
core name stays locked on that node.
h3. When it happens
{{ZkController.register}} checks that the replica exists in cluster state,
joins leader election and waits for a leader (up to leaderVoteWait + 10 min),
replays any tlog, and only then installs {{UnloadCoreOnDeletedWatcher}}. If the
replica is removed in that window, the watcher sees it gone and calls
{{CoreContainer.unload}} on a core that is still being created.
Since SOLR-17700, {{unload}} waits on the per-core pending op. The create
already holds that op, so:
# *Node already hosts a replica of the collection:* the create thread runs the
watcher inline from {{registerDocCollectionWatcher}} and waits on itself.
# *First replica of the collection on the node:* registering the watcher also
queues an async notification. The notification thread takes the watcher monitor
({{onStateChanged}} is synchronized) and waits for the pending op. The create
thread holds the op and waits for the monitor.
The JVM doesn't flag either as a deadlock, because the per-core lock is the
{{pendingCoreOps}} set, not a monitor. The node just looks stuck.
It takes a slow register to hit this with the Collection API. I reproduced it
with a plain DELETEREPLICA on default timeouts: DELETEREPLICA waits for the
shard lock until ADDREPLICA gives up (90s), its core UNLOAD then parks behind
the create's pending op until the request times out (90s more), and after
another 30s it removes the replica from state.json. If register is still
waiting for a leader at that point (around 210s in), the create deadlocks. That
wait can last leaderVoteWait + 10 min when the shard has no live leader. A
failed ADDREPLICA followed by a DELETEREPLICA cleanup is a likely way to get
there. I haven't tested split rollback (DELETESHARD).
Startup load releases the pending op before registering in the background, so
only {{CoreContainer.create}} is affected (ADDREPLICA, collection create, split
sub-shards). That's why
{{DeleteReplicaTest.raceConditionOnDeleteAndRegisterReplica}}, which covers the
restart path, doesn't catch it.
h3. Repro
I found this while going through the core create and unload locking, and
reproduced it locally with a test that forces the race. The test is attached
({{SOLR-XXXXX-repro-test.patch}}, applies on main):
{noformat}
git apply SOLR-XXXXX-repro-test.patch
./gradlew :solr:core:test --tests
"org.apache.solr.cloud.CoreCreateReplicaRemovedDeadlockTest"
{noformat}
It stretches the window with a test {{UpdateLog}} that blocks in
{{recoverFromLog()}}, the last hook point after the existence check, removes
the replica while register is paused, then lets the create continue. Five
tests, all fail every time, with and without the Overseer (seeds
BAE60C1D1A3FBB96 and 814077321E33EF2E):
* both variants with the replica removed by a DELETECORE state update (fast,
about 45s each)
* both variants with the replica removed by a real DELETEREPLICA on default
timeouts (about 4 min each)
* follow-up core admin calls on the stuck core name
On timeout each test fails with the stacks of the stuck threads.
h3. Stack (variant 1, main @ 22a8cfebbbd)
{noformat}
"qtp1724204461-60-null-8" WAITING on java.lang.Object@142135dd
(SolrCores.modifyLock)
at o.a.s.core.SolrCores.waitAddPendingCoreOps(SolrCores.java:291)
at o.a.s.core.CoreContainer.unload(CoreContainer.java:2064)
at
o.a.s.cloud.ZkController$UnloadCoreOnDeletedWatcher.onStateChanged(ZkController.java:2970)
- locked o.a.s.cloud.ZkController$UnloadCoreOnDeletedWatcher@439e24f4
at
o.a.s.common.cloud.ZkStateReader.registerDocCollectionWatcher(ZkStateReader.java:1626)
at o.a.s.cloud.ZkController.register(ZkController.java:1572)
at o.a.s.cloud.ZkController.register(ZkController.java:1385)
at o.a.s.core.ZkContainer.lambda$registerInZk$0(ZkContainer.java:261)
at o.a.s.core.ZkContainer.registerInZk(ZkContainer.java:290)
at o.a.s.core.CoreContainer.registerCore(CoreContainer.java:1465)
at o.a.s.core.CoreContainer.createFromDescriptor(CoreContainer.java:1692)
at o.a.s.core.CoreContainer.create(CoreContainer.java:1548)
{noformat}
Variant 2:
{noformat}
"qtp1724204461-52-null-4" BLOCKED on
ZkController$UnloadCoreOnDeletedWatcher@26c37a27 owned by
"watches-44-thread-1-..."
at
o.a.s.cloud.ZkController$UnloadCoreOnDeletedWatcher.onStateChanged(ZkController.java:2964)
at
o.a.s.common.cloud.ZkStateReader.registerDocCollectionWatcher(ZkStateReader.java:1626)
at o.a.s.cloud.ZkController.register(ZkController.java:1572)
... down to CoreContainer.create(CoreContainer.java:1548)
"watches-44-thread-1-..." WAITING on java.lang.Object@142135dd
at o.a.s.core.SolrCores.waitAddPendingCoreOps(SolrCores.java:291)
at o.a.s.core.CoreContainer.unload(CoreContainer.java:2064)
at
o.a.s.cloud.ZkController$UnloadCoreOnDeletedWatcher.onStateChanged(ZkController.java:2970)
- locked ZkController$UnloadCoreOnDeletedWatcher@26c37a27
at o.a.s.common.cloud.ZkStateReader$Notification.run(ZkStateReader.java:1950)
{noformat}
h3. Impact
* The core admin CREATE never returns. ADDREPLICA fails after the 90s shard
request timeout.
* The core stays loaded, and its state updates are rejected ("Failed to update
state because the replica does not exist").
* Every later state.json change for the collection starts another watcher
thread that blocks on the same monitor.
* On that node, core admin UNLOAD and RELOAD of the same core name block (no
response within the test's 20s bound, threads parked in
{{waitAddPendingCoreOps}}), and CREATE with the same name fails with "Already
creating a core with name ...". DELETEREPLICA's own UNLOAD thread stays parked
after its request times out.
* Stopping the node releases everything (shutdown completes in about half a
second). I found no other way to clear it.
h3. Where it came from
SOLR-17700 (fix version 9.9) made the public {{unload}} take the core op lock
and moved the old body to {{unloadWithoutCoreOp}}. It switched the
{{NotInClusterStateException}} path inside {{createFromDescriptor}} to
{{unloadWithoutCoreOp}}, but the watcher path through {{register}} still calls
{{unload}}. 9.8.1's {{unload}} doesn't take the lock, so it doesn't hang here.
Reverting SOLR-17700 isn't the answer though: before it, the watcher would
likely unload the core in the middle of the create.
Related: SOLR-12187 (added the watcher), SOLR-16497 (finer grained locking in
SolrCores).
I'm working on a fix.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
