[ICE-1039] Framework can deadlock under certain conditions. - ICEsoft JIRA Issue Tracker

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: 1.5
Fix Version/s: 1.5.2
Component/s: Framework
Labels:
None
Environment:
Operating System: All
Platform: All

Description

In order to apply this update to the 1.5 branch, I've broken this issue off from
it's original home in ~~ICE-992~~.

The problem typically only occurs under heavy load but can be generated
synthetically by putting a long (20 sec) sleep in the correct location of the
PersistentFacesServlet.

A live thread dump + stack trace showing the deadlock from a clustered JBoss
instance (jboss2) running the ICEfaces.org site.

Found one Java-level deadlock:
=============================
"TP-Processor2326":
  waiting to lock monitor 0x089e5c34 (object 0x3565e8d8, a java.lang.String),
  which is held by "TP-Processor2603"
"TP-Processor2603":
  waiting to lock monitor 0x0839bd14 (object 0x332218e0, a
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager),
  which is held by "TP-Processor2326"

Java stack information for the threads listed above:
===================================================
"TP-Processor2326":
        at
com.icesoft.faces.webapp.xmlhttp.BlockingResponseState.<init>(BlockingResponseState.java:84)
        - waiting to lock <0x3565e8d8> (a java.lang.String)
        at
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager.createState(ResponseStateManager.java:120)
        at
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager.getState(ResponseStateManager.java:136)
        - locked <0x332218e0> (a
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager)
        at
com.icesoft.faces.webapp.xmlhttp.BlockingServlet.service(BlockingServlet.java:175)
        - locked <0x332f66a8> (a com.icesoft.faces.webapp.xmlhttp.BlockingServlet)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
        at
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
        at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
        at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
        at
org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)
        at
org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)
        at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
        at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
        at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
        at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
        at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:199)
        at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
        at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:754)
        at
org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:684)
        at
org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:876)
        at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
        at java.lang.Thread.run(Thread.java:595)
"TP-Processor2603":
        at
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager.getState(ResponseStateManager.java:131)
        - waiting to lock <0x332218e0> (a
com.icesoft.faces.webapp.xmlhttp.ResponseStateManager)
        at
com.icesoft.faces.webapp.xmlhttp.PersistentFacesServlet.service(PersistentFacesServlet.java:402)
        - locked <0x3565e8d8> (a java.lang.String)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
        at
org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
        at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
        at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
        at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
        at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
        at
org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)
        at
org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)
        at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
        at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
        at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
        at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
        at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:199)
        at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:282)
        at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:754)
        at
org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:684)
        at
org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:876)
        at
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
        at java.lang.Thread.run(Thread.java:595)

Found 1 deadlock.

Activity

Ascending order - Click to sort in descending order

Deryk Sinotte created issue - 30/Nov/06 3:19 PM

Hide

Permalink

Deryk Sinotte added a comment - 30/Nov/06 3:39 PM

So was I finally able to reproduce the deadlock synthetically by putting a long
sleep in the PersistentFacesServlet between when the execute and render
lifecycles are fired and when the "state" is put into the session.

What was happening is that when the initial request was made to the
PersistentFacesServlet, it was writing back the complete response before
creating the new state and putting it into the session. Under certain high load
conditions, the BlockingServlet would get invoked and request the state before
the PersistentFacesServlet could get around to it.

To avoid this, I've moved the following chunk of code so that it is executed
before the lifecycle methods are called. That way the state is ready for the
BlockingServlet.

String viewNumberString = String.valueOf(viewNumber);
ResponseState state = stateManager.getState(session, viewNumberString);
state.setFocusID(request.getParameter("focus"));
session.setAttribute(viewNumberString + "/" + ResponseState.STATE, state);

Coupled with Ted's changes, this should help us with performance under load.

Marking as FIXED but only real world load testing will fully validate it. This
change has already been applied to the HEAD of the repository:

------------------------------------------------------------------------
r12489 | deryks | 2006-11-30 14:37:27 -0700 (Thu, 30 Nov 2006) | 1 line

~~ICE-992~~: Moved logic for putting state into session ahead of lifecycle execution.

I have also applied it to the 1.5 branch:

------------------------------------------------------------------------
r12504 | deryks | 2006-11-30 16:37:59 -0700 (Thu, 30 Nov 2006) | 1 line

~~ICE-1039~~: Moved logic for putting state into session ahead of lifecycle execution.

Marking as FIXED.

Show

Deryk Sinotte added a comment - 30/Nov/06 3:39 PM So was I finally able to reproduce the deadlock synthetically by putting a long sleep in the PersistentFacesServlet between when the execute and render lifecycles are fired and when the "state" is put into the session. What was happening is that when the initial request was made to the PersistentFacesServlet, it was writing back the complete response before creating the new state and putting it into the session. Under certain high load conditions, the BlockingServlet would get invoked and request the state before the PersistentFacesServlet could get around to it. To avoid this, I've moved the following chunk of code so that it is executed before the lifecycle methods are called. That way the state is ready for the BlockingServlet. String viewNumberString = String.valueOf(viewNumber); ResponseState state = stateManager.getState(session, viewNumberString); state.setFocusID(request.getParameter("focus")); session.setAttribute(viewNumberString + "/" + ResponseState.STATE, state); Coupled with Ted's changes, this should help us with performance under load. Marking as FIXED but only real world load testing will fully validate it. This change has already been applied to the HEAD of the repository: ------------------------------------------------------------------------ r12489 | deryks | 2006-11-30 14:37:27 -0700 (Thu, 30 Nov 2006) | 1 line ICE-992 : Moved logic for putting state into session ahead of lifecycle execution. I have also applied it to the 1.5 branch: ------------------------------------------------------------------------ r12504 | deryks | 2006-11-30 16:37:59 -0700 (Thu, 30 Nov 2006) | 1 line ICE-1039 : Moved logic for putting state into session ahead of lifecycle execution. Marking as FIXED.

Hide

Permalink

Deryk Sinotte added a comment - 30/Nov/06 3:39 PM

Adjusting target milestone to 1.5.2

Show

Deryk Sinotte added a comment - 30/Nov/06 3:39 PM Adjusting target milestone to 1.5.2

Hide

Permalink

Deryk Sinotte added a comment - 11/Dec/06 10:48 AM

There remain conditions under which the framework can be deadlocked. We need a
serious review/audit of the synchronization in the framework and a some good way
of load testing to reveal if the problem is still there or fixed.

Marking as RE-OPENed.

Show

Deryk Sinotte added a comment - 11/Dec/06 10:48 AM There remain conditions under which the framework can be deadlocked. We need a serious review/audit of the synchronization in the framework and a some good way of load testing to reveal if the problem is still there or fixed. Marking as RE-OPENed.

Hide

Permalink

Ken Fyten added a comment - 02/Jan/07 10:39 AM

Note that this change has been deployed successfully to the .org site for the
last 4 weeks or so without any deadlocks being observed in either the site
itself or the Comp. Showcase or other demo apps.

We need to decide if the incremental change above should be included in the
v1.5.2 patch, or if we want to make no changes related to the deadlocking issue
at this time and wait for a more comprehensive solution.

Deryk, can you please review with Ted as necessary and make a recommendation.
Since it's definately helped the .org stuff, I'd like to roll it out unless we
think it may cause more problems than it solves.

Show

Ken Fyten added a comment - 02/Jan/07 10:39 AM Note that this change has been deployed successfully to the .org site for the last 4 weeks or so without any deadlocks being observed in either the site itself or the Comp. Showcase or other demo apps. We need to decide if the incremental change above should be included in the v1.5.2 patch, or if we want to make no changes related to the deadlocking issue at this time and wait for a more comprehensive solution. Deryk, can you please review with Ted as necessary and make a recommendation. Since it's definately helped the .org stuff, I'd like to roll it out unless we think it may cause more problems than it solves.

Hide

Permalink

Deryk Sinotte added a comment - 05/Jan/07 1:32 PM

The fix is on the 1.5.0 branch and, based on the performance of the ICEfaces.org
site over the past month or so, this fix has improved the performance of
ICEfaces on the site if not entirely fixing the problem (as we deadlocked again
with the same characteristics).

So I'm marking this as fixed for the 1.5.2 release and I'll open another case
for ongoing deadlock issues if and when they occur.

Show

Deryk Sinotte added a comment - 05/Jan/07 1:32 PM The fix is on the 1.5.0 branch and, based on the performance of the ICEfaces.org site over the past month or so, this fix has improved the performance of ICEfaces on the site if not entirely fixing the problem (as we deadlocked again with the same characteristics). So I'm marking this as fixed for the 1.5.2 release and I'll open another case for ongoing deadlock issues if and when they occur.

Hide

Permalink

Deryk Sinotte added a comment - 09/Jan/07 12:59 PM

I've checked the 1.5 branch in the repository, the src build, and decompiled
PersistentFacesServlet in the icefaces.jar of the binary build and the fix is
there in all of them. For this release, this is what we are considering as
verified so I'm marking it as such.

Show

Deryk Sinotte added a comment - 09/Jan/07 12:59 PM I've checked the 1.5 branch in the repository, the src build, and decompiled PersistentFacesServlet in the icefaces.jar of the binary build and the fix is there in all of them. For this release, this is what we are considering as verified so I'm marking it as such.

Icefaces Administrator made changes - 16/Feb/07 11:43 AM

Field	Original Value	New Value
issue.field.bugzillaimportkey	1059	12308

Ken Fyten made changes - 16/Feb/07 7:41 PM

Status

Resolved [ 5 ]

Closed [ 6 ]

People

Assignee:

Deryk Sinotte

Reporter:

Deryk Sinotte

Votes:

0 Vote for this issue

Watchers:

1 Start watching this issue

Dates

Created:

30/Nov/06 3:19 PM

Updated:

16/Feb/07 7:41 PM

Resolved:

16/Feb/07 7:41 PM