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

[Regression] First hit of login page generates stacktrace (only in Wicket development mode)

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Normal
    • Resolution: Cannot Reproduce
    • 5.1.0
    • None
    • None
    • None
    • 0
    • Tiger
    • Tiger Sprint 159, Tiger Sprint 166, Tiger Sprint 167

    Description

      This was fixed previously but I am getting the same stack traces again.

      ========================================================

      After each fresh start of Tomcat, the CMS login page generates a stack trace (see below). This only happens when you request the page from a browser that has logged in to the CMS before (i.e. there's already a JSESSIONID cookie) and the CMS runs in Wicket development mode.

      These stack traces are annoying for product developers. And while the system seems to works fine, the phrase "Please review your code for proper session management" from Jackrabbit suggests there's a deeper problem going on. It's also a bit fishy that this only happens in Wicket development mode.

      Steps to reproduce:

      1. Start a CMS
      mvn -Pcargo.run -Drepo.path=storage
      1. Request the login page (http://localhost:8080/cms)
      2. Stop the CMS
      3. Start the CMS again in Wicket development mode
      mvn -Pcargo.run -Drepo.path=storage -Dcargo.jvm.args='-Dwicket.configuration=development'
      1. Request the login page again in the same browser

      Expected: no errors logged

      Actual: a stacktrace like this is logged:

      [echo] Press Ctrl-C to stop the Cargo container...
26.04.2017 09:23:06 WARN http-nio-8080-exec-8 [SessionState.close:283] Attempt to close session-31 after it has already been closed. Please review your code for proper session management.
java.lang.Exception: Stack trace of the duplicate attempt to close session-31
at org.apache.jackrabbit.core.session.SessionState.close(SessionState.java:280) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:987) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:399) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.hippoecm.repository.jackrabbit.XASessionImpl.logout(XASessionImpl.java:170) [hippo-repository-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.repository.decorating.SessionDecorator.logout(SessionDecorator.java:292) [hippo-repository-connector-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.repository.impl.SessionDecorator.logout(SessionDecorator.java:331) [hippo-repository-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.frontend.session.PluginUserSession.detach(PluginUserSession.java:452) [hippo-cms-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.apache.wicket.request.cycle.RequestCycle.onDetach(RequestCycle.java:645) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.request.cycle.RequestCycle.detach(RequestCycle.java:589) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:293) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.processRequestCycle(WicketFilter.java:259) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:201) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.doFilter(WicketFilter.java:282) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [catalina.jar:8.5.12]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [catalina.jar:8.5.12]
at org.hippoecm.frontend.plugins.login.ConcurrentLoginFilter.doFilter(ConcurrentLoginFilter.java:54) [hippo-cms-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [catalina.jar:8.5.12]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardContextValve.__invoke(StandardContextValve.java:96) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java) [catalina.jar:8.5.12]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [catalina.jar:8.5.12]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) [catalina.jar:8.5.12]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.12]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341) [catalina.jar:8.5.12]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:783) [tomcat-coyote.jar:8.5.12]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:8.5.12]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:798) [tomcat-coyote.jar:8.5.12]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1441) [tomcat-coyote.jar:8.5.12]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.12]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.12]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
26.04.2017 09:23:06 WARN http-nio-8080-exec-8 [SessionState.close:286] session-31 has already been closed. See the attached exception for a trace of where this session was closed.
java.lang.Exception: Stack trace of where session-31 was originally closed
at org.apache.jackrabbit.core.session.SessionState.close(SessionState.java:275) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.apache.jackrabbit.core.SessionImpl.logout(SessionImpl.java:987) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.apache.jackrabbit.core.XASessionImpl.logout(XASessionImpl.java:399) [jackrabbit-core-2.14.0-h1-SNAPSHOT.jar:2.14.0-h1-SNAPSHOT]
at org.hippoecm.repository.jackrabbit.XASessionImpl.logout(XASessionImpl.java:170) [hippo-repository-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.repository.decorating.SessionDecorator.logout(SessionDecorator.java:292) [hippo-repository-connector-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.repository.impl.SessionDecorator.logout(SessionDecorator.java:331) [hippo-repository-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.hippoecm.frontend.session.PluginUserSession.detach(PluginUserSession.java:452) [hippo-cms-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.apache.wicket.request.cycle.RequestCycle.onDetach(RequestCycle.java:645) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.request.cycle.RequestCycle.detach(RequestCycle.java:589) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:293) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.processRequestCycle(WicketFilter.java:259) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:201) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.wicket.protocol.http.WicketFilter.doFilter(WicketFilter.java:282) [wicket-core-6.19.0.jar:6.19.0]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [catalina.jar:8.5.12]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [catalina.jar:8.5.12]
at org.hippoecm.frontend.plugins.login.ConcurrentLoginFilter.doFilter(ConcurrentLoginFilter.java:54) [hippo-cms-engine-5.0.0-visual-editing-psp2-SNAPSHOT.jar:5.0.0-visual-editing-psp2-SNAPSHOT]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:192) [catalina.jar:8.5.12]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:165) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardContextValve.__invoke(StandardContextValve.java:96) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java) [catalina.jar:8.5.12]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [catalina.jar:8.5.12]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80) [catalina.jar:8.5.12]
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:624) [catalina.jar:8.5.12]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [catalina.jar:8.5.12]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:341) [catalina.jar:8.5.12]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:783) [tomcat-coyote.jar:8.5.12]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:8.5.12]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:798) [tomcat-coyote.jar:8.5.12]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1441) [tomcat-coyote.jar:8.5.12]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:8.5.12]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_131]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.5.12]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. CMS-10713 First hit of login page generates stacktrace (only in Wicket development mode)

          • Normal - Normal priority, tasks to be done before next intermediate release
          • Closed

          Activity

            People

              Unassigned Unassigned
              abogaart Arthur Bogaart
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: