From 52c0888500d552282f51779cbbdd580a6247ab79 Mon Sep 17 00:00:00 2001 From: Patrik Nordwall Date: Mon, 28 Nov 2011 09:47:41 +0100 Subject: [PATCH 1/5] Changed slf4j version to 1.6.4. See #1400 --- project/AkkaBuild.scala | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/project/AkkaBuild.scala b/project/AkkaBuild.scala index b2a828b3a6..fdc8ecd877 100644 --- a/project/AkkaBuild.scala +++ b/project/AkkaBuild.scala @@ -424,7 +424,7 @@ object Dependency { val Netty = "3.2.5.Final" val Protobuf = "2.4.1" val Scalatest = "1.6.1" - val Slf4j = "1.6.0" + val Slf4j = "1.6.4" val Spring = "3.0.5.RELEASE" val Zookeeper = "3.4.0" val Rabbit = "2.3.1" From 19a78c0e58bf1ce4c2315da6407d39b4bc770d51 Mon Sep 17 00:00:00 2001 From: Patrik Nordwall Date: Mon, 28 Nov 2011 09:48:36 +0100 Subject: [PATCH 2/5] Slf4jEventHandler should not format log message. See #1401 * Updated documentation with info about MDC. * Updated documentation conf of logLevel. * Updated documentation Logback 1.0.0. --- akka-docs/general/configuration.rst | 4 +-- akka-docs/general/event-handler.rst | 2 +- akka-docs/general/slf4j.rst | 20 +++++++++-- akka-docs/scala/testing.rst | 2 +- .../main/scala/akka/event/slf4j/SLF4J.scala | 36 ++++++++++++++----- 5 files changed, 48 insertions(+), 16 deletions(-) diff --git a/akka-docs/general/configuration.rst b/akka-docs/general/configuration.rst index 5e8c3e9344..cffd15b4dd 100644 --- a/akka-docs/general/configuration.rst +++ b/akka-docs/general/configuration.rst @@ -142,7 +142,7 @@ akka.dev.conf: :: akka { - event-handler-level = "DEBUG" + loglevel = "DEBUG" } The mode option works in the same way when using configuration files in ``AKKA_HOME/config/`` directory. @@ -162,7 +162,7 @@ akka.dev.conf: include "akka.conf" akka { - event-handler-level = "DEBUG" + loglevel = "DEBUG" } .. _-Dakka.output.config.source: diff --git a/akka-docs/general/event-handler.rst b/akka-docs/general/event-handler.rst index e4396faef5..c23911939e 100644 --- a/akka-docs/general/event-handler.rst +++ b/akka-docs/general/event-handler.rst @@ -16,7 +16,7 @@ You can configure which event handlers should be registered at boot time. That i akka { # event handlers to register at boot time (EventHandler$DefaultListener logs to STDOUT) event-handlers = ["akka.event.EventHandler$DefaultListener"] - event-handler-level = "DEBUG" # Options: ERROR, WARNING, INFO, DEBUG + loglevel = "DEBUG" # Options: ERROR, WARNING, INFO, DEBUG } The default one logs to STDOUT and is registered by default. It is not intended to be used for production. There is also an :ref:`slf4j` event handler available in the 'akka-slf4j' module. diff --git a/akka-docs/general/slf4j.rst b/akka-docs/general/slf4j.rst index a49b731771..876b139d65 100644 --- a/akka-docs/general/slf4j.rst +++ b/akka-docs/general/slf4j.rst @@ -4,11 +4,11 @@ SLF4J ===== This module is available in the 'akka-slf4j.jar'. It has one single dependency; the slf4j-api jar. In runtime you -also need a SLF4J backend, we recommend: +also need a SLF4J backend, we recommend `Logback `_: .. code-block:: scala - lazy val logback = "ch.qos.logback" % "logback-classic" % "0.9.28" % "runtime" + lazy val logback = "ch.qos.logback" % "logback-classic" % "1.0.0" % "runtime" Event Handler @@ -20,8 +20,22 @@ This module includes a SLF4J Event Handler that works with Akka's standard Event akka { event-handlers = ["akka.event.slf4j.Slf4jEventHandler"] - event-handler-level = "DEBUG" + loglevel = "DEBUG" } Read more about how to use the :ref:`event-handler`. +Logging thread in MDC +--------------------- + +Since the logging is done asynchronously the thread in which the logging was performed is captured in +Mapped Diagnostic Context (MDC) with attribute name ``sourceThread``. +With Logback the thread name is available with ``%X{sourceThread}`` specifier within the pattern layout configuration:: + + + + %date{ISO8601} %-5level %logger{36} %X{sourceThread} - %msg%n + + + + \ No newline at end of file diff --git a/akka-docs/scala/testing.rst b/akka-docs/scala/testing.rst index 5eca79a784..ca1469217c 100644 --- a/akka-docs/scala/testing.rst +++ b/akka-docs/scala/testing.rst @@ -750,7 +750,7 @@ All these messages are logged at ``DEBUG`` level. To summarize, you can enable full logging of actor activities using this configuration fragment:: akka { - event-handler-level = "DEBUG" + loglevel = "DEBUG" actor { debug { receive = "true" diff --git a/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala b/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala index dc175e4e82..acd794adaa 100644 --- a/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala +++ b/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala @@ -5,7 +5,7 @@ package akka.event.slf4j import org.slf4j.{ Logger ⇒ SLFLogger, LoggerFactory ⇒ SLFLoggerFactory } - +import org.slf4j.MDC import akka.event.Logging._ import akka.actor._ @@ -27,31 +27,49 @@ object Logger { /** * SLF4J Event Handler. * + * The thread in which the logging was performed is captured in + * Mapped Diagnostic Context (MDC) with attribute name "sourceThread". + * * @author Jonas Bonér */ class Slf4jEventHandler extends Actor with SLF4JLogging { + val mdcThreadAttributeName = "sourceThread" + def receive = { case event @ Error(cause, logSource, message) ⇒ - Logger(logSource).error("[{}] [{}] [{}]", - Array[AnyRef](event.thread.getName, message.asInstanceOf[AnyRef], stackTraceFor(cause))) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).error(message.toString, cause) + } case event @ Warning(logSource, message) ⇒ - Logger(logSource).warn("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).warn("{}", message.asInstanceOf[AnyRef]) + } case event @ Info(logSource, message) ⇒ - Logger(logSource).info("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).info("{}", message.asInstanceOf[AnyRef]) + } case event @ Debug(logSource, message) ⇒ - Logger(logSource).debug("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).debug("{}", message.asInstanceOf[AnyRef]) + } case InitializeLogger(_) ⇒ log.info("Slf4jEventHandler started") sender ! LoggerInitialized } + def withMdc(name: String, value: String)(logStatement: ⇒ Unit) { + MDC.put(name, value) + try { + logStatement + } finally { + MDC.remove(name) + } + } + } From 10517e518333c162b906b6bcef6f462a72ba7b2a Mon Sep 17 00:00:00 2001 From: Patrik Nordwall Date: Mon, 28 Nov 2011 13:35:10 +0100 Subject: [PATCH 3/5] Skip stack trace when log error without exception. See #1402 --- .../src/main/scala/akka/event/Logging.scala | 20 ++++++--- .../main/scala/akka/event/slf4j/SLF4J.scala | 41 +++++++++++++++---- 2 files changed, 46 insertions(+), 15 deletions(-) diff --git a/akka-actor/src/main/scala/akka/event/Logging.scala b/akka-actor/src/main/scala/akka/event/Logging.scala index 5b3ae4b801..af3fc25797 100644 --- a/akka-actor/src/main/scala/akka/event/Logging.scala +++ b/akka-actor/src/main/scala/akka/event/Logging.scala @@ -268,6 +268,7 @@ object Logging { val AllLogLevels = Seq(ErrorLevel: AnyRef, WarningLevel, InfoLevel, DebugLevel).asInstanceOf[Seq[LogLevel]] val errorFormat = "[ERROR] [%s] [%s] [%s] %s\n%s".intern + val errorFormatWithoutCause = "[ERROR] [%s] [%s] [%s] %s".intern val warningFormat = "[WARN] [%s] [%s] [%s] %s".intern val infoFormat = "[INFO] [%s] [%s] [%s] %s".intern val debugFormat = "[DEBUG] [%s] [%s] [%s] %s".intern @@ -311,7 +312,12 @@ object Logging { def level = ErrorLevel } object Error { - def apply(logSource: String, message: Any) = new Error(new EventHandlerException, logSource, message) + def apply(logSource: String, message: Any) = new Error(NoCause, logSource, message) + + /** Null Object used for errors without cause Throwable */ + object NoCause extends RuntimeException { + setStackTrace(Array.empty[StackTraceElement]) + } } case class Warning(logSource: String, message: Any = "") extends LogEvent { @@ -363,13 +369,15 @@ object Logging { } } - def error(event: Error) = - println(errorFormat.format( + def error(event: Error) = { + val f = if (event.cause == Error.NoCause) errorFormatWithoutCause else errorFormat + println(f.format( timestamp, event.thread.getName, event.logSource, event.message, stackTraceFor(event.cause))) + } def warning(event: Warning) = println(warningFormat.format( @@ -429,14 +437,14 @@ object Logging { } def stackTraceFor(e: Throwable) = { - if (e ne null) { + if ((e eq null) || e == Error.NoCause) { + "" + } else { import java.io.{ StringWriter, PrintWriter } val sw = new StringWriter val pw = new PrintWriter(sw) e.printStackTrace(pw) sw.toString - } else { - "[NO STACK TRACE]" } } diff --git a/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala b/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala index dc175e4e82..73d37a838b 100644 --- a/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala +++ b/akka-slf4j/src/main/scala/akka/event/slf4j/SLF4J.scala @@ -5,7 +5,7 @@ package akka.event.slf4j import org.slf4j.{ Logger ⇒ SLFLogger, LoggerFactory ⇒ SLFLoggerFactory } - +import org.slf4j.MDC import akka.event.Logging._ import akka.actor._ @@ -27,31 +27,54 @@ object Logger { /** * SLF4J Event Handler. * + * The thread in which the logging was performed is captured in + * Mapped Diagnostic Context (MDC) with attribute name "sourceThread". + * * @author Jonas Bonér */ class Slf4jEventHandler extends Actor with SLF4JLogging { + val mdcThreadAttributeName = "sourceThread" + def receive = { + case event @ Error(cause, logSource, message) ⇒ - Logger(logSource).error("[{}] [{}] [{}]", - Array[AnyRef](event.thread.getName, message.asInstanceOf[AnyRef], stackTraceFor(cause))) + withMdc(mdcThreadAttributeName, event.thread.getName) { + cause match { + case Error.NoCause ⇒ Logger(logSource).error(message.toString) + case _ ⇒ Logger(logSource).error(message.toString, cause) + } + } case event @ Warning(logSource, message) ⇒ - Logger(logSource).warn("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).warn("{}", message.asInstanceOf[AnyRef]) + } case event @ Info(logSource, message) ⇒ - Logger(logSource).info("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).info("{}", message.asInstanceOf[AnyRef]) + } case event @ Debug(logSource, message) ⇒ - Logger(logSource).debug("[{}] [{}]", - event.thread.getName, message.asInstanceOf[AnyRef]) + withMdc(mdcThreadAttributeName, event.thread.getName) { + Logger(logSource).debug("{}", message.asInstanceOf[AnyRef]) + } case InitializeLogger(_) ⇒ log.info("Slf4jEventHandler started") sender ! LoggerInitialized } + @inline + final def withMdc(name: String, value: String)(logStatement: ⇒ Unit) { + MDC.put(name, value) + try { + logStatement + } finally { + MDC.remove(name) + } + } + } From 01e43c3edbde026bf1a3b6ede2ea15fb79b5b437 Mon Sep 17 00:00:00 2001 From: Patrik Nordwall Date: Mon, 28 Nov 2011 17:08:10 +0100 Subject: [PATCH 4/5] Use scala.util.control.NoStackTrace --- akka-actor/src/main/scala/akka/event/Logging.scala | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/akka-actor/src/main/scala/akka/event/Logging.scala b/akka-actor/src/main/scala/akka/event/Logging.scala index af3fc25797..bae930cb17 100644 --- a/akka-actor/src/main/scala/akka/event/Logging.scala +++ b/akka-actor/src/main/scala/akka/event/Logging.scala @@ -14,6 +14,7 @@ import akka.actor.Timeout import akka.dispatch.FutureTimeoutException import java.util.concurrent.atomic.AtomicInteger import akka.actor.ActorRefProvider +import scala.util.control.NoStackTrace object LoggingBus { implicit def fromActorSystem(system: ActorSystem): LoggingBus = system.eventStream @@ -315,9 +316,7 @@ object Logging { def apply(logSource: String, message: Any) = new Error(NoCause, logSource, message) /** Null Object used for errors without cause Throwable */ - object NoCause extends RuntimeException { - setStackTrace(Array.empty[StackTraceElement]) - } + object NoCause extends NoStackTrace } case class Warning(logSource: String, message: Any = "") extends LogEvent { From 16850388e0aa73a5b35d84282c35e5220ebd2b20 Mon Sep 17 00:00:00 2001 From: Viktor Klang Date: Mon, 28 Nov 2011 17:24:41 +0100 Subject: [PATCH 5/5] Fixing #1379 - making the DLAR the default sender in tell --- akka-actor/src/main/scala/akka/actor/ActorRef.scala | 2 +- .../src/main/scala/akka/remote/netty/NettyRemoteSupport.scala | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/akka-actor/src/main/scala/akka/actor/ActorRef.scala b/akka-actor/src/main/scala/akka/actor/ActorRef.scala index afa7299669..e62a04938a 100644 --- a/akka-actor/src/main/scala/akka/actor/ActorRef.scala +++ b/akka-actor/src/main/scala/akka/actor/ActorRef.scala @@ -381,7 +381,7 @@ class DeadLetterActorRef(val eventStream: EventStream) extends MinimalActorRef { override def isTerminated(): Boolean = true - override def !(message: Any)(implicit sender: ActorRef = null): Unit = message match { + override def !(message: Any)(implicit sender: ActorRef = this): Unit = message match { case d: DeadLetter ⇒ eventStream.publish(d) case _ ⇒ eventStream.publish(DeadLetter(message, sender, this)) } diff --git a/akka-remote/src/main/scala/akka/remote/netty/NettyRemoteSupport.scala b/akka-remote/src/main/scala/akka/remote/netty/NettyRemoteSupport.scala index cf922feafe..d12f5ea7e4 100644 --- a/akka-remote/src/main/scala/akka/remote/netty/NettyRemoteSupport.scala +++ b/akka-remote/src/main/scala/akka/remote/netty/NettyRemoteSupport.scala @@ -282,7 +282,7 @@ class ActiveRemoteClientHandler( val client: ActiveRemoteClient) extends SimpleChannelUpstreamHandler { - def runOnceNow(thunk: ⇒ Unit) = timer.newTimeout(new TimerTask() { + def runOnceNow(thunk: ⇒ Unit): Unit = timer.newTimeout(new TimerTask() { def run(timeout: Timeout) = try { thunk } finally { timeout.cancel() } }, 0, TimeUnit.MILLISECONDS)