Uploaded image for project: 'Dev - Nexus Repo'
  1. Dev - Nexus Repo
  2. NEXUS-13407

Filtering in Component view can timeout with IllegalStateException: Timed out reading query result from queue after 60 seconds

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Won't Fix
    • Affects Version/s: 3.4.0
    • Fix Version/s: None
    • Component/s: Database, UI
    • Labels:

      Description

      Another area where performance is a concern, if you apply a filter which doesn't match against a large data set it triggers a full table scan and timeouts in the UI due to exceptions on the server trying to run the query. The DB being tested had 1m Components and 3m Assets in a single repository, with 100-1000's of Components/Assets in a handful of other repos.

      2017-06-14 11:27:37,269-0700 ERROR [qtp1228682909-272] admin org.sonatype.nexus.extdirect.internal.ExtDirectServlet - Failed to invoke action method: coreui_Component.read, java-method: org.sonatype.nexus.coreui.ComponentComponent.read
      java.lang.IllegalStateException: Timed out reading query result from queue 5afeed67 after 60 seconds
      	at org.sonatype.nexus.repository.storage.OrientAsyncHelper$QueueConsumingIterable.hasNext(OrientAsyncHelper.java:201)
      	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:42)
      	at com.google.common.collect.Iterators.addAll(Iterators.java:366)
      	at com.google.common.collect.Lists.newArrayList(Lists.java:165)
      	at com.google.common.collect.Lists.newArrayList(Lists.java:150)
      	at org.sonatype.nexus.repository.browse.internal.BrowseServiceImpl.getComponents(BrowseServiceImpl.java:323)
      	at org.sonatype.nexus.repository.browse.internal.BrowseServiceImpl.browseComponents(BrowseServiceImpl.java:123)
      	at org.sonatype.nexus.repository.browse.BrowseService$browseComponents.call(Unknown Source)
      	at org.sonatype.nexus.coreui.ComponentComponent.read(ComponentComponent.groovy:130)
      	at com.palominolabs.metrics.guice.ExceptionMeteredInterceptor.invoke(ExceptionMeteredInterceptor.java:49)
      	at com.palominolabs.metrics.guice.TimedInterceptor.invoke(TimedInterceptor.java:47)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeJavaMethod(DispatcherBase.java:142)
      	at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeMethod(DispatcherBase.java:133)
      	at org.sonatype.nexus.extdirect.internal.ExtDirectServlet$3.invokeMethod(ExtDirectServlet.java:227)
      	at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.dispatch(DispatcherBase.java:63)
      	at com.softwarementors.extjs.djn.router.processor.standard.StandardRequestProcessorBase.dispatchStandardMethod(StandardRequestProcessorBase.java:73)
      	at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.processIndividualRequest(JsonRequestProcessor.java:502)
      	at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.processIndividualRequestsInThisThread(JsonRequestProcessor.java:150)
      	at com.softwarementors.extjs.djn.router.processor.standard.json.JsonRequestProcessor.process(JsonRequestProcessor.java:133)
      	at com.softwarementors.extjs.djn.router.RequestRouter.processJsonRequest(RequestRouter.java:83)
      	at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.processRequest(DirectJNgineServlet.java:617)
      	at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doPost(DirectJNgineServlet.java:580)
      	at org.sonatype.nexus.extdirect.internal.ExtDirectServlet.doPost(ExtDirectServlet.java:133)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
      	at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:286)
      	at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:276)
      	at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:181)
      	at com.google.inject.servlet.DynamicServletPipeline.service(DynamicServletPipeline.java:71)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)
      	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:112)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61)
      	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
      	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
      	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
      	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
      	at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108)
      	at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137)
      	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
      	at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66)
      	at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449)
      	at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:85)
      	at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365)
      	at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
      	at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
      	at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383)
      	at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362)
      	at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:101)
      	at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at com.sonatype.nexus.licensing.internal.LicensingRedirectFilter.doFilter(LicensingRedirectFilter.java:108)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at org.sonatype.nexus.internal.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:68)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at org.sonatype.nexus.internal.web.EnvironmentFilter.doFilter(EnvironmentFilter.java:102)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at org.sonatype.nexus.internal.web.HeaderPatternFilter.doFilter(HeaderPatternFilter.java:98)
      	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
      	at com.google.inject.servlet.DynamicFilterPipeline.dispatch(DynamicFilterPipeline.java:104)
      	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:135)
      	at org.sonatype.nexus.bootstrap.osgi.DelegatingFilter.doFilter(DelegatingFilter.java:73)
      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668)
      	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
      	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
      	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
      	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1158)
      	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
      	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
      	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1090)
      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119)
      	at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:175)
      	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109)
      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119)
      	at org.eclipse.jetty.server.Server.handle(Server.java:517)
      	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
      	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:242)
      	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
      	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
      	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:75)
      	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:213)
      	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:147)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
      	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
      	at java.lang.Thread.run(Thread.java:745)
      

      Browsing the same data set without a filter presently loads the first page in ~3s.

      To exacerbate the situation, the immediacy of the filter field makes it almost impossible to avoid re-querying as you type, so multiple queries can be fired off at the same time. While the ExtDirect protocol seems to ensure that the responses come back almost simultaneously, the overhead on the DB is increased per-query.

      Also noted: Browsing an entirely empty repository, with or without a filter, took 8-10s to return... nothing.

      Mitigation

      Until this issue is resolved, users browsing very large datasets should avoid using the Browse Components table Filter field to limit results and instead use the distinct Search feature.

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            krobinson Kelly Robinson
            Last Updated By:
            Joe Tom Joe Tom
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:
              Date of First Response:

                tigCommentSecurity.panel-title