#2583
  • Created on
    2012-10-02 16:08
  • Reported by
    bjorn.antonsson@typesafe.com
  • Status
    Fixed
  • Priority
    High (2)
  • Assigned to
    Patrik Nordwall
  • Milestone
    2.1-RC2
  • Plan Level
    -
  • Due Date
    -

Attachments

WrongBarrier failure

http://217.142.157.108:8080/job/akka-nightly/308

[info] * akka.cluster.LeaderElectionWithFailureDetectorPuppet
[JVM-Node1] [INFO] [10/02/2012 04:13:35.705] [main] [LeaderElectionWithFailureDetectorPuppetMultiJvmNode1(akka://LeaderElectionSpec)] Role [controller] started with address [akka://LeaderElectionSpec@localhost:42898]
[JVM-Node1] LeaderElectionWithFailureDetectorPuppetMultiJvmNode1:
[JVM-Node2] [INFO] [10/02/2012 04:13:35.786] [main] [LeaderElectionWithFailureDetectorPuppetMultiJvmNode2(akka://LeaderElectionSpec)] Role [first] started with address [akka://LeaderElectionSpec@localhost:59476]
[JVM-Node4] [INFO] [10/02/2012 04:13:35.786] [main] [LeaderElectionWithFailureDetectorPuppetMultiJvmNode4(akka://LeaderElectionSpec)] Role [third] started with address [akka://LeaderElectionSpec@localhost:46933]
[JVM-Node1] A cluster of four nodes 
[JVM-Node5] [INFO] [10/02/2012 04:13:35.800] [main] [LeaderElectionWithFailureDetectorPuppetMultiJvmNode5(akka://LeaderElectionSpec)] Role [fourth] started with address [akka://LeaderElectionSpec@localhost:41943]
[JVM-Node3] [INFO] [10/02/2012 04:13:35.806] [main] [LeaderElectionWithFailureDetectorPuppetMultiJvmNode3(akka://LeaderElectionSpec)] Role [second] started with address [akka://LeaderElectionSpec@localhost:36354]
[JVM-Node4] LeaderElectionWithFailureDetectorPuppetMultiJvmNode4:
[JVM-Node2] LeaderElectionWithFailureDetectorPuppetMultiJvmNode2:
[JVM-Node4] A cluster of four nodes 
[JVM-Node5] LeaderElectionWithFailureDetectorPuppetMultiJvmNode5:
[JVM-Node3] LeaderElectionWithFailureDetectorPuppetMultiJvmNode3:
[JVM-Node2] A cluster of four nodes 
[JVM-Node3] A cluster of four nodes 
[JVM-Node5] A cluster of four nodes 
[JVM-Node2] [INFO] [10/02/2012 04:13:35.917] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:59476] - is starting up...
[JVM-Node2] [INFO] [10/02/2012 04:13:35.919] [main] [Cluster(akka://LeaderElectionSpec)] Using a dedicated scheduler for cluster. Default scheduler can be used if configured with 'akka.scheduler.tick-duration' [100 ms] <=  'akka.cluster.scheduler.tick-duration' [33 ms].
[JVM-Node2] [INFO] [10/02/2012 04:13:35.973] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:59476] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node2] [INFO] [10/02/2012 04:13:35.973] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:59476] - has started up successfully
[JVM-Node2] [INFO] [10/02/2012 04:13:35.986] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Hyperic SIGAR was not found on the classpath or not installed properly. Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriateplatform-specific native libary to 'java.library.path'.
[JVM-Node2] [INFO] [10/02/2012 04:13:35.997] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://LeaderElectionSpec@localhost:59476]
[JVM-Node2] [WARN] [10/02/2012 04:13:36.027] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/system/cluster/core] unhandled message from Actor[akka://LeaderElectionSpec/system/cluster/core]: JoinSeedNodes(Vector())
[JVM-Node5] [INFO] [10/02/2012 04:13:36.115] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:41943] - is starting up...
[JVM-Node3] [INFO] [10/02/2012 04:13:36.115] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - is starting up...
[JVM-Node4] [INFO] [10/02/2012 04:13:36.115] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:46933] - is starting up...
[JVM-Node3] [INFO] [10/02/2012 04:13:36.117] [main] [Cluster(akka://LeaderElectionSpec)] Using a dedicated scheduler for cluster. Default scheduler can be used if configured with 'akka.scheduler.tick-duration' [100 ms] <=  'akka.cluster.scheduler.tick-duration' [33 ms].
[JVM-Node5] [INFO] [10/02/2012 04:13:36.117] [main] [Cluster(akka://LeaderElectionSpec)] Using a dedicated scheduler for cluster. Default scheduler can be used if configured with 'akka.scheduler.tick-duration' [100 ms] <=  'akka.cluster.scheduler.tick-duration' [33 ms].
[JVM-Node4] [INFO] [10/02/2012 04:13:36.117] [main] [Cluster(akka://LeaderElectionSpec)] Using a dedicated scheduler for cluster. Default scheduler can be used if configured with 'akka.scheduler.tick-duration' [100 ms] <=  'akka.cluster.scheduler.tick-duration' [33 ms].
[JVM-Node5] [INFO] [10/02/2012 04:13:36.169] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:41943] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node5] [INFO] [10/02/2012 04:13:36.169] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:41943] - has started up successfully
[JVM-Node4] [INFO] [10/02/2012 04:13:36.171] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:46933] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node4] [INFO] [10/02/2012 04:13:36.171] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:46933] - has started up successfully
[JVM-Node3] [INFO] [10/02/2012 04:13:36.173] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node3] [INFO] [10/02/2012 04:13:36.173] [main] [Cluster(akka://LeaderElectionSpec)] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - has started up successfully
[JVM-Node5] [INFO] [10/02/2012 04:13:36.178] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Hyperic SIGAR was not found on the classpath or not installed properly. Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriateplatform-specific native libary to 'java.library.path'.
[JVM-Node4] [INFO] [10/02/2012 04:13:36.181] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Hyperic SIGAR was not found on the classpath or not installed properly. Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriateplatform-specific native libary to 'java.library.path'.
[JVM-Node3] [INFO] [10/02/2012 04:13:36.182] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/cluster/metrics] Hyperic SIGAR was not found on the classpath or not installed properly. Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriateplatform-specific native libary to 'java.library.path'.
[JVM-Node4] [INFO] [10/02/2012 04:13:36.186] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://LeaderElectionSpec@localhost:46933]
[JVM-Node5] [INFO] [10/02/2012 04:13:36.189] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://LeaderElectionSpec@localhost:41943]
[JVM-Node3] [INFO] [10/02/2012 04:13:36.191] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://LeaderElectionSpec@localhost:36354]
[JVM-Node5] [WARN] [10/02/2012 04:13:36.215] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/cluster/core] unhandled message from Actor[akka://LeaderElectionSpec/system/cluster/core]: JoinSeedNodes(Vector())
[JVM-Node4] [WARN] [10/02/2012 04:13:36.217] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/cluster/core] unhandled message from Actor[akka://LeaderElectionSpec/system/cluster/core]: JoinSeedNodes(Vector())
[JVM-Node3] [WARN] [10/02/2012 04:13:36.218] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/system/cluster/core] unhandled message from Actor[akka://LeaderElectionSpec/system/cluster/core]: JoinSeedNodes(Vector())
[JVM-Node2] [INFO] [10/02/2012 04:13:36.332] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@localhost:59476] - Leader is moving node [akka://LeaderElectionSpec@localhost:59476] from JOINING to UP
[JVM-Node4] [WARN] [10/02/2012 04:13:36.535] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/FailureInjector] installing context org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@42143753 instead of org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@3d3c4c09 for address akka://LeaderElectionSpec@localhost:41943
[JVM-Node5] [WARN] [10/02/2012 04:13:36.562] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/system/FailureInjector] installing context org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@1fb88122 instead of org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@a25ef73 for address akka://LeaderElectionSpec@localhost:46933
[JVM-Node3] [INFO] [10/02/2012 04:13:36.920] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - Leader is moving node [akka://LeaderElectionSpec@localhost:36354] from JOINING to UP
[JVM-Node3] [INFO] [10/02/2012 04:13:36.920] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - Leader is moving node [akka://LeaderElectionSpec@localhost:41943] from JOINING to UP
[JVM-Node3] [INFO] [10/02/2012 04:13:36.921] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@localhost:36354] - Leader is moving node [akka://LeaderElectionSpec@localhost:46933] from JOINING to UP
[JVM-Node3] [WARN] [10/02/2012 04:13:36.925] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec@localhost:41943/system/cluster/core] received dead letter from Actor[akka://LeaderElectionSpec/system/cluster/core/coreSender]: GossipEnvelope(akka://LeaderElectionSpec@localhost:36354,Gossip(overview = GossipOverview(seen = [akka://LeaderElectionSpec@localhost:59476 -> VectorClock(Node(ba2821b93a191a21dd71f0b8071762e1) -> 0000013a1f3ff5d4), akka://LeaderElectionSpec@localhost:36354 -> VectorClock(Node(ba2821b93a191a21dd71f0b8071762e1) -> 0000013a1f3ff5d4), akka://LeaderElectionSpec@localhost:41943 -> VectorClock(Node(ba2821b93a191a21dd71f0b8071762e1) -> 0000013a1f3ff5d4), akka://LeaderElectionSpec@localhost:46933 -> VectorClock(Node(ba2821b93a191a21dd71f0b8071762e1) -> 0000013a1f3ff5d4)], unreachable = []), members = [Member(address = akka://LeaderElectionSpec@localhost:36354, status = Joining), Member(address = akka://LeaderElectionSpec@localhost:41943, status = Joining), Member(address = akka://LeaderElectionSpec@localhost:46933, status = Joining), Member(address = akka://LeaderElectionSpec@localhost:59476, status = Up)], version = VectorClock(Node(ba2821b93a191a21dd71f0b8071762e1) -> 0000013a1f3ff5d4)),true)
[JVM-Node3] [WARN] [10/02/2012 04:13:36.928] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/system/FailureInjector] installing context org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@228ca8ac instead of org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext@4095c5ec for address akka://LeaderElectionSpec@localhost:41943
[JVM-Node5] - must be able to 'elect' a single leader (1 second, 726 milliseconds)
[JVM-Node2] - must be able to 'elect' a single leader (1 second, 731 milliseconds)
[JVM-Node1] - must be able to 'elect' a single leader (1 second, 829 milliseconds)
[JVM-Node4] - must be able to 'elect' a single leader (1 second, 743 milliseconds)
[JVM-Node3] - must be able to 'elect' a single leader (1 second, 727 milliseconds)
[JVM-Node2] [INFO] [10/02/2012 04:13:37.660] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@localhost:59476] - Marking node [akka://LeaderElectionSpec@localhost:36354] as DOWN
[JVM-Node1] [ERROR] [10/02/2012 04:13:37.666] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] Actor[akka://LeaderElectionSpec/user/controller/127.0.0.1:37745-server2] tried to enter 'after-shutdown' while we were waiting for 'completed' (akka.remote.testconductor.BarrierCoordinator$WrongBarrier)
[JVM-Node1] - be able to 're-elect' a single leader after leader has left *** FAILED *** (38 milliseconds)
[JVM-Node2] - be able to 're-elect' a single leader after leader has left *** FAILED *** (39 milliseconds)
[JVM-Node2]   java.lang.RuntimeException: barrier failed: completed
[JVM-Node2]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:203)
[JVM-Node2]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:179)
[JVM-Node2]   at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:37)
[JVM-Node2]   at akka.actor.FSM$class.processEvent(FSM.scala:571)
[JVM-Node2]   at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:142)
[JVM-Node2]   at akka.actor.LoggingFSM$class.processEvent(FSM.scala:702)
[JVM-Node2]   at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:142)
[JVM-Node2]   at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:565)
[JVM-Node2]   at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:559)
[JVM-Node2]   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:394)
[JVM-Node2]   at akka.actor.ActorCell.invoke(ActorCell.scala:369)
[JVM-Node2]   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230)
[JVM-Node2]   at akka.dispatch.Mailbox.run(Mailbox.scala:212)
[JVM-Node2]   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:509)
[JVM-Node2]   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
[JVM-Node2]   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
[JVM-Node2]   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
[JVM-Node2]   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)
[JVM-Node1]   java.lang.RuntimeException: barrier failed: completed
[JVM-Node1]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:203)
[JVM-Node1]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:179)
[JVM-Node1]   at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:37)
[JVM-Node1]   at akka.actor.FSM$class.processEvent(FSM.scala:571)
[JVM-Node1]   at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:142)
[JVM-Node1]   at akka.actor.LoggingFSM$class.processEvent(FSM.scala:702)
[JVM-Node1]   at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:142)
[JVM-Node1]   at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:565)
[JVM-Node1]   at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:559)
[JVM-Node1]   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:394)
[JVM-Node1]   at akka.actor.ActorCell.invoke(ActorCell.scala:369)
[JVM-Node1]   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230)
[JVM-Node1]   at akka.dispatch.Mailbox.run(Mailbox.scala:212)
[JVM-Node1]   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:509)
[JVM-Node1]   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
[JVM-Node1]   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
[JVM-Node1]   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
[JVM-Node1]   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)
[JVM-Node1] [ERROR] [10/02/2012 04:13:37.681] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/barriers] cannot remove RoleName(controller): no client to remove (akka.remote.testconductor.BarrierCoordinator$BarrierEmpty)
[JVM-Node1] - be able to 're-elect' a single leader after leader has left (again) *** FAILED *** (5 milliseconds)
[JVM-Node1]   Previous step failed (MultiNodeClusterSpec.scala:82)
[JVM-Node1]   org.scalatest.exceptions.TestFailedException:
[JVM-Node1]   at akka.cluster.MultiNodeClusterSpec$class.withFixture(MultiNodeClusterSpec.scala:82)
[JVM-Node2] - be able to 're-elect' a single leader after leader has left (again) *** FAILED *** (4 milliseconds)
[JVM-Node2]   Previous step failed (MultiNodeClusterSpec.scala:82)
[JVM-Node2]   org.scalatest.exceptions.TestFailedException:
[JVM-Node2]   at akka.cluster.MultiNodeClusterSpec$class.withFixture(MultiNodeClusterSpec.scala:82)
User picture
  on 2012-10-02 17:21 *
By Patrik Nordwall
Assigned to set to Patrik Nordwall
User picture
  on 2012-10-02 22:26 *
By Patrik Nordwall
Status changed from New to Accepted
This is tricky. I have added some debug logging and started testing on scalable1 to gather more information.
User picture
  on 2012-10-03 00:08 *
By Patrik Nordwall
Component changed from None to cluster-tests
Milestone changed from 2.1-RC1 to Coltrane
Changing milestone, since it's not critical for 2.1 release
User picture
  on 2012-10-03 17:46 *
By Patrik Nordwall
Was run 50 times without failure yesterday evening. Will continue to run today and hopefully have a failure with the extra debug logging.
User picture
  on 2012-10-04 15:28 *
By Patrik Nordwall
No failures after 200 runs. The extra logging probably hides the race.
User picture
  on 2012-10-11 21:08 *
By Patrik Nordwall
yes, now I have a failure with debug-logging!
http://217.142.157.108:8080/job/akka-multi-node/336/consoleText
User picture
  on 2012-10-12 22:13 *
By Patrik Nordwall
I'm totally dizzy of trying to analyze this log. I think there is a race in the barriers (given that I don't use them in wrong) way.
I attach the interesting part of the log, which was run with commit 6f70624ddd818673ae2b262d1491168411946959
The answer is there somewhere, but I think we need to consult the implementer.

[third] [DEBUG] [10/11/2012 11:17:09.897] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (before-shutdown-2, after-shutdown-2)
[second] - must be able to 're-elect' a single leader after leader has left (415 milliseconds)
[controller] [DEBUG] [10/11/2012 11:17:09.897] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-2,Some(29999991106 nanoseconds))),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$m]
[first] [DEBUG] [10/11/2012 11:17:09.898] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (before-shutdown-2, after-shutdown-2)
[controller] [DEBUG] [10/11/2012 11:17:09.898] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711] written 23
[second] [DEBUG] [10/11/2012 11:17:09.898] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (before-shutdown-2, after-shutdown-2, after-down-2)
[third] [DEBUG] [10/11/2012 11:17:09.899] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(before-shutdown-2,Some(29999983115 nanoseconds))),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$m]
[first] [DEBUG] [10/11/2012 11:17:09.899] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(before-shutdown-2,Some(29999990554 nanoseconds))),Data(Some([id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$m]
[second] [DEBUG] [10/11/2012 11:17:09.899] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(before-shutdown-2,Some(29999951265 nanoseconds))),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$m]
[third] [DEBUG] [10/11/2012 11:17:09.899] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711] written 33
[second] [DEBUG] [10/11/2012 11:17:09.900] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711] written 33
[first] [DEBUG] [10/11/2012 11:17:09.899] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711] written 33
[controller] [DEBUG] [10/11/2012 11:17:09.899] [New I/O  worker #9] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:45637: EnterBarrier(after-2,Some(29999991106 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.900] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(EnterBarrier(after-2,Some(29999991106 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.901] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-2,Some(29999991106 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.901] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-2,Some(29999991106 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),,List(),Deadline(3877848123633569 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]
[controller] [DEBUG] [10/11/2012 11:17:09.902] [New I/O  worker #12] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.102:56237: EnterBarrier(after-2,Some(29999990401 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.902] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/barriers] setting timer 'Timeout'/29999936083 nanoseconds: StateTimeout
[controller] [DEBUG] [10/11/2012 11:17:09.902] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(EnterBarrier(after-2,Some(29999990401 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.903] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/barriers] transition Idle -> Waiting
[controller] [DEBUG] [10/11/2012 11:17:09.904] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-2,Some(29999990401 nanoseconds))
[third] [DEBUG] [10/11/2012 11:17:09.904] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(before-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.904] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-2,Some(29999990401 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]
[third] [DEBUG] [10/11/2012 11:17:09.904] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(before-shutdown-2,true),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),Some((before-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$m])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[first] [DEBUG] [10/11/2012 11:17:09.904] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(before-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.904] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds)))
[third] [DEBUG] [10/11/2012 11:17:09.905] [main] [ActorSystem(LeaderElectionSpec)] passed barrier before-shutdown-2
[controller] [DEBUG] [10/11/2012 11:17:09.905] [New I/O  worker #11] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.104:49878: EnterBarrier(after-2,Some(29999981713 nanoseconds))
[third] [DEBUG] [10/11/2012 11:17:09.905] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-shutdown-2,Some(29992660939 nanoseconds))),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$n]
[controller] [DEBUG] [10/11/2012 11:17:09.905] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(EnterBarrier(after-2,Some(29999981713 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[first] [DEBUG] [10/11/2012 11:17:09.905] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(before-shutdown-2,true),Data(Some([id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711]),Some((before-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$m])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[third] [DEBUG] [10/11/2012 11:17:09.906] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711] written 32
[controller] [DEBUG] [10/11/2012 11:17:09.906] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-2,Some(29999981713 nanoseconds))
[first] [DEBUG] [10/11/2012 11:17:09.906] [main] [ActorSystem(LeaderElectionSpec)] passed barrier before-shutdown-2
[controller] [DEBUG] [10/11/2012 11:17:09.906] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-2,Some(29999981713 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]
[first] [DEBUG] [10/11/2012 11:17:09.907] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-shutdown-2,Some(29991727189 nanoseconds))),Data(Some([id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$n]
[first] [DEBUG] [10/11/2012 11:17:09.907] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711] written 32
[controller] [DEBUG] [10/11/2012 11:17:09.907] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds)))
[controller] [DEBUG] [10/11/2012 11:17:09.907] [New I/O  worker #10] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.103:46510: EnterBarrier(after-2,Some(29999989717 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.908] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(EnterBarrier(after-2,Some(29999989717 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.908] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-2,Some(29999989717 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.908] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-2,Some(29999989717 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]
[controller] [DEBUG] [10/11/2012 11:17:09.909] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848471977668 nanoseconds)))
[controller] [DEBUG] [10/11/2012 11:17:09.909] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] canceling timer 'Timeout'
[second] [DEBUG] [10/11/2012 11:17:09.909] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(before-shutdown-2,true)
[second] [DEBUG] [10/11/2012 11:17:09.910] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(before-shutdown-2,true),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),Some((before-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$m])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.910] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/barriers] transition Waiting -> Idle
[controller] [DEBUG] [10/11/2012 11:17:09.910] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(ToClient(BarrierResult(after-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.911] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(ToClient(BarrierResult(after-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[second] [DEBUG] [10/11/2012 11:17:09.910] [main] [ActorSystem(LeaderElectionSpec)] passed barrier before-shutdown-2
[second] [DEBUG] [10/11/2012 11:17:09.911] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-shutdown-2,Some(29987995280 nanoseconds))),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$n]
[controller] [DEBUG] [10/11/2012 11:17:09.911] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(ToClient(BarrierResult(after-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.911] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(ToClient(BarrierResult(after-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[second] [DEBUG] [10/11/2012 11:17:09.911] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711] written 32
[controller] [DEBUG] [10/11/2012 11:17:09.912] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:4711: BarrierResult(after-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.912] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-2,true),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),Some((after-2,Actor[akka://LeaderElectionSpec/temp/$m])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.913] [main] [ActorSystem(LeaderElectionSpec)] passed barrier after-2
[controller] [DEBUG] [10/11/2012 11:17:09.913] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (before-shutdown-2)
[controller] [DEBUG] [10/11/2012 11:17:09.913] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(before-shutdown-2,Some(29999990937 nanoseconds))),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$n]
[second] [DEBUG] [10/11/2012 11:17:09.913] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka.cluster.FailureDetectorPuppet] isAvailable: Cluster node IS NOT available [akka://LeaderElectionSpec@first]
[controller] [DEBUG] [10/11/2012 11:17:09.914] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711] written 33
[second] [DEBUG] [10/11/2012 11:17:09.914] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka.cluster.FailureDetectorPuppet] isAvailable: Cluster node IS NOT available [akka://LeaderElectionSpec@third]
[controller] [DEBUG] [10/11/2012 11:17:09.914] [New I/O  worker #9] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:45637: EnterBarrier(before-shutdown-2,Some(29999990937 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.915] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(EnterBarrier(before-shutdown-2,Some(29999990937 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.915] [New I/O  worker #12] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.102:56237: EnterBarrier(before-shutdown-2,Some(29999990554 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.916] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(before-shutdown-2,Some(29999990937 nanoseconds))
[third] [DEBUG] [10/11/2012 11:17:09.916] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(after-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.916] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(before-shutdown-2,Some(29999990937 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),,List(),Deadline(3877848471977668 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]
[third] [DEBUG] [10/11/2012 11:17:09.917] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-shutdown-2,true),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),Some((after-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$n])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[third] [DEBUG] [10/11/2012 11:17:09.917] [main] [ActorSystem(LeaderElectionSpec)] passed barrier after-shutdown-2
[third] [DEBUG] [10/11/2012 11:17:09.917] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (after-down-2, completed-2)
[controller] [DEBUG] [10/11/2012 11:17:09.917] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] setting timer 'Timeout'/29999966326 nanoseconds: StateTimeout
[controller] [DEBUG] [10/11/2012 11:17:09.918] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] transition Idle -> Waiting
[third] [INFO] [10/11/2012 11:17:09.918] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/system/cluster/core] Cluster Node [akka://LeaderElectionSpec@third] - Marking node [akka://LeaderElectionSpec@first] as DOWN
[first] [DEBUG] [10/11/2012 11:17:09.918] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: TerminateMsg(0)
[controller] [DEBUG] [10/11/2012 11:17:09.918] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(EnterBarrier(before-shutdown-2,Some(29999990554 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.919] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(before-shutdown-2,Some(29999990554 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.919] [New I/O  worker #11] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.104:49878: EnterBarrier(before-shutdown-2,Some(29999983115 nanoseconds))
[first] [DEBUG] [10/11/2012 11:17:09.919] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(TerminateMsg(0),Data(Some([id: 0x52b57e9a, /172.16.42.102:56237 => scalable2-01/172.16.42.101:4711]),Some((after-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$n])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[third] [DEBUG] [10/11/2012 11:17:09.919] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-down-2,Some(29999990407 nanoseconds))),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$o]
[controller] [DEBUG] [10/11/2012 11:17:09.920] [New I/O  worker #10] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.103:46510: EnterBarrier(before-shutdown-2,Some(29999951265 nanoseconds))
[third] [DEBUG] [10/11/2012 11:17:09.920] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711] written 28
[controller] [DEBUG] [10/11/2012 11:17:09.920] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(before-shutdown-2,Some(29999990554 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]
[controller] [DEBUG] [10/11/2012 11:17:09.921] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(EnterBarrier(before-shutdown-2,Some(29999983115 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.921] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(EnterBarrier(before-shutdown-2,Some(29999951265 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[second] [DEBUG] [10/11/2012 11:17:09.921] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(after-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.922] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds)))
[second] [DEBUG] [10/11/2012 11:17:09.922] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-shutdown-2,true),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),Some((after-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$n])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.922] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(before-shutdown-2,Some(29999983115 nanoseconds))
[second] [DEBUG] [10/11/2012 11:17:09.922] [main] [ActorSystem(LeaderElectionSpec)] passed barrier after-shutdown-2
[controller] [DEBUG] [10/11/2012 11:17:09.922] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(before-shutdown-2,Some(29999951265 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.923] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(before-shutdown-2,Some(29999983115 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]
[second] [DEBUG] [10/11/2012 11:17:09.923] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-down-2,Some(29975999067 nanoseconds))),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$o]
[controller] [DEBUG] [10/11/2012 11:17:09.923] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds)))
[second] [DEBUG] [10/11/2012 11:17:09.923] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711] written 28
[controller] [DEBUG] [10/11/2012 11:17:09.924] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(before-shutdown-2,Some(29999951265 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]
[controller] [DEBUG] [10/11/2012 11:17:09.924] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),before-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848482214292 nanoseconds)))
[controller] [DEBUG] [10/11/2012 11:17:09.925] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] canceling timer 'Timeout'
[controller] [DEBUG] [10/11/2012 11:17:09.925] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/barriers] transition Waiting -> Idle
[controller] [DEBUG] [10/11/2012 11:17:09.925] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(ToClient(BarrierResult(before-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.926] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(ToClient(BarrierResult(before-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.926] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(ToClient(BarrierResult(before-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.926] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(ToClient(BarrierResult(before-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.926] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:4711: BarrierResult(before-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.927] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(before-shutdown-2,true),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),Some((before-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$n])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.927] [main] [ActorSystem(LeaderElectionSpec)] passed barrier before-shutdown-2
[controller] [DEBUG] [10/11/2012 11:17:09.927] [main] [ActorSystem(LeaderElectionSpec)] entering barriers (after-shutdown-2, after-down-2, completed-2)
[controller] [DEBUG] [10/11/2012 11:17:09.927] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller] received handled message Terminate(RoleName(first),0)
[controller] [DEBUG] [10/11/2012 11:17:09.927] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(RemoveClient(RoleName(first)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(first),akka://LeaderElectionSpec@first,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),,List(),Deadline(3877848482214292 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller]
[controller] [DEBUG] [10/11/2012 11:17:09.927] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(ToClient(TerminateMsg(0)),None) from Actor[akka://LeaderElectionSpec/temp/$o]
[controller] [DEBUG] [10/11/2012 11:17:09.927] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-shutdown-2,Some(29999992709 nanoseconds))),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$p]
[controller] [DEBUG] [10/11/2012 11:17:09.928] [New I/O  worker #11] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.104:49878: EnterBarrier(after-shutdown-2,Some(29992660939 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.928] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(EnterBarrier(after-shutdown-2,Some(29992660939 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.928] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-shutdown-2,Some(29992660939 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.928] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-shutdown-2,Some(29992660939 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),,List(),Deadline(3877848482214292 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]
[controller] [DEBUG] [10/11/2012 11:17:09.928] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/barriers] setting timer 'Timeout'/29992642307 nanoseconds: StateTimeout
[controller] [DEBUG] [10/11/2012 11:17:09.928] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/barriers] transition Idle -> Waiting
[controller] [DEBUG] [10/11/2012 11:17:09.928] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711] written 32
[controller] [DEBUG] [10/11/2012 11:17:09.929] [New I/O  worker #9] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:45637: EnterBarrier(after-shutdown-2,Some(29999992709 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.929] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(EnterBarrier(after-shutdown-2,Some(29999992709 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.929] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-shutdown-2,Some(29999992709 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.929] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-shutdown-2,Some(29999992709 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]),Deadline(3877848483043255 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]
[controller] [DEBUG] [10/11/2012 11:17:09.929] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]),Deadline(3877848483043255 nanoseconds)))
[controller] [DEBUG] [10/11/2012 11:17:09.929] [New I/O  worker #10] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.103:46510: EnterBarrier(after-shutdown-2,Some(29987995280 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.929] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(EnterBarrier(after-shutdown-2,Some(29987995280 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-shutdown-2,Some(29987995280 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-shutdown-2,Some(29987995280 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]),Deadline(3877848483043255 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] handleBarrier(Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-shutdown-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1], Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]),Deadline(3877848483043255 nanoseconds)))
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] canceling timer 'Timeout'
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] transition Waiting -> Idle
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(ToClient(BarrierResult(after-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.930] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(ToClient(BarrierResult(after-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.931] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:4711: BarrierResult(after-shutdown-2,true)
[controller] [DEBUG] [10/11/2012 11:17:09.931] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-shutdown-2,true),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),Some((after-shutdown-2,Actor[akka://LeaderElectionSpec/temp/$p])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.931] [main] [ActorSystem(LeaderElectionSpec)] passed barrier after-shutdown-2
[controller] [DEBUG] [10/11/2012 11:17:09.931] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(ToServer(EnterBarrier(after-down-2,Some(29988907371 nanoseconds))),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),None)) from Actor[akka://LeaderElectionSpec/temp/$q]
[controller] [DEBUG] [10/11/2012 11:17:09.931] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] channel [id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711] written 28
[controller] [DEBUG] [10/11/2012 11:17:09.931] [New I/O  worker #9] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:45637: EnterBarrier(after-down-2,Some(29988907371 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.931] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(EnterBarrier(after-down-2,Some(29988907371 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.932] [LeaderElectionSpec-akka.actor.default-dispatcher-6] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-down-2,Some(29988907371 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.932] [New I/O  worker #12] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.102:56237: EnterBarrier(after-shutdown-2,Some(29991727189 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.932] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-down-2,Some(29988907371 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),,List(),Deadline(3877848483043255 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]
[controller] [DEBUG] [10/11/2012 11:17:09.932] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(EnterBarrier(after-shutdown-2,Some(29991727189 nanoseconds)),Some(Actor[akka://LeaderElectionSpec/temp/$o])) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.932] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/user/controller/barriers] setting timer 'Timeout'/29988887245 nanoseconds: StateTimeout
[controller] [DEBUG] [10/11/2012 11:17:09.932] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/user/controller/barriers] transition Idle -> Waiting
[controller] [DEBUG] [10/11/2012 11:17:09.934] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-shutdown-2,Some(29991727189 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.934] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-shutdown-2,Some(29991727189 nanoseconds)),Data(Set(NodeInfo(RoleName(controller),akka://LeaderElectionSpec@controller,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]), NodeInfo(RoleName(second),akka://LeaderElectionSpec@second,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]), NodeInfo(RoleName(third),akka://LeaderElectionSpec@third,Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3])),after-down-2,List(Actor[akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1]),Deadline(3877848489857289 nanoseconds))) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4]
[controller] [ERROR] [10/11/2012 11:17:09.937] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/barriers] Actor[akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] tried to enter 'after-shutdown-2' while we were waiting for 'after-down-2' (akka.remote.testconductor.BarrierCoordinator$WrongBarrier)
[controller] [DEBUG] [10/11/2012 11:17:09.937] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(ToClient(BarrierResult(after-shutdown-2,true)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
















[controller] [DEBUG] [10/11/2012 11:17:09.937] [New I/O  worker #11] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.104:49878: EnterBarrier(after-down-2,Some(29999990407 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.938] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(EnterBarrier(after-down-2,Some(29999990407 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[second] [DEBUG] [10/11/2012 11:17:09.939] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(after-down-2,false)
[controller] [DEBUG] [10/11/2012 11:17:09.938] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-down-2,Some(29999990407 nanoseconds))
[third] [DEBUG] [10/11/2012 11:17:09.939] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] message from scalable2-01/172.16.42.101:4711: BarrierResult(after-down-2,false)
[second] [DEBUG] [10/11/2012 11:17:09.939] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-down-2,false),Data(Some([id: 0x239c7c21, /172.16.42.103:46510 => scalable2-01/172.16.42.101:4711]),Some((after-down-2,Actor[akka://LeaderElectionSpec/temp/$o])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.939] [New I/O  worker #10] [ConductorHandler(akka://LeaderElectionSpec)] message from /172.16.42.103:46510: EnterBarrier(after-down-2,Some(29975999067 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.940] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(EnterBarrier(after-down-2,Some(29975999067 nanoseconds)),None) from Actor[akka://LeaderElectionSpec/deadLetters]
[third] [DEBUG] [10/11/2012 11:17:09.940] [LeaderElectionSpec-akka.actor.default-dispatcher-8] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-down-2,false),Data(Some([id: 0x571a4bd4, /172.16.42.104:49878 => scalable2-01/172.16.42.101:4711]),Some((after-down-2,Actor[akka://LeaderElectionSpec/temp/$o])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.940] [LeaderElectionSpec-akka.actor.default-dispatcher-7] [akka://LeaderElectionSpec/user/controller] received handled message EnterBarrier(after-down-2,Some(29975999067 nanoseconds))
[controller] [DEBUG] [10/11/2012 11:17:09.941] [LeaderElectionSpec-akka.actor.default-dispatcher-3] [akka://LeaderElectionSpec/user/controller/172.16.42.102:56237-server4] processing Event(ToClient(BarrierResult(after-shutdown-2,false)),Some(Actor[akka://LeaderElectionSpec/temp/$o])) from Actor[akka://LeaderElectionSpec/user/controller]
[controller] [DEBUG] [10/11/2012 11:17:09.941] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/user/controller/172.16.42.101:45637-server1] processing Event(ToClient(BarrierResult(after-down-2,false)),None) from Actor[akka://LeaderElectionSpec/user/controller]
[controller] [DEBUG] [10/11/2012 11:17:09.941] [New I/O  worker #13] [PlayerHandler(akka://LeaderElectionSpec)] message from /172.16.42.101:4711: BarrierResult(after-down-2,false)
[controller] [DEBUG] [10/11/2012 11:17:09.941] [LeaderElectionSpec-akka.actor.default-dispatcher-1] [akka://LeaderElectionSpec/user/TestConductorClient] processing Event(BarrierResult(after-down-2,false),Data(Some([id: 0x0669a4cb, /172.16.42.101:45637 => /172.16.42.101:4711]),Some((after-down-2,Actor[akka://LeaderElectionSpec/temp/$q])))) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.942] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-down-2,Some(29999990407 nanoseconds)),Data(Set(),,List(),null)) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3]
[controller] [DEBUG] [10/11/2012 11:17:09.942] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(ToClient(BarrierResult(after-down-2,false)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.942] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(EnterBarrier(after-down-2,Some(29975999067 nanoseconds)),Data(Set(),,List(),null)) from Actor[akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2]
[controller] [DEBUG] [10/11/2012 11:17:09.943] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(ToClient(BarrierResult(after-down-2,false)),None) from Actor[akka://LeaderElectionSpec/user/controller/barriers]
[controller] [DEBUG] [10/11/2012 11:17:09.943] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller] received handled message Remove(RoleName(controller))
[controller] [DEBUG] [10/11/2012 11:17:09.943] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] processing Event(RemoveClient(RoleName(controller)),Data(Set(),,List(),null)) from Actor[akka://LeaderElectionSpec/user/controller]
[controller] [ERROR] [10/11/2012 11:17:09.944] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller/barriers] cannot remove RoleName(controller): no client to remove (akka.remote.testconductor.BarrierCoordinator$BarrierEmpty)
[controller] - be able to 're-elect' a single leader after leader has left (again) *** FAILED *** (38 milliseconds)
[controller]   java.lang.RuntimeException: barrier failed: after-down-2
[controller]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:203)
[controller]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:179)
[controller]   at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:37)
[controller]   at akka.actor.FSM$class.processEvent(FSM.scala:571)
[controller]   at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:142)
[controller]   at akka.actor.LoggingFSM$class.processEvent(FSM.scala:702)
[controller]   at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:142)
[controller]   at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:565)
[controller]   at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:559)
[controller]   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:408)
[controller]   at akka.actor.ActorCell.invoke(ActorCell.scala:369)
[controller]   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230)
[controller]   at akka.dispatch.Mailbox.run(Mailbox.scala:212)
[controller]   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:502)
[controller]   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
[controller]   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
[controller]   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
[controller]   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)
[third] - be able to 're-elect' a single leader after leader has left (again) *** FAILED *** (45 milliseconds)
[third]   java.lang.RuntimeException: barrier failed: after-down-2
[third]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:203)
[third]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:179)
[third]   at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:37)
[third]   at akka.actor.FSM$class.processEvent(FSM.scala:571)
[third]   at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:142)
[third]   at akka.actor.LoggingFSM$class.processEvent(FSM.scala:702)
[third]   at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:142)
[controller] [DEBUG] [10/11/2012 11:17:09.946] [LeaderElectionSpec-akka.actor.default-dispatcher-4] [akka://LeaderElectionSpec/user/controller] received handled message GetNodes
[third]   at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:565)
[third]   at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:559)
[third]   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:408)
[third]   at akka.actor.ActorCell.invoke(ActorCell.scala:369)
[second] - be able to 're-elect' a single leader after leader has left (again) *** FAILED *** (44 milliseconds)
[second]   java.lang.RuntimeException: barrier failed: after-down-2
[second]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:203)
[second]   at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:179)
[second]   at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:37)
[second]   at akka.actor.FSM$class.processEvent(FSM.scala:571)
[second]   at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:142)
[second]   at akka.actor.LoggingFSM$class.processEvent(FSM.scala:702)
[second]   at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:142)
[second]   at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:565)
[second]   at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:559)
[second]   at akka.actor.ActorCell.receiveMessage(ActorCell.scala:408)
[second]   at akka.actor.ActorCell.invoke(ActorCell.scala:369)
[second]   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230)
[second]   at akka.dispatch.Mailbox.run(Mailbox.scala:212)
[second]   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:502)
[second]   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
[second]   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
[second]   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
[second]   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)
[third]   at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230)
[third]   at akka.dispatch.Mailbox.run(Mailbox.scala:212)
[third]   at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:502)
[third]   at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
[third]   at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
[third]   at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
[third]   at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)
[controller] [DEBUG] [10/11/2012 11:17:09.948] [New I/O  worker #11] [ConductorHandler(akka://LeaderElectionSpec)] disconnect from /172.16.42.104:49878
[third] [DEBUG] [10/11/2012 11:17:09.948] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] disconnected from scalable2-01/172.16.42.101:4711
[controller] [DEBUG] [10/11/2012 11:17:09.949] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller/172.16.42.104:49878-server3] processing Event(ClientDisconnected,None) from Actor[akka://LeaderElectionSpec/deadLetters]
[second] [DEBUG] [10/11/2012 11:17:09.949] [New I/O  worker #9] [PlayerHandler(akka://LeaderElectionSpec)] disconnected from scalable2-01/172.16.42.101:4711
[controller] [DEBUG] [10/11/2012 11:17:09.949] [New I/O  worker #10] [ConductorHandler(akka://LeaderElectionSpec)] disconnect from /172.16.42.103:46510
[controller] [DEBUG] [10/11/2012 11:17:09.950] [LeaderElectionSpec-akka.actor.default-dispatcher-5] [akka://LeaderElectionSpec/user/controller/172.16.42.103:46510-server2] processing Event(ClientDisconnected,None) from Actor[akka://LeaderElectionSpec/deadLetters]
[controller] [DEBUG] [10/11/2012 11:17:09.950] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller] received handled message ClientDisconnected(RoleName(third))
[controller] [DEBUG] [10/11/2012 11:17:09.950] [LeaderElectionSpec-akka.actor.default-dispatcher-2] [akka://LeaderElectionSpec/user/controller] received handled message ClientDisconnected(RoleName(second))
[controller] [DEBUG] [10/11/2012 11:17:09.951] [LeaderElectionSpec
User picture
  on 2012-10-15 19:58 *
By Patrik Nordwall
Summary changed from LeaderElectionWithFailureDetectorPuppet failure on scalable1 to WrongBarrier failure
User picture
  on 2012-10-17 02:08 *
By Patrik Nordwall
Status changed from Accepted to Test
I was finally able to minimize the test and make it reproducible. The problem was that we didn't wait for the testconductor.shutdown Future to complete and therefore barriers could be triggered in unexpected order. The reason why we didn't await, was that during shutdown the Future was completed with client disconnected failure. I have fixed that and added await to all shutdowns.
User picture
  on 2012-10-17 19:43 *
By Patrik Nordwall
Status changed from Test to Fixed
User picture
User picture