Epic Logback Failure

[Kevin Wright]

I'm using Logback with a groovy config file, and recently migrated to use ActorLogging.

The same project starts just fine under sbt/jetty on my macbook, yet fails under Tomcat on a small (single core) amazon instance.

For the most part, I'm completely stumped; but suspect that thread starvation is occurring, given the difference in core count between the machines and that the handling of InitialiseLogger in Slf4jEventHandler responds immediately:

case InitializeLogger(_) ⇒

  log.info("Slf4jEventHandler started")

  sender ! LoggerInitialized

Stack trace as follows:

INFO: Starting service Catalina

24-May-2012 16:22:28 org.apache.catalina.core.StandardEngine startInternal

INFO: Starting Servlet Engine: Apache Tomcat/7.0.22

24-May-2012 16:22:28 org.apache.catalina.startup.HostConfig deployWAR

INFO: Deploying web application archive copernicus.war

24-May-2012 16:22:45 org.apache.catalina.realm.JAASRealm setContainer

INFO: Set JAAS app name Catalina

Starting spray application ...

[WARN] [05/24/2012 16:22:55.270] [Thread-4] [EventStream(akka://servlet)] Logger log1-Slf4jEventHandler did not respond within Timeout(5 seconds) to InitializeLogger(bus)

error while starting up EventHandler

akka.config.ConfigurationException:Event Handler specified in config can't be loaded [akka.event.slf4j.Slf4jEventHandler] due to [akka.event.Logging$LoggerInitializationException:Logger log1-Slf4jEventHandler did not respond with LoggerInitialized, sent instead [TIMEOUT]

[55f8f1a0-a5b4-11e1-b4c7-12313b05422c]]

[55f918b0-a5b4-11e1-b4c7-12313b05422c]

at akka.event.LoggingBus$$anonfun$4.apply(Logging.scala:109)

at akka.event.LoggingBus$$anonfun$4.apply(Logging.scala:99)

at scala.collection.TraversableLike$WithFilter$$anonfun$map$2.apply(TraversableLike.scala:661)

at scala.collection.Iterator$class.foreach(Iterator.scala:660)

at scala.collection.JavaConversions$JIteratorWrapper.foreach(JavaConversions.scala:573)

at scala.collection.IterableLike$class.foreach(IterableLike.scala:73)

at scala.collection.JavaConversions$JListWrapper.foreach(JavaConversions.scala:615)

at scala.collection.TraversableLike$WithFilter.map(TraversableLike.scala:660)

at akka.event.LoggingBus$class.startDefaultLoggers(Logging.scala:99)

at akka.event.EventStream.startDefaultLoggers(EventStream.scala:23)

at akka.actor.LocalActorRefProvider.init(ActorRefProvider.scala:506)

at akka.actor.ActorSystemImpl._start(ActorSystem.scala:549)

at akka.actor.ActorSystemImpl.start(ActorSystem.scala:556)

at akka.actor.ActorSystem$.apply(ActorSystem.scala:103)

at akka.actor.ActorSystem$.apply(ActorSystem.scala:89)

at cc.spray.connectors.Initializer.cc$spray$connectors$Initializer$$system(Initializer.scala:27)

at cc.spray.connectors.Initializer$$anonfun$contextInitialized$1.apply$mcV$sp(Initializer.scala:37)

at akka.util.Switch.liftedTree1$1(LockUtil.scala:33)

at akka.util.Switch.transcend(LockUtil.scala:32)

at akka.util.Switch.switchOn(LockUtil.scala:55)

at cc.spray.connectors.Initializer.contextInitialized(Initializer.scala:30)

at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4723)

at org.apache.catalina.core.StandardContext$1.call(StandardContext.java:5226)

at org.apache.catalina.core.StandardContext$1.call(StandardContext.java:5221)

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

at java.util.concurrent.FutureTask.run(FutureTask.java:138)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

at java.lang.Thread.run(Thread.java:662)

Caused by: akka.event.Logging$LoggerInitializationException:Logger log1-Slf4jEventHandler did not respond with LoggerInitialized, sent instead [TIMEOUT]

[55f8f1a0-a5b4-11e1-b4c7-12313b05422c]

at akka.event.LoggingBus$class.akka$event$LoggingBus$$addLogger(Logging.scala:164)

at akka.event.LoggingBus$$anonfun$4.apply(Logging.scala:104)

... 28 more

[Kevin Wright]

For the record, this is under Akka 2.0.1 (the standard build, not the instrumented console one)

[√iktor Ҡlang]

Hi Kevin

Set a higher minimum parallelism of your default dispatcher, and see if that works.

In 2.0.2 the timeout will also be configurable.

Cheers,

√

--
You received this message because you are subscribed to the Google Groups "Akka User List" group.
To post to this group, send email to akka...@googlegroups.com.
To unsubscribe from this group, send email to akka-user+...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/akka-user?hl=en.

--
Viktor Klang

Akka Tech Lead

Typesafe - The software stack for applications that scale

Twitter: @viktorklang

[Kevin Wright]

Right you are!

Working against the reference at http://doc.akka.io/docs/akka/2.0.1/general/configuration.html, I'm now going with this, to see if it does the trick?

akka {

  loglevel = DEBUG

  event-handlers = ["akka.event.slf4j.Slf4jEventHandler"]

  default-dispatcher {

    fork-join-executor {

      parallelism-min = 8

    }

  }

  ... other stuff ...

  

}

On the offchance that it doesn't work, do you have any other ideas or areas of debugging that it would be worth my while enabling?

[√iktor Ҡlang]

On Thu, May 24, 2012 at 5:51 PM, Kevin Wright <kev.lee...@gmail.com> wrote:

Right you are!

Working against the reference at http://doc.akka.io/docs/akka/2.0.1/general/configuration.html, I'm now going with this, to see if it does the trick?

akka {

  loglevel = DEBUG

  event-handlers = ["akka.event.slf4j.Slf4jEventHandler"]

  default-dispatcher {

    fork-join-executor {

      parallelism-min = 8

    }

  }

  ... other stuff ...

  

}

On the offchance that it doesn't work, do you have any other ideas or areas of debugging that it would be worth my while enabling?

Might be that your logback config takes too long to load for some reason (which is why we made this timeout configurable for 2.0.2)

Cheers,

√

 

--
You received this message because you are subscribed to the Google Groups "Akka User List" group.
To post to this group, send email to akka...@googlegroups.com.
To unsubscribe from this group, send email to akka-user+...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/akka-user?hl=en.

[Kevin Wright]

I meant "parallelism-min = 16", of course

--
Kevin Wright
mail: kevin....@scalatechnology.com
gtalk / msn : kev.lee...@gmail.com

quora: http://www.quora.com/Kevin-Wright

google+: http://gplus.to/thecoda

twitter: @thecoda

vibe / skype: kev.lee.wright

steam: kev_lee_wright

"My point today is that, if we wish to count lines of code, we should not regard them as "lines produced" but as "lines spent": the current conventional wisdom is so foolish as to book that count on the wrong side of the ledger" ~ Dijkstra

[Kevin Wright]

If so, can we pretty please have a milestone soon?

[√iktor Ҡlang]

On Thu, May 24, 2012 at 5:58 PM, Kevin Wright <kev.lee...@gmail.com> wrote:

If so, can we pretty please have a milestone soon?

http://groups.google.com/group/akka-user/browse_thread/thread/926b944ec163b3bd?hl=en_US#

[Kevin Wright]

Point release? :p

For now, I can just copy the offending file into my local codebase and tweak it.  Normally I'd be fine with this, but do you know if it would have any impact running against the console instrumented jars?

[√iktor Ҡlang]

On Thu, May 24, 2012 at 8:11 PM, Kevin Wright <kev.lee...@gmail.com> wrote:

Point release? :p

"I'm currently withholding the 2.0.2 release until my binary compat work is 

done, so I know what will need to be deprecated in 2.0.2, this should 
hopefully be done some time this week, and I hope to be able to ship 2.0.2 
on friday. "

 

For now, I can just copy the offending file into my local codebase and tweak it.  Normally I'd be fine with this, but do you know if it would have any impact running against the console instrumented jars?

I recommend to hold out another 24h ;-)

Cheers,

√