[jira] [Created] (SOLR-18525) Core create hangs forever if its replica is removed from cluster state during registration

["Amrit Sarkar (Jira)" <ji...@apache.org>]

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: issues-unsubscribe@solr.apache.org
For additional commands, e-mail: issues-help@solr.apache.org