StatsSampleSingleMasterSpec: job sent to deadLetters
akka-multi-node 354 at scalable1
[info] * sample.cluster.stats.StatsSampleSingleMasterSpec
[JVM-Node1] [INFO] [10/17/2012 16:11:56.233] [main] [StatsSampleSingleMasterSpecMultiJvmNode1(akka://StatsSampleSingleMasterSpec)] Role [first] started with address [akka://StatsSampleSingleMasterSpec@scalable2-01:45741]
[JVM-Node3] [INFO] [10/17/2012 16:11:56.306] [main] [StatsSampleSingleMasterSpecMultiJvmNode3(akka://StatsSampleSingleMasterSpec)] Role [thrid] started with address [akka://StatsSampleSingleMasterSpec@scalable2-03:46158]
[JVM-Node1] Run starting. Expected test count is: 2
[JVM-Node1] StatsSampleSingleMasterSpecMultiJvmNode1:
[JVM-Node2] [INFO] [10/17/2012 16:11:56.314] [main] [StatsSampleSingleMasterSpecMultiJvmNode2(akka://StatsSampleSingleMasterSpec)] Role [second] started with address [akka://StatsSampleSingleMasterSpec@scalable2-02:35781]
[JVM-Node1] The stats sample with single master
[JVM-Node1] [INFO] [10/17/2012 16:11:56.337] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - is starting up...
[JVM-Node1] [INFO] [10/17/2012 16:11:56.342] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] 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-Node3] Run starting. Expected test count is: 2
[JVM-Node3] StatsSampleSingleMasterSpecMultiJvmNode3:
[JVM-Node3] The stats sample with single master
[JVM-Node2] Run starting. Expected test count is: 2
[JVM-Node1] [INFO] [10/17/2012 16:11:56.412] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node1] [INFO] [10/17/2012 16:11:56.413] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - has started up successfully
[JVM-Node2] StatsSampleSingleMasterSpecMultiJvmNode2:
[JVM-Node1] [INFO] [10/17/2012 16:11:56.420] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-2] [akka://StatsSampleSingleMasterSpec/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-Node1] [INFO] [10/17/2012 16:11:56.423] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-2] [akka://StatsSampleSingleMasterSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741]
[JVM-Node3] [INFO] [10/17/2012 16:11:56.424] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158] - is starting up...
[JVM-Node2] The stats sample with single master
[JVM-Node3] [INFO] [10/17/2012 16:11:56.430] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] 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/17/2012 16:11:56.446] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] - is starting up...
[JVM-Node2] [INFO] [10/17/2012 16:11:56.451] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] 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-Node3] [INFO] [10/17/2012 16:11:56.488] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node3] [INFO] [10/17/2012 16:11:56.489] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158] - has started up successfully
[JVM-Node3] [INFO] [10/17/2012 16:11:56.492] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-5] [akka://StatsSampleSingleMasterSpec/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/17/2012 16:11:56.497] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-5] [akka://StatsSampleSingleMasterSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158]
[JVM-Node2] [INFO] [10/17/2012 16:11:56.520] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] - registered cluster JMX MBean [akka:type=Cluster]
[JVM-Node2] [INFO] [10/17/2012 16:11:56.521] [main] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] - has started up successfully
[JVM-Node2] [INFO] [10/17/2012 16:11:56.526] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-5] [akka://StatsSampleSingleMasterSpec/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-Node1] [INFO] [10/17/2012 16:11:56.530] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-2] [akka://StatsSampleSingleMasterSpec/user/statsFacade] Creating new statsService master at [akka://StatsSampleSingleMasterSpec@scalable2-01:45741]
[JVM-Node2] [INFO] [10/17/2012 16:11:56.544] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-5] [akka://StatsSampleSingleMasterSpec/system/cluster/metrics] Metrics collection has started successfully on node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781]
[JVM-Node3] [INFO] [10/17/2012 16:11:56.781] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-4] [akka://StatsSampleSingleMasterSpec/user/statsFacade] Using statsService master at [akka://StatsSampleSingleMasterSpec@scalable2-01:45741]
[JVM-Node1] [INFO] [10/17/2012 16:11:57.470] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-4] [akka://StatsSampleSingleMasterSpec/system/cluster/core] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - Leader is moving node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] from JOINING to UP
[JVM-Node1] [INFO] [10/17/2012 16:11:57.470] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-4] [akka://StatsSampleSingleMasterSpec/system/cluster/core] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - Leader is moving node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] from JOINING to UP
[JVM-Node1] [INFO] [10/17/2012 16:11:57.470] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-4] [akka://StatsSampleSingleMasterSpec/system/cluster/core] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-01:45741] - Leader is moving node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158] from JOINING to UP
[JVM-Node1] - must illustrate how to startup cluster
[JVM-Node3] - must illustrate how to startup cluster
[JVM-Node2] - must illustrate how to startup cluster
[JVM-Node2] [WARN] [10/17/2012 16:11:57.604] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-3] [akka://StatsSampleSingleMasterSpec@scalable2-03:46158/user/statsFacade] received dead letter from Actor[akka://StatsSampleSingleMasterSpec/system/testActor1]: StatsJob(this is the text that will be analyzed)
[JVM-Node2] [WARN] [10/17/2012 16:11:57.605] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-3] [akka://StatsSampleSingleMasterSpec@scalable2-03:46158/system/cluster/heartbeatReceiver] received dead letter from Actor[akka://StatsSampleSingleMasterSpec/system/cluster/core/heartbeatSender/akka%3A%2F%2FStatsSampleSingleMasterSpec%40scalable2-03%3A46158]: Heartbeat(akka://StatsSampleSingleMasterSpec@scalable2-02:35781)
[JVM-Node2] [INFO] [10/17/2012 16:11:57.609] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-1] [akka://StatsSampleSingleMasterSpec/user/statsFacade] Using statsService master at [akka://StatsSampleSingleMasterSpec@scalable2-01:45741]
[JVM-Node2] - show usage of the statsFacade *** FAILED ***
[JVM-Node2] java.lang.AssertionError: assertion failed: timeout (4981615064 nanoseconds) during expectMsg:
[JVM-Node2] at scala.Predef$.assert(Predef.scala:179)
[JVM-Node2] at akka.testkit.TestKitBase$class.expectMsgPF(TestKit.scala:312)
[JVM-Node2] at akka.testkit.TestKit.expectMsgPF(TestKit.scala:641)
[JVM-Node2] at sample.cluster.stats.StatsSampleSingleMasterSpec$$anonfun$1$$anonfun$apply$mcV$sp$3$$anonfun$apply$mcV$sp$4$$anonfun$apply$mcV$sp$5.apply$mcZ$sp(StatsSampleSingleMasterSpec.scala:94)
[JVM-Node2] at akka.testkit.TestKitBase$class.poll$1(TestKit.scala:224)
[JVM-Node2] at akka.testkit.TestKitBase$class.awaitCond(TestKit.scala:231)
[JVM-Node2] at akka.testkit.TestKit.awaitCond(TestKit.scala:641)
[JVM-Node2] at sample.cluster.stats.StatsSampleSingleMasterSpec$$anonfun$1$$anonfun$apply$mcV$sp$3$$anonfun$apply$mcV$sp$4.apply$mcV$sp(StatsSampleSingleMasterSpec.scala:92)
[JVM-Node2] at sample.cluster.stats.StatsSampleSingleMasterSpec$$anonfun$1$$anonfun$apply$mcV$sp$3$$anonfun$apply$mcV$sp$4.apply(StatsSampleSingleMasterSpec.scala:87)
[JVM-Node2] at sample.cluster.stats.StatsSampleSingleMasterSpec$$anonfun$1$$anonfun$apply$mcV$sp$3$$anonfun$apply$mcV$sp$4.apply(StatsSampleSingleMasterSpec.scala:87)
[JVM-Node2] ...
[JVM-Node2] [WARN] [10/17/2012 16:12:02.602] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-6] [akka://StatsSampleSingleMasterSpec/user/TestConductorClient] received dead letter from Actor[akka://StatsSampleSingleMasterSpec/deadLetters]: PoisonPill
[JVM-Node1] [ERROR] [10/17/2012 16:12:02.606] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-2] [akka://StatsSampleSingleMasterSpec/user/controller/barriers] unannounced disconnect of RoleName(second) (akka.remote.testconductor.BarrierCoordinator$ClientLost)
[JVM-Node3] - show usage of the statsFacade *** FAILED ***
[JVM-Node3] java.lang.RuntimeException: barrier failed: done
[JVM-Node3] at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:201)
[JVM-Node3] at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:177)
[JVM-Node3] at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:33)
[JVM-Node3] at akka.actor.FSM$class.processEvent(FSM.scala:573)
[JVM-Node3] at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:140)
[JVM-Node3] at akka.actor.LoggingFSM$class.processEvent(FSM.scala:704)
[JVM-Node3] at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:140)
[JVM-Node3] at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:567)
[JVM-Node3] at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:561)
[JVM-Node3] at akka.actor.ActorCell.receiveMessage(ActorCell.scala:408)
[JVM-Node3] ...
[JVM-Node1] - show usage of the statsFacade *** FAILED ***
[JVM-Node1] java.lang.RuntimeException: barrier failed: done
[JVM-Node1] at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:201)
[JVM-Node1] at akka.remote.testconductor.ClientFSM$$anonfun$4.applyOrElse(Player.scala:177)
[JVM-Node1] at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:33)
[JVM-Node1] at akka.actor.FSM$class.processEvent(FSM.scala:573)
[JVM-Node1] at akka.remote.testconductor.ClientFSM.akka$actor$LoggingFSM$$super$processEvent(Player.scala:140)
[JVM-Node1] at akka.actor.LoggingFSM$class.processEvent(FSM.scala:704)
[JVM-Node1] at akka.remote.testconductor.ClientFSM.processEvent(Player.scala:140)
[JVM-Node1] at akka.actor.FSM$class.akka$actor$FSM$$processMsg(FSM.scala:567)
[JVM-Node1] at akka.actor.FSM$$anonfun$receive$1.applyOrElse(FSM.scala:561)
[JVM-Node1] at akka.actor.ActorCell.receiveMessage(ActorCell.scala:408)
[JVM-Node1] ...
[JVM-Node1] [ERROR] [10/17/2012 16:12:02.622] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-6] [akka://StatsSampleSingleMasterSpec/user/controller/barriers] cannot remove RoleName(first): no client to remove (akka.remote.testconductor.BarrierCoordinator$BarrierEmpty)
[JVM-Node3] [WARN] [10/17/2012 16:12:02.625] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-6] [akka://StatsSampleSingleMasterSpec/user/TestConductorClient] received dead letter from Actor[akka://StatsSampleSingleMasterSpec/deadLetters]: PoisonPill
[JVM-Node2] [INFO] [10/17/2012 16:12:02.633] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-3] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] - Shutting down cluster Node and cluster daemons...
[JVM-Node2] [INFO] [10/17/2012 16:12:02.639] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-3] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-02:35781] - Cluster node successfully shut down
[JVM-Node3] [INFO] [10/17/2012 16:12:02.660] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-1] [Cluster(akka://StatsSampleSingleMasterSpec)] Cluster Node [akka://StatsSampleSingleMasterSpec@scalable2-03:46158] - Shutting down cluster Node and cluster daemons...
Leave a comment
on 2012-10-24 07:45 *
By Patrik Nordwall
Priority changed from Normal (3) to High (2)
Summary changed from StatsSampleSingleMasterSpec failed to Remote message not delivered when target actor is starting
Status changed from Test to New
Why is the dead letter is produced?
The target actor is started (system.actorOf) before the message send, but anyway the message is delivered to deadLetters.
[JVM-Node2] [WARN] [10/17/2012 16:11:57.604] [StatsSampleSingleMasterSpec-akka.actor.default-dispatcher-3] [akka://StatsSampleSingleMasterSpec@scalable2-03:46158/user/statsFacade] received dead letter from Actor[akka://StatsSampleSingleMasterSpec/system/testActor1]: StatsJob(this is the text that will be analyzed)
The target actor is started (system.actorOf) before the message send, but anyway the message is delivered to deadLetters.
on 2012-10-24 07:47 *
By Patrik Nordwall
I have minimized the tests and been able to produce the unexpected dead letter a few times, and it comes from an EmptyLocalActorRef when delegating the incoming remote message.
[JVM-Node2] at akka.actor.EmptyLocalActorRef.$bang(ActorRef.scala:454)
[JVM-Node2] at akka.remote.RemoteTransport.receiveMessage(RemoteTransport.scala:287)
[JVM-Node2] at akka.remote.netty.ActiveRemoteClientHandler.messageReceived(Client.scala:272)
[JVM-Node2] at akka.actor.EmptyLocalActorRef.$bang(ActorRef.scala:454)
[JVM-Node2] at akka.remote.RemoteTransport.receiveMessage(RemoteTransport.scala:287)
[JVM-Node2] at akka.remote.netty.ActiveRemoteClientHandler.messageReceived(Client.scala:272)
on 2012-10-24 13:27 *
By Patrik Nordwall
Priority changed from High (2) to Normal (3)
Summary changed from Remote message not delivered when target actor is starting to StatsSampleSingleMasterSpec: job sent to deadLetters
I have found the real reason for this. It's not serious, just a glitch in the sample. I will fix.
Updating tickets (#939, #940, #1941, #2081, #2126, #2213, #2214, #2215, #2219, #2222, #2223, #2239, #2240, #2249, #2250, #2252, #2253, #2254, #2256, #2259, #2263, #2264, #2265, #2267, #2270, #2271, #2275, #2277, #2286, #2287, #2289, #2290, #2303, #2304, #2308, #2310, #2311, #2317, #2323, #2331, #2374, #2392, #2394, #2405, #2408, #2423, #2424, #2425, #2440, #2444, #2445, #2449, #2453, #2456, #2459, #2461, #2473, #2477, #2485, #2491, #2495, #2498, #2501, #2505, #2515, #2517, #2523, #2534, #2541, #2544, #2545, #2549, #2582, #2583, #2588, #2589, #2598, #2599, #2618, #2623, #2626, #2627, #2630, #2631, #2633, #2634, #2635, #2637, #2638, #2642, #2643, #2646, #2647, #2648, #2649, #2650, #2653, #2655, #2657, #2658)