Uploaded image for project: 'Hippo CMS'
  1. Hippo CMS
  2. CMS-11629

Sometimes many stacktraces are logged during clicking through CMS or Console

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Blocker
    • Resolution: Fixed
    • None
    • 13.0.0
    • None
    • None
    • Pulsar
    • Platform 197 - Workshop+

    Description

      Most of the stacktraces resulted that a jcr session was tried to be logged out in org.hippoecm.frontend.session.PluginUserSession#resetFallbackSession which was not live anymore....which is very odd because the code is in PluginUserSession:

          private void resetFallbackSession() {
              if (fallbackSession != null) {
                  if (fallbackSession.isLive()) {
                      fallbackSession.logout();
                  }
                  fallbackSession = null;
              }
          }
      

      For some reason I do not know, the code above thus gets executed concurrently on a single PluginUserSession object! That surprised me. I am really sure that there is concurrency going on since adding a print statement resulted even that the fallbackSession was null....inside the if statement!. Changing the above to

       private synchronized void resetFallbackSession() 
      

      did avoid the already logged out issue but resulted in stacks below:

      [INFO] [talledLocalContainer] 17.12.2018 20:57:22 WARN  Finalizer [SessionImpl.finalize:1376] Unclosed session detected. The session was opened here: 
      [INFO] [talledLocalContainer] java.lang.Exception: Stack Trace
      [INFO] [talledLocalContainer] 	at org.apache.jackrabbit.core.SessionImpl.<init>(SessionImpl.java:283) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.apache.jackrabbit.core.SessionImpl.<init>(SessionImpl.java:243) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.apache.jackrabbit.core.XASessionImpl.<init>(XASessionImpl.java:106) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.repository.jackrabbit.XASessionImpl.<init>(XASessionImpl.java:67) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.repository.jackrabbit.RepositoryImpl.createSessionInstance(RepositoryImpl.java:219) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.apache.jackrabbit.core.RepositoryImpl.createSession(RepositoryImpl.java:957) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.apache.jackrabbit.core.RepositoryImpl.login(RepositoryImpl.java:1502) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.repository.jackrabbit.RepositoryImpl.login(RepositoryImpl.java:373) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.repository.impl.RepositoryDecorator.login(RepositoryDecorator.java:109) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.repository.impl.RepositoryDecorator.login(RepositoryDecorator.java:86) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.frontend.model.JcrSessionModel.login(JcrSessionModel.java:176) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.frontend.session.PluginUserSession.getJcrSession(PluginUserSession.java:199) ~[?:?]
      [INFO] [talledLocalContainer] 	at org.hippoecm.frontend.Main$4.mapRequest(Main.java:355) ~[?:?]
      

      After quite some digging, it seems that behind a single HttpSession there can be multiple PluginUserSession objects. I don't know why. Unexpected for me. It seems that there are more when having an incognito window....perhaps for fetching resources...ah now I write this, I think something like that most be the reason (incognito most likely fetches all resources again). For fetching wicket resources, no jcr session is needed and most likely this is done concurrently hence multiple threads and thus multiple PluginUserSession objects since they are thread-locals.

      This might be the cause, since fetching a resource does most likely not detach wicket components, and thus also perhaps does not always call resetFallbackSession, hence some non-logged out session stay behind.

      The reason why this happens now in version 13.0.0 is that Main.java did get:

      @Override
                      public IRequestHandler mapRequest(final Request request) {
                          final HstRequestContext requestContext = RequestContextProvider.get();
                          if (requestContext != null && requestContext instanceof HstMutableRequestContext) {
                              ((HstMutableRequestContext) requestContext).setSession(PluginUserSession.get().getJcrSession());
                          }
      

      which gets invoked for every request...thus also resources. However for resources (i think for resources),

      PluginUserSession.get().getJcrSession()
      

      results in a new anonymous jcr session login per request since the PluginUserSession does not have a jcrSessionModel object (it is null).

      For now the only simple fix I can think of is moving setting the jcr session on the hst requestcontext when there is a jcr session model in the PluginUserSession. This means that on the HstRequestContext the jcr session becomes only available after in wicket the method

      org.hippoecm.frontend.session.PluginUserSession#getJcrSessionInternal
      

      is invoked...which in practice will always be the case.

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              aschrijvers Ard Schrijvers
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: