Tim
Tim

Reputation: 1665

Akka logging resets during shutdown

Under Akka 2.10 my logging configuration is being reset during shutdown... resulting in potentially-important messages being written to standard output rather than the logging mechanism.

For example, this code:

String settings =
        "akka.event-handlers = [\"akka.event.slf4j.Slf4jEventHandler\"]\n" +
        "akka.actor.provider = \"akka.cluster.ClusterActorRefProvider\"";
Config config = ConfigFactory.parseString(settings);
ActorSystem system = ActorSystem.create("testing", config);
LoggingAdapter log = Logging.getLogger(system, new Object());
log.info("Via SlF4J");
system.shutdown();
Thread.sleep(1000);
log.info("After shutdown");

Produces this output:

17:24:11.999 [testing-akka.actor.default-dispatcher-4] INFO  akka.event.slf4j.Slf4jEventHandler - Slf4jEventHandler started
17:24:12.151 [testing-akka.actor.default-dispatcher-4] INFO  N.168.1.106:2552) - RemoteServerStarted@akka://[email protected]:2552
17:24:12.155 [testing-akka.actor.default-dispatcher-4] INFO  java.lang.Object - Via SlF4J
[INFO] [04/12/2013 17:24:12.218] [testing-akka.actor.default-dispatcher-4] [NettyRemoteTransport(akka://[email protected]:2552)] RemoteServerShutdown@akka://[email protected]:2552
[INFO] [04/12/2013 17:24:13.156] [main] [Object(akka://testing)] After shutdown

The first three lines of output are via SLF4J (my configured logger), whereas the final two are via akka.event.Logging$StandardOutLogger -- which means that exceptions being logged during shutdown (and I am seeing a few, in some circumstances) are being lost to the logger.

(It would also be nice to see the RemoteServerShutdown message logged correctly, of course.)

Anybody have any insight into this behavior?

Upvotes: 0

Views: 244

Answers (2)

Roland Kuhn
Roland Kuhn

Reputation: 15472

Akka’s logging is built upon actors, and naturally since all actors are shut down during ActorSystem.shutdown() it must stop working at some point. The fallback to console logging has been put in place so that messages logged really late are still not completely lost.

What you are seeing is that your log.info sometimes comes in before and sometimes after the point in time when logging is shut down, since ActorSystem.shutdown() merely initiates the shutdown which then proceeds asynchronously.

Thus the conclusion is that logging via the actor system should be done only from within the actor system, since that ensures that things are still up and running.

Upvotes: 1

Tim
Tim

Reputation: 1665

This problem seems to be resolved by upgrading to Akka 2.10-2.1.2.

Upvotes: 0

Related Questions