You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@solr.apache.org by Ankur Gupta <ak...@gmail.com> on 2022/02/12 00:01:28 UTC

Solr 8.11.1 Read requests failing randomly.

Hello All,

I am seeing the following issue where read requests are failing
occasionally and randomly with the stack trace below.


ERROR (qtp998242313-17635) [c:collection1 s:shard15 r:core_node59 x:
collection1_shard15_replica_n56] o.a.s.h.RequestHandlerBase
org.apache.solr.client.solrj.impl.BaseHttpSolrClient$RemoteSolrException:
Error from server at null: parsing error =>
org.apache.solr.client.solrj.impl.BaseHttpSolrClient$RemoteSolrException:
Error from server at null: parsing error
        at
org.apache.solr.client.solrj.impl.Http2SolrClient.processErrorsAndResponse(Http2SolrClient.java:713)
org.apache.solr.client.solrj.impl.BaseHttpSolrClient$RemoteSolrException:
Error from server at null: parsing error
        at
org.apache.solr.client.solrj.impl.Http2SolrClient.processErrorsAndResponse(Http2SolrClient.java:713)
~[?:?]
        at
org.apache.solr.client.solrj.impl.Http2SolrClient.request(Http2SolrClient.java:421)
~[?:?]
        at
org.apache.solr.client.solrj.impl.Http2SolrClient.request(Http2SolrClient.java:776)
~[?:?]
        at
org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:369)
~[?:?]
        at
org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:297)
~[?:?]
        at
org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:371)
~[?:?]
        at
org.apache.solr.handler.component.ShardRequestor.call(ShardRequestor.java:132)
~[?:?]
        at
org.apache.solr.handler.component.ShardRequestor.call(ShardRequestor.java:41)
~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        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:218)
~[?:?]
        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:834) [?:?]
Caused by: org.apache.solr.common.SolrException: parsing error
        at
org.apache.solr.client.solrj.impl.BinaryResponseParser.processResponse(BinaryResponseParser.java:53)
~[?:?]
        at
org.apache.solr.client.solrj.impl.Http2SolrClient.processErrorsAndResponse(Http2SolrClient.java:711)
~[?:?]
        ... 15 more
Caused by: java.nio.channels.AsynchronousCloseException
        at
org.eclipse.jetty.http2.client.http.HttpConnectionOverHTTP2.close(HttpConnectionOverHTTP2.java:150)
~[?:?]
        at
org.eclipse.jetty.http2.client.http.HttpClientTransportOverHTTP2.onClose(HttpClientTransportOverHTTP2.java:175)
~[?:?]
        at
org.eclipse.jetty.http2.client.http.HttpClientTransportOverHTTP2$SessionListenerPromise.onClose(HttpClientTransportOverHTTP2.java:234)
~[?:?]
        at
org.eclipse.jetty.http2.api.Session$Listener.onClose(Session.java:214)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.notifyClose(HTTP2Session.java:1078)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.terminate(HTTP2Session.java:1995)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.lambda$sendGoAwayAndTerminate$16(HTTP2Session.java:1910)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at org.eclipse.jetty.util.Callback$5.completed(Callback.java:190)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.Callback$Nested.succeeded(Callback.java:289)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.Callback$Nested.succeeded(Callback.java:285)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$ControlEntry.succeeded(HTTP2Session.java:1259)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at java.util.ArrayList.forEach(ArrayList.java:1541) ~[?:?]
        at
org.eclipse.jetty.http2.HTTP2Flusher.finish(HTTP2Flusher.java:326)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Flusher.succeeded(HTTP2Flusher.java:318)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:293)
~[jetty-io-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381)
~[jetty-io-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Flusher.process(HTTP2Flusher.java:295)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.frame(HTTP2Session.java:729)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.frames(HTTP2Session.java:701)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.control(HTTP2Session.java:683)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.access$3100(HTTP2Session.java:80)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.sendGoAway(HTTP2Session.java:1915)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.sendGoAwayAndTerminate(HTTP2Session.java:1910)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.lambda$onGoAway$4(HTTP2Session.java:1626)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.tryRunZeroStreamsAction(HTTP2Session.java:1986)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.onGoAway(HTTP2Session.java:1710)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session$StreamsState.access$300(HTTP2Session.java:1436)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Session.onGoAway(HTTP2Session.java:446)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.parser.Parser$Listener$Wrapper.onGoAway(Parser.java:396)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.parser.BodyParser.notifyGoAway(BodyParser.java:192)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.parser.GoAwayBodyParser.onGoAway(GoAwayBodyParser.java:169)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.parser.GoAwayBodyParser.parse(GoAwayBodyParser.java:139)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at org.eclipse.jetty.http2.parser.Parser.parseBody(Parser.java:198)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at org.eclipse.jetty.http2.parser.Parser.parse(Parser.java:127)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:261)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:362)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:186)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:183)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:138)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:361)
~[http2-common-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
~[jetty-io-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
~[jetty-io-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.Invocable.invokeNonBlocking(Invocable.java:69)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.invokeTask(EatWhatYouKill.java:350)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:305)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:137)
~[jetty-util-9.4.44.v20210927.jar:9.4.44.v20210927]
        ... 4 more


Strangely the status code is logged as "status=200" for the request.


INFO  (qtp998242313-17635) [c:collection1 s:shard15 r:core_node59 x:
collection1_shard15_replica_n56] o.a.s.c.S.Request
[collection1_shard15_replica_n56]  webapp=/solr path=/customquery
rid=example.com-1446 params={qt=/customquery&_stateVer_=
collection1:150&fl=id&start=0&version=2&q=(name:(John+Doe))&sow=true&timeAllowed=600000&wt=javabin}
status=200 QTime=120014


Rerunning the same query doesn't fail. And usually responds within a couple
of millis.

I am using default timeout settings.


Any pointers are appreciated!


Thank you!