[
https://issues.apache.org/jira/browse/SOLR-18525?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Amrit Sarkar updated SOLR-18525:
--------------------------------
Attachment: SOLR-18525-repro-test.patch
> 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: 9.9, 9.10, 10.0, 9.11, 9.10.1
> Reporter: Amrit Sarkar
> Priority: Major
> Attachments: SOLR-18525-repro-test.patch
>
>
> 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]
