Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: EE-1.8.2.GA_P08
    • Fix Version/s: EE-1.8.2.GA_P09
    • Component/s: Framework
    • Labels:
      None
    • Environment:
      Tomcat, OC4J
    • Assignee Priority:
      P1
    • Support Case References:
       Support case #13482 and #13486

      Description

      On session expiry coupled with a page redirect causes the framework to lockup with the following thread dump:

      Found one Java-level deadlock:
      =============================
      "Session Monitor":
        waiting to lock monitor 0x003e4b9c (object 0x0a2a03a0, a java.util.HashMap),
        which is held by "HTTPThreadGroup-6"
      "HTTPThreadGroup-6":
        waiting to lock monitor 0x003e4bbc (object 0x0acf4880, a com.evermind.server.http.EvermindHttpSession),
        which is held by "Session Monitor"

      Java stack information for the threads listed above:
      ===================================================
      "Session Monitor":
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.notifySessionShutdown(SessionDispatcher.java:272)
      - waiting to lock <0x0a2a03a0> (a java.util.HashMap)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.access$400(SessionDispatcher.java:73)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener.sessionDestroyed(SessionDispatcher.java:361)
      at com.icesoft.faces.util.event.servlet.ContextEventRepeater.sessionDestroyed(ContextEventRepeater.java:319)
      at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:996)
      at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:978)
      at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:411)
      - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
      at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:378)
      - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdown(SessionDispatcher.java:445)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdownIfExpired(SessionDispatcher.java:457)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener$1.run(SessionDispatcher.java:325)
      "HTTPThreadGroup-6":
      at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:171)
      - waiting to lock <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
      at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:137)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.<init>(SessionDispatcher.java:388)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.checkSession(SessionDispatcher.java:136)
      - locked <0x0a2a03a0> (a java.util.HashMap)
      at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:96)
      at com.icesoft.faces.webapp.http.servlet.BlockExpiredSessionRequests.service(BlockExpiredSessionRequests.java:53)
      at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:55)
      at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:204)
      at ***.***Servlet.service(***Servlet.java:149)
      at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
      at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:734)
      at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
      at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
      at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
      at com.evermind.server.http.HttpRequestHandler.serveOneRequest(HttpRequestHandler.java:226)
      at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:127)
      at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:116)
      at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
      at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
      at java.lang.Thread.run(Thread.java:595)

      Found 1 deadlock.
       

        Activity

        Ken Fyten made changes -
        Status Resolved [ 5 ] Closed [ 6 ]
        Hide
        Liana Munroe added a comment -

        Tested using ICEfaces r45867, Tomcat 7, IE 11, 10, 9, FF 34, Chrome 43 with the following results:
        3 tests with FF - popup occurred at 1:02, 49 secs and 46 secs
        3 tests with Chrome - popup occurred at 49 secs, 51 secs and 44 secs
        3 tests with IE 11- popup occurred at 52 secs, 44 secs and 48 secs
        2 tests with IE 10 - popup ocurred at 47 secs, 46 secs.
        2 tests with IE 9 - popup ocurred at 52 secs, 51 secs.
        Session expired with or without using the "test" button on the page before starting timer.
        Did not have to clear browser cache or restart server between tests. Was able to test in multiple browsers without restarting server or closing other browser windows. Did not use strictSessionTimeout=true in the web.xml

        Show
        Liana Munroe added a comment - Tested using ICEfaces r45867, Tomcat 7, IE 11, 10, 9, FF 34, Chrome 43 with the following results: 3 tests with FF - popup occurred at 1:02, 49 secs and 46 secs 3 tests with Chrome - popup occurred at 49 secs, 51 secs and 44 secs 3 tests with IE 11- popup occurred at 52 secs, 44 secs and 48 secs 2 tests with IE 10 - popup ocurred at 47 secs, 46 secs. 2 tests with IE 9 - popup ocurred at 52 secs, 51 secs. Session expired with or without using the "test" button on the page before starting timer. Did not have to clear browser cache or restart server between tests. Was able to test in multiple browsers without restarting server or closing other browser windows. Did not use strictSessionTimeout=true in the web.xml
        Mircea Toma made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Mircea Toma added a comment -

        Indeed the previous commit introduced a regression where the session's last access timestamp is updated on any kind of request.

        The fix avoids touching the session's last access time for any request (push requests in particular) and initialises the timestamp only when the session monitor is created.

        Show
        Mircea Toma added a comment - Indeed the previous commit introduced a regression where the session's last access timestamp is updated on any kind of request. The fix avoids touching the session's last access time for any request (push requests in particular) and initialises the timestamp only when the session monitor is created.
        Repository Revision Date User Message
        ICEsoft Public SVN Repository #45863 Tue Aug 18 13:31:06 MDT 2015 mircea.toma ICE-10758 Avoid touching the session's last access time for any request (push requests in particular).
        Files Changed
        Commit graph MODIFY /icefaces/trunk/icefaces/core/src/com/icesoft/faces/webapp/http/servlet/SessionDispatcher.java
        Hide
        Ken Fyten added a comment -

        Seems like it only works the 1st time after a cleared cache and server restart reliably, or something like that. Try multiple browsers with multiple test attempts without clearing the cache to reproduce.

        Show
        Ken Fyten added a comment - Seems like it only works the 1st time after a cleared cache and server restart reliably, or something like that. Try multiple browsers with multiple test attempts without clearing the cache to reproduce.
        Hide
        Liana Munroe added a comment -

        Used strictSessionTimeout=true in the web.xml
        3 tests with FF - popup occurred at 1:30, 49 secs and 1:26
        3 tests with IE - similar time frames to FF test
        1 test with Chrome with cleared cache, popup occurred at 1:30,
        2 tests with Chrome - no popup. Stopped tests after 2 mins each. (cache was not cleared for these tests)

        Show
        Liana Munroe added a comment - Used strictSessionTimeout=true in the web.xml 3 tests with FF - popup occurred at 1:30, 49 secs and 1:26 3 tests with IE - similar time frames to FF test 1 test with Chrome with cleared cache, popup occurred at 1:30, 2 tests with Chrome - no popup. Stopped tests after 2 mins each. (cache was not cleared for these tests)
        Hide
        Arran Mccullough added a comment -

        I'm seeing inconsistent results now. I'm able to see the popup now with my test case (running on Tomcat 8.0.9.0). Yesterday I wasn't able to see this popup, now I can. Even after cleaning out my browser and Tomcat caches I wasn't getting the timeout popup. I can consistently see it now though...

        Show
        Arran Mccullough added a comment - I'm seeing inconsistent results now. I'm able to see the popup now with my test case (running on Tomcat 8.0.9.0). Yesterday I wasn't able to see this popup, now I can. Even after cleaning out my browser and Tomcat caches I wasn't getting the timeout popup. I can consistently see it now though...
        Hide
        Mircea Toma added a comment -

        The test ran fine for me. I could see the session expiry popup after 1 minute. What server do you use?

        Show
        Mircea Toma added a comment - The test ran fine for me. I could see the session expiry popup after 1 minute. What server do you use?
        Ken Fyten made changes -
        Resolution Fixed [ 1 ]
        Status Resolved [ 5 ] Reopened [ 4 ]
        Arran Mccullough made changes -
        Attachment Case13482Example.war [ 20880 ]
        Hide
        Arran Mccullough added a comment -

        Attached test case.

        After 1 min of inactivity the User Session Expired popup should be shown. Even after clicking the commandButton 'Test' the session is not expired.

        Show
        Arran Mccullough added a comment - Attached test case. After 1 min of inactivity the User Session Expired popup should be shown. Even after clicking the commandButton 'Test' the session is not expired.
        Hide
        Arran Mccullough added a comment -

        When I do my testing I shut the server down and start it again between tests. This should apply the session timeout value correct? If I change the jars from the patched build to the standard P08 release, I can see the timeout correctly. I have it set to 1 minute in my sample. The customer is setting the timeout as follows:

        We are setting the session timeout on our ServletFilter by calling session.setMaxInactiveInterval()

        When they test between the patched P08 and P04 releases they have in use, they get the timeout in the P04 jars but not with the P08.

        Show
        Arran Mccullough added a comment - When I do my testing I shut the server down and start it again between tests. This should apply the session timeout value correct? If I change the jars from the patched build to the standard P08 release, I can see the timeout correctly. I have it set to 1 minute in my sample. The customer is setting the timeout as follows: We are setting the session timeout on our ServletFilter by calling session.setMaxInactiveInterval() When they test between the patched P08 and P04 releases they have in use, they get the timeout in the P04 jars but not with the P08.
        Mircea Toma made changes -
        Status Reopened [ 4 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Mircea Toma added a comment -

        I don't see any problems with the session expiration. Arran, please make sure you restart the app server after you modify the expiry timeout, Tomcat will pick the new value on restart only.

        Show
        Mircea Toma added a comment - I don't see any problems with the session expiration. Arran, please make sure you restart the app server after you modify the expiry timeout, Tomcat will pick the new value on restart only.
        Arran Mccullough made changes -
        Resolution Fixed [ 1 ]
        Status Resolved [ 5 ] Reopened [ 4 ]
        Hide
        Arran Mccullough added a comment -

        Found an issue with these changes. The session no longer expires on session timeout/inactivity.

        Show
        Arran Mccullough added a comment - Found an issue with these changes. The session no longer expires on session timeout/inactivity.
        Mircea Toma made changes -
        Status Open [ 1 ] Resolved [ 5 ]
        Resolution Fixed [ 1 ]
        Hide
        Mircea Toma added a comment -

        Modified SessionDispatcher.checkSession method to associate the monitor to the session outside the synchronized block thus avoiding potential deadlocks when HttpSession implementation is synchronized.

        Show
        Mircea Toma added a comment - Modified SessionDispatcher.checkSession method to associate the monitor to the session outside the synchronized block thus avoiding potential deadlocks when HttpSession implementation is synchronized.
        Repository Revision Date User Message
        ICEsoft Public SVN Repository #45813 Tue Aug 04 10:57:18 MDT 2015 mircea.toma ICE-10758 Associate monitor to session outside the synchronized block to avoid deadlocks when HttpSession implementation is synchronized.
        Files Changed
        Commit graph MODIFY /icefaces/trunk/icefaces/core/src/com/icesoft/faces/webapp/http/servlet/SessionDispatcher.java
        Ken Fyten made changes -
        Assignee Priority P1 [ 10010 ]
        Mircea Toma made changes -
        Fix Version/s EE-1.8.2.GA_P09 [ 12470 ]
        Mircea Toma made changes -
        Assignee Mircea Toma [ mircea.toma ]
        Mircea Toma made changes -
        Support Case References  Support case #13482 and #13486
        Mircea Toma made changes -
        Field Original Value New Value
        Description On session expiry coupled with a page redirect causes the framework to lockup with the following thread dump:

        Found one Java-level deadlock:
        =============================
        "Session Monitor":
          waiting to lock monitor 0x003e4b9c (object 0x0a2a03a0, a java.util.HashMap),
          which is held by "HTTPThreadGroup-6"
        "HTTPThreadGroup-6":
          waiting to lock monitor 0x003e4bbc (object 0x0acf4880, a com.evermind.server.http.EvermindHttpSession),
          which is held by "Session Monitor"

        Java stack information for the threads listed above:
        ===================================================
        "Session Monitor":
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.notifySessionShutdown(SessionDispatcher.java:272)
        - waiting to lock <0x0a2a03a0> (a java.util.HashMap)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.access$400(SessionDispatcher.java:73)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener.sessionDestroyed(SessionDispatcher.java:361)
        at com.icesoft.faces.util.event.servlet.ContextEventRepeater.sessionDestroyed(ContextEventRepeater.java:319)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:996)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:978)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:411)
        - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:378)
        - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdown(SessionDispatcher.java:445)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdownIfExpired(SessionDispatcher.java:457)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener$1.run(SessionDispatcher.java:325)
        "HTTPThreadGroup-6":
        at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:171)
        - waiting to lock <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:137)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.<init>(SessionDispatcher.java:388)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.checkSession(SessionDispatcher.java:136)
        - locked <0x0a2a03a0> (a java.util.HashMap)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:96)
        at com.icesoft.faces.webapp.http.servlet.BlockExpiredSessionRequests.service(BlockExpiredSessionRequests.java:53)
        at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:55)
        at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:204)
        at ***.***Servlet.service(KmfServlet.java:149)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
        at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:734)
        at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
        at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
        at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
        at com.evermind.server.http.HttpRequestHandler.serveOneRequest(HttpRequestHandler.java:226)
        at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:127)
        at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:116)
        at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
        at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
        at java.lang.Thread.run(Thread.java:595)

        Found 1 deadlock.
         
        On session expiry coupled with a page redirect causes the framework to lockup with the following thread dump:

        Found one Java-level deadlock:
        =============================
        "Session Monitor":
          waiting to lock monitor 0x003e4b9c (object 0x0a2a03a0, a java.util.HashMap),
          which is held by "HTTPThreadGroup-6"
        "HTTPThreadGroup-6":
          waiting to lock monitor 0x003e4bbc (object 0x0acf4880, a com.evermind.server.http.EvermindHttpSession),
          which is held by "Session Monitor"

        Java stack information for the threads listed above:
        ===================================================
        "Session Monitor":
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.notifySessionShutdown(SessionDispatcher.java:272)
        - waiting to lock <0x0a2a03a0> (a java.util.HashMap)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.access$400(SessionDispatcher.java:73)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener.sessionDestroyed(SessionDispatcher.java:361)
        at com.icesoft.faces.util.event.servlet.ContextEventRepeater.sessionDestroyed(ContextEventRepeater.java:319)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:996)
        at com.evermind.server.http.HttpApplication.invalidateSession(HttpApplication.java:978)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:411)
        - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.evermind.server.http.EvermindHttpSession.invalidate(EvermindHttpSession.java:378)
        - locked <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdown(SessionDispatcher.java:445)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.shutdownIfExpired(SessionDispatcher.java:457)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Listener$1.run(SessionDispatcher.java:325)
        "HTTPThreadGroup-6":
        at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:171)
        - waiting to lock <0x0acf4880> (a com.evermind.server.http.EvermindHttpSession)
        at com.evermind.server.http.EvermindHttpSession.setAttribute(EvermindHttpSession.java:137)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher$Monitor.<init>(SessionDispatcher.java:388)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.checkSession(SessionDispatcher.java:136)
        - locked <0x0a2a03a0> (a java.util.HashMap)
        at com.icesoft.faces.webapp.http.servlet.SessionDispatcher.service(SessionDispatcher.java:96)
        at com.icesoft.faces.webapp.http.servlet.BlockExpiredSessionRequests.service(BlockExpiredSessionRequests.java:53)
        at com.icesoft.faces.webapp.http.servlet.PathDispatcher.service(PathDispatcher.java:55)
        at com.icesoft.faces.webapp.http.servlet.MainServlet.service(MainServlet.java:204)
        at ***.***Servlet.service(***Servlet.java:149)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
        at com.evermind.server.http.ServletRequestDispatcher.invoke(ServletRequestDispatcher.java:734)
        at com.evermind.server.http.ServletRequestDispatcher.forwardInternal(ServletRequestDispatcher.java:391)
        at com.evermind.server.http.HttpRequestHandler.doProcessRequest(HttpRequestHandler.java:908)
        at com.evermind.server.http.HttpRequestHandler.processRequest(HttpRequestHandler.java:458)
        at com.evermind.server.http.HttpRequestHandler.serveOneRequest(HttpRequestHandler.java:226)
        at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:127)
        at com.evermind.server.http.HttpRequestHandler.run(HttpRequestHandler.java:116)
        at oracle.oc4j.network.ServerSocketReadHandler$SafeRunnable.run(ServerSocketReadHandler.java:260)
        at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
        at java.lang.Thread.run(Thread.java:595)

        Found 1 deadlock.
         
        Mircea Toma created issue -

          People

          • Assignee:
            Mircea Toma
            Reporter:
            Mircea Toma
          • Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: