[JBoss JIRA] Created: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout
5:49 p.m.
Seam is allowing concurrent thread access to conversation components during conversation
timeout
------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
6:02 p.m.
New subject: [JBoss JIRA] Updated: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout
[
https://issues.jboss.org/browse/JBSEAM-4758?page=com.atlassian.jira.plugi...
]
Andrew Duckworth updated JBSEAM-4758:
-------------------------------------
Attachment: myseamwebproject2.war.zip
Seam Gen sample illustrating the behaviour minus the WEB-INF/lib directory to decrease
size
Seam is allowing concurrent thread access to conversation components
during conversation timeout
------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Labels: concurrent, locking, manager, thread
Attachments: myseamwebproject2.war.zip
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
6:47 p.m.
New subject: [JBoss JIRA] Commented: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout
[
https://issues.jboss.org/browse/JBSEAM-4758?page=com.atlassian.jira.plugi...
]
Andrew Duckworth commented on JBSEAM-4758:
------------------------------------------
My suggested fix would be to have a new destroyed flag on ConversationEntry which is set
immediately before calling Manager.destroyConversation() which can then be tested for in
other threads to prevent duplicate destroys on the conversation entry. To be completely
safe this flag would need to be set/tested for while holding a Monitor that was session
scoped to prevent race conditions between multiple threads.
Seam is allowing concurrent thread access to conversation components
during conversation timeout
------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Labels: concurrent, locking, manager, thread
Attachments: myseamwebproject2.war.zip
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
7:15 p.m.
New subject: [JBoss JIRA] Issue Comment Edited: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout
[
https://issues.jboss.org/browse/JBSEAM-4758?page=com.atlassian.jira.plugi...
]
Andrew Duckworth edited comment on JBSEAM-4758 at 1/4/11 8:14 PM:
------------------------------------------------------------------
My suggested fix would be to have a new destroyed flag on ConversationEntry which is set
immediately before calling Manager.destroyConversation() which can then be tested for in
other threads to prevent duplicate destroys on the conversation entry. To be completely
safe this flag would need to be set/tested for while holding a Monitor on the
ConversationEntry to prevent race conditions between multiple threads.
was (Author: andrewduckworth):
My suggested fix would be to have a new destroyed flag on ConversationEntry which is
set immediately before calling Manager.destroyConversation() which can then be tested for
in other threads to prevent duplicate destroys on the conversation entry. To be completely
safe this flag would need to be set/tested for while holding a Monitor that was session
scoped to prevent race conditions between multiple threads.
Seam is allowing concurrent thread access to conversation components
during conversation timeout
------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Labels: concurrent, locking, manager, thread
Attachments: myseamwebproject2.war.zip
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
7:35 p.m.
New subject: [JBoss JIRA] Updated: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout, resulting in @Destroy being called multiple times
[
https://issues.jboss.org/browse/JBSEAM-4758?page=com.atlassian.jira.plugi...
]
Andrew Duckworth updated JBSEAM-4758:
-------------------------------------
Summary: Seam is allowing concurrent thread access to conversation components during
conversation timeout, resulting in @Destroy being called multiple times (was: Seam is
allowing concurrent thread access to conversation components during conversation timeout)
Seam is allowing concurrent thread access to conversation components
during conversation timeout, resulting in @Destroy being called multiple times
---------------------------------------------------------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Labels: concurrent, locking, manager, thread
Attachments: myseamwebproject2.war.zip
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
12:22 a.m.
New subject: [JBoss JIRA] Updated: (JBSEAM-4758) Seam is allowing concurrent thread access to conversation components during conversation timeout, resulting in @Destroy being called multiple times
[
https://issues.jboss.org/browse/JBSEAM-4758?page=com.atlassian.jira.plugi...
]
Andrew Duckworth updated JBSEAM-4758:
-------------------------------------
Description:
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy needs to manage its own
synchronization ? I have looked at the 2.2.1 release and the same issue looks like it is
still present. If it would be helpful to have the entire test application WAR, please let
me know and I can send it.
was:
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy and
@Observer(endConversation) need to manage their own synchronization ? I have looked at the
2.2.1 release and the same issue looks like it is still present. If it would be helpful to
have the entire test application WAR, please let me know and I can send it.
Seam is allowing concurrent thread access to conversation components
during conversation timeout, resulting in @Destroy being called multiple times
---------------------------------------------------------------------------------------------------------------------------------------------------
Key: JBSEAM-4758
URL: https://issues.jboss.org/browse/JBSEAM-4758
Project: Seam
Issue Type: Bug
Components: Core
Affects Versions: 2.0.2.SP1
Reporter: Andrew Duckworth
Labels: concurrent, locking, manager, thread
Attachments: myseamwebproject2.war.zip
Our application is using Seam 2.0.2. During timeout processing for conversations, it
appears that org.jboss.seam.core.Manager allows concurrent thread access to conversation
scoped components and does not enforce normal conversation locking. This can cause major
problems in components that expect single threaded behaviour and in our application that
has some legacy Hibernate Session management, this can lead to multi-threaded access to
the same HB session causing unpredictable results.
I have verified the issue using a simple POJO and Seam Gen. The code for the POJO is as
follows, (the large sleeps are to be able to easily reproduce the race condition):
package org.domain.myseamwebproject.managertest;
import java.text.SimpleDateFormat;
import java.util.Date;
import org.jboss.seam.ScopeType;
import org.jboss.seam.annotations.Create;
import org.jboss.seam.annotations.Destroy;
import org.jboss.seam.annotations.Logger;
import org.jboss.seam.annotations.Name;
import org.jboss.seam.annotations.Observer;
import org.jboss.seam.annotations.Scope;
import org.jboss.seam.core.Conversation;
import org.jboss.seam.log.Log;
@Name("convScopedBean")
@Scope(ScopeType.CONVERSATION)
public class ConvScopedBean
{
int activeDestroyThreads = 0;
int activeTimeoutThreads = 0;
@Logger
Log log;
@Create
public void create()
{
log.info("Bean created {0}", beanId());
}
@Destroy
public void destroy()
{
activeDestroyThreads++;
log.info("Bean destroy starting on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Bean destroy finished on bean {0} in thread: {1} with {2} active
destroy threads", beanId(), getCurrentThreadDetails(), activeDestroyThreads);
activeDestroyThreads--;
}
private String getCurrentThreadDetails()
{
return Thread.currentThread().getName() + " id:" +
Thread.currentThread().getId();
}
private String beanId()
{
return String.valueOf(System.identityHashCode(this));
}
public String getConversationId()
{
return Conversation.instance().getId();
}
public String getCurrentTime()
{
return (new SimpleDateFormat("hh:mm:ss")).format(new Date());
}
@Observer("org.jboss.seam.conversationTimeout")
public void conversationTimeout(String cid)
{
activeTimeoutThreads++;
log.info("Conversation timeout starting on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
try
{
Thread.sleep(10000);
}
catch (InterruptedException e)
{
e.printStackTrace();
}
log.info("Conversation timeout finished on bean {0} in thread: {1} with {2}
active timeout threads", beanId(), getCurrentThreadDetails(), activeTimeoutThreads);
activeTimeoutThreads--;
}
}
On the xhtml page, I have an a4j:poll that polls getCurrentTime:
<f:facet name="header">View Conversation</f:facet>
<p>The current long running conversation is:
#{convScopedBean.conversationId}</p>
<p>The current time is: </p> <h:outputText id="currentTime"
value="#{convScopedBean.currentTime}"/>
<a4j:poll id="poll" interval="1000" enabled="true"
reRender="poll,currentTime"/>
<div class="actionButtons">
<s:button value="Go to Home" propagation="none"
action="home"/>
</div>
As soon as the background expired conversation starts to get destroyed during a a4j:poll
event, I click the s:button to generate a concurrent request to the same bean. The
following log shows that the convScopedBean has multi-threaded access:
16:53:25,763 INFO [ConvScopedBean] Bean created 2923901
16:53:29,199 INFO [ConvScopedBean] Bean created 7938954
16:53:54,317 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,318 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:54:04,321 INFO [ConvScopedBean] Bean destroy starting on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:54:14,322 INFO [ConvScopedBean] Bean destroy finished on bean 12791208 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:28,896 INFO [ConvScopedBean] Conversation timeout starting on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:29,983 INFO [Manager] destroying conversation with garbage lock: 7
16:55:29,985 INFO [ConvScopedBean] Bean created 12033604
16:55:29,987 INFO [ConvScopedBean] Conversation timeout starting on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:31,492 INFO [Manager] destroying conversation with garbage lock: 7
16:55:31,494 INFO [ConvScopedBean] Bean created 7531789
16:55:31,496 INFO [ConvScopedBean] Conversation timeout starting on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:38,897 INFO [ConvScopedBean] Conversation timeout finished on bean 7938954 in
thread: http-0.0.0.0-8080-3 id:79 with 1 active timeout threads
16:55:38,900 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 1 active destroy threads
16:55:39,988 INFO [ConvScopedBean] Conversation timeout finished on bean 12033604 in
thread: http-0.0.0.0-8080-2 id:78 with 1 active timeout threads
16:55:39,991 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:41,497 INFO [ConvScopedBean] Conversation timeout finished on bean 7531789 in
thread: http-0.0.0.0-8080-1 id:77 with 1 active timeout threads
16:55:41,500 INFO [ConvScopedBean] Bean destroy starting on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 3 active destroy threads
16:55:48,901 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-3 id:79 with 3 active destroy threads
16:55:49,992 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-2 id:78 with 2 active destroy threads
16:55:50,041 INFO [ConvScopedBean] Bean destroy starting on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:55:51,501 INFO [ConvScopedBean] Bean destroy finished on bean 2923901 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:55:51,536 INFO [ConvScopedBean] Bean destroy starting on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
16:56:00,042 INFO [ConvScopedBean] Bean destroy finished on bean 12033604 in thread:
http-0.0.0.0-8080-2 id:78 with 1 active destroy threads
16:56:01,538 INFO [ConvScopedBean] Bean destroy finished on bean 7531789 in thread:
http-0.0.0.0-8080-1 id:77 with 1 active destroy threads
Can someone tell me if this is a known issue and that @Destroy needs to manage its own
synchronization ? I have looked at the 2.2.1 release and the same issue looks like it is
still present. If it would be helpful to have the entire test application WAR, please let
me know and I can send it.
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
4907
days inactive
4909
days old
5 comments
1 participants
participants (1)
-
Andrew Duckworth (JIRA)