[JBoss JIRA] (WFLY-10757) ParseError when deploying application with netty dependency
by Jan Kašík (JIRA)
[ https://issues.jboss.org/browse/WFLY-10757?page=com.atlassian.jira.plugin... ]
Jan Kašík reassigned WFLY-10757:
--------------------------------
Assignee: Jan Kašík (was: Jason Greene)
> ParseError when deploying application with netty dependency
> ------------------------------------------------------------
>
> Key: WFLY-10757
> URL: https://issues.jboss.org/browse/WFLY-10757
> Project: WildFly
> Issue Type: Bug
> Components: Server, XML Frameworks
> Affects Versions: 14.0.0.CR1
> Reporter: Jan Kašík
> Assignee: Jan Kašík
> Priority: Critical
>
> It is not possible to deploy app which has {{org.jboss.netty}} packed as a dependency. During processing of {{jboss-beans.xml}}, the deployment fails because there is an unexpected element: {{\{urn:jboss:bean-deployer:2.0}deployment}}.
> {code:title=Part of log including exception|borderStyle=solid}
> 2018-07-30 05:57:16.701 DEBUG o.w.e.c.c.o.OnlineManagementClient: Executing CLI operation undeploy *metamer*
> 05:57:20,757 INFO [org.jboss.as.repository] (management-handler-thread - 1) WFLYDR0001: Content added at location /home/hudson/hudson_workspace/workspace/eap-7.x-jsf-richfaces/6b4879d7/wildfly-14.0.0.Beta2-SNAPSHOT/standalone/data/content/c1/ef588d063c7cd396e765ef8452fbc43c04ce75/content
> 05:57:20,779 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0027: Starting deployment of "metamer.war" (runtime-name: "metamer.war")
> 05:57:22,206 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-1) MSC000001: Failed to start service jboss.deployment.unit."metamer.war".PARSE: org.jboss.msc.service.StartException in service jboss.deployment.unit."metamer.war".PARSE: WFLYSRV0153: Failed to process phase PARSE of deployment "metamer.war"
> at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:151)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1736)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1698)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1556)
> at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
> at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: "/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml"
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptor(KernelDeploymentParsingProcessor.java:154)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptors(KernelDeploymentParsingProcessor.java:125)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.deploy(KernelDeploymentParsingProcessor.java:82)
> at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:144)
> ... 8 more
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'
> at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:120)
> at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:76)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptor(KernelDeploymentParsingProcessor.java:145)
> ... 11 more
> 05:57:22,210 ERROR [org.jboss.as.controller.management-operation] (management-handler-thread - 1) WFLYCTL0013: Operation ("deploy") failed - address: ([("deployment" => "metamer.war")]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.deployment.unit.\"metamer.war\".PARSE" => "WFLYSRV0153: Failed to process phase PARSE of deployment \"metamer.war\"
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: \"/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml\"
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'"}}
> 05:57:22,217 ERROR [org.jboss.as.server] (management-handler-thread - 1) WFLYSRV0021: Deploy of deployment "metamer.war" was rolled back with the following failure message:
> {"WFLYCTL0080: Failed services" => {"jboss.deployment.unit.\"metamer.war\".PARSE" => "WFLYSRV0153: Failed to process phase PARSE of deployment \"metamer.war\"
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: \"/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml\"
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'"}}
> 05:57:22,266 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) WFLYSRV0028: Stopped deployment metamer.war (runtime-name: metamer.war) in 47ms
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10757) ParseError when deploying application with netty dependency
by Jan Kašík (JIRA)
[ https://issues.jboss.org/browse/WFLY-10757?page=com.atlassian.jira.plugin... ]
Jan Kašík reassigned WFLY-10757:
--------------------------------
Assignee: Jason Greene (was: Jan Kašík)
> ParseError when deploying application with netty dependency
> ------------------------------------------------------------
>
> Key: WFLY-10757
> URL: https://issues.jboss.org/browse/WFLY-10757
> Project: WildFly
> Issue Type: Bug
> Components: Server, XML Frameworks
> Affects Versions: 14.0.0.CR1
> Reporter: Jan Kašík
> Assignee: Jason Greene
> Priority: Critical
>
> It is not possible to deploy app which has {{org.jboss.netty}} packed as a dependency. During processing of {{jboss-beans.xml}}, the deployment fails because there is an unexpected element: {{\{urn:jboss:bean-deployer:2.0}deployment}}.
> {code:title=Part of log including exception|borderStyle=solid}
> 2018-07-30 05:57:16.701 DEBUG o.w.e.c.c.o.OnlineManagementClient: Executing CLI operation undeploy *metamer*
> 05:57:20,757 INFO [org.jboss.as.repository] (management-handler-thread - 1) WFLYDR0001: Content added at location /home/hudson/hudson_workspace/workspace/eap-7.x-jsf-richfaces/6b4879d7/wildfly-14.0.0.Beta2-SNAPSHOT/standalone/data/content/c1/ef588d063c7cd396e765ef8452fbc43c04ce75/content
> 05:57:20,779 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) WFLYSRV0027: Starting deployment of "metamer.war" (runtime-name: "metamer.war")
> 05:57:22,206 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-1) MSC000001: Failed to start service jboss.deployment.unit."metamer.war".PARSE: org.jboss.msc.service.StartException in service jboss.deployment.unit."metamer.war".PARSE: WFLYSRV0153: Failed to process phase PARSE of deployment "metamer.war"
> at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:151)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1736)
> at org.jboss.msc.service.ServiceControllerImpl$StartTask.execute(ServiceControllerImpl.java:1698)
> at org.jboss.msc.service.ServiceControllerImpl$ControllerTask.run(ServiceControllerImpl.java:1556)
> at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
> at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
> at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: "/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml"
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptor(KernelDeploymentParsingProcessor.java:154)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptors(KernelDeploymentParsingProcessor.java:125)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.deploy(KernelDeploymentParsingProcessor.java:82)
> at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:144)
> ... 8 more
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'
> at org.jboss.staxmapper.XMLMapperImpl.processNested(XMLMapperImpl.java:120)
> at org.jboss.staxmapper.XMLMapperImpl.parseDocument(XMLMapperImpl.java:76)
> at org.jboss.as.pojo.KernelDeploymentParsingProcessor.parseDescriptor(KernelDeploymentParsingProcessor.java:145)
> ... 11 more
> 05:57:22,210 ERROR [org.jboss.as.controller.management-operation] (management-handler-thread - 1) WFLYCTL0013: Operation ("deploy") failed - address: ([("deployment" => "metamer.war")]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.deployment.unit.\"metamer.war\".PARSE" => "WFLYSRV0153: Failed to process phase PARSE of deployment \"metamer.war\"
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: \"/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml\"
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'"}}
> 05:57:22,217 ERROR [org.jboss.as.server] (management-handler-thread - 1) WFLYSRV0021: Deploy of deployment "metamer.war" was rolled back with the following failure message:
> {"WFLYCTL0080: Failed services" => {"jboss.deployment.unit.\"metamer.war\".PARSE" => "WFLYSRV0153: Failed to process phase PARSE of deployment \"metamer.war\"
> Caused by: org.jboss.as.server.deployment.DeploymentUnitProcessingException: WFLYPOJO0038: Exception while parsing POJO descriptor file: \"/content/metamer.war/WEB-INF/lib/netty-3.2.10.Final.jar/META-INF/jboss-beans.xml\"
> Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[17,1]
> Message: Unexpected element '{urn:jboss:bean-deployer:2.0}deployment'"}}
> 05:57:22,266 INFO [org.jboss.as.server.deployment] (MSC service thread 1-3) WFLYSRV0028: Stopped deployment metamer.war (runtime-name: metamer.war) in 47ms
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (DROOLS-2781) [Guided Rule] Can't be opened if constraint to bound field present
by Jozef Marko (JIRA)
[ https://issues.jboss.org/browse/DROOLS-2781?page=com.atlassian.jira.plugi... ]
Jozef Marko updated DROOLS-2781:
--------------------------------
Fix Version/s: 7.10.0.Final
> [Guided Rule] Can't be opened if constraint to bound field present
> ------------------------------------------------------------------
>
> Key: DROOLS-2781
> URL: https://issues.jboss.org/browse/DROOLS-2781
> Project: Drools
> Issue Type: Bug
> Components: Guided Rule Editor
> Affects Versions: 7.9.0.Final
> Reporter: Jozef Marko
> Assignee: Toni Rikkola
> Priority: Critical
> Labels: drools-tools
> Fix For: 7.10.0.Final
>
> Attachments: Screenshot from 2018-07-24 14-32-00.png
>
>
> {code:mvel}
> package com.myspace.repr;
> import java.lang.Number;
> rule "rule"
> dialect "mvel"
> when
> DataObject( $stringField : sFieldOne == "something" )
> DataObjectTwo( sFieldTwo == $stringField )
> then
> end
> {code}
> Assume the rdrl file above where both *sFieldOne* and *sFieldTwo* are both of *String* type. Then if you try open this rdrl file in workbench the unexpected error dialog appears.
> The same can be seen if we assign role EVENT to *DataObject* and have this rule below.
> {code:mvel}
> package com.myspace.repr;
> import java.lang.Number;
> rule "eventRule"
> dialect "mvel"
> when
> e1 : DataObject( this after [1m, 2m] "24-Jul-2018" ) over window:time (10d)
> e2 : DataObject( this before e1 )
> then
> end
> {code}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10758) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
by tommaso borgato (JIRA)
[ https://issues.jboss.org/browse/WFLY-10758?page=com.atlassian.jira.plugin... ]
tommaso borgato updated WFLY-10758:
-----------------------------------
Description:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}}) was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
...
{noformat}
the repeated block in the stack is the following:
{noformat}
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
was:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}}) was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
...
{noformat}
the repeated block in the stack is the following:
{noformat}
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
> ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> -----------------------------------------------------------------------------------------------------
>
> Key: WFLY-10758
> URL: https://issues.jboss.org/browse/WFLY-10758
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Reporter: tommaso borgato
> Assignee: Paul Ferraro
>
> The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
> The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}}) was failed:
> {noformat}
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> [JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
> [JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
> [JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
> ...
> {noformat}
> the repeated block in the stack is the following:
> {noformat}
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
> {noformat}
> 3396 sampling errors occurred in this run.
> Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10736) Server in cluster hangs during start after previous kill
by Miroslav Novak (JIRA)
[ https://issues.jboss.org/browse/WFLY-10736?page=com.atlassian.jira.plugin... ]
Miroslav Novak commented on WFLY-10736:
---------------------------------------
[~pferraro] This use case does not seem to be so uncommon in production. In case that any liveness check of server fails there are scripts which simply restart the server. Yes, it can try clean shutdown first but if server does not shutdown due to any reason in given timeout then it will kill and start server again which is the same scenario. This is default behaviour for our Wildfly/EAP CD docker images for OpenShift. If server crashes in the pod then server in the pod is restarted immediately with the same node name.
Also this issue is regression. Those tests with kill and restart scenario are executed since EAP 6 times and there were no issues until now. There is used default config for infinispan and JGroups.
I tried the workaround:
{{/subsytem=infinispan/cache-container=server/replicated-cache=default/component=state-transfer:write-attribute(name=timeout, value=0)}}
and it seems to work. I can still see the exception on node-2 however node-1 does not hang any more.
cc-ing [~bmaxwell] [~msvehla] to let them know as well.
> Server in cluster hangs during start after previous kill
> --------------------------------------------------------
>
> Key: WFLY-10736
> URL: https://issues.jboss.org/browse/WFLY-10736
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Reporter: Miroslav Novak
> Assignee: Paul Ferraro
> Priority: Blocker
> Labels: blocker-WF14
> Attachments: clusterKilTest.zip, node-1-thread-dump-before-kill-shutdown-sequence.txt, standalone-full-ha-1.xml, standalone-full-ha-2.xml
>
>
> There is regression in JGroups or Infinispan in one of our tests for fault tolerance of JMS bridges. However work on JMS bridge appears to be unrelated. Issue was hit in WF weekly run.
> Test Scenario:
> * There are two servers. InQueue is deployed on Node 1,
> * OutQueue is deployed on Node 2. Both servers are started.
> * Large byte messages are sent to InQueue deployed on Node 1. Bridge between servers/queues transfers messages from node 1 to node 2.
> * Node 1 is killed and started again.
> * All messages are received from OutQueue deployed on Node 2.
> Result:
> Node 1 does not start after kill and hangs. There is following exception logged in node 2:
> {code}
> :26:17,894 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100000: Node node-1 joined the cluster
> 09:26:18,520 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,521 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,521 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,523 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,868 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) ISPN000310: Starting cluster-wide rebalance for cache default, topology CacheTopology{id=17, phase=READ_OLD_WRITE_ALL, rebalanceId=6, currentCH=ReplicatedConsistentHash{ns = 256, owners = (2)[node-2: 122, node-1: 134]}, pendingCH=ReplicatedConsistentHash{ns = 256, owners = (3)[node-2: 84, node-1: 90, node-1: 82]}, unionCH=null, actualMembers=[node-2, node-1, node-1], persistentUUIDs=[12443bfb-e88a-46f3-919e-9213bf38ce19, 2873237f-d881-463f-8a5a-940bf1d764e5, a05ea8af-a83b-42a9-b937-dc2da1cae6d1]}
> 09:26:18,869 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) [Context=default][Scope=node-2]ISPN100002: Started rebalance with topology id 17
> 09:26:18,870 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t5) [Context=default][Scope=node-2]ISPN100003: Node node-2 finished rebalance phase with topology id 17
> 09:26:18,981 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) [Context=default][Scope=node-1]ISPN100003: Node node-1 finished rebalance phase with topology id 17
> 09:27:18,530 WARN [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread--p15-t4) ISPN000197: Error updating cluster member list: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
> Suppressed: java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) [rt.jar:1.8.0_131]
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) [rt.jar:1.8.0_131]
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
> at org.infinispan.remoting.transport.Transport.invokeRemotely(Transport.java:71)
> at org.infinispan.topology.ClusterTopologyManagerImpl.confirmMembersAvailable(ClusterTopologyManagerImpl.java:540)
> at org.infinispan.topology.ClusterTopologyManagerImpl.updateCacheMembers(ClusterTopologyManagerImpl.java:523)
> at org.infinispan.topology.ClusterTopologyManagerImpl.handleClusterView(ClusterTopologyManagerImpl.java:334)
> at org.infinispan.topology.ClusterTopologyManagerImpl.access$500(ClusterTopologyManagerImpl.java:85)
> at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.lambda$handleViewChange$0(ClusterTopologyManagerImpl.java:745)
> at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144)
> at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33)
> at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
> ... 1 more
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> ... 1 more
> [CIRCULAR REFERENCE:java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1]
> 09:27:18,530 WARN [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread--p16-t4) ISPN000197: Error updating cluster member list: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
> Suppressed: java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) [rt.jar:1.8.0_131]
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) [rt.jar:1.8.0_131]
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
> at org.infinispan.remoting.transport.Transport.invokeRemotely(Transport.java:71)
> at org.infinispan.topology.ClusterTopologyManagerImpl.confirmMembersAvailable(ClusterTopologyManagerImpl.java:540)
> at org.infinispan.topology.ClusterTopologyManagerImpl.updateCacheMembers(ClusterTopologyManagerImpl.java:523)
> at org.infinispan.topology.ClusterTopologyManagerImpl.handleClusterView(ClusterTopologyManagerImpl.java:334)
> at org.infinispan.topology.ClusterTopologyManagerImpl.access$500(ClusterTopologyManagerImpl.java:85)
> at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.lambda$handleViewChange$0(ClusterTopologyManagerImpl.java:745)
> at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144)
> at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33)
> at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
> ... 1 more
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> ... 1 more
> [CIRCULAR REFERENCE:java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1]
> {code}
> There is default JGroups udp stack configured which is used by Infinispan. Both of the servers (jgroups udp) are bound to 127.0.0.1. Node 2 has port offset 1000.
> Attaching thread dump from node 1 when it hangs during start.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10758) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
by tommaso borgato (JIRA)
[ https://issues.jboss.org/browse/WFLY-10758?page=com.atlassian.jira.plugin... ]
tommaso borgato updated WFLY-10758:
-----------------------------------
Description:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}}) was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
...
{noformat}
the repeated block in the stack is the following:
{noformat}
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
was:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}} was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
...
{noformat}
the repeated block in the stack is the following:
{noformat}
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
> ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> -----------------------------------------------------------------------------------------------------
>
> Key: WFLY-10758
> URL: https://issues.jboss.org/browse/WFLY-10758
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Reporter: tommaso borgato
> Assignee: Paul Ferraro
>
> The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
> The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}}) was failed:
> {noformat}
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> [JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
> [JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
> [JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> ...
> {noformat}
> the repeated block in the stack is the following:
> {noformat}
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
> {noformat}
> 3396 sampling errors occurred in this run.
> Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10758) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
by tommaso borgato (JIRA)
[ https://issues.jboss.org/browse/WFLY-10758?page=com.atlassian.jira.plugin... ]
tommaso borgato updated WFLY-10758:
-----------------------------------
Description:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}} was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
...
{noformat}
the repeated block in the stack is the following:
{noformat}
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
was:
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}} was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
> ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> -----------------------------------------------------------------------------------------------------
>
> Key: WFLY-10758
> URL: https://issues.jboss.org/browse/WFLY-10758
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Reporter: tommaso borgato
> Assignee: Paul Ferraro
>
> The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
> The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}} was failed:
> {noformat}
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
> [JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
> [JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
> [JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
> [JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
> [JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
> [JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
> [JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
> [JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
> [JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
> [JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
> [JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
> [JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
> [JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
> [JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
> [JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
> [JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
> [JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
> [JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
> [JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
> [JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> ...
> {noformat}
> the repeated block in the stack is the following:
> {noformat}
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
> [JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
> [JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
> [JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
> [JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:190)
> {noformat}
> 3396 sampling errors occurred in this run.
> Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months
[JBoss JIRA] (WFLY-10758) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
by tommaso borgato (JIRA)
tommaso borgato created WFLY-10758:
--------------------------------------
Summary: ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
Key: WFLY-10758
URL: https://issues.jboss.org/browse/WFLY-10758
Project: WildFly
Issue Type: Bug
Components: Clustering
Reporter: tommaso borgato
Assignee: Paul Ferraro
The error was observed in scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/]*}}: a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the server jvm.
The error was observed on node {{*[dev215|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_perf27_JJB/1/console-dev215/]*}} after the server was started and the first node ({{*dev212*}} was failed:
{noformat}
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,724 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,725 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|4] (3) [dev215, dev213, dev214]
[JBossINF] [0m[0m04:08:13,726 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-29,ejb,dev215) ISPN100001: Node dev212 left the cluster
[JBossINF] [0m[0m04:08:13,770 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,771 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,781 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,782 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,789 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,795 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t37) [Context=client-mappings] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,797 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,801 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,804 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,809 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p17-t8) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,814 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t63) [Context=default-server] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,818 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p20-t1) [Context=default] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,825 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t46) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,828 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t21) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,836 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t5) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,838 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:13,847 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=client-mappings] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,857 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,858 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t61) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:13,863 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t6) [Context=default-server] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,877 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t3) [Context=default] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:13,878 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t15) [Context=client-mappings] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,893 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t8) [Context=default-server] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,918 INFO [org.infinispan.CLUSTER] (remote-thread--p7-t2) [Context=default] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:13,943 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100007: After merge (or coordinator change), recovered members [dev212, dev215, dev213, dev214] with topology id 14
[JBossINF] [0m[0m04:08:13,944 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100008: Updating cache members list [dev215, dev213, dev214], topology id 15
[JBossINF] [0m[0m04:08:13,947 INFO [org.infinispan.CLUSTER] (stateTransferExecutor-thread--p19-t62) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100002: Starting rebalance with members [dev215, dev213, dev214], phase READ_OLD_WRITE_ALL, topology id 16
[JBossINF] [0m[0m04:08:14,004 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,069 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t29) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,103 INFO [org.infinispan.CLUSTER] (transport-thread--p13-t2) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,109 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t7) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-passivating.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,127 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t28) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,175 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t20) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-granular.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,219 INFO [org.wildfly.clustering.server] (DistributedSingletonService - 1) WFLYCLSV0003: dev215 elected as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,237 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t17) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,260 INFO [org.wildfly.clustering.server] (ChannelCommandDispatcherFactory - 17) WFLYCLSV0001: This node will now operate as the singleton provider of the org.wildfly.ejb3.clustered.singleton service
[JBossINF] [0m[0m04:08:14,284 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t5) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,296 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t27) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_ALL_WRITE_ALL, topology id 17
[JBossINF] [0m[0m04:08:14,356 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t23) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100009: Advancing to rebalance phase READ_NEW_WRITE_ALL, topology id 18
[JBossINF] [0m[0m04:08:14,358 INFO [org.infinispan.CLUSTER] (remote-thread--p8-t21) [Context=clusterbench-ee7.ear/clusterbench-ee7-ejb.jar] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[0m04:08:14,478 INFO [org.infinispan.CLUSTER] (remote-thread--p6-t18) [Context=clusterbench-ee7.ear.clusterbench-ee7-web-default.war] ISPN100010: Finished rebalance with members [dev215, dev213, dev214], topology id 19
[JBossINF] [0m[33m04:10:03,055 WARN [org.jgroups.protocols.UDP] (TQ-Bundler-4,ejb,dev215) JGRP000032: dev215: no physical address for f9eaadfd-8df2-bbee-54e5-7b83f3095679, dropping message
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,213 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN000094: Received new cluster view for channel ejb: [dev215|5] (2) [dev215, dev214]
[JBossINF] [0m[0m04:10:22,214 INFO [org.infinispan.CLUSTER] (VERIFY_SUSPECT.TimerThread-90,ejb,dev215) ISPN100001: Node dev213 left the cluster
[JBossINF] [0m[31m04:10:22,404 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t7) ISPN000136: Error executing command GetKeyValueCommand, writing keys []: java.lang.StackOverflowError
[JBossINF] at org.infinispan.marshall.exts.ReplicableCommandExternalizer.writeCommandHeader(ReplicableCommandExternalizer.java:87)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:110)
[JBossINF] at org.infinispan.marshall.exts.CacheRpcCommandExternalizer.writeObject(CacheRpcCommandExternalizer.java:67)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeInternal(GlobalMarshaller.java:638)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNonNullableObject(GlobalMarshaller.java:402)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeNullableObject(GlobalMarshaller.java:355)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:183)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.writeObjectOutput(GlobalMarshaller.java:176)
[JBossINF] at org.infinispan.marshall.core.GlobalMarshaller.objectToBuffer(GlobalMarshaller.java:305)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.marshallRequest(JGroupsTransport.java:1007)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.sendCommand(JGroupsTransport.java:1207)
[JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeCommand(JGroupsTransport.java:853)
[JBossINF] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeCommand(RpcManagerImpl.java:166)
[JBossINF] at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:192)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:74)
[JBossINF] at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataReadCommand(PessimisticLockingInterceptor.java:78)
[JBossINF] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:107)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.interceptors.impl.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:313)
[JBossINF] at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:39)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:41)
[JBossINF] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleExceptionOnCommandReturn(BaseStateTransferInterceptor.java:248)
[JBossINF] at org.infinispan.interceptors.impl.BaseStateTransferInterceptor.handleReadCommandReturn(BaseStateTransferInterceptor.java:261)
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
{noformat}
3396 sampling errors occurred in this run.
Please note that this scenario is the counterpart of scenario {{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/]*}} with the only difference of being executed on a different segment (perf27 instead of perf17). This other scenario has zero sampling errors and doesn't exhibit this error.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
7 years, 9 months