[jboss-jira] [JBoss JIRA] (WFLY-4697) EJBCLient access to SFSBs in a managed transaction context does not play well with clean shutdown
Richard Achmatowicz (JIRA)
issues at jboss.org
Wed Jun 10 10:33:03 EDT 2015
[ https://issues.jboss.org/browse/WFLY-4697?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13076866#comment-13076866 ]
Richard Achmatowicz edited comment on WFLY-4697 at 6/10/15 10:32 AM:
---------------------------------------------------------------------
Although this does not relate to transaction context per-se, here is an example of how an EJBCLient invocation can arrive at the remoting connector and start to be processed (i.e. unpack the message, look up the deployment, set up the invocation), even though the component and the deployment repository have already called stop():
{noformat}
----- Shutdown clusterB-node1 -----
10:02:10,055 INFO [org.jboss.as.test.clustering.NodeUtil] (main) Stopping container=container-3
10:02:10,058 INFO [org.jboss.arquillian.container.test.impl.client.container.ClientContainerController] (main) Manual stopping of a server instance
[0m10:02:10,061 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER: calling suspend with timeout = 5
[0m[0m10:02:10,061 INFO [org.jboss.as.server] (management-handler-thread - 2) WFLYSRV0211: Suspending server
[0m[0m10:02:10,061 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER (OP LISTENER): calling suspendStarted() (noop)
[0m[0m10:02:10,062 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER (OP LISTENER): calling complete() (initiates shutdown)
[0m[0m10:02:10,064 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested.
[0m[0m10:02:10,075 INFO [org.jboss.modcluster] (ServerService Thread Pool -- 71) MODCLUSTER000002: Initiating mod_cluster shutdown
[0m[0m10:02:10,074 INFO [stdout] (ServerService Thread Pool -- 69) EJB CACHE: stop()
[0m[0m10:02:10,079 INFO [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0019: Host default-host stopping
[0m[0m10:02:10,081 INFO [stdout] (MSC service thread 1-3) ENDPOINT SERVICE: stopping endpoint service: name = clusterB-node1:MANAGEMENT
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 68) EJB CACHE: stop()
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 69) EJB COMPONENT: stop(): name = clusterbench-ee6-ejb
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 68) EJB COMPONENT: stop(): name = clusterbench-ee6-ejb
[0m[0m10:02:10,083 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 70) ISPN000029: Passivating all entries to disk
[0m[0m10:02:10,088 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-5) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
[0m[0m10:02:10,090 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0019: Stopped Driver service with driver-name = h2
[0m[0m10:02:10,092 INFO [org.jboss.weld.deployer] (MSC service thread 1-6) WFLYWELD0010: Stopping weld service for deployment clusterbench-ee6-ejb.jar
[0m[0m10:02:10,095 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 70) ISPN000030: Passivated 2 entries in 11 milliseconds
[0m[0m10:02:10,108 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 70) WFLYCLINF0003: Stopped clusterbench-ee6-ejb.jar cache from ejb container
[0m[0m10:02:10,111 INFO [stdout] (MSC service thread 1-5) DEPLOYMENT REPOSITORY: calling deploymentRemoved() for deployment: DeploymentModuleIdentifier{applicationName='', moduleName='clusterbench-ee6-ejb', distinctName=''}
[0m[0m10:02:10,112 INFO [stdout] (MSC service thread 1-7) DEPLOYMENT REPOSITORY: stop()
[0m[0m10:02:10,129 INFO [org.wildfly.extension.undertow] (MSC service thread 1-7) WFLYUT0008: Undertow AJP listener ajp suspending
[0m[0m10:02:10,130 INFO [org.jboss.as.server.deployment] (MSC service thread 1-5) WFLYSRV0028: Stopped deployment clusterbench-ee6-ejb.jar (runtime-name: clusterbench-ee6-ejb.jar) in 63ms
[0m[0m10:02:10,130 INFO [org.wildfly.extension.undertow] (MSC service thread 1-7) WFLYUT0007: Undertow AJP listener ajp stopped, was bound to /127.0.0.1:8309
[0mCLIENT: start invocation (215)
[0m10:02:10,137 INFO [org.jboss.as.test.clustering.twoclusters.bean.forwarding.AbstractForwardingStatefulSBImpl] (EJB default - 3) getSerialAndIncrement() called on forwarding node clusterA-node0
[0m[0m10:02:10,138 INFO [stdout] (MSC service thread 1-3) ENDPOINT SERVICE: stopping endpoint service: name = clusterB-node1
[0m[0m10:02:10,138 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0008: Undertow HTTP listener default suspending
[0m[31m10:02:10,138 ERROR [org.jboss.as.ejb3] (default task-115) WFLYEJB0148: Exception on channel Channel ID 00efde47 (inbound) of Remoting connection 6f051902 to /127.0.0.1:57460 from message org.jboss.remoting3.remote.InboundMessage$3 at 61c2ea92: java.lang.NullPointerException
at org.jboss.as.ejb3.deployment.DeploymentRepository.getStartedModules(DeploymentRepository.java:155)
at org.jboss.as.ejb3.remote.protocol.versionone.EJBIdentifierBasedMessageHandler.findEJB(EJBIdentifierBasedMessageHandler.java:46)
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.processMessage(MethodInvocationMessageHandler.java:124)
at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:207)
at org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:74)
at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:149)
at org.jboss.remoting3.remote.RemoteConnectionChannel$5.run(RemoteConnectionChannel.java:463)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[0m[0m10:02:10,139 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0007: Undertow HTTP listener default stopped, was bound to /127.0.0.1:8380
[0m[0m10:02:10,140 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0004: Undertow 1.2.6.Final stopping
{noformat}
This generates an exception on the invocation, which then causes the session bean state to be discarded on the cluster. The net effect of this is that all subsequent invocations cannot find the bean:
{noformat}
CLIENT: start invocation (216)
[31m10:02:20,372 ERROR [org.jboss.as.ejb3.invocation] (EJB default - 4) WFLYEJB0034: EJB Invocation failed on component ForwardingStatefulSBImpl for method public abstract int org.jboss.as.test.clustering.twoclusters.bean.common.CommonStatefulSB.getSerialAndIncrement(): javax.ejb.NoSuchEJBException: WFLYEJB0168: Could not find EJB with id UnknownSessionID [5555675353486954555353675253665157535670575665575653505048545652]
at org.jboss.as.ejb3.component.stateful.StatefulComponentInstanceInterceptor.processInvocation(StatefulComponentInstanceInterceptor.java:61)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:275)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
{noformat}
was (Author: rachmato):
Although this does not relate to transaction context per-se, here is an example of how an EJBCLient invocation can arrive at the remoting connector and start to be processed (i.e. unpack the message, look up the deployment, set up the invocation), even though the component and the deployment repository have already called stop():
{noformat}
----- Shutdown clusterB-node1 -----
10:02:10,055 INFO [org.jboss.as.test.clustering.NodeUtil] (main) Stopping container=container-3
10:02:10,058 INFO [org.jboss.arquillian.container.test.impl.client.container.ClientContainerController] (main) Manual stopping of a server instance
[0m10:02:10,061 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER: calling suspend with timeout = 5
[0m[0m10:02:10,061 INFO [org.jboss.as.server] (management-handler-thread - 2) WFLYSRV0211: Suspending server
[0m[0m10:02:10,061 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER (OP LISTENER): calling suspendStarted() (noop)
[0m[0m10:02:10,062 INFO [stdout] (management-handler-thread - 2) SERVER SHUTDOWN HANDLER (OP LISTENER): calling complete() (initiates shutdown)
[0m[0m10:02:10,064 INFO [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested.
[0m[0m10:02:10,075 INFO [org.jboss.modcluster] (ServerService Thread Pool -- 71) MODCLUSTER000002: Initiating mod_cluster shutdown
[0m[0m10:02:10,074 INFO [stdout] (ServerService Thread Pool -- 69) EJB CACHE: stop()
[0m[0m10:02:10,079 INFO [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0019: Host default-host stopping
[0m[0m10:02:10,081 INFO [stdout] (MSC service thread 1-3) ENDPOINT SERVICE: stopping endpoint service: name = clusterB-node1:MANAGEMENT
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 68) EJB CACHE: stop()
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 69) EJB COMPONENT: stop(): name = clusterbench-ee6-ejb
[0m[0m10:02:10,081 INFO [stdout] (ServerService Thread Pool -- 68) EJB COMPONENT: stop(): name = clusterbench-ee6-ejb
[0m[0m10:02:10,083 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 70) ISPN000029: Passivating all entries to disk
[0m[0m10:02:10,088 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-5) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
[0m[0m10:02:10,090 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) WFLYJCA0019: Stopped Driver service with driver-name = h2
[0m[0m10:02:10,092 INFO [org.jboss.weld.deployer] (MSC service thread 1-6) WFLYWELD0010: Stopping weld service for deployment clusterbench-ee6-ejb.jar
[0m[0m10:02:10,095 INFO [org.infinispan.eviction.impl.PassivationManagerImpl] (ServerService Thread Pool -- 70) ISPN000030: Passivated 2 entries in 11 milliseconds
[0m[0m10:02:10,108 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 70) WFLYCLINF0003: Stopped clusterbench-ee6-ejb.jar cache from ejb container
[0m[0m10:02:10,111 INFO [stdout] (MSC service thread 1-5) DEPLOYMENT REPOSITORY: calling deploymentRemoved() for deployment: DeploymentModuleIdentifier{applicationName='', moduleName='clusterbench-ee6-ejb', distinctName=''}
[0m[0m10:02:10,112 INFO [stdout] (MSC service thread 1-7) DEPLOYMENT REPOSITORY: stop()
[0m[0m10:02:10,129 INFO [org.wildfly.extension.undertow] (MSC service thread 1-7) WFLYUT0008: Undertow AJP listener ajp suspending
[0m[0m10:02:10,130 INFO [org.jboss.as.server.deployment] (MSC service thread 1-5) WFLYSRV0028: Stopped deployment clusterbench-ee6-ejb.jar (runtime-name: clusterbench-ee6-ejb.jar) in 63ms
[0m[0m10:02:10,130 INFO [org.wildfly.extension.undertow] (MSC service thread 1-7) WFLYUT0007: Undertow AJP listener ajp stopped, was bound to /127.0.0.1:8309
[0mCLIENT: start invocation (215)
[0m10:02:10,137 INFO [org.jboss.as.test.clustering.twoclusters.bean.forwarding.AbstractForwardingStatefulSBImpl] (EJB default - 3) getSerialAndIncrement() called on forwarding node clusterA-node0
[0m[0m10:02:10,138 INFO [stdout] (MSC service thread 1-3) ENDPOINT SERVICE: stopping endpoint service: name = clusterB-node1
[0m[0m10:02:10,138 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0008: Undertow HTTP listener default suspending
[0m[31m10:02:10,138 ERROR [org.jboss.as.ejb3] (default task-115) WFLYEJB0148: Exception on channel Channel ID 00efde47 (inbound) of Remoting connection 6f051902 to /127.0.0.1:57460 from message org.jboss.remoting3.remote.InboundMessage$3 at 61c2ea92: java.lang.NullPointerException
at org.jboss.as.ejb3.deployment.DeploymentRepository.getStartedModules(DeploymentRepository.java:155)
at org.jboss.as.ejb3.remote.protocol.versionone.EJBIdentifierBasedMessageHandler.findEJB(EJBIdentifierBasedMessageHandler.java:46)
at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.processMessage(MethodInvocationMessageHandler.java:124)
at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.processMessage(VersionOneProtocolChannelReceiver.java:207)
at org.jboss.as.ejb3.remote.protocol.versiontwo.VersionTwoProtocolChannelReceiver.processMessage(VersionTwoProtocolChannelReceiver.java:74)
at org.jboss.as.ejb3.remote.protocol.versionone.VersionOneProtocolChannelReceiver.handleMessage(VersionOneProtocolChannelReceiver.java:149)
at org.jboss.remoting3.remote.RemoteConnectionChannel$5.run(RemoteConnectionChannel.java:463)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[0m[0m10:02:10,139 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0007: Undertow HTTP listener default stopped, was bound to /127.0.0.1:8380
[0m[0m10:02:10,140 INFO [org.wildfly.extension.undertow] (MSC service thread 1-1) WFLYUT0004: Undertow 1.2.6.Final stopping
{noformat}
> EJBCLient access to SFSBs in a managed transaction context does not play well with clean shutdown
> -------------------------------------------------------------------------------------------------
>
> Key: WFLY-4697
> URL: https://issues.jboss.org/browse/WFLY-4697
> Project: WildFly
> Issue Type: Bug
> Components: Clustering, EJB, Remoting
> Affects Versions: 10.0.0.Alpha1
> Reporter: Richard Achmatowicz
> Assignee: Richard Achmatowicz
>
> The clean shutdown mechanism allows EJB and web applications to make use of shutdown interceptors to allow the application server to refuse requests when a server is in the process of shutting down. These interceptors are tied to the processing of EJB invocations and web requests.
> In the case of EJBCLient invocations, they arrive at the remoting connector, and undergo some preliminary processing before being sent to the EJB interface in question. When a server is shutting down, EJBCLient invocations can arrive at the RemoteConnector and start processing, even when the EJB interface has been locked down, so to speak.
> I am seeing various types of exceptions arising from this preliminary processing (e.g. NPE on DeploymentRepository lookups) and these get returned to the client as exceptions on the SFSB invocation, before even reaching the SFSB interceptors.
> If the EJBCLient is running in a managed transaction context, these returned exceptions will case the SFSB to be discarded (as the SFSB invocation is considered failed with the exception returned) and the transaction will attempt to rollback. If the rollback processing fails (because the original node in the transaction is down the bean gets removed anyway. The SFSB session state is lost, even if there is another node in the cluster which can support the invocation.
> In short, it looks as though the clean shutdown mechanism needs to be used to also lock down the processing of EJBCLient invocations in some way.
>
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
More information about the jboss-jira
mailing list