Hello
"Inspired" by the
presentation http://www.slideshare.net/EvanChan2/akka-inproductionpnw-scala2013
I wanted to introduce stackable traits pattern to my Akka application. For
now I wanted to add logging of messages using LoggingReceive and basic
tracing with akka-tracing.
Following the presentation I created:
trait ActorStack extends Actor {
def wrappedReceive: Receive
def receive: Receive = {
case x => if (wrappedReceive.isDefinedAt(x)) wrappedReceive(x) else
unhandled(x)
}
}
and two traits:
trait LoggingReceiveActor extends ActorStack {
override def receive: Receive = LoggingReceive {
case x => {
println("+++" + x) // added for debugging
super.receive(x)
}
}
}
trait StackableActorTracing extends ActorStack with ActorTracing {
var currentMessage: Traced[Any] = Traced("tracing turned off")
override def receive: Receive = {
case msg @ Traced(inner) => {
trace.sample(msg, this.getClass.getSimpleName)
currentMessage = msg
super.receive(inner)
}
case msg => {
currentMessage = Traced("tracing turned off")
super.receive(msg)
}
}
def msg = {
currentMessage
}
}
also I created one utility trait that gathers those two traits:
trait BaseActor extends ActorStack with ActorLogging
with LoggingReceiveActor with StackableActorTracing
Now when I take my example actor:
class RotationService(rotationRepository: ActorRef) extends BaseActor with
DefaultAskTimeout {
implicit val dispatcher = context.dispatcher
def wrappedReceive: Receive = {
case createCommand @ CreateRotation() => {
...
}
When I execute unit test that sends *CreateRotation *message to
*RotationService
*actor I am getting:
Testing started at 3:41 PM ...
Connected to the target VM, address: '127.0.0.1:51978', transport: 'socket'
15:41:36.520
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-2]
INFO akka.event.slf4j.Slf4jLogger - Slf4jLogger started
15:41:36.565
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-2]
DEBUG akka.event.EventStream - logger log1-Slf4jLogger started
15:41:36.584
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-2]
DEBUG akka.event.EventStream - Default Loggers started
15:41:36.586
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-2]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/deadLetterListener#-162762200]
15:41:36.588
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-2]
DEBUG akka.event.DeadLetterListener - started
(akka.event.DeadLetterListener@2025eae4)
15:41:36.627
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
INFO kamon.statsd.StatsDExtension - Starting the Kamon(StatsD) extension
15:41:36.652
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/user/statsd-metrics-sender#-609019730]
15:41:36.688
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-4]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF#221802495]
15:41:36.707
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG kamon.statsd.StatsDMetricsSender - started
(kamon.statsd.StatsDMetricsSender@1f06d526)
15:41:36.747
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-4]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/user/kamon-metrics-subscriptions#-992962374]
15:41:36.770
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-4]
DEBUG kamon.metrics.Subscriptions - started
(kamon.metrics.Subscriptions@6680693)
15:41:36.778
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-4]
DEBUG akka.routing.RouterPoolActor - started
(akka.routing.RouterPoolActor@66ee2542)
15:41:36.779
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-4]
DEBUG akka.routing.RouterPoolActor - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF/selectors/$a#-483988336]
15:41:36.787
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG akka.io.UdpManager - started (akka.io.UdpManager@4fb22e7b)
15:41:36.792
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG akka.io.UdpManager - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF/selectors#1030403184]
15:41:36.931
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG akka.testkit.TestActor - started (akka.testkit.TestActor@15e46de6)
15:41:36.934
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/testActor1#-958709488]
15:41:36.955
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/user/$a#756409676]
15:41:36.960
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG akka.io.SelectionHandler - started (akka.io.SelectionHandler@dc33904)
15:41:36.964
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG akka.io.SelectionHandler - now watched by
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF/selectors#1030403184]
15:41:36.971
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-5]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/user/$b#-689772232]
15:41:36.999
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-6]
DEBUG akka.io.SelectionHandler - now supervising
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF/selectors/$a/0#437926056]
15:41:37.012
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG commands.domain.RotationRepository - started
(commands.domain.RotationRepository@58053ef7)
15:41:37.015
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-3]
DEBUG commands.application.RotationService - started
(commands.application.RotationService@4068f746)
15:41:37.038
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-6]
DEBUG akka.io.UdpSender - started (akka.io.UdpSender@69161204)
15:41:37.040
[TestActorSystem-9dc08bc090f2416bbf369947fd64908b-akka.actor.default-dispatcher-6]
DEBUG akka.io.UdpSender - now watched by
Actor[akka://TestActorSystem-9dc08bc090f2416bbf369947fd64908b/system/IO-UDP-FF/selectors/$a#-483988336]
*+++CreateRotation()*
In the last line in logs it can be seen that the body of receive defined in
*LoggingReceiveActor
*is properly executed, but there is no message in logs *received handled
message CreateRotation().*
But when I change my definition of BaseActor to:
trait BaseActor extends ActorStack with ActorLogging
with StackableActorTracing with LoggingReceiveActor
So I swapped *StackableActorTracing *with *LoggingReceiveActor *and now I
am getting in my logs:
Testing started at 3:46 PM ...
Connected to the target VM, address: '127.0.0.1:49575', transport: 'socket'
15:46:14.086
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
INFO akka.event.slf4j.Slf4jLogger - Slf4jLogger started
15:46:14.130
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG akka.event.EventStream - logger log1-Slf4jLogger started
15:46:14.150
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG akka.event.EventStream - Default Loggers started
15:46:14.151
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/deadLetterListener#1184326713]
15:46:14.153
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG akka.event.DeadLetterListener - started
(akka.event.DeadLetterListener@7347bcf4)
15:46:14.163
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
INFO kamon.statsd.StatsDExtension - Starting the Kamon(StatsD) extension
15:46:14.184
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/user/statsd-metrics-sender#1184566021]
15:46:14.225
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-4]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF#-1386767628]
15:46:14.244
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-3]
DEBUG kamon.statsd.StatsDMetricsSender - started
(kamon.statsd.StatsDMetricsSender@11e5adb2)
15:46:14.276
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-3]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/user/kamon-metrics-subscriptions#-600730271]
15:46:14.290
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG kamon.metrics.Subscriptions - started
(kamon.metrics.Subscriptions@4a32ee13)
15:46:14.381
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG akka.io.UdpManager - started (akka.io.UdpManager@32f514f3)
15:46:14.382
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG akka.io.UdpManager - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF/selectors#-1172677154]
15:46:14.389
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG akka.routing.RouterPoolActor - started
(akka.routing.RouterPoolActor@3747681)
15:46:14.391
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG akka.routing.RouterPoolActor - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF/selectors/$a#887910570]
15:46:14.423
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-2]
DEBUG akka.testkit.TestActor - started (akka.testkit.TestActor@138a6240)
15:46:14.428
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG a.a.LocalActorRefProvider$SystemGuardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/testActor1#-34049509]
15:46:14.452
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG akka.io.SelectionHandler - started (akka.io.SelectionHandler@1af2688a)
15:46:14.455
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG akka.io.SelectionHandler - now watched by
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF/selectors#-1172677154]
15:46:14.461
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-3]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/user/$a#1251946934]
15:46:14.472
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG a.a.LocalActorRefProvider$Guardian - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/user/$b#193466603]
15:46:14.478
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-5]
DEBUG akka.io.SelectionHandler - now supervising
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF/selectors/$a/0#657471358]
15:46:14.529
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG commands.domain.RotationRepository - started
(commands.domain.RotationRepository@57afefb7)
15:46:14.532
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG commands.application.RotationService - started
(commands.application.RotationService@44af61a4)
15:46:14.534
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG akka.io.UdpSender - started (akka.io.UdpSender@101cd25f)
15:46:14.535
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG akka.io.UdpSender - now watched by
Actor[akka://TestActorSystem-5c322748c8fd4465b79823a366dabea4/system/IO-UDP-FF/selectors/$a#887910570]
15:46:14.536
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG commands.application.RotationService - received handled message
CreateRotation()
+++CreateRotation()
So now I am getting two log messages about incoming message - one from
LoggingReceive: *15:46:14.536
[TestActorSystem-5c322748c8fd4465b79823a366dabea4-akka.actor.default-dispatcher-6]
DEBUG commands.application.RotationService - received handled message
CreateRotation()* and one from my *println.*
I am wondering then what is the cause of this - why the *LoggingReceive *does
not want to work properly in the first case?
--
>>>>>>>>>> Read the docs: http://akka.io/docs/
>>>>>>>>>> Check the FAQ:
>>>>>>>>>> http://doc.akka.io/docs/akka/current/additional/faq.html
>>>>>>>>>> Search the archives: https://groups.google.com/group/akka-user
---
You received this message because you are subscribed to the Google Groups "Akka
User List" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at http://groups.google.com/group/akka-user.
For more options, visit https://groups.google.com/d/optout.
