Wicket
  1. Wicket
  2. WICKET-311

race condition between wicket.session.pagemap.LeastRecentlyAccessedEvictionStrategy and Session.getPage()

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Won't Fix
    • Affects Version/s: 1.2.3
    • Fix Version/s: 1.2.7
    • Component/s: wicket
    • Labels:
      None
    • Environment:
      Glassfish, Open Portlet Container

      Description

      I'm seeing a race condition when using PortletApplication (probably because of overlapping RENDER and ACTION phases)

      One thread is stopped here:

      wicket.session.pagemap.LeastRecentlyAccessedEvictionStrategy.evict(LeastRecentlyAccessedEvictionStrategy.java:60)
      wicket.Page.endVersion(Page.java:1136)
      wicket.Page.internalOnDetach(Page.java:811)
      wicket.Component.internalDetach(Component.java:2571)
      wicket.MarkupContainer.internalDetach(MarkupContainer.java:374)
      wicket.Page.internalDetach(Page.java:300)
      wicket.request.target.component.PageRequestTarget.detach(PageRequestTarget.java:84)
      wicket.RequestCycle.detach(RequestCycle.java:807)
      wicket.RequestCycle.steps(RequestCycle.java:1102)
      wicket.RequestCycle.request(RequestCycle.java:454)
      wicket.protocol.http.portlet.WicketPortlet.render(WicketPortlet.java:250)

      The other throws an exception after 1 minute here:

      wicket.WicketRuntimeException: After 1 minute the Pagemap null is still locked by: Thread[httpWorkerThread-8080-0,10,Grizzly], giving up trying to get the page for path: 0:tabs:panel:tasklist:topToolbars:1:toolbar:span:navigator:navigation:4:pageLink
      at wicket.Session.getPage(Session.java:440)
      at wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolveRenderedPage(PortletRequestTargetResolverStrategy.java:214)
      at wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:135)
      at wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48)
      at wicket.RequestCycle.step(RequestCycle.java:992)
      at wicket.RequestCycle.steps(RequestCycle.java:1084)
      at wicket.RequestCycle.request(RequestCycle.java:454)
      at wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198)

        Activity

        Hide
        Johan Compagner added a comment -

        is this really a deadlock?
        that last one is needed. That is our barrier (but only that it is not a sync block of code!)

        and that lock has to be released just after that RequestCycle.detach()
        So where is that LeastRecentlyAccessedEvictionStrategy.java:60) really waiting on?

        Show
        Johan Compagner added a comment - is this really a deadlock? that last one is needed. That is our barrier (but only that it is not a sync block of code!) and that lock has to be released just after that RequestCycle.detach() So where is that LeastRecentlyAccessedEvictionStrategy.java:60) really waiting on?
        Hide
        János Cserép added a comment -

        I think this happens when a new request hits the portlet container while the first is not yet finished. Then the second makes the first thread wait until the second thread times out with the 1 minute warning... I don't have a full understanding of request handling's internals, but I only experienced this when it takes a bit longer for the backend to answer and the user gets angry and tries to click on something else on the screen....

        Show
        János Cserép added a comment - I think this happens when a new request hits the portlet container while the first is not yet finished. Then the second makes the first thread wait until the second thread times out with the 1 minute warning... I don't have a full understanding of request handling's internals, but I only experienced this when it takes a bit longer for the backend to answer and the user gets angry and tries to click on something else on the screen....
        Hide
        Johan Compagner added a comment -

        the question is
        why does the second makes the first thread to wait? I don't see that in your stacktrace. What is waiting on what?
        The second should just wait on the first in the Session.getPage()

        Show
        Johan Compagner added a comment - the question is why does the second makes the first thread to wait? I don't see that in your stacktrace. What is waiting on what? The second should just wait on the first in the Session.getPage()
        Hide
        János Cserép added a comment -

        According to jconsole:

        Name: httpWorkerThread-8080-0
        State: BLOCKED on hu.fmc.frontend.worklist.WorklistSession@11da1d1 owned by: httpWorkerThread-8080-1
        Total blocked: 3 Total waited: 72

        Stack trace:
        wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:87)
        wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48)
        wicket.RequestCycle.step(RequestCycle.java:992)
        wicket.RequestCycle.steps(RequestCycle.java:1084)
        wicket.RequestCycle.request(RequestCycle.java:454)
        wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198)
        com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278)
        javax.servlet.http.HttpServlet.service(HttpServlet.java:820)

        Name: httpWorkerThread-8080-1
        State: TIMED_WAITING on java.util.HashMap@1b8496f
        Total blocked: 8 Total waited: 337

        Stack trace:
        java.lang.Object.wait(Native Method)
        wicket.Session.getPage(Session.java:427)
        wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolveRenderedPage(PortletRequestTargetResolverStrategy.java:214)
        wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:135)

        • locked hu.fmc.frontend.worklist.WorklistSession@11da1d1
          wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48)
          wicket.RequestCycle.step(RequestCycle.java:992)
          wicket.RequestCycle.steps(RequestCycle.java:1084)
          wicket.RequestCycle.request(RequestCycle.java:454)
          wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198)
          com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278)

        Name: httpWorkerThread-8080-2
        State: BLOCKED on hu.fmc.frontend.worklist.WorklistSession@11da1d1 owned by: httpWorkerThread-8080-1
        Total blocked: 3 Total waited: 3

        Stack trace:
        wicket.session.pagemap.LeastRecentlyAccessedEvictionStrategy.evict(LeastRecentlyAccessedEvictionStrategy.java:60)
        wicket.Page.endVersion(Page.java:1136)
        wicket.Page.internalOnDetach(Page.java:811)
        wicket.Component.internalDetach(Component.java:2571)
        wicket.MarkupContainer.internalDetach(MarkupContainer.java:374)
        wicket.Page.internalDetach(Page.java:300)
        wicket.request.target.component.PageRequestTarget.detach(PageRequestTarget.java:84)
        wicket.RequestCycle.detach(RequestCycle.java:807)
        wicket.RequestCycle.steps(RequestCycle.java:1102)
        wicket.RequestCycle.request(RequestCycle.java:454)
        wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198)
        com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278)

        Show
        János Cserép added a comment - According to jconsole: Name: httpWorkerThread-8080-0 State: BLOCKED on hu.fmc.frontend.worklist.WorklistSession@11da1d1 owned by: httpWorkerThread-8080-1 Total blocked: 3 Total waited: 72 Stack trace: wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:87) wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48) wicket.RequestCycle.step(RequestCycle.java:992) wicket.RequestCycle.steps(RequestCycle.java:1084) wicket.RequestCycle.request(RequestCycle.java:454) wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198) com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278) javax.servlet.http.HttpServlet.service(HttpServlet.java:820) Name: httpWorkerThread-8080-1 State: TIMED_WAITING on java.util.HashMap@1b8496f Total blocked: 8 Total waited: 337 Stack trace: java.lang.Object.wait(Native Method) wicket.Session.getPage(Session.java:427) wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolveRenderedPage(PortletRequestTargetResolverStrategy.java:214) wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:135) locked hu.fmc.frontend.worklist.WorklistSession@11da1d1 wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48) wicket.RequestCycle.step(RequestCycle.java:992) wicket.RequestCycle.steps(RequestCycle.java:1084) wicket.RequestCycle.request(RequestCycle.java:454) wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198) com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278) Name: httpWorkerThread-8080-2 State: BLOCKED on hu.fmc.frontend.worklist.WorklistSession@11da1d1 owned by: httpWorkerThread-8080-1 Total blocked: 3 Total waited: 3 Stack trace: wicket.session.pagemap.LeastRecentlyAccessedEvictionStrategy.evict(LeastRecentlyAccessedEvictionStrategy.java:60) wicket.Page.endVersion(Page.java:1136) wicket.Page.internalOnDetach(Page.java:811) wicket.Component.internalDetach(Component.java:2571) wicket.MarkupContainer.internalDetach(MarkupContainer.java:374) wicket.Page.internalDetach(Page.java:300) wicket.request.target.component.PageRequestTarget.detach(PageRequestTarget.java:84) wicket.RequestCycle.detach(RequestCycle.java:807) wicket.RequestCycle.steps(RequestCycle.java:1102) wicket.RequestCycle.request(RequestCycle.java:454) wicket.protocol.http.portlet.WicketPortlet.processAction(WicketPortlet.java:198) com.sun.portal.portletcontainer.portletappengine.PortletAppEngineServlet.service(PortletAppEngineServlet.java:278)
        Hide
        János Cserép added a comment -

        Are PageMaps used in Portlets? I don't think it fits JSR 168... I think I have to dig deeper into the internals of WicketPortlet...

        Show
        János Cserép added a comment - Are PageMaps used in Portlets? I don't think it fits JSR 168... I think I have to dig deeper into the internals of WicketPortlet...
        Hide
        János Cserép added a comment -

        Who shouldl call notifyAll() when the whole block is synchronized?

        From Session.getPage():

        synchronized (pageMapsUsedInRequest)
        {
        long startTime = System.currentTimeMillis();

        // TODO For now only use the setting. Might be extended with
        // something overridable on request/ page/ request target level
        // later
        Duration timeout = Application.get().getRequestCycleSettings().getTimeout();

        // Get page entry for id and version
        Thread t = (Thread)pageMapsUsedInRequest.get(pageMap);
        while (t != null && t != Thread.currentThread())
        {
        try

        { pageMapsUsedInRequest.wait(timeout.getMilliseconds()); }

        catch (InterruptedException ex)

        { throw new WicketRuntimeException(ex); }

        t = (Thread)pageMapsUsedInRequest.get(pageMap);
        if (t != null && t != Thread.currentThread()
        && (startTime + timeout.getMilliseconds()) < System.currentTimeMillis())

        { // if it is still not the right thread.. // This either points to long running code (a report // page?) or a deadlock or such throw new WicketRuntimeException("After " + timeout + " the Pagemap " + pageMapName + " is still locked by: " + t + ", giving up trying to get the page for path: " + path); }

        }
        pageMapsUsedInRequest.put(pageMap, Thread.currentThread());
        final String id = Strings.firstPathComponent(path, Component.PATH_SEPARATOR);
        Page page = pageMap.get(Integer.parseInt(id), versionNumber);
        if (page == null)

        { pageMapsUsedInRequest.remove(pageMap); pageMapsUsedInRequest.notifyAll(); }

        return page;
        }

        Show
        János Cserép added a comment - Who shouldl call notifyAll() when the whole block is synchronized? From Session.getPage(): synchronized (pageMapsUsedInRequest) { long startTime = System.currentTimeMillis(); // TODO For now only use the setting. Might be extended with // something overridable on request/ page/ request target level // later Duration timeout = Application.get().getRequestCycleSettings().getTimeout(); // Get page entry for id and version Thread t = (Thread)pageMapsUsedInRequest.get(pageMap); while (t != null && t != Thread.currentThread()) { try { pageMapsUsedInRequest.wait(timeout.getMilliseconds()); } catch (InterruptedException ex) { throw new WicketRuntimeException(ex); } t = (Thread)pageMapsUsedInRequest.get(pageMap); if (t != null && t != Thread.currentThread() && (startTime + timeout.getMilliseconds()) < System.currentTimeMillis()) { // if it is still not the right thread.. // This either points to long running code (a report // page?) or a deadlock or such throw new WicketRuntimeException("After " + timeout + " the Pagemap " + pageMapName + " is still locked by: " + t + ", giving up trying to get the page for path: " + path); } } pageMapsUsedInRequest.put(pageMap, Thread.currentThread()); final String id = Strings.firstPathComponent(path, Component.PATH_SEPARATOR); Page page = pageMap.get(Integer.parseInt(id), versionNumber); if (page == null) { pageMapsUsedInRequest.remove(pageMap); pageMapsUsedInRequest.notifyAll(); } return page; }
        Hide
        János Cserép added a comment -

        Oh, I found it:

        final void requestDetached()
        {
        if (pageMapsUsedInRequest != null)
        {
        synchronized (pageMapsUsedInRequest)
        {
        Thread t = Thread.currentThread();
        Iterator it = pageMapsUsedInRequest.entrySet().iterator();
        while (it.hasNext())
        {
        Entry entry = (Entry)it.next();
        if (entry.getValue() == t)

        { it.remove(); }

        }
        pageMapsUsedInRequest.notifyAll();
        }
        }
        }

        But that block is also synchronized on the same object... hmm... hmm...

        Show
        János Cserép added a comment - Oh, I found it: final void requestDetached() { if (pageMapsUsedInRequest != null) { synchronized (pageMapsUsedInRequest) { Thread t = Thread.currentThread(); Iterator it = pageMapsUsedInRequest.entrySet().iterator(); while (it.hasNext()) { Entry entry = (Entry)it.next(); if (entry.getValue() == t) { it.remove(); } } pageMapsUsedInRequest.notifyAll(); } } } But that block is also synchronized on the same object... hmm... hmm...
        Hide
        János Cserép added a comment -

        In RequestCycle I found:

        // clear the used pagemap for this thread,
        // maybe we can move this a few lines above to have a but more
        // concurrency (session.update)
        try

        { session.requestDetached(); }

        The other thread is blocked exactly a few lines above... So I'm starting to have a strong feeling that this indeed is a bug...

        Show
        János Cserép added a comment - In RequestCycle I found: // clear the used pagemap for this thread, // maybe we can move this a few lines above to have a but more // concurrency (session.update) try { session.requestDetached(); } The other thread is blocked exactly a few lines above... So I'm starting to have a strong feeling that this indeed is a bug...
        Hide
        Johan Compagner added a comment -

        the problem is that this:

        wicket.Session.getPage(Session.java:427)
        wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolveRenderedPage(PortletRequestTargetResolverStrategy.java:214)
        wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:135)

        • locked hu.fmc.frontend.worklist.WorklistSession@11da1d1
          wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48)

        already locks the session somehow
        That shouldn't happen.

        The problem is that that code is changed now in 1.3+ so i need to check out the code of 1.2 for this.

        Show
        Johan Compagner added a comment - the problem is that this: wicket.Session.getPage(Session.java:427) wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolveRenderedPage(PortletRequestTargetResolverStrategy.java:214) wicket.protocol.http.portlet.PortletRequestTargetResolverStrategy.resolve(PortletRequestTargetResolverStrategy.java:135) locked hu.fmc.frontend.worklist.WorklistSession@11da1d1 wicket.request.compound.AbstractCompoundRequestCycleProcessor.resolve(AbstractCompoundRequestCycleProcessor.java:48) already locks the session somehow That shouldn't happen. The problem is that that code is changed now in 1.3+ so i need to check out the code of 1.2 for this.
        Hide
        Alastair Maw added a comment -

        This isn't going to get fixed in 1.2.x, is it?

        Show
        Alastair Maw added a comment - This isn't going to get fixed in 1.2.x, is it?
        Hide
        Alastair Maw added a comment -

        And might this affect 1.3?

        Show
        Alastair Maw added a comment - And might this affect 1.3?
        Hide
        Johan Compagner added a comment -

        Ate, is this lock still there in the current portlet implementation?

        if not please close this issue

        Show
        Johan Compagner added a comment - Ate, is this lock still there in the current portlet implementation? if not please close this issue
        Hide
        Ate Douma added a comment -

        This problem won't be addressed for the 1.2.x releases anymore.
        Furthermore, the portlet support has been completely rewritten/replaced in 1.3.x and none of the related code for this issue, nor anything even remotely similar, is in use anymore.
        This issue is therefore now out-of-scope for 1.3.x.

        Show
        Ate Douma added a comment - This problem won't be addressed for the 1.2.x releases anymore. Furthermore, the portlet support has been completely rewritten/replaced in 1.3.x and none of the related code for this issue, nor anything even remotely similar, is in use anymore. This issue is therefore now out-of-scope for 1.3.x.

          People

          • Assignee:
            Ate Douma
            Reporter:
            János Cserép
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development