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) [?:?]
