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

Could not dispatch event RepositoryStoppedEvent to RepositoryAuditor at migration end because the session id was not valid

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: New
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 3.34.0
    • Fix Version/s: None
    • Component/s: Audit, Migration
    • Labels:
    • Notability:
      3

      Description

      A migration from NXRM 2 to NXRM 3 was taking place. The migration was ended in step 8 of 9, which as by design tries to record nxrm 3 Audit events for RepositoryStopped events.

      Recording these stop events failed because the event handling code tries to determine the userid making the request from a session object and the session could not be found. This is an example of what stack trace this causes when using NXRM 3.34.0.

      Notice that the user is known to be "admin" ( since the log message includes "admin" user id ) but the event code cannot find a matching session for that user. There was no logged session deletion recorded, however there were two login session creations logged 4 seconds apart, prior to migration being ended.

      2021-09-20 14:03:16,014+0000 INFO  [qtp1538102844-13380]  admin org.sonatype.nexus.rapture.internal.security.SessionServlet - Created session for user: admin
      
      2021-09-20 14:03:20,080+0000 INFO  [qtp1538102844-18562]  admin org.sonatype.nexus.rapture.internal.security.SessionServlet - Created session for user: admin
      
      2021-09-20 14:09:30,466+0000 ERROR [plan-executor-14-thread-10]  admin com.google.common.eventbus.EventBus.nexus - Could not dispatch event RepositoryStoppedEvent{repository=RepositoryImpl$$EnhancerByGuice$$522978809{type=hosted, format=maven2, name='agent-plugin-releases'}} to subscriber org.sonatype.nexus.repository.manager.internal.RepositoryAuditor@1f945939 method [public void org.sonatype.nexus.repository.manager.internal.RepositoryAuditor.on(org.sonatype.nexus.repository.RepositoryEvent)]
      org.apache.shiro.session.UnknownSessionException: There is no session with id [ea61d40b-f777-444e-800a-0bdc66df8b0a]
      	at org.apache.shiro.session.mgt.eis.AbstractSessionDAO.readSession(AbstractSessionDAO.java:170)
      	at org.apache.shiro.session.mgt.eis.CachingSessionDAO.readSession(CachingSessionDAO.java:261)
      	at org.apache.shiro.session.mgt.DefaultSessionManager.retrieveSessionFromDataSource(DefaultSessionManager.java:236)
      	at org.apache.shiro.session.mgt.DefaultSessionManager.retrieveSession(DefaultSessionManager.java:222)
      	at org.apache.shiro.session.mgt.AbstractValidatingSessionManager.doGetSession(AbstractValidatingSessionManager.java:118)
      	at org.apache.shiro.session.mgt.AbstractNativeSessionManager.lookupSession(AbstractNativeSessionManager.java:148)
      	at org.apache.shiro.session.mgt.AbstractNativeSessionManager.lookupRequiredSession(AbstractNativeSessionManager.java:152)
      	at org.apache.shiro.session.mgt.AbstractNativeSessionManager.getAttribute(AbstractNativeSessionManager.java:249)
      	at org.apache.shiro.session.mgt.DelegatingSession.getAttribute(DelegatingSession.java:141)
      	at org.apache.shiro.session.ProxiedSession.getAttribute(ProxiedSession.java:121)
      	at org.apache.shiro.subject.support.DelegatingSubject.getRunAsPrincipalsStack(DelegatingSubject.java:473)
      	at org.apache.shiro.subject.support.DelegatingSubject.getPrincipals(DelegatingSubject.java:157)
      	at org.apache.shiro.subject.support.DelegatingSubject.getPrincipal(DelegatingSubject.java:153)
      	at org.sonatype.nexus.security.UserIdHelper.get(UserIdHelper.java:55)
      	at org.sonatype.nexus.security.UserIdHelper.get(UserIdHelper.java:47)
      	at org.sonatype.nexus.audit.internal.InitiatorProviderImpl.get(InitiatorProviderImpl.java:57)
      	at org.sonatype.nexus.audit.internal.AuditRecorderImpl.record(AuditRecorderImpl.java:88)
      	at org.sonatype.nexus.audit.AuditorSupport.record(AuditorSupport.java:127)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryAuditor.on(RepositoryAuditor.java:99)
      	at sun.reflect.GeneratedMethodAccessor536.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at com.google.common.eventbus.Subscriber.invokeSubscriberMethod(Subscriber.java:87)
      	at com.google.common.eventbus.Subscriber$1.run(Subscriber.java:72)
      	at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
      	at com.google.common.eventbus.Subscriber.dispatchEvent(Subscriber.java:67)
      	at com.google.common.eventbus.Dispatcher$ImmediateDispatcher.dispatch(Dispatcher.java:186)
      	at com.google.common.eventbus.EventBus.post(EventBus.java:212)
      	at org.sonatype.nexus.internal.event.EventManagerImpl.post(EventManagerImpl.java:127)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryImpl.stop(RepositoryImpl.java:257)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryImpl$$EnhancerByGuice$$522978809.GUICE$TRAMPOLINE(<generated>)
      	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:74)
      	at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
      	at org.sonatype.nexus.common.stateguard.StateGuard$TransitionImpl.run(StateGuard.java:193)
      	at org.sonatype.nexus.common.stateguard.TransitionsInterceptor.invoke(TransitionsInterceptor.java:57)
      	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:75)
      	at com.google.inject.internal.InterceptorStackCallback.invoke(InterceptorStackCallback.java:55)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryImpl$$EnhancerByGuice$$522978809.stop(<generated>)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryManagerImpl.update(RepositoryManagerImpl.java:381)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryManagerImpl$$EnhancerByGuice$$433484108.GUICE$TRAMPOLINE(<generated>)
      	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:74)
      	at org.sonatype.nexus.common.stateguard.MethodInvocationAction.run(MethodInvocationAction.java:39)
      	at org.sonatype.nexus.common.stateguard.StateGuard$GuardImpl.run(StateGuard.java:272)
      	at org.sonatype.nexus.common.stateguard.GuardedInterceptor.invoke(GuardedInterceptor.java:54)
      	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:75)
      	at com.google.inject.internal.InterceptorStackCallback.invoke(InterceptorStackCallback.java:55)
      	at org.sonatype.nexus.repository.manager.internal.RepositoryManagerImpl$$EnhancerByGuice$$433484108.update(<generated>)
      	at org.sonatype.nexus.repository.manager.RepositoryManager$update$1.call(Unknown Source)
      	at com.sonatype.nexus.migration.repository.RepositoryFinishStep.doRun(RepositoryFinishStep.groovy:125)
      	at com.sonatype.nexus.migration.plan.Step.run(Step.groovy:271)
      	at com.sonatype.nexus.migration.plan.Step$run$1.call(Unknown Source)
      	at com.sonatype.nexus.migration.plan.StepExecutor.runSync(StepExecutor.groovy:168)
      	at sun.reflect.GeneratedMethodAccessor316.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:98)
      	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
      	at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:352)
      	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1034)
      	at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:68)
      	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:169)
      	at com.sonatype.nexus.migration.plan.StepExecutor$_runAsync_closure1.doCall(StepExecutor.groovy:197)
      	at com.sonatype.nexus.migration.plan.StepExecutor$_runAsync_closure1.doCall(StepExecutor.groovy)
      	at sun.reflect.GeneratedMethodAccessor375.invoke(Unknown Source)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:98)
      	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
      	at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:264)
      	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1034)
      	at groovy.lang.Closure.call(Closure.java:420)
      	at groovy.lang.Closure.call(Closure.java:414)
      	at groovy.lang.Closure.run(Closure.java:501)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      
      

      Expected

      Event handling code should not ERROR. It should log an audit event with what data it has, just because it cannot locate a session id does not warrant a failure. At the very least, it is not expected that a message is logged where the userid is known, when the cause of the logged ERROR message is that the session for that user is not known.

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            plynch Peter Lynch
            Last Updated By:
            Michael Oliverio Michael Oliverio
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Dates

              Created:
              Updated:

                tigCommentSecurity.panel-title