Hello,
We have recently seen the below errors repeated when update requests were
received by Solr. Could you please advise on how to deal with this issue.
The error and warning from the Solr log as below:
========================================
2023-05-09 10:03:05.128 ERROR
(updateExecutor-8-thread-11857-processing-test_shard1_replica_n1 core_node3
null stg-test-search--1.i.kandasearch.com:8983_solr test shard1) [c:test
s:shard1 r:
core_node3 x:test_shard1_replica_n1]
o.a.s.u.ErrorReportingConcurrentUpdateSolrClient Error when calling
SolrCmdDistributor$Req: cmd=add{,id=xxx,commitWithin=30000};
<https://www.toyota.co.jp/jpn/company/history/75years/text/leaping_forward_as_a_global_corporation/chapter2/section1/item3.html,commitWithin=30000%7D;>
node=ForwardNode: http://test.com:8983/solr/test_shard1_replica_n2/
<http://stg-toyota-search--2.i.kandasearch.com:8983/solr/test-mcf_shard1_replica_n2/>
to http://test.com:8983/solr/test_shard1_replica_n2/
<http://stg-toyota-search--2.i.kandasearch.com:8983/solr/test-mcf_shard1_replica_n2/>
=> java.io.IOException: java.util.concurrent.TimeoutException: Total
timeout 600000 ms elapsed
at
org.eclipse.jetty.client.util.DeferredContentProvider.flush(DeferredContentProvider.java:197)
java.io.IOException: java.util.concurrent.TimeoutException: Total timeout
600000 ms elapsed
at
org.eclipse.jetty.client.util.DeferredContentProvider.flush(DeferredContentProvider.java:197)
~[?:?]
at
org.eclipse.jetty.client.util.OutputStreamContentProvider$DeferredOutputStream.flush(OutputStreamContentProvider.java:151)
~[?:?]
at
org.eclipse.jetty.client.util.OutputStreamContentProvider$DeferredOutputStream.write(OutputStreamContentProvider.java:145)
~[?:?]
at
org.apache.solr.common.util.FastOutputStream.flush(FastOutputStream.java:207)
~[?:?]
at
org.apache.solr.common.util.FastOutputStream.flushBuffer(FastOutputStream.java:200)
~[?:?]
at org.apache.solr.common.util.JavaBinCodec.marshal(JavaBinCodec.java:169)
~[?:?]
at
org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.marshal(JavaBinUpdateRequestCodec.java:100)
~[?:?]
at
org.apache.solr.client.solrj.impl.BinaryRequestWriter.write(BinaryRequestWriter.java:80)
~[?:?]
at
org.apache.solr.client.solrj.impl.Http2SolrClient.send(Http2SolrClient.java:367)
~[?:?]
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient$Runner.sendUpdateStream(ConcurrentUpdateHttp2SolrClient.java:238)
~[?:?]
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient$Runner.run(ConcurrentUpdateHttp2SolrClient.java:180)
~[?:?]
at
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180)
~[metrics-core-4.1.5.jar:4.1.5]
at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:271)
~[?:?]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
~[?:?]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
~[?:?]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
Suppressed: java.io.IOException: java.util.concurrent.TimeoutException:
Total timeout 600000 ms elapsed
at
org.eclipse.jetty.client.util.DeferredContentProvider.flush(DeferredContentProvider.java:197)
~[?:?]
at
org.eclipse.jetty.client.util.OutputStreamContentProvider$DeferredOutputStream.flush(OutputStreamContentProvider.java:151)
~[?:?]
at
org.eclipse.jetty.client.util.OutputStreamContentProvider$DeferredOutputStream.write(OutputStreamContentProvider.java:145)
~[?:?]
at
org.apache.solr.common.util.FastOutputStream.flush(FastOutputStream.java:207)
~[?:?]
at
org.apache.solr.common.util.FastOutputStream.flushBuffer(FastOutputStream.java:200)
~[?:?]
at org.apache.solr.common.util.JavaBinCodec.close(JavaBinCodec.java:1286)
~[?:?]
at
org.apache.solr.client.solrj.request.JavaBinUpdateRequestCodec.marshal(JavaBinUpdateRequestCodec.java:99)
~[?:?]
at
org.apache.solr.client.solrj.impl.BinaryRequestWriter.write(BinaryRequestWriter.java:80)
~[?:?]
at
org.apache.solr.client.solrj.impl.Http2SolrClient.send(Http2SolrClient.java:367)
~[?:?]
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient$Runner.sendUpdateStream(ConcurrentUpdateHttp2SolrClient.java:238)
~[?:?]
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient$Runner.run(ConcurrentUpdateHttp2SolrClient.java:180)
~[?:?]
at
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180)
~[metrics-core-4.1.5.jar:4.1.5]
at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:271)
~[?:?]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
~[?:?]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
~[?:?]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.util.concurrent.TimeoutException: Total timeout 600000 ms
elapsed
at
org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:567)
~[?:?]
at
org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:550)
~[?:?]
at
org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:110)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.CyclicTimeouts.access$100(CyclicTimeouts.java:50)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:196)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:298)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
~[?:?]
... 3 more
Caused by: java.util.concurrent.TimeoutException: Total timeout 600000 ms
elapsed
at
org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:567)
~[?:?]
at
org.eclipse.jetty.client.HttpDestination$RequestTimeouts.onExpired(HttpDestination.java:550)
~[?:?]
at
org.eclipse.jetty.io.CyclicTimeouts.onTimeoutExpired(CyclicTimeouts.java:110)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.CyclicTimeouts.access$100(CyclicTimeouts.java:50)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.io.CyclicTimeouts$Timeouts.onTimeoutExpired(CyclicTimeouts.java:196)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.CyclicTimeout$Wakeup.run(CyclicTimeout.java:298)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
~[?:?]
... 3 more
2023-05-09 10:03:05.396 WARN (qtp1167088639-27634) [c:test s:shard1 r:
core_node3 x:test_shard1_replica_n1] o.a.s.u.SolrCmdDistributor Unable to
finish sending updates => java.io.IOException: Task queue processing has
stalled for 20008 ms with 1 remaining elements to process.
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient.waitForEmptyQueue(ConcurrentUpdateHttp2SolrClient.java:602)
java.io.IOException: Task queue processing has stalled for 20008 ms with 1
remaining elements to process.
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient.waitForEmptyQueue(ConcurrentUpdateHttp2SolrClient.java:602)
~[?:?]
at
org.apache.solr.client.solrj.impl.ConcurrentUpdateHttp2SolrClient.blockUntilFinished(ConcurrentUpdateHttp2SolrClient.java:475)
~[?:?]
at
org.apache.solr.update.StreamingSolrClients.blockUntilFinished(StreamingSolrClients.java:87)
~[?:?]
at
org.apache.solr.update.SolrCmdDistributor.blockAndDoRetries(SolrCmdDistributor.java:292)
~[?:?]
at
org.apache.solr.update.SolrCmdDistributor.finish(SolrCmdDistributor.java:91)
~[?:?]
at
org.apache.solr.update.processor.DistributedZkUpdateProcessor.doDistribFinish(DistributedZkUpdateProcessor.java:1263)
~[?:?]
at
org.apache.solr.update.processor.DistributedUpdateProcessor.finish(DistributedUpdateProcessor.java:1253)
~[?:?]
at
org.apache.solr.update.processor.LogUpdateProcessorFactory$LogUpdateProcessor.finish(LogUpdateProcessorFactory.java:197)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
com.rondhuit.solr.update.KnownWordsExtractUpdateProcessorFactory$KnownWordsExtractUpdateProcessor.finish(KnownWordsExtractUpdateProcessorFactory.java:240)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
org.apache.solr.update.processor.UpdateRequestProcessor.finish(UpdateRequestProcessor.java:78)
~[?:?]
at
org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:94)
~[?:?]
at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:224)
~[?:?]
at org.apache.solr.core.SolrCore.execute(SolrCore.java:2865) ~[?:?]
at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:887)
~[?:?]
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:606) ~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.dispatch(SolrDispatchFilter.java:250)
~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.lambda$doFilter$0(SolrDispatchFilter.java:218)
~[?:?]
at
org.apache.solr.servlet.ServletUtils.traceHttpRequestExecution2(ServletUtils.java:257)
~[?:?]
at
org.apache.solr.servlet.ServletUtils.rateLimitRequest(ServletUtils.java:227)
~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:213)
~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:195)
~[?:?]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:201)
~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1626)
~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:552)
~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600)
~[jetty-security-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
~[jetty-servlet-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:191)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.InetAccessHandler.handle(InetAccessHandler.java:177)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
~[jetty-rewrite-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:772)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.Server.handle(Server.java:516)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
~[jetty-server-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
~[jetty-io-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at
org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
~[jetty-util-9.4.48.v20220622.jar:9.4.48.v20220622]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
========================================
Kind regards,
Mingchun
