[JBoss JIRA] (WFLY-9892) Upgrade org.apache.santuario.xmlsec to 2.1.1. caused regression in PicketLinkSTS
by David Lloyd (JIRA)
[ https://issues.jboss.org/browse/WFLY-9892?page=com.atlassian.jira.plugin.... ]
David Lloyd edited comment on WFLY-9892 at 2/23/18 9:37 AM:
------------------------------------------------------------
The workaround should be simple: just remove any whitespace and {{&\#13;}} from the content and it should work.
was (Author: dmlloyd):
The workaround should be simple: just remove any whitespace and from the content and it should work.
> Upgrade org.apache.santuario.xmlsec to 2.1.1. caused regression in PicketLinkSTS
> --------------------------------------------------------------------------------
>
> Key: WFLY-9892
> URL: https://issues.jboss.org/browse/WFLY-9892
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Affects Versions: 12.0.0.Beta1
> Reporter: Ondrej Lukas
> Priority: Blocker
> Attachments: ejb-security-picketlink.zip, ejb-test.jar, picketlink-sts.war, sts-config.properties
>
>
> When token from PicketLink STS is issued and signed then it is not able to be used for authentication through Remoting in WildFly 12 (i.e. it cannot be set as {{remote.connection.main.password}} property which can be used in PicketLink {{org.picketlink.identity.federation.bindings.jboss.auth.SAML2STSLoginModule}}). It seems it is caused by upgrade of org.apache.santuario.xmlsec to version 2.1.1. [1]. When WILDFLY11_HOME/modules/system/layers/base/org/apache/santuario/xmlsec/main/xmlsec-2.0.8.jar is placed to WildFly 12 modules then it works correctly.
> We report it as a blocker since it is regression - application which works correctly on WildFly 11 stops to work on WildFly 12 - users are not able to authenticate through Remoting with signed tokens from PicketLink STS correctly.
> Remoting fails due to following exception:
> {code}
> java.lang.IllegalArgumentException: ELY05131: Invalid ASCII control "0xA"
> at org.wildfly.security.sasl.util.StringPrep.forbidAsciiControl(StringPrep.java:117)
> at org.wildfly.security.sasl.util.StringPrep.encode(StringPrep.java:295)
> at org.wildfly.security.sasl.util.StringPrep.encode(StringPrep.java:196)
> at org.wildfly.security.sasl.plain.PlainSaslClient.evaluateChallenge(PlainSaslClient.java:95)
> at org.wildfly.security.sasl.util.AbstractDelegatingSaslClient.evaluateChallenge(AbstractDelegatingSaslClient.java:54)
> at org.wildfly.security.sasl.util.PrivilegedSaslClient.lambda$evaluateChallenge$0(PrivilegedSaslClient.java:55)
> at java.security.AccessController.doPrivileged(Native Method)
> at org.wildfly.security.sasl.util.PrivilegedSaslClient.evaluateChallenge(PrivilegedSaslClient.java:55)
> at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.lambda$handleEvent$1(ClientConnectionOpenListener.java:460)
> at org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:926)
> at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> It is caused by different formating value of SignatureValue in assertion. In WildFly 11 SignatureValue looks like:
> {code}
> <dsig:SignatureValue xmlns:dsig="http://www.w3.org/2000/09/xmldsig#">nFVkKrXTyYEQ9cwc9OOgySYebEtwzw4alVYP0viXzvqZAUAKtAXEBAfDB8xIOms78twlDdq79MiSvk8OrOdf126Kw/IR8JRn1fYyZ5tsIRcNoTXMgGaTqhrn/HKlLqqqHhVHrJURunqkSzTTxylA2AEPhEDD5Y7hS0W2ZZCeSvuri+PRDSTrRnuedz0yQuHQu1mZ0gjoEFbHh4Wkkn5Ac1R4gmewmmzPud+ZE6Ux4YpeHzQ8rAvZ4bDk6j+eQIRsSxFTLo5RSA3FWN8+lUNV/CSRqBPXsK7QxOaTdBgF+4NXWeExrNJ9SeVFcf9yelvReAtR2JNZ6DUY8u45KtXmLw==</dsig:SignatureValue>
> {code}
> In WildFly 12 it looks like (there are end of lines):
> {code}
> <dsig:SignatureValue xmlns:dsig="http://www.w3.org/2000/09/xmldsig#">cUNpFJIZlLYrBDZtQSTDrq2K6PbnAHyg2qbx/D5FuB4XMjdQ5oxQjkMejLyelnA7s4GFusoLhahl
> qlTOT8UrOyxrR4yYAmJ/e5s+f4gys926+tbiraT/3/wG8wM/Lvcjvk5Ap69zODuRYpypsWfA4jrI
> 7TTBXVPGy8g4KUdnFviUiTuFTc2Ghgxp53AmUuLis/THyP28jE7+28//q8bi/bQrFwHC6tWX67+N
> K1duFCOcQ6IPIKeVrePZz55Ivgl+WWdkF6uYCz5IdMzurhzmeQ3K8DAMIxz/MG67VWJIOnuGNWF7
> nmdye5zd9AFcRsr1XadvZJCbGNfuc89AL5inCg==</dsig:SignatureValue>
> {code}
> [1] https://github.com/wildfly/wildfly/commit/536de514829f2187abf1126c8916a04...
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9902) SimpleRole.hashCode NPE when a principal has the roles set to null
by Sergey Beryozkin (JIRA)
[ https://issues.jboss.org/browse/WFLY-9902?page=com.atlassian.jira.plugin.... ]
Sergey Beryozkin updated WFLY-9902:
-----------------------------------
Description:
If a principal is created with the roles set to null then NPE is reported back to the user during the authentication process:
{noformat}
java.lang.RuntimeException: java.lang.NullPointerException
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verifyCredential(JAASIdentityManagerImpl.java:140)
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verify(JAASIdentityManagerImpl.java:94)
at io.undertow.security.impl.BasicAuthenticationMechanism.authenticate(BasicAuthenticationMechanism.java:167)
at io.undertow.security.impl.SecurityContextImpl$AuthAttempter.transition(SecurityContextImpl.java:245)
....
Caused by: java.lang.NullPointerException
at org.jboss.security.identity.plugins.SimpleRole.hashCode(SimpleRole.java:106)
{noformat}
was:
If a principal is created with the roles set to null then NPE is is reported during the authentication process:
{noformat}
java.lang.RuntimeException: java.lang.NullPointerException
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verifyCredential(JAASIdentityManagerImpl.java:140)
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verify(JAASIdentityManagerImpl.java:94)
at io.undertow.security.impl.BasicAuthenticationMechanism.authenticate(BasicAuthenticationMechanism.java:167)
at io.undertow.security.impl.SecurityContextImpl$AuthAttempter.transition(SecurityContextImpl.java:245)
....
Caused by: java.lang.NullPointerException
at org.jboss.security.identity.plugins.SimpleRole.hashCode(SimpleRole.java:106)
{noformat}
> SimpleRole.hashCode NPE when a principal has the roles set to null
> ------------------------------------------------------------------
>
> Key: WFLY-9902
> URL: https://issues.jboss.org/browse/WFLY-9902
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Environment: Wild Fly Swarm 2018.2.0
> Reporter: Sergey Beryozkin
> Assignee: Darran Lofthouse
> Priority: Minor
>
> If a principal is created with the roles set to null then NPE is reported back to the user during the authentication process:
> {noformat}
> java.lang.RuntimeException: java.lang.NullPointerException
> at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verifyCredential(JAASIdentityManagerImpl.java:140)
> at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verify(JAASIdentityManagerImpl.java:94)
> at io.undertow.security.impl.BasicAuthenticationMechanism.authenticate(BasicAuthenticationMechanism.java:167)
> at io.undertow.security.impl.SecurityContextImpl$AuthAttempter.transition(SecurityContextImpl.java:245)
> ....
> Caused by: java.lang.NullPointerException
> at org.jboss.security.identity.plugins.SimpleRole.hashCode(SimpleRole.java:106)
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9902) SimpleRole.hashCode NPE when a principal has the roles set to null
by Sergey Beryozkin (JIRA)
Sergey Beryozkin created WFLY-9902:
--------------------------------------
Summary: SimpleRole.hashCode NPE when a principal has the roles set to null
Key: WFLY-9902
URL: https://issues.jboss.org/browse/WFLY-9902
Project: WildFly
Issue Type: Bug
Components: Security
Environment: Wild Fly Swarm 2018.2.0
Reporter: Sergey Beryozkin
Assignee: Darran Lofthouse
Priority: Minor
If a principal is created with the roles set to null then NPE is is reported during the authentication process:
{noformat}
java.lang.RuntimeException: java.lang.NullPointerException
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verifyCredential(JAASIdentityManagerImpl.java:140)
at org.wildfly.extension.undertow.security.JAASIdentityManagerImpl.verify(JAASIdentityManagerImpl.java:94)
at io.undertow.security.impl.BasicAuthenticationMechanism.authenticate(BasicAuthenticationMechanism.java:167)
at io.undertow.security.impl.SecurityContextImpl$AuthAttempter.transition(SecurityContextImpl.java:245)
....
Caused by: java.lang.NullPointerException
at org.jboss.security.identity.plugins.SimpleRole.hashCode(SimpleRole.java:106)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9892) Upgrade org.apache.santuario.xmlsec to 2.1.1. caused regression in PicketLinkSTS
by David Lloyd (JIRA)
[ https://issues.jboss.org/browse/WFLY-9892?page=com.atlassian.jira.plugin.... ]
David Lloyd commented on WFLY-9892:
-----------------------------------
The workaround should be simple: just remove any whitespace and from the content and it should work.
> Upgrade org.apache.santuario.xmlsec to 2.1.1. caused regression in PicketLinkSTS
> --------------------------------------------------------------------------------
>
> Key: WFLY-9892
> URL: https://issues.jboss.org/browse/WFLY-9892
> Project: WildFly
> Issue Type: Bug
> Components: Security
> Affects Versions: 12.0.0.Beta1
> Reporter: Ondrej Lukas
> Priority: Blocker
> Attachments: ejb-security-picketlink.zip, ejb-test.jar, picketlink-sts.war, sts-config.properties
>
>
> When token from PicketLink STS is issued and signed then it is not able to be used for authentication through Remoting in WildFly 12 (i.e. it cannot be set as {{remote.connection.main.password}} property which can be used in PicketLink {{org.picketlink.identity.federation.bindings.jboss.auth.SAML2STSLoginModule}}). It seems it is caused by upgrade of org.apache.santuario.xmlsec to version 2.1.1. [1]. When WILDFLY11_HOME/modules/system/layers/base/org/apache/santuario/xmlsec/main/xmlsec-2.0.8.jar is placed to WildFly 12 modules then it works correctly.
> We report it as a blocker since it is regression - application which works correctly on WildFly 11 stops to work on WildFly 12 - users are not able to authenticate through Remoting with signed tokens from PicketLink STS correctly.
> Remoting fails due to following exception:
> {code}
> java.lang.IllegalArgumentException: ELY05131: Invalid ASCII control "0xA"
> at org.wildfly.security.sasl.util.StringPrep.forbidAsciiControl(StringPrep.java:117)
> at org.wildfly.security.sasl.util.StringPrep.encode(StringPrep.java:295)
> at org.wildfly.security.sasl.util.StringPrep.encode(StringPrep.java:196)
> at org.wildfly.security.sasl.plain.PlainSaslClient.evaluateChallenge(PlainSaslClient.java:95)
> at org.wildfly.security.sasl.util.AbstractDelegatingSaslClient.evaluateChallenge(AbstractDelegatingSaslClient.java:54)
> at org.wildfly.security.sasl.util.PrivilegedSaslClient.lambda$evaluateChallenge$0(PrivilegedSaslClient.java:55)
> at java.security.AccessController.doPrivileged(Native Method)
> at org.wildfly.security.sasl.util.PrivilegedSaslClient.evaluateChallenge(PrivilegedSaslClient.java:55)
> at org.jboss.remoting3.remote.ClientConnectionOpenListener$Capabilities.lambda$handleEvent$1(ClientConnectionOpenListener.java:460)
> at org.jboss.remoting3.EndpointImpl$TrackingExecutor.lambda$execute$0(EndpointImpl.java:926)
> at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> It is caused by different formating value of SignatureValue in assertion. In WildFly 11 SignatureValue looks like:
> {code}
> <dsig:SignatureValue xmlns:dsig="http://www.w3.org/2000/09/xmldsig#">nFVkKrXTyYEQ9cwc9OOgySYebEtwzw4alVYP0viXzvqZAUAKtAXEBAfDB8xIOms78twlDdq79MiSvk8OrOdf126Kw/IR8JRn1fYyZ5tsIRcNoTXMgGaTqhrn/HKlLqqqHhVHrJURunqkSzTTxylA2AEPhEDD5Y7hS0W2ZZCeSvuri+PRDSTrRnuedz0yQuHQu1mZ0gjoEFbHh4Wkkn5Ac1R4gmewmmzPud+ZE6Ux4YpeHzQ8rAvZ4bDk6j+eQIRsSxFTLo5RSA3FWN8+lUNV/CSRqBPXsK7QxOaTdBgF+4NXWeExrNJ9SeVFcf9yelvReAtR2JNZ6DUY8u45KtXmLw==</dsig:SignatureValue>
> {code}
> In WildFly 12 it looks like (there are end of lines):
> {code}
> <dsig:SignatureValue xmlns:dsig="http://www.w3.org/2000/09/xmldsig#">cUNpFJIZlLYrBDZtQSTDrq2K6PbnAHyg2qbx/D5FuB4XMjdQ5oxQjkMejLyelnA7s4GFusoLhahl
> qlTOT8UrOyxrR4yYAmJ/e5s+f4gys926+tbiraT/3/wG8wM/Lvcjvk5Ap69zODuRYpypsWfA4jrI
> 7TTBXVPGy8g4KUdnFviUiTuFTc2Ghgxp53AmUuLis/THyP28jE7+28//q8bi/bQrFwHC6tWX67+N
> K1duFCOcQ6IPIKeVrePZz55Ivgl+WWdkF6uYCz5IdMzurhzmeQ3K8DAMIxz/MG67VWJIOnuGNWF7
> nmdye5zd9AFcRsr1XadvZJCbGNfuc89AL5inCg==</dsig:SignatureValue>
> {code}
> [1] https://github.com/wildfly/wildfly/commit/536de514829f2187abf1126c8916a04...
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9900) EJB client rarely hangs
by Radoslav Husar (JIRA)
[ https://issues.jboss.org/browse/WFLY-9900?page=com.atlassian.jira.plugin.... ]
Radoslav Husar updated WFLY-9900:
---------------------------------
Priority: Blocker (was: Major)
> EJB client rarely hangs
> -----------------------
>
> Key: WFLY-9900
> URL: https://issues.jboss.org/browse/WFLY-9900
> Project: WildFly
> Issue Type: Bug
> Components: Clustering, EJB
> Affects Versions: 12.0.0.Beta1
> Reporter: Richard Janík
> Assignee: David Lloyd
> Priority: Blocker
>
> Seen in our clustering tests where remote EJB clients invoke beans on 4 servers in cluster, while each of those is being killed and restarted. This is done in sequence and there's plenty of time in between the kill/start/kill-another (1 minute).
> In two ouf our tests, we saw a small number of clients hang and resist termination at the end. The scenarios are:
> [jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/jo...] (36 clients)
> [shutdown-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...] (1 client)
> The hangs are not related to any error or warning message on the server-side. There are ClosedChannelExceptions on the client side, but these seem to be unrelated as the numbers of clients reporting the exceptions are not the same (lower) as the numbers of hanging clients.
> No thread dump as I didn't manage to reproduce yet.
> Might be related to JBEAP-12074 or JBEAP-13169.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9890) Timed out waiting for responses for request X from node Y immediately after node Y rejoins the cluster (failover with fine granularity)
by Radoslav Husar (JIRA)
[ https://issues.jboss.org/browse/WFLY-9890?page=com.atlassian.jira.plugin.... ]
Radoslav Husar commented on WFLY-9890:
--------------------------------------
As per WFLY-9901 this is also affecting EJB tests.
> Timed out waiting for responses for request X from node Y immediately after node Y rejoins the cluster (failover with fine granularity)
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9890
> URL: https://issues.jboss.org/browse/WFLY-9890
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 12.0.0.Beta1
> Reporter: Michal Vinkler
> Assignee: Paul Ferraro
> Priority: Critical
>
> Seen in SF failover tests - scenario: failover-http-granular-shutdown-repl-sync
> (replication granularity is set to ATTRIBUTE level)
> Description: In the failover test, each server is shut down and after some time it rejoins the cluster. After joining the cluster again, the load is distributed to this node. It seems that first request for some session handled by that node produces ERROR in the log of some other server until the time another cluster topology change occurs.
> Stacktrace of the error:
> {code}
> [JBossINF] [0m[31m10:18:00,256 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAccessMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAttributeKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9[1])]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 30250 from perf18
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> {code}
> Client gets the stale data:
> {code}
> 2018/02/21 10:18:00:272 EST [WARN ][Runner - 16] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16>
> org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16
> at org.jboss.smartfrog.loaddriver.http.AbstractSerialNumberValidatorFactoryImpl$SerialNumberValidator.processRequest(AbstractSerialNumberValidatorFactoryImpl.java:133)
> at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:52)
> at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:103)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> Example - timeline:
> {code}
> 4 servers are running, 2000 clients, no issue in the beggining
> 2018/02/21 10:16:43:234 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Node 0 (perf18) is down.
> - still no issues
> 2018/02/21 10:17:43:234 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Bringing back node 0 (perf18)
> 2018/02/21 10:17:55:611 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Node 0 (perf18) is up.
> 2018/02/21 10:18:00:272 EST [WARN ][Runner - 16] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16>
> {code}
> perf20 started logging the errors meanwhile and stopped only after perf19 was shut down:
> {code}
> [JBossINF] [0m[0m10:17:50,227 INFO [org.infinispan.CLUSTER] (thread-19,ejb,perf20) ISPN000094: Received new cluster view for channel ejb: [perf19|5] (4) [perf19, perf20, perf21, perf18]
> [JBossINF] [0m[0m10:17:50,228 INFO [org.infinispan.CLUSTER] (thread-19,ejb,perf20) ISPN100000: Node perf18 joined the cluster
> [JBossINF] [0m[31m10:18:00,256 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAccessMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAttributeKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9[1])]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 30250 from perf18
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> [JBossINF]
> {code}
> There were no issues in this scenario in EAP 7.1.0.GA.
> Links:
> Clients: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
> perf18: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
> perf20: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9890) Timed out waiting for responses for request X from node Y immediately after node Y rejoins the cluster (failover with fine granularity)
by Radoslav Husar (JIRA)
[ https://issues.jboss.org/browse/WFLY-9890?page=com.atlassian.jira.plugin.... ]
Radoslav Husar updated WFLY-9890:
---------------------------------
Priority: Critical (was: Major)
> Timed out waiting for responses for request X from node Y immediately after node Y rejoins the cluster (failover with fine granularity)
> ---------------------------------------------------------------------------------------------------------------------------------------
>
> Key: WFLY-9890
> URL: https://issues.jboss.org/browse/WFLY-9890
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 12.0.0.Beta1
> Reporter: Michal Vinkler
> Assignee: Paul Ferraro
> Priority: Critical
>
> Seen in SF failover tests - scenario: failover-http-granular-shutdown-repl-sync
> (replication granularity is set to ATTRIBUTE level)
> Description: In the failover test, each server is shut down and after some time it rejoins the cluster. After joining the cluster again, the load is distributed to this node. It seems that first request for some session handled by that node produces ERROR in the log of some other server until the time another cluster topology change occurs.
> Stacktrace of the error:
> {code}
> [JBossINF] [0m[31m10:18:00,256 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAccessMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAttributeKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9[1])]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 30250 from perf18
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> {code}
> Client gets the stale data:
> {code}
> 2018/02/21 10:18:00:272 EST [WARN ][Runner - 16] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16>
> org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16
> at org.jboss.smartfrog.loaddriver.http.AbstractSerialNumberValidatorFactoryImpl$SerialNumberValidator.processRequest(AbstractSerialNumberValidatorFactoryImpl.java:133)
> at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:52)
> at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:103)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> Example - timeline:
> {code}
> 4 servers are running, 2000 clients, no issue in the beggining
> 2018/02/21 10:16:43:234 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Node 0 (perf18) is down.
> - still no issues
> 2018/02/21 10:17:43:234 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Bringing back node 0 (perf18)
> 2018/02/21 10:17:55:611 EST [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Node 0 (perf18) is up.
> 2018/02/21 10:18:00:272 EST [WARN ][Runner - 16] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 60, received 59, Runner: 16>
> {code}
> perf20 started logging the errors meanwhile and stopped only after perf19 was shut down:
> {code}
> [JBossINF] [0m[0m10:17:50,227 INFO [org.infinispan.CLUSTER] (thread-19,ejb,perf20) ISPN000094: Received new cluster view for channel ejb: [perf19|5] (4) [perf19, perf20, perf21, perf18]
> [JBossINF] [0m[0m10:17:50,228 INFO [org.infinispan.CLUSTER] (thread-19,ejb,perf20) ISPN100000: Node perf18 joined the cluster
> [JBossINF] [0m[31m10:18:00,256 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAccessMetaDataKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9), SessionAttributeKey(f25_wwXXpvtNC9QTHZUtSwhmEUmg-wI77RL_17b9[1])]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 30250 from perf18
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> [JBossINF]
> {code}
> There were no issues in this scenario in EAP 7.1.0.GA.
> Links:
> Clients: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
> perf18: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
> perf20: http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-fa...
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9901) Timed out waiting for responses for request X from Y
by Richard Janík (JIRA)
[ https://issues.jboss.org/browse/WFLY-9901?page=com.atlassian.jira.plugin.... ]
Richard Janík updated WFLY-9901:
--------------------------------
Description:
Seen in our clustering tests in scenarios with EJBs:
{noformat}
[JBossINF] [0m[31m08:51:55,228 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p9-t1) ISPN000136: Error executing command PrepareCommand, writing keys [UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2], UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2]]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 22482 from perf19
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
{noformat}
and
{noformat}
[JBossINF] [0m[31m08:56:32,059 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-30) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
[JBossINF] at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
[JBossINF] at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
[JBossINF] at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
[JBossINF] at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
[JBossINF] at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:154)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:200)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.handleAfterCompletion(StatefulSessionSynchronizationInterceptor.java:287)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:260)
[JBossINF] at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
[JBossINF] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)
[JBossINF] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
[JBossINF] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
[JBossINF] at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73)
[JBossINF] at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
[JBossINF] at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
[JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
[JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
[JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
[JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
[JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:541)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:536)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:194)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] ... 1 more
{noformat}
Example: [shutdown-repl-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...]
Looks similar to WFLY-6356 (that maybe should be closed as the clone was verified), but the cause is different and this is not restricted to *REPL* scenarios. Otherwise it behaves the same - seen after a node rejoins a cluster and doesn't result in invocation failures.
was:
Seen in our clustering tests in scenarios with EJBs:
{noformat}
[JBossINF] [0m[31m08:56:32,059 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-30) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
[JBossINF] at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
[JBossINF] at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
[JBossINF] at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
[JBossINF] at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
[JBossINF] at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:154)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:200)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.handleAfterCompletion(StatefulSessionSynchronizationInterceptor.java:287)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:260)
[JBossINF] at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
[JBossINF] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)
[JBossINF] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
[JBossINF] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
[JBossINF] at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73)
[JBossINF] at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
[JBossINF] at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
[JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
[JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
[JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
[JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
[JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:541)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:536)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:194)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] ... 1 more
{noformat}
Example: [shutdown-repl-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...]
Looks similar to WFLY-6356 (that maybe should be closed as the clone was verified), but the cause is different and this is not restricted to *REPL* scenarios. Otherwise it behaves the same - seen after a node rejoins a cluster and doesn't result in invocation failures.
> Timed out waiting for responses for request X from Y
> ----------------------------------------------------
>
> Key: WFLY-9901
> URL: https://issues.jboss.org/browse/WFLY-9901
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 12.0.0.Beta1
> Reporter: Richard Janík
> Assignee: Paul Ferraro
>
> Seen in our clustering tests in scenarios with EJBs:
> {noformat}
> [JBossINF] [0m[31m08:51:55,228 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p9-t1) ISPN000136: Error executing command PrepareCommand, writing keys [UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2], UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2]]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 22482 from perf19
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> {noformat}
> and
> {noformat}
> [JBossINF] [0m[31m08:56:32,059 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-30) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
> [JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
> [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
> [JBossINF] at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
> [JBossINF] at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
> [JBossINF] at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
> [JBossINF] at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
> [JBossINF] at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:154)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:200)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.handleAfterCompletion(StatefulSessionSynchronizationInterceptor.java:287)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:260)
> [JBossINF] at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
> [JBossINF] at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
> [JBossINF] at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
> [JBossINF] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
> [JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
> [JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)
> [JBossINF] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
> [JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289)
> [JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
> [JBossINF] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
> [JBossINF] at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73)
> [JBossINF] at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
> [JBossINF] at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
> [JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
> [JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
> [JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
> [JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
> [JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:541)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:536)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:194)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] ... 1 more
> {noformat}
> Example: [shutdown-repl-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...]
> Looks similar to WFLY-6356 (that maybe should be closed as the clone was verified), but the cause is different and this is not restricted to *REPL* scenarios. Otherwise it behaves the same - seen after a node rejoins a cluster and doesn't result in invocation failures.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9901) Timed out waiting for responses for request X from Y
by Radoslav Husar (JIRA)
[ https://issues.jboss.org/browse/WFLY-9901?page=com.atlassian.jira.plugin.... ]
Radoslav Husar closed WFLY-9901.
--------------------------------
Resolution: Duplicate Issue
Duplicates WFLY-9890.
> Timed out waiting for responses for request X from Y
> ----------------------------------------------------
>
> Key: WFLY-9901
> URL: https://issues.jboss.org/browse/WFLY-9901
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 12.0.0.Beta1
> Reporter: Richard Janík
> Assignee: Paul Ferraro
>
> Seen in our clustering tests in scenarios with EJBs:
> {noformat}
> [JBossINF] [0m[31m08:51:55,228 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p9-t1) ISPN000136: Error executing command PrepareCommand, writing keys [UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2], UUIDSessionID [0e37be8b-b6a0-4057-b4c4-68fa5d39ecf2]]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 22482 from perf19
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> {noformat}
> and
> {noformat}
> [JBossINF] [0m[31m08:56:32,059 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-30) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
> [JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
> [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
> [JBossINF] at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
> [JBossINF] at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
> [JBossINF] at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
> [JBossINF] at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
> [JBossINF] at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
> [JBossINF] at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:154)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:200)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.handleAfterCompletion(StatefulSessionSynchronizationInterceptor.java:287)
> [JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:260)
> [JBossINF] at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
> [JBossINF] at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
> [JBossINF] at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
> [JBossINF] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
> [JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
> [JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)
> [JBossINF] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
> [JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289)
> [JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
> [JBossINF] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
> [JBossINF] at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73)
> [JBossINF] at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
> [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
> [JBossINF] at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
> [JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
> [JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
> [JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
> [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
> [JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
> [JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
> [JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:541)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:536)
> [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:194)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
> [JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
> [JBossINF] at java.lang.Thread.run(Thread.java:748)
> [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
> [JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
> [JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
> [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [JBossINF] ... 1 more
> {noformat}
> Example: [shutdown-repl-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...]
> Looks similar to WFLY-6356 (that maybe should be closed as the clone was verified), but the cause is different and this is not restricted to *REPL* scenarios. Otherwise it behaves the same - seen after a node rejoins a cluster and doesn't result in invocation failures.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0
[JBoss JIRA] (WFLY-9901) Timed out waiting for responses for request X from Y
by Richard Janík (JIRA)
Richard Janík created WFLY-9901:
-----------------------------------
Summary: Timed out waiting for responses for request X from Y
Key: WFLY-9901
URL: https://issues.jboss.org/browse/WFLY-9901
Project: WildFly
Issue Type: Bug
Components: Clustering
Affects Versions: 12.0.0.Beta1
Reporter: Richard Janík
Assignee: Paul Ferraro
Seen in our clustering tests in scenarios with EJBs:
{noformat}
[JBossINF] [0m[31m08:56:32,059 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-30) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
[JBossINF] at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
[JBossINF] at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
[JBossINF] at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
[JBossINF] at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
[JBossINF] at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
[JBossINF] at org.jboss.as.ejb3.cache.distributable.DistributableCache.release(DistributableCache.java:154)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.releaseInstance(StatefulSessionSynchronizationInterceptor.java:200)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor.handleAfterCompletion(StatefulSessionSynchronizationInterceptor.java:287)
[JBossINF] at org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor$StatefulSessionSynchronization.afterCompletion(StatefulSessionSynchronizationInterceptor.java:260)
[JBossINF] at org.jboss.as.txn.service.internal.tsr.JCAOrderedLastSynchronizationList.afterCompletion(JCAOrderedLastSynchronizationList.java:147)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:196)
[JBossINF] at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.afterCompletion(AbstractTransaction.java:279)
[JBossINF] at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:542)
[JBossINF] at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:101)
[JBossINF] at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289)
[JBossINF] at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
[JBossINF] at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
[JBossINF] at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73)
[JBossINF] at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:90)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330)
[JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
[JBossINF] at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
[JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
[JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
[JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
[JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
[JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
[JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
[JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:541)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:536)
[JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:194)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1979)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1481)
[JBossINF] at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1374)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 68008 from perf21
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] ... 1 more
{noformat}
Example: [shutdown-repl-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/j...]
Looks similar to WFLY-6356 (that maybe should be closed as the clone was verified), but the cause is different and this is not restricted to *REPL* scenarios. Otherwise it behaves the same - seen after a node rejoins a cluster and doesn't result in invocation failures.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
8 years, 2 months
- 1
- 0