Infinispan cluster error in RadarGun 1.0.0 Final
kavandesai Mar 16, 2012 7:22 AMHi
Since last couple of day I was trying to form cluster of infinispan nodes in Radargun 1.0.
I was able to start both master and slave nodes (2 slave) however the log message on master appear that cluster is not formed
2012-03-13 11:20:18,401 [main] INFO [org.radargun.state.MasterState] Started benchmarking product 'infinispan4'
2012-03-13 11:20:18,418 [main] INFO [org.radargun.Master] Master started and listening for connection on: /10.83.14.234:2103
2012-03-13 11:20:18,418 [main] INFO [org.radargun.Master] Waiting 5 seconds for server socket to open completely
2012-03-13 11:20:23,421 [main] INFO [org.radargun.Master] Waiting for 2 slaves to register to the master.
2012-03-13 11:20:23,472 [main] INFO [org.radargun.Master] Waiting for 1 slaves to register to the master.
2012-03-13 11:20:25,058 [main] INFO [org.radargun.Master] Connection established from 2 slaves.
2012-03-13 11:20:25,058 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] Initializing: 2,2,1
2012-03-13 11:20:25,058 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] Initializing config 2
2012-03-13 11:20:25,058 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarkIt=0
2012-03-13 11:20:25,058 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarks size=1
2012-03-13 11:20:25,058 [main] INFO [org.radargun.Master] Starting dist stage 'DestroyWrapperStage' on 2 Slaves: DestroyWrapperStage {slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
2012-03-13 11:20:25,236 [main] INFO [org.radargun.stages.DestroyWrapperStage] DestroyWrapperStage received ack from all (2) slaves. Durations [0:61 milliseconds, 1:47 milliseconds]
2012-03-13 11:20:25,237 [main] INFO [org.radargun.stages.DestroyWrapperStage] Node 1 has an initial free memory of: 1002447kb
2012-03-13 11:20:25,237 [main] INFO [org.radargun.stages.DestroyWrapperStage] Node 0 has an initial free memory of: 1002447kb
2012-03-13 11:20:25,237 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarkIt=0
2012-03-13 11:20:25,237 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarks size=1
2012-03-13 11:20:25,237 [main] INFO [org.radargun.Master] Starting dist stage 'StartClusterStage' on 2 Slaves: StartClusterStage {productName='infinispan4', useSmartClassLoading=true, config=dist-sync.xml, slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
2012-03-13 11:23:38,018 [main] INFO [org.radargun.stages.StartClusterStage] StartClusterStage received ack from all (2) slaves. Durations [0:187.28 seconds, 1:192.78 seconds]
2012-03-13 11:23:38,019 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarkIt=0
2012-03-13 11:23:38,019 [main] INFO [org.radargun.config.ScalingBenchmarkConfig] fixedBenchmarks size=1
2012-03-13 11:23:38,019 [main] INFO [org.radargun.Master] Starting dist stage 'ClusterValidationStage' on 2 Slaves: ClusterValidationStage {isPartialReplication=false, replicationTryCount=60, replicationTimeSleep=2000, wrapper=null, slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
2012-03-13 11:25:38,229 [main] INFO [org.radargun.stages.ClusterValidationStage] ClusterValidationStage received ack from all (2) slaves. Durations [0:120.12 seconds, 1:120.2 seconds]
2012-03-13 11:25:38,229 [main] WARN [org.radargun.stages.ClusterValidationStage] On slave DefaultDistStageAck{slaveIndex=0, slaveAddress=/10.83.14.227, isError=false, errorMessage='null', payload=-1, remoteExceptionString=null} total replication hasn't occurred. Expected 1 and received -1
2012-03-13 11:25:38,230 [main] WARN [org.radargun.stages.ClusterValidationStage] On slave DefaultDistStageAck{slaveIndex=1, slaveAddress=/10.83.14.226, isError=false, errorMessage='null', payload=-1, remoteExceptionString=null} total replication hasn't occurred. Expected 1 and received -1
2012-03-13 11:25:38,230 [main] WARN [org.radargun.stages.ClusterValidationStage] Cluster hasn't formed!
On slave the message appears like
java -server -Xmx1024M -Xms1024M -Dresolve.dns=false -Djgroups.timer.num_threads=4 -Djava.net.preferIPv4Stack=true -Dlog4j.file.prefix=node1 -Dbind.address= -classpath /opt/RadarGun-1.0.0-FINAL/lib/activation-1.1.jar:/opt/RadarGun-1.0.0-FINAL/lib/commons-beanutils-1.8.0.jar:/opt/RadarGun-1.0.0-FINAL/lib/commons-digester-2.0.jar:/opt/RadarGun-1.0.0-FINAL/lib/commons-logging-1.1.1.jar:/opt/RadarGun-1.0.0-FINAL/lib/commons-math-1.2.jar:/opt/RadarGun-1.0.0-FINAL/lib/jboss-transaction-api-1.0.1.GA.jar:/opt/RadarGun-1.0.0-FINAL/lib/jcommon-1.0.15.jar:/opt/RadarGun-1.0.0-FINAL/lib/jfreechart-1.0.12.jar:/opt/RadarGun-1.0.0-FINAL/lib/log4j-1.2.14.jar:/opt/RadarGun-1.0.0-FINAL/lib/mail-1.4.2.jar:/opt/RadarGun-1.0.0-FINAL/lib/radargun-framework-1.0.0-FINAL.jar:/opt/RadarGun-1.0.0-FINAL/conf org.radargun.Slave -master 10.83.14.234:2103
--------------------------------------------------------------------------------
PerNodeRollingFileAppender::Using file prefix:node1
11:20:12,021 INFO [Slave] Attempting to connect to master 10.83.14.234:2103
11:20:12,039 INFO [Slave] Successfully established connection with master at: 10.83.14.234:2103
11:20:15,281 INFO [Slave] Executing stage: DestroyWrapperStage {slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
11:20:15,281 INFO [DestroyWrapperStage] Received destroy cache wrapper request from master...
11:20:15,287 INFO [DestroyWrapperStage] No cache wrapper deployed on this slave, nothing to do.
11:20:15,306 INFO [DestroyWrapperStage] Before executing clear, memory looks like this: Memory - free: 1002447 - max:1,013,632 kb- total:1,013,632 kb
11:20:15,342 INFO [DestroyWrapperStage] After executing cleanup, memory looks like this: Memory - free: 1007531 - max:1,013,632 kb- total:1,013,632 kb
11:20:15,356 INFO [Slave] Finished stage: DestroyWrapperStage {slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
11:20:15,359 INFO [Slave] Ack successfully sent to the master
11:20:15,368 INFO [Slave] Executing stage: StartClusterStage {productName='infinispan4', useSmartClassLoading=true, config=dist-sync.xml, slaveIndex=0, activeSlavesCount=2, totalSlavesCount=2}
11:20:15,368 INFO [StartClusterStage] Startup staggering, cluster size is 2 This is the slave with index 0, not sleeping
11:20:15,368 INFO [StartClusterStage] Ack master's StartCluster stage. Local address is: /10.83.14.227. This slave's index is: 0
11:20:15,373 INFO [StartClusterStage] Creating newInstance org.radargun.cachewrappers.InfinispanWrapper with classloader java.net.URLClassLoader@6fc5f743
11:20:16,279 WARN [GenericTransactionManagerLookup] Falling back to DummyTransactionManager from Infinispan
11:20:16,716 INFO [JGroupsTransport] Starting JGroups Channel
-------------------------------------------------------------------
GMS: address=node1-37250, cluster=x, physical address=127.0.0.1:35211
-------------------------------------------------------------------
11:20:22,389 INFO [JGroupsTransport] Received new cluster view: [node1-37250|0] [node1-37250]
11:20:22,391 INFO [JGroupsTransport] Cache local address is node1-37250, physical addresses are [127.0.0.1:35211]
11:20:22,391 INFO [GlobalComponentRegistry] Infinispan version: Infinispan 'Ursus' 4.2.0-SNAPSHOT
11:20:22,453 INFO [ComponentRegistry] Infinispan version: Infinispan 'Ursus' 4.2.0-SNAPSHOT
11:20:22,453 INFO [InfinispanWrapper] Loading JGroups form: file:/opt/RadarGun-1.0.0-FINAL/plugins/infinispan4/lib/jgroups-2.11.0.GA.jar
11:20:22,453 INFO [InfinispanWrapper] JGroups version: JGroups 2.11.0.GA [$Id: Version.java,v 1.110 2010/10/29 12:02:06 belaban Exp $]
11:20:22,453 INFO [StartClusterStage] Number of members=1 is not the one expected: 2
11:20:23,455 INFO [StartClusterStage] Number of members=1 is not the one expected: 2
When I reduced the number of salve from 2 to 1 it works.