You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@solr.apache.org by Dominic Humphries <do...@adzuna.com.INVALID> on 2021/08/31 15:54:39 UTC
"The request took too long" cause exceptions in upgrade testing
I'm trying to upgrade from 8.3.1 to 8.8.1, and we're seeing slower
performance and higher rate of failed requests when testing the upgrade.
The main culprit seems to be when we're burdening the service enough to
start causing "The request took too long to iterate over doc/point values"
warnings. On 8.3.1 these warnings are just that and no more; but on 8.8.1
the warning gets a full stack trace in the logs (See below). AIUI (my
Java's not great) this indicates an uncaught exception that could easily
explain the performance and request failures. But I don't understand why
we're getting such an exception for 8.8.1 when we don't for 8.3.1. Is there
anything I can do about this?
Thanks
Dom
2021-08-31 14:02:37.967 WARN (qtp1037163664-65) [ x:jobs_UK]
o.a.s.h.c.SearchHandler Query: <truncated> =>
org.apache.lucene.index.ExitableDirectoryReader$ExitingReaderException: The
request took too long to iterate over doc values. Timeout: timeoutAt:
25316267453971 (System.nanoTime(): 25317582929106),
DocValues=org.apache.lucene.codecs.lucene80.Lucene80DocValuesProducer$8@18ff1305
at
org.apache.lucene.index.ExitableDirectoryReader$ExitableFilterAtomicReader.checkAndThrow(ExitableDirectoryReader.java:319)
org.apache.lucene.index.ExitableDirectoryReader$ExitingReaderException: The
request took too long to iterate over doc values. Timeout: timeoutAt:
25316267453971 (System.nanoTime(): 25317582929106),
DocValues=org.apache.lucene.codecs.lucene80.Lucene80DocValuesProducer$8@18ff1305
at
org.apache.lucene.index.ExitableDirectoryReader$ExitableFilterAtomicReader.checkAndThrow(ExitableDirectoryReader.java:319)
~[?:?]
at
org.apache.lucene.index.ExitableDirectoryReader$ExitableFilterAtomicReader.access$100(ExitableDirectoryReader.java:73)
~[?:?]
at
org.apache.lucene.index.ExitableDirectoryReader$ExitableFilterAtomicReader$1.advance(ExitableDirectoryReader.java:127)
~[?:?]
at
org.apache.lucene.queries.function.valuesource.FloatFieldSource$1.getValueForDoc(FloatFieldSource.java:67)
~[?:?]
at
org.apache.lucene.queries.function.valuesource.FloatFieldSource$1.exists(FloatFieldSource.java:83)
~[?:?]
at
org.apache.solr.handler.component.NumericStatsValues.accumulate(StatsValuesFactory.java:484)
~[?:?]
at
org.apache.solr.handler.component.StatsField.computeLocalValueSourceStats(StatsField.java:472)
~[?:?]
at
org.apache.solr.handler.component.StatsField.computeLocalStatsValues(StatsField.java:431)
~[?:?]
at
org.apache.solr.handler.component.StatsComponent.process(StatsComponent.java:60)
~[?:?]
at
org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:355)
~[?:?]
at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:216)
~[?:?]
at org.apache.solr.core.SolrCore.execute(SolrCore.java:2646) ~[?:?]
at
org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:794) ~[?:?]
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:567)
~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:427)
~[?:?]
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:357)
~[?:?]
at
org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:201)
~[jetty-servlet-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
~[jetty-servlet-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
~[jetty-servlet-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:602)
~[jetty-security-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1612)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
~[jetty-servlet-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1582)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:191)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.InetAccessHandler.handle(InetAccessHandler.java:177)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
~[jetty-rewrite-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at org.eclipse.jetty.server.Server.handle(Server.java:516)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
~[jetty-io-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
~[jetty-io-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
~[jetty-io-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at
org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
at java.lang.Thread.run(Thread.java:834) [?:?]