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

Log spam when a user's session expires while viewing the repositories UI

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 3.2.0
    • Fix Version/s: 3.3.0
    • Component/s: Logging
    • Labels:
    • Story Points:
      1
    • Sprint:
      Sprint 91, Formats/Core Team - Sprint 92

      Description

      When you're looking at the repository list in the nexus UI it polls the repository status using this call:

      127.0.0.1 - - [07/Feb/2017:12:38:36 -0500] "GET /service/extdirect/poll/coreui_Repository_readStatus?_dc=1486489116483 HTTP/1.1" 200 189 8

      When a user's session expires, the poll request fails. This is logged at ERROR level with a stack trace.

      This should not be logged at ERROR, this is a normal occurrence. The message should be logged at INFO, and the stack trace logged at DEBUG. The message should be logged at DEBUG with no stack trace (and should definitely not be at ERROR level).

      2017-02-07 12:12:38,363-0500 ERROR [qtp599637027-208] *UNKNOWN org.sonatype.nexus.extdirect.internal.ExtDirectServlet - Failed to invoke action method: coreui_Repository.coreui_Repository_readStatus, java-method: org.sonatype.nexus.coreui.RepositoryComponent.readStatus 
      org.apache.shiro.authz.UnauthenticatedException: The current Subject is not authenticated. Access denied. 
      at org.apache.shiro.authz.aop.AuthenticatedAnnotationHandler.assertAuthorized(AuthenticatedAnnotationHandler.java:53) [na:na] 
      at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.assertAuthorized(AuthorizingAnnotationMethodInterceptor.java:84) [na:na] 
      at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.invoke(AuthorizingAnnotationMethodInterceptor.java:67) [na:na] 
      at org.apache.shiro.guice.aop.AopAllianceMethodInterceptorAdapter.invoke(AopAllianceMethodInterceptorAdapter.java:36) [na:na] 
      at sun.reflect.GeneratedMethodAccessor252.invoke(Unknown Source) [na:na] 
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [na:1.8.0_31] 
      at java.lang.reflect.Method.invoke(Method.java:483) [na:1.8.0_31] 
      at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeJavaMethod(DispatcherBase.java:142) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.invokeMethod(DispatcherBase.java:133) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at org.sonatype.nexus.extdirect.internal.ExtDirectServlet$3.invokeMethod(ExtDirectServlet.java:221) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.router.dispatcher.DispatcherBase.dispatch(DispatcherBase.java:63) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.router.processor.poll.PollRequestProcessor.process(PollRequestProcessor.java:145) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at org.sonatype.nexus.extdirect.internal.ExtDirectServlet$4.processPollRequest(ExtDirectServlet.java:315) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.processRequest(DirectJNgineServlet.java:621) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doPost(DirectJNgineServlet.java:580) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at org.sonatype.nexus.extdirect.internal.ExtDirectServlet.doPost(ExtDirectServlet.java:127) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at com.softwarementors.extjs.djn.servlet.DirectJNgineServlet.doGet(DirectJNgineServlet.java:553) [org.sonatype.nexus.extdirect:3.2.0.01] 
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) [javax.servlet-api:3.1.0] 
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) [javax.servlet-api:3.1.0] 
      at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:286) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:276) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:181) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.DynamicServletPipeline.service(DynamicServletPipeline.java:71) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) [com.google.inject:4.1.0] 
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:112) [org.apache.shiro.web:1.3.2] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:61) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.AdviceFilter.executeChain(AdviceFilter.java:108) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.AdviceFilter.doFilterInternal(AdviceFilter.java:137) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.ProxiedFilterChain.doFilter(ProxiedFilterChain.java:66) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449) [org.apache.shiro.web:1.3.2] 
      at org.sonatype.nexus.security.SecurityFilter.executeChain(SecurityFilter.java:85) [org.sonatype.nexus.security:3.2.0.01] 
      at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365) [org.apache.shiro.web:1.3.2] 
      at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90) [org.apache.shiro.core:1.3.2] 
      at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83) [org.apache.shiro.core:1.3.2] 
      at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383) [org.apache.shiro.core:1.3.2] 
      at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362) [org.apache.shiro.web:1.3.2] 
      at org.sonatype.nexus.security.SecurityFilter.doFilterInternal(SecurityFilter.java:101) [org.sonatype.nexus.security:3.2.0.01] 
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [org.apache.shiro.web:1.3.2] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at com.sonatype.nexus.licensing.internal.LicensingRedirectFilter.doFilter(LicensingRedirectFilter.java:112) [com.sonatype.nexus.plugins.nexus-licensing-plugin:3.2.0.01] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at com.codahale.metrics.servlet.AbstractInstrumentedFilter.doFilter(AbstractInstrumentedFilter.java:97) [com.codahale.metrics.servlet:3.0.2] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at org.sonatype.nexus.internal.web.ErrorPageFilter.doFilter(ErrorPageFilter.java:68) [org.sonatype.nexus.base:3.2.0.01] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at org.sonatype.nexus.internal.web.EnvironmentFilter.doFilter(EnvironmentFilter.java:102) [org.sonatype.nexus.base:3.2.0.01] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at org.sonatype.nexus.internal.web.HeaderPatternFilter.doFilter(HeaderPatternFilter.java:98) [org.sonatype.nexus.base:3.2.0.01] 
      at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.DynamicFilterPipeline.dispatch(DynamicFilterPipeline.java:104) [com.google.inject:4.1.0] 
      at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:135) [com.google.inject:4.1.0] 
      at org.sonatype.nexus.bootstrap.osgi.DelegatingFilter.doFilter(DelegatingFilter.java:73) [org.sonatype.nexus.bootstrap:3.2.0.01] 
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) [org.eclipse.jetty.servlet:9.3.7.v20160115] 
      at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) [org.eclipse.jetty.servlet:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [org.eclipse.jetty.security:9.3.7.v20160115] 
      at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1158) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) [org.eclipse.jetty.servlet:9.3.7.v20160115] 
      at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1090) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:175) [com.codahale.metrics.jetty9:3.0.2] 
      at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:119) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.Server.handle(Server.java:517) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:242) [org.eclipse.jetty.server:9.3.7.v20160115] 
      at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [org.eclipse.jetty.io:9.3.7.v20160115] 
      at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [org.eclipse.jetty.io:9.3.7.v20160115] 
      at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:75) [org.eclipse.jetty.io:9.3.7.v20160115] 
      at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:213) [org.eclipse.jetty.util:9.3.7.v20160115] 
      at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:147) [org.eclipse.jetty.util:9.3.7.v20160115] 
      at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654) [org.eclipse.jetty.util:9.3.7.v20160115] 
      at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572) [org.eclipse.jetty.util:9.3.7.v20160115] 
      at java.lang.Thread.run(Thread.java:745) [na:1.8.0_31] 
      Caused by: org.apache.shiro.authz.AuthorizationException: Not authorized to invoke method: public java.util.List org.sonatype.nexus.coreui.RepositoryComponent.readStatus(java.util.Map) 
      at org.apache.shiro.authz.aop.AuthorizingAnnotationMethodInterceptor.assertAuthorized(AuthorizingAnnotationMethodInterceptor.java:90) [na:na] 
      ... 81 common frames omitted
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              jstephens Joseph Stephens
              Reporter:
              rseddon Rich Seddon
              Last Updated By:
              Peter Lynch
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:
                Date of First Response:

                  tigCommentSecurity.panel-title