In the first two parts (one, two), we briefly talked about Actors and how messaging works. In this part, let’s look at fixing up Logging and Testing our TeacherActor.
Recap
This is how our Actor from the previous part looked like :
class TeacherActor extends Actor {
val quotes = List(
"Moderation is for cowards",
"Anything worth doing is worth overdoing",
"The trouble is you think you have time",
"You never gonna know if you never even try")
def receive = {
case QuoteRequest => {
import util.Random
//Get a random Quote from the list and construct a response
val quoteResponse=QuoteResponse(quotes(Random.nextInt(quotes.size)))
println (quoteResponse)
}
}
}Logging Akka with SLF4J
You notice that in the code we are printing the quoteResponse to the standard output which you would obviously agree is a bad idea. Let’s fix that up by enabling logging via the SLF4J Facade.
1. Fix the Class to use Logging
Akka provides a nice little trait called ActorLogging to achieve it. Let’s mix that in :
class TeacherLogActor extends Actor with ActorLogging {
val quotes = List(
"Moderation is for cowards",
"Anything worth doing is worth overdoing",
"The trouble is you think you have time",
"You never gonna know if you never even try")
def receive = {
case QuoteRequest => {
import util.Random
//get a random element (for now)
val quoteResponse=QuoteResponse(quotes(Random.nextInt(quotes.size)))
log.info(quoteResponse.toString())
}
}
//We'll cover the purpose of this method in the Testing section
def quoteList=quotes
}A small detour here :
Internally, when we log a message, the logging methods in the ActorLogging (eventually) publish the log message to an EventStream. Yes, I did say publish. So, what actually is an EventStream?
EventStream and Logging
EventStream behaves just like a message broker to which we could publish and receive messages. One subtle distinction from a regular MOM is that the subscribers of the EventStream could only be an Actor.
In case of logging messages, all log messages would be published to the EventStream. By default, the Actor that subscribes to these messages is the DefaultLogger which simply prints the message to the standard output.
class DefaultLogger extends Actor with StdOutLogger {
override def receive: Receive = {
...
case event: LogEvent ⇒ print(event)
}
}So, that’s the reason when we try to kick off the StudentSimulatorApp, we see the log message written to the console.
That said, EventStream isn’t suited only for logging. It is a general purpose publish-subscribe mechanism available inside the ActorWorld inside a VM (more on that later).
Back to SLF4J setup :
2. Configure Akka to use SLF4J
akka{
loggers = ["akka.event.slf4j.Slf4jLogger"]
loglevel = "DEBUG"
logging-filter = "akka.event.slf4j.Slf4jLoggingFilter"
}We store this information in a file called application.conf which should be in your classpath. In our sbt folder structure, we would throw this in your main/resources directory.
From the configuration, we could derive that:
- the
loggersproperty indicates the Actor that is going to subscribe to the log events. What Slf4jLogger does is to simply consume the log messages and delegate that to the SLF4J Logger facade. - the
loglevelproperty simply indicates the minimum level that should be considered for logging. - the
logging-filtercompares the currently configuredlogleveland incoming log message level and chucks out any log message below the configured loglevel before publishing to the EventStream.
But why didn’t we have an application.conf for the previous example?
Simply because Akka provides some sane defaults so that we needn’t build a configuration file before we start playing with it. We’ll revisit this file too often here on for customizing various things. There are a whole bunch of awesome parameters that you could use inside the application.conf for logging alone. They are explained in detail here.
3. Throw in a logback.xml
We’ll be configuring an SLF4J logger backed by logback now.
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="FILE"
class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs\akka.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<maxFileSize>50MB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>
</appender>
<root level="DEBUG">
<appender-ref ref="FILE" />
</root>
</configuration>I threw this inside the main/resources folder too along with application.conf. Please ensure that the main/resources is now in your eclipse or other IDE’s classpath. Also include logback and slf4j-api to your build.sbt.
And when we kick off our StudentSimulatorApp and send a message to our new TeacherLogActor, the akkaxxxxx.log file that we configured looks like this.
Testing Akka
Please note that this is by no means an exhaustive coverage of Testing Akka. We would be building our tests on more features of Testing in the following parts under their respective topic headers. These testcases are aimed to cover the Actors we wrote earlier.
While the StudentSimulatorApp does what we need, you would agree that it should be driven out of testcases.
To ease the testing pain, Akka came up with an amazing testing toolkit with which we could do some magical stuff like probing directly into the Actor implementation’s internals.
Enough talk, let’s see the testcases.
Let’s first try to map the StudentSimulatorApp to a Testcase.
Let’s look at the declaration alone now.
class TeacherPreTest extends TestKit(ActorSystem("UniversityMessageSystem"))
with WordSpecLike
with MustMatchers
with BeforeAndAfterAll {So, from the definition of the TestCase class we see that :
- The
TestKittrait accepts anActorSystemthrough which we would be creating Actors. Internally, the TestKit decorates the ActorSystem and replaces the default dispatcher too. - We use WordSpec which is one of the many fun ways to write testcases with ScalaTest.
- The MustMatchers provide convenient methods to make the testcase look like natural language
- We mixin the
BeforeAndAfterAllto shutdown the ActorSystem after the testcases are complete. TheafterAllmethod that the trait provides is more like ourtearDownin JUnit
1, 2 – Sending message to Actors
- The first testcase just sends a message to the PrintActor. It doesn’t assert anything!
- The second case sends message to the Log actor which uses the
logfield of the ActorLogging to publish the message to the EventStream. This doesn’t assert anything too!
//1. Sends message to the Print Actor. Not even a testcase actually
"A teacher" must {
"print a quote when a QuoteRequest message is sent" in {
val teacherRef = TestActorRef[TeacherActor]
teacherRef ! QuoteRequest
}
}
//2. Sends message to the Log Actor. Again, not a testcase per se
"A teacher with ActorLogging" must {
"log a quote when a QuoteRequest message is sent" in {
val teacherRef = TestActorRef[TeacherLogActor]
teacherRef ! QuoteRequest
}3 – Asserting internal state of Actors
The third case uses the underlyingActor method of the TestActorRef and calls upon the quoteList method of the TeacherActor. The quoteList method returns the list of quotes back. We use this list to assert its size.
If reference to quoteList throws you back, refer to the TeacherLogActor code listed above and look for:
//From TeacherLogActor //We'll cover the purpose of this method in the Testing section def quoteList=quotes
//3. Asserts the internal State of the Log Actor.
"have a quote list of size 4" in {
val teacherRef = TestActorRef[TeacherLogActor]
teacherRef.underlyingActor.quoteList must have size (4)
teacherRef.underlyingActor.quoteList must have size (4)
}4 – Asserting log messages
As we discussed earlier in the EventStream and Logging section (above), all log messages go to the EventStream and the SLF4JLogger subscribes to it and uses its appenders to write to the log file/console etc. Wouldn’t it be nice to subscribe to the EventStream directly in our testcase and assert the presence of the log message itself? Looks like we can do that too.
This involves two steps :
- You need to add an extra configuration to your
TestKitlike so :class TeacherTest extends TestKit(ActorSystem("UniversityMessageSystem", ConfigFactory.parseString("""akka.loggers = ["akka.testkit.TestEventListener"]"""))) with WordSpecLike with MustMatchers with BeforeAndAfterAll { - Now that we have a subscription to the EventStream, we could assert it from our testcase as :
//4. Verifying log messages from eventStream "be verifiable via EventFilter in response to a QuoteRequest that is sent" in { val teacherRef = TestActorRef[TeacherLogActor] EventFilter.info(pattern = "QuoteResponse*", occurrences = 1) intercept { teacherRef ! QuoteRequest } }
The EventFilter.info block just intercepts for 1 log message which starts with QuoteResponse (pattern='QuoteResponse*). (You could also achieve it by using a start='QuoteResponse'. If there is no log message as a result of sending a message to the TeacherLogActor, the testcase would fail.
5 – Testing Actors with constructor parameters
Please note that the way we create Actors in the testcase is via the TestActorRef[TeacherLogActor] and not via system.actorOf. This is just so that we could get access to the Actor’s internals through the underlyingActor method in the TeacherActorRef. We wouldn’t be able to achieve this via the ActorRef that we have access during the regular runtime. (That doesn’t give us any excuse to use TestActorRef in production. You’ll be hunted down).
If the Actor accepts parameters, then the way we create TestActorRef would be like :
val teacherRef = TestActorRef(new TeacherLogParameterActor(quotes))
The entire testcase would then look something like :
//5. have a quote list of the same size as the input parameter
" have a quote list of the same size as the input parameter" in {
val quotes = List(
"Moderation is for cowards",
"Anything worth doing is worth overdoing",
"The trouble is you think you have time",
"You never gonna know if you never even try")
val teacherRef = TestActorRef(new TeacherLogParameterActor(quotes))
//val teacherRef = TestActorRef(Props(new TeacherLogParameterActor(quotes)))
teacherRef.underlyingActor.quoteList must have size (4)
EventFilter.info(pattern = "QuoteResponse*", occurrences = 1) intercept {
teacherRef ! QuoteRequest
}
}Shutting down ActorSystem
And finally, the afterAll lifecycle method:
override def afterAll() {
super.afterAll()
system.shutdown()
}CODE
- As always, the entire project could be downloaded from github here.
| Reference: | Akka Notes – Actor Logging and Testing from our JCG partner Arun Manivannan at the Rerun.me blog. |
