Tag Archives: Logging

Akka .NET supports a flexible logging mechanism that can adapt with various logging providers, as we have seen in my earlier article on logging with Akka .NET. Aside from the default logger that writes to the console, you can plug in various loggers of your own choosing (e.g. NLog), set them up in configuration, and work with them using a common interface.

Sometimes, you may have specific logging requirements that are not covered by any of the existing logging plugins for Akka .NET. In such cases, you would need to write your own custom logger. Unfortunately, the Akka .NET Logging documentation does not explain how to do this at the time of writing this article.

This article is intended to fill this gap, explaining how to write a custom logger for Akka .NET, but also touching upon various topics such as reading custom configuration, actor lifecycle hooks, and cleanup of resources used by the ActorSystem. The source code for this article is available at the Gigi Labs BitBucket repository.

In a Nutshell

Akka .NET Logging is basically a port of Akka logging. Any logger is an actor that receives the following messages: Debug, Info, Warning, Error and InitializeLogger. These are all standard Akka .NET messages, and we will see how to use them in a minute. At the time of writing this article, I’ve come across the following loggers that one can refer to in order to see how custom loggers are built:

Here, we’re turning on all internal Akka .NET logging so that we can automatically get some logging output.

The important thing here is the loggers configuration, where we’re specifying the custom logger that we want Akka .NET to use. This is exactly how we had set up Akka .NET to use NLog in my earlier article, but this time we’re going to use a class called ConsoleLogger (which we have yet to create).

Writing the ConsoleLogger

As I mentioned earlier, any custom logger needs to handle five messages: Debug, Info, Warning, Error, and InitializeLogger. That’s the first thing we’ll set up our ConsoleLogger to do.

The actual logging messages will use a common Log() helper method, since they differ only in log level (the operation of writing to the log destination is the same for all). Note that when we convert each of these classes to string, that includes the log level, so we don’t need to write it separately. In the case of the ConsoleLogger, we are passing in the LogLevel merely so we can use a different colour for each level.

The special message we haven’t covered yet is InitializeLogger. When the ActorSystem creates the logger actor, the internal event bus needs to know whether the logger is ready to start accepting messages. It does this by sending the logger actor an InitializeLogger message, and expects a LoggerInitialized message in return:

Aside from sending back the required message, I’m also logging the init operation itself, so that we can later observe the sequence of events. I am using my trusty ScopedConsoleColour class to change the colour, and then reset it back after the message has been written.

If you don’t send the LoggerInitialized message back, the actor system reports a timeout from initialising the logger, and basically you get no logging. (Well, ironically, the timeout itself is logged… presumably using the DefaultLogger as a fallback.)

Here we’re doing nothing but using a different colour per level, and writing the message to the console (which is pretty much what StandardOutLogger does). Remember, the level is already part of the message, so we don’t need to format it into the output message. (And if you’re outraged at the use of goto above, I suggest you read about goto case in C#.)

Actor Life Cycle Hooks

If your custom logger depends on external resources (which is most likely the case) such as the filesystem or a database, you will want to initialise those resources when the logger actor is created, and clean them up when it is destroyed. That work typically goes into actor life cycle hooks, i.e. overridable methods that allow you to run arbitrary code when an actor starts, stops, or restarts.

We don’t need to do this for ConsoleLogger, so we will simply log the start and stop operation instead. However, we will use these hooks more realistically when we implement the FileLogger.

Now, for something interesting, put a breakpoint inside PostStop(), and press ENTER to cause the program to continue and terminate. One would expect PostStop() to run as the ActorSystem is shutting down. But in fact, it doesn’t.

Next, go back to the main program, and add a second Console.ReadLine() at the end:

Run it again, and when you press ENTER, the breakpoint is hit and the PostStop event is written to the console while waiting for the second ENTER:

When we disposed the ActorSystem earlier, the program terminated before the ActorSystem had the chance to do its cleanup work. It appears that when the ActorSystem shuts down, it doesn’t clean resources right away; most likely it is done using asynchronous messaging just like in the rest of Akka .NET. For this reason, in your program’s stopping code, you might want to wait a little bit between destroying the ActorSystem and actually letting the application terminate, in order to let it gracefully free its resources.

Writing the FileLogger

We will now write a second custom logger, this time one that writes to file.

However, there is another problem. If you press ENTER to close the program, the following happens:

Upon further inspection, it seems that logging messages are coming in around the same time that PostStop() is running, causing a race condition on the underlying resource. I’ve opened a bug report for this, but until this is sorted, you can flush synchronously as a workaround:

Basically we’re reading the “akka.logfilepath” key from the HOCON config. We’re also passing in filePath as a default in case the setting is not found.

Running Multiple Loggers

So far we’ve been using either one logger or the other. But if you notice, the loggers configuration in HOCON is actually an array. Thus there is nothing stopping us from using multiple loggers at once: