Jerry Chung created SOLR-18568:
----------------------------------
Summary: Unload/delete-replica can wait indefinitely in
SolrCore.closeAndWait() while request or recovery threads hold the core;
threads stuck in consumeInputFully on HTTP/2 streams
Key: SOLR-18568
URL: https://issues.apache.org/jira/browse/SOLR-18568
Project: Solr
Issue Type: Bug
Components: SolrCloud
Affects Versions: 10.0
Reporter: Jerry Chung
On a node with replicas in recovery, an unload (/admin/cores?action=UNLOAD,
deleteInstanceDir=true) of one core never finished. The thread was parked in
SolrCore.closeAndWait() (line 1627) via CoreContainer.unload, logging Core
<name> is not yet closed, waiting 100 ms before checking again. about 10 times
per second. That produced about 36,000 lines in an hour for one core, and the
wait lasted at least 1h53m. Another core's unload waited about 3.5 minutes.
closeAndWait() has no timeout.
Observations (thread dump and shutdown log)
1. A thread dump showed three qtp threads blocked in
ServletUtils.consumeInputFully (called from
SolrDispatchFilter.doFilterRetry:194, reading via
ServletInputStreamWrapper.read and HttpInput.read) on HTTP/2 streams
(HttpStreamOverHTTP2). One of them had a request id (4403346) far lower than
current requests (about 9 million), so it appears to have been stuck for a long
time. The node had only 131 threads in total, so the thread pool was not
exhausted.
2. At shutdown (13:32:32.883), when Jetty stopped, those three threads logged
Could not consume full client request => EofException at
HttpStreamOverHTTP2.onFailure. Immediately after, one of them
(qtp…-24474-null-4403346) logged CLOSING SolrCore … <core>, then Error removing
directory => NoSuchFileException …/data/tlog and clearRequestInfo called too
many times. The spinning is not yet closed lines for that core stopped at the
same moment.
3. A recovery thread (recoveryExecutor) blocked in
RecoveryStrategy.commitOnLeader (see ticket 1) held another core.
CoreContainer.unload calls cancelRecovery() and then waits in closeAndWait(),
but the blocked HTTP call isn't interrupted. The core closed only when the
recovery ended: Finished recovery process, successful=[false]
msTimeTaken=577454, then CLOSING SolrCore by the recovery thread.
Problems
- A. Request threads can block indefinitely in consumeInputFully on an HTTP/2
stream whose client never finishes sending, with no read timeout. In the log,
freeing these threads coincided with a core finally closing, which suggests
they held a core reference. I'm not sure how, because call.destroy() in
SolrDispatchFilter.dispatch runs before consumeInputFully. This needs a
reviewer who knows that path.
- B. closeAndWait() waits forever and logs at INFO every 100 ms. It should have
a bounded wait, back off its logging, or at least log the thread(s) or
reference count that block the close.
- C. cancelRecovery() doesn't interrupt a recovery thread blocked in an HTTP
call, so unloading a replica that is in recovery blocks until the call times
out (10 minutes by default).
Impact
Unload and delete-replica operations hang for hours. Everything holding the
core stays blocked, and the node needed a restart to clear it.
Suggestions (untested)
- Make cancelRecovery() abort the in-flight request.
- Add a bounded wait and rate-limited logging in closeAndWait().
- Review whether the body draining in consumeInputFully needs a timeout for
HTTP/2 streams.
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
