Re: Issue integrating a Logging trait (SLF4J, Logback) with a ActorSystem

[Edward Sargisson]

I'm not an Akka expert and perhaps I'm being dumb but this looks suspicious to me:

"Caused by: java.lang.ClassCastException: org.slf4j.helpers.SubstituteLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext

at com.ignidata.core.logging.LogFactory$.createLoggerContext(LoggerFactory.scala:68)"

Perhaps this isn't an Akka problem but is a type problem in your code?

Cheers,

Edward

On Wednesday, June 4, 2014 2:00:06 AM UTC-7, Pedro Ferreira de Almeida wrote:

Hi, fellow hAkkers!

I'm quite a newcomer to the whole Akka (as well as Scala) scene so I'm not completely familiarized with some techniques.

I have built a very, very simple Logging trait using SLF4J and Logback. By now I'm able to save logs on MongoDB, using ReactiveMongo driver (which is built on Akka, curiously).

It works quite well with non-actor entities. However, with actors, it semi-works... basically, if I have, say, a Consumer and a Producer, I can't get a logger working for Consumer but it works for Producer... =/

SLF4J just throws me this exception in the face :

[ERROR] [06/04/2014 09:51:52.860] [kafka-workers-akka.actor.default-dispatcher-2] [akka://kafka-workers/user/consumer] org.slf4j.helpers.SubstituteLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext

akka.actor.ActorInitializationException: exception during creation

at akka.actor.ActorInitializationException$.apply(Actor.scala:164)

at akka.actor.ActorCell.create(ActorCell.scala:596)

at akka.actor.ActorCell.invokeAll$1(ActorCell.scala:456)

at akka.actor.ActorCell.systemInvoke(ActorCell.scala:478)

at akka.dispatch.Mailbox.processAllSystemMessages(Mailbox.scala:263)

at akka.dispatch.Mailbox.run(Mailbox.scala:219)

at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)

at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)

at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)

at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)

at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

Caused by: java.lang.ClassCastException: org.slf4j.helpers.SubstituteLoggerFactory cannot be cast to ch.qos.logback.classic.LoggerContext

at com.ignidata.core.logging.LogFactory$.createLoggerContext(LoggerFactory.scala:68)

at com.ignidata.core.logging.LogFactory$.createLogger(LoggerFactory.scala:40)

at com.ignidata.core.logging.persistence.Logging$class.$init$(Logging.scala:22)

at com.ignidata.core.integration.KafkaAkkaConsumer.<init>(KafkaAkkaConsumer.scala:20)

at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)

at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

at java.lang.reflect.Constructor.newInstance(Constructor.java:526)

at java.lang.Class.newInstance(Class.java:374)

at akka.util.Reflect$.instantiate(Reflect.scala:45)

at akka.actor.NoArgsReflectConstructor.produce(Props.scala:358)

at akka.actor.Props.newActor(Props.scala:249)

at akka.actor.ActorCell.newActor(ActorCell.scala:552)

at akka.actor.ActorCell.create(ActorCell.scala:578)

... 9 more

[INFO] [06/04/2014 09:51:52.905] [kafka-workers-akka.actor.default-dispatcher-4] [akka://kafka-workers/user/consumer] Message [scala.Tuple4] from Actor[akka://kafka-workers/deadLetters] to Actor[akka://kafka-workers/user/consumer#-91164000] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.

[INFO] [06/04/2014 09:51:52.915] [kafka-workers-akka.actor.default-dispatcher-5] [akka://kafka-workers/user/consumer] Message [java.lang.String] from Actor[akka://kafka-workers/deadLetters] to Actor[akka://kafka-workers/user/consumer#-91164000] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.

09:51:53,376 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]

09:51:53,388 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]

09:51:53,444 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property

09:51:53,555 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to DEBUG

09:51:53,555 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]

09:51:53,557 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.

09:51:53,559 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@13836c80 - Registering current configuration as safe fallback point

09:51:53,619 |-INFO in ch.qos.logback.classic.net.SyslogAppender[null] - Defaulting maxMessageSize to [65000]

09:51:53.660 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Creating producer with config: (page-visits,localhost:9092,true,false,200,3)

log4j:WARN No appenders could be found for logger (kafka.utils.VerifiableProperties).

log4j:WARN Please initialize the log4j system properly.

09:51:54.984 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Created producer with config: (page-visits,localhost:9092,true,false,200,3)

09:51:55.039 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Message about to be sent: test 1

09:51:56.928 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Message sent: test 1

09:51:56.966 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Message about to be sent: test 2

09:51:57.142 [kafka-workers-akka.actor.test-dispatcher-7] INFO  c.i.c.integration.KafkaAkkaProducer - Message sent: test 2

So you see, both Consumer and Producer mix the same trait, but only the last one manages to get a logger instance.

Something anyone has seen at some point? How have you manage to work around it?

Thanks for your help!

Pedro

[volker...@eligotech.com]

Hi Pedro,

logback returns a SubstituteLoggerFactory when a LoggerFactory is requested before the logging system is loaded completely (see also: http://www.slf4j.org/codes.html#substituteLogger). Casting this to a

LoggerContext fails. If you are assigning the returned LoggerFactory to a val it might already help, if you used a lazy val instead.

HTH
Volker

[Pedro Ferreira de Almeida]

Hello, Edward and Volker!

@Edward,

the issue is not strictly related to Akka but rather - as Volker pointed out -  caused by a delay on the Logger initialization through SLF4J, after an ActorSystem has loaded.

@Volker,

I had a custom LoggerFactory (where I defined several props programatically) assigned to a lazy val, but had to comment it out and carry on only with SLF4J's own LoggerFactory and configurations shipped on a logback.xml file. A bit of a hack, still... =) But it logs, heh.

Thanks a lot for your help!

Best regards,

Pedro