Classic Logging
Pekko Classic pertains to the original Actor APIs, which have been improved by more type safe and guided Actor APIs. Pekko Classic is still fully supported and existing applications can continue to use the classic APIs. It is also possible to use the new Actor APIs together with classic actors in the same ActorSystem, see coexistence. For new projects we recommend using the new Actor API.
For the new API see Logging.
Module info
To use Logging, you must at least use the Pekko actors dependency in your project, and will most likely want to configure logging via the SLF4J module (see below).
- sbt
val PekkoVersion = "1.0.1" libraryDependencies += "org.apache.pekko" %% "pekko-actor" % PekkoVersion
- Maven
<properties> <scala.binary.version>2.13</scala.binary.version> </properties> <dependencyManagement> <dependencies> <dependency> <groupId>org.apache.pekko</groupId> <artifactId>pekko-bom_${scala.binary.version}</artifactId> <version>1.0.1</version> <type>pom</type> <scope>import</scope> </dependency> </dependencies> </dependencyManagement> <dependencies> <dependency> <groupId>org.apache.pekko</groupId> <artifactId>pekko-actor_${scala.binary.version}</artifactId> </dependency> </dependencies>
- Gradle
def versions = [ ScalaBinary: "2.13" ] dependencies { implementation platform("org.apache.pekko:pekko-bom_${versions.ScalaBinary}:1.0.1") implementation "org.apache.pekko:pekko-actor_${versions.ScalaBinary}" }
Project Info: Pekko Logging (classic) | |
---|---|
Artifact | org.apache.pekko
pekko-slf4j
1.0.1
|
JDK versions | OpenJDK 8 OpenJDK 11 OpenJDK 17 |
Scala versions | 2.13.11, 2.12.18, 3.3.1 |
JPMS module name | pekko.slf4j |
License | |
Home page | https://pekko.apache.org/ |
API documentation | |
Forums | |
Release notes | Release Notes |
Issues | Github issues |
Sources | https://github.com/apache/incubator-pekko |
Introduction
Logging in Pekko is not tied to a specific logging backend. By default log messages are printed to STDOUT, but you can plug-in a SLF4J logger or your own logger. Logging is performed asynchronously to ensure that logging has minimal performance impact. Logging generally means IO and locks, which can slow down the operations of your code if it was performed synchronously.
How to Log
Create a LoggingAdapter
LoggingAdapter
and use the error
, warning
, info
, or debug
methods, as illustrated in this example:
- Scala
-
source
import org.apache.pekko.event.Logging class MyActor extends Actor { val log = Logging(context.system, this) override def preStart() = { log.debug("Starting") } override def preRestart(reason: Throwable, message: Option[Any]): Unit = { log.error(reason, "Restarting due to [{}] when processing [{}]", reason.getMessage, message.getOrElse("")) } def receive = { case "test" => log.info("Received test") case x => log.warning("Received unknown message: {}", x) } }
- Java
-
source
import org.apache.pekko.actor.*; import org.apache.pekko.event.Logging; import org.apache.pekko.event.LoggingAdapter;
source
class MyActor extends AbstractActor { LoggingAdapter log = Logging.getLogger(getContext().getSystem(), this); @Override public void preStart() { log.debug("Starting"); } @Override public void preRestart(Throwable reason, Optional<Object> message) { log.error( reason, "Restarting due to [{}] when processing [{}]", reason.getMessage(), message.isPresent() ? message.get() : ""); } @Override public Receive createReceive() { return receiveBuilder() .matchEquals("test", msg -> log.info("Received test")) .matchAny(msg -> log.warning("Received unknown message: {}", msg)) .build(); } }
For convenience, you can mix in the log
member into actors, instead of defining it as above.
class MyActor extends Actor with org.apache.pekko.actor.ActorLogging {
...
}
The first parameter to Logging
Logging.getLogger
could also be any LoggingBus
LoggingBus
, specifically system.eventStream
system.getEventStream()
. In the demonstrated case, the actor system’s address is included in the pekkoSource
representation of the log source (see Logging Thread, Pekko Source and Actor System in MDC), while in the second case this is not automatically done. The second parameter to Logging
Logging.getLogger
is the source of this logging channel. The source object is translated to a String according to the following rules:
- if it is an Actor or ActorRef, its path is used
- in case of a String it is used as is
- in case of a Class an approximation of its
simpleName
is used - in all other cases a compile error occurs unless an implicit
LogSource[T]
is in scope for the type in question thesimpleName
of its class is used
The log message may contain argument placeholders {}
, which will be substituted if the log level is enabled. Compared to constructing a full string for the log message this has the advantage of avoiding superfluous string concatenation and object allocations when the log level is disabled. Giving more arguments than placeholders results in a warning being appended to the log statement (i.e. on the same line with the same severity). You may pass an array as the only substitution argument to have its elements be treated individually:
- Scala
-
source
val args = Array("The", "brown", "fox", "jumps", 42) system.log.debug("five parameters: {}, {}, {}, {}, {}", args)
- Java
-
source
final Object[] args = new Object[] {"The", "brown", "fox", "jumps", 42}; system.log().debug("five parameters: {}, {}, {}, {}, {}", args);
The Java Class
of the log source is also included in the generated Logging.LogEvent
Logging.LogEvent
. In case of a simple string this is replaced with a “marker” class DummyClassForStringSources
DummyClassForStringSources
in order to allow special treatment of this case, e.g. in the SLF4J event listener which will then use the string instead of the class’ name for looking up the logger instance to use.
Logging of Dead Letters
By default messages sent to dead letters are logged at INFO
level. Existence of dead letters does not necessarily indicate a problem, but they are logged by default for the sake of caution. After a few messages this logging is turned off, to avoid flooding the logs. You can disable this logging completely or adjust how many dead letters are logged. During system shutdown it is likely that you see dead letters, since pending messages in the actor mailboxes are sent to dead letters. You can also disable logging of dead letters during shutdown.
pekko {
log-dead-letters = 10
log-dead-letters-during-shutdown = on
}
To customize the logging further or take other actions for dead letters you can subscribe to the Event Stream.
Auxiliary logging options
Pekko has a few configuration options for very low level debugging. These make more sense in development than in production.
You almost definitely need to have logging set to DEBUG
to use any of the options below:
pekko {
loglevel = "DEBUG"
}
This config option is very good if you want to know what config settings are loaded by Pekko:
pekko {
# Log the complete configuration at INFO level when the actor system is started.
# This is useful when you are uncertain of what configuration is used.
log-config-on-start = on
}
If you want very detailed logging of user-level messages then wrap your actors’ behaviors with LoggingReceive
and enable the receive
option:
pekko {
actor {
debug {
# enable function of LoggingReceive, which is to log any received message at
# DEBUG level
receive = on
}
}
}
If you want very detailed logging of all automatically received messages that are processed by Actors:
pekko {
actor {
debug {
# enable DEBUG logging of all AutoReceiveMessages (Kill, PoisonPill etc.)
autoreceive = on
}
}
}
If you want very detailed logging of all lifecycle changes of Actors (restarts, deaths etc.):
pekko {
actor {
debug {
# enable DEBUG logging of actor lifecycle changes
lifecycle = on
}
}
}
If you want unhandled messages logged at DEBUG
:
pekko {
actor {
debug {
# enable DEBUG logging of unhandled messages
unhandled = on
}
}
}
If you want very detailed logging of all events, transitions and timers of FSM Actors that extend LoggingFSM:
pekko {
actor {
debug {
# enable DEBUG logging of all LoggingFSMs for events, transitions and timers
fsm = on
}
}
}
If you want to monitor subscriptions (subscribe/unsubscribe) on the ActorSystem.eventStream:
pekko {
actor {
debug {
# enable DEBUG logging of subscription changes on the eventStream
event-stream = on
}
}
}
Auxiliary remote logging options
If you want to see all messages that are sent through remoting at DEBUG
log level, use the following config option. Note that this logs the messages as they are sent by the transport layer, not by an actor.
pekko.remote.artery {
# If this is "on", Pekko will log all outbound messages at DEBUG level,
# if off then they are not logged
log-sent-messages = on
}
If you want to see all messages that are received through remoting at DEBUG
log level, use the following config option. Note that this logs the messages as they are received by the transport layer, not by an actor.
pekko.remote.artery {
# If this is "on", Pekko will log all inbound messages at DEBUG level,
# if off then they are not logged
log-received-messages = on
}
Also see the logging options for TestKit.
Translating Log Source to String and Class
The rules for translating the source object to the source string and class which are inserted into the LogEvent
during runtime are implemented using implicit parameters and thus fully customizable: create your own instance of LogSource[T]
and have it in scope when creating the logger.
sourceimport org.apache.pekko
import pekko.actor.ActorSystem
import pekko.event.LogSource
object MyType {
implicit val logSource: LogSource[AnyRef] = new LogSource[AnyRef] {
def genString(o: AnyRef): String = o.getClass.getName
override def getClazz(o: AnyRef): Class[_] = o.getClass
}
}
class MyType(system: ActorSystem) {
import MyType._
import pekko.event.Logging
val log = Logging(system, this)
}
This example creates a log source which mimics traditional usage of Java loggers, which are based upon the originating object’s class name as log category. The override of getClazz
is only included for demonstration purposes as it contains exactly the default behavior.
You may also create the string representation up front and pass that in as the log source, but be aware that then the Class[_]
which will be put in the LogEvent
is event.DummyClassForStringSources
.
The SLF4J event listener treats this case specially (using the actual string to look up the logger instance to use instead of the class’ name), and you might want to do this also in case you implement your own logging adapter.
Turn Off Logging
To turn off logging you can configure the log levels to be OFF
like this.
pekko {
stdout-loglevel = "OFF"
loglevel = "OFF"
}
The stdout-loglevel
is only in effect during system startup and shutdown, and setting it to OFF
as well, ensures that nothing gets logged during system startup or shutdown.
Loggers
Logging is performed asynchronously through an event bus. Log events are processed by an event handler actor that receives the log events in the same order they were emitted.
The event handler actor does not have a bounded inbox and is run on the default dispatcher. This means that logging extreme amounts of data may affect your application badly. This can be somewhat mitigated by using an async logging backend though. (See Using the SLF4J API directly)
You can configure which event handlers are created at system start-up and listen to logging events. That is done using the loggers
element in the configuration. Here you can also define the log level. More fine grained filtering based on the log source can be implemented in a custom LoggingFilter
LoggingFilter
, which can be defined in the logging-filter
configuration property.
pekko {
# Loggers to register at boot time (org.apache.pekko.event.Logging$DefaultLogger logs
# to STDOUT)
loggers = ["org.apache.pekko.event.Logging$DefaultLogger"]
# Options: OFF, ERROR, WARNING, INFO, DEBUG
loglevel = "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 SLF4J logger available in the ‘pekko-slf4j’ module.
If pekko-actor-typed
is available on your classpath, logging will automatically switch to SLF4J instead of the default logger. See the Pekko typed logging docs for more details.
Example of creating a listener:
- Scala
-
source
import org.apache.pekko import pekko.event.Logging.Debug import pekko.event.Logging.Error import pekko.event.Logging.Info import pekko.event.Logging.InitializeLogger import pekko.event.Logging.LoggerInitialized import pekko.event.Logging.Warning class MyEventListener extends Actor { def receive = { case InitializeLogger(_) => sender() ! LoggerInitialized case Error(cause, logSource, logClass, message) => // ... case Warning(logSource, logClass, message) => // ... case Info(logSource, logClass, message) => // ... case Debug(logSource, logClass, message) => // ... } }
- Java
-
source
import org.apache.pekko.actor.*; import org.apache.pekko.event.Logging; import org.apache.pekko.event.LoggingAdapter; import org.apache.pekko.event.Logging.InitializeLogger; import org.apache.pekko.event.Logging.Error; import org.apache.pekko.event.Logging.Warning; import org.apache.pekko.event.Logging.Info; import org.apache.pekko.event.Logging.Debug;
source
class MyEventListener extends AbstractActor { @Override public Receive createReceive() { return receiveBuilder() .match( InitializeLogger.class, msg -> { getSender().tell(Logging.loggerInitialized(), getSelf()); }) .match( Error.class, msg -> { // ... }) .match( Warning.class, msg -> { // ... }) .match( Info.class, msg -> { // ... }) .match( Debug.class, msg -> { // ... }) .build(); } }
Logging to stdout during startup and shutdown
When the actor system is starting up and shutting down the configured loggers
are not used. Instead log messages are printed to stdout (System.out). The default log level for this stdout logger is WARNING
and it can be silenced completely by setting pekko.stdout-loglevel=OFF
.
SLF4J
Pekko provides a logger for SLF4J. This module is available in the ‘pekko-slf4j.jar’. It has a single dependency: the slf4j-api jar. In your runtime, you also need a SLF4J backend. We recommend Logback:
- sbt
val PekkoVersion = "1.0.1" libraryDependencies ++= Seq( "org.apache.pekko" %% "pekko-slf4j" % PekkoVersion, "ch.qos.logback" % "logback-classic" % "1.2.11" )
- Maven
<properties> <scala.binary.version>2.13</scala.binary.version> </properties> <dependencyManagement> <dependencies> <dependency> <groupId>org.apache.pekko</groupId> <artifactId>pekko-bom_${scala.binary.version}</artifactId> <version>1.0.1</version> <type>pom</type> <scope>import</scope> </dependency> </dependencies> </dependencyManagement> <dependencies> <dependency> <groupId>org.apache.pekko</groupId> <artifactId>pekko-slf4j_${scala.binary.version}</artifactId> </dependency> <dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>1.2.11</version> </dependency> </dependencies>
- Gradle
def versions = [ ScalaBinary: "2.13" ] dependencies { implementation platform("org.apache.pekko:pekko-bom_${versions.ScalaBinary}:1.0.1") implementation "org.apache.pekko:pekko-slf4j_${versions.ScalaBinary}" implementation "ch.qos.logback:logback-classic:1.2.11" }
You need to enable the Slf4jLogger in the loggers
element in the configuration. Here you can also define the log level of the event bus. More fine grained log levels can be defined in the configuration of the SLF4J backend (e.g. logback.xml). You should also define Slf4jLoggingFilter
Slf4jLoggingFilter
in the logging-filter
configuration property. It will filter the log events using the backend configuration (e.g. logback.xml) before they are published to the event bus.
If you set the loglevel
to a higher level than DEBUG
, any DEBUG
events will be filtered out already at the source and will never reach the logging backend, regardless of how the backend is configured.
You can enable DEBUG
level for pekko.loglevel
and control the actual level in the SLF4J backend without any significant overhead, also for production.
pekko {
loggers = ["org.apache.pekko.event.slf4j.Slf4jLogger"]
loglevel = "DEBUG"
logging-filter = "org.apache.pekko.event.slf4j.Slf4jLoggingFilter"
}
One gotcha is that the timestamp is attributed in the event handler, not when actually doing the logging.
The SLF4J logger selected for each log event is chosen based on the Class[_]
Class
of the log source specified when creating the LoggingAdapter
LoggingAdapter
, unless that was given directly as a string in which case that string is used (i.e. LoggerFactory.getLogger(c: Class[_ ])
LoggerFactory.getLogger(Class c)
is used in the first case and LoggerFactory.getLogger(s: String)
LoggerFactory.getLogger(String s)
in the second).
Beware that the actor system’s name is appended to a String
log source if the LoggingAdapter was created giving an ActorSystem
ActorSystem
to the factory. If this is not intended, give a LoggingBus
LoggingBus
instead as shown below:
- Scala
-
val log = Logging(system.eventStream, "my.nice.string")
- Java
-
final LoggingAdapter log = Logging.getLogger(system.eventStream(), "my.string");
Using the SLF4J API directly
If you use the SLF4J API directly in your application, remember that the logging operations will block while the underlying infrastructure writes the log statements.
This can be avoided by configuring the logging implementation to use a non-blocking appender. Logback provides AsyncAppender that does this.
Logback configuration
Logback has flexible configuration options and details can be found in the Logback manual and other external resources.
One part that is important to highlight is the importance of configuring an AsyncAppender, because it offloads rendering of logging events to a background thread, increasing performance. It doesn’t block the threads of the ActorSystem
ActorSystem
while the underlying infrastructure writes the log messages to disk or other configured destination. It also contains a feature which will drop INFO
and DEBUG
messages if the logging load is high.
A starting point for configuration of logback.xml
for production:
source<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>myapp.log</file>
<immediateFlush>false</immediateFlush>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>myapp_%d{yyyy-MM-dd}.log</fileNamePattern>
</rollingPolicy>
<encoder>
<pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg MDC: {%mdc}%n</pattern>
</encoder>
</appender>
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>8192</queueSize>
<neverBlock>true</neverBlock>
<appender-ref ref="FILE" />
</appender>
<root level="INFO">
<appender-ref ref="ASYNC"/>
</root>
</configuration>
For development you might want to log to standard out, but also have all DEBUG
level logging to file, like in this example:
source<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<encoder>
<pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg MDC: {%mdc}%n</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>target/myapp-dev.log</file>
<encoder>
<pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg MDC: {%mdc}%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="STDOUT"/>
<appender-ref ref="FILE"/>
</root>
</configuration>
Place the logback.xml
file in src/main/resources/logback.xml
. For tests you can define different logging configuration in src/test/resources/logback-test.xml
.
MDC properties can be included in the Logback output with for example %X{pekkoSource}
specifier within the pattern layout configuration:
<encoder>
<pattern>%date{ISO8601} %-5level %logger{36} %X{pekkoSource} - %msg%n</pattern>
</encoder>
All MDC properties as key-value entries can be included with %mdc
:
<encoder>
<pattern>%date{ISO8601} %-5level %logger{36} - %msg MDC: {%mdc}%n</pattern>
</encoder>
Logging Thread, Pekko Source and Actor System 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
.
It will probably be a good idea to use the sourceThread
MDC value also in non-Pekko parts of the application in order to have this property consistently available in the logs.
Another helpful facility is that Pekko captures the actor’s address when instantiating a logger within it, meaning that the full instance identification is available for associating log messages e.g. with members of a router. This information is available in the MDC with attribute name pekkoSource
.
The address of the actor system, containing host and port if the system is using cluster, is available through pekkoAddress
.
Finally, the actor system in which the logging was performed is available in the MDC with attribute name sourceActorSystem
.
For more details on what this attribute contains—also for non-actors—please see How to Log.
More accurate timestamps for log output in MDC
Pekko’s logging is asynchronous which means that the timestamp of a log entry is taken from when the underlying logger implementation is called, which can be surprising at first. If you want to more accurately output the timestamp, use the MDC attribute pekkoTimestamp
.
MDC values defined by the application
One useful feature available in Slf4j is MDC, Pekko has a way to let the application specify custom values, for this you need to use a specialized LoggingAdapter
LoggingAdapter
, the DiagnosticLoggingAdapter
DiagnosticLoggingAdapter
. In order to get it you can use the factory, providing an Actor
AbstractActor
as logSource:
- Scala
-
// Within your Actor val log: DiagnosticLoggingAdapter = Logging(this);
- Java
-
// Within your AbstractActor final DiagnosticLoggingAdapter log = Logging.getLogger(this);
Once you have the logger, you need to add the custom values before you log something. This way, the values will be put in the SLF4J MDC right before appending the log and removed after.
The cleanup (removal) should be done in the actor at the end, otherwise, next message will log with same MDC values, if it is not set to a new map. Use log.clearMDC()
log.clearMDC()
.
- Scala
-
source
val mdc = Map("requestId" -> 1234, "visitorId" -> 5678) log.mdc(mdc) // Log something log.info("Starting new request") log.clearMDC()
- Java
-
source
import org.apache.pekko.event.DiagnosticLoggingAdapter; import java.util.HashMap; import java.util.Map;
source
class MdcActor extends AbstractActor { final DiagnosticLoggingAdapter log = Logging.getLogger(this); @Override public Receive createReceive() { return receiveBuilder() .matchAny( msg -> { Map<String, Object> mdc; mdc = new HashMap<String, Object>(); mdc.put("requestId", 1234); mdc.put("visitorId", 5678); log.setMDC(mdc); log.info("Starting new request"); log.clearMDC(); }) .build(); } }
For convenience, you can mix in the log
member into actors, instead of defining it as above. This trait also lets you override mdc(msg: Any)
for specifying MDC values depending on current message and lets you forget about the cleanup as well, since it already does it for you.
sourceimport Logging.MDC
final case class Req(work: String, visitorId: Int)
class MdcActorMixin extends Actor with pekko.actor.DiagnosticActorLogging {
var reqId = 0
override def mdc(currentMessage: Any): MDC = {
reqId += 1
val always = Map("requestId" -> reqId)
val perMessage = currentMessage match {
case r: Req => Map("visitorId" -> r.visitorId)
case _ => Map()
}
always ++ perMessage
}
def receive: Receive = {
case r: Req => {
log.info(s"Starting new request: ${r.work}")
}
}
}
Now, the values will be available in the MDC, so you can use them in the layout pattern:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>
%-5level %logger{36} [req: %X{requestId}, visitor: %X{visitorId}] - %msg%n
</pattern>
</encoder>
</appender>
All MDC properties as key-value entries can be included with %mdc
:
<encoder>
<pattern>%date{ISO8601} %-5level %logger{36} - %msg MDC: {%mdc}%n</pattern>
</encoder>
Using Markers
Some logging libraries allow, in addition to MDC data, attaching so called “markers” to log statements. These are used to filter out rare and special events, for example you might want to mark logs that detect some malicious activity and mark them with a SECURITY
tag, and in your appender configuration make these trigger emails and other notifications immediately.
Markers are available through the LoggingAdapters, when obtained via Logging.withMarker
Logging.withMarker
. The first argument passed into all log calls then should be a LogMarker
LogMarker
.
The slf4j bridge provided by Pekko in pekko-slf4j
will automatically pick up this marker value and make it available to SLF4J.
Pekko is logging some events with markers. Some of these events also include structured MDC properties.
- The “SECURITY” marker is used for highlighting security related events or incidents.
- Pekko Actor is using the markers defined in
ActorLogMarker
ActorLogMarker
. - Pekko Cluster is using the markers defined in
ClusterLogMarker
ClusterLogMarker
. - Pekko Remoting is using the markers defined in
RemoteLogMarker
RemoteLogMarker
. - Pekko Cluster Sharding is using the markers defined in
ShardingLogMarker
ShardingLogMarker
.
Markers and MDC properties are automatically picked up by the Logstash Logback encoder.
The marker can be included in the Logback output with %marker
and all MDC properties as key-value entries with %mdc
.
<encoder>
<pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg MDC: {%mdc}%n</pattern>
</encoder>
Using SLF4J’s Markers
It is also possible to use the org.slf4j.Marker
with the LoggingAdapter
LoggingAdapter
when using slf4j.
Since the pekko-actor library avoids depending on any specific logging library, the support for this is included in pekko-slf4j
, which provides the Slf4jLogMarker
Slf4jLogMarker
type which can be passed in as first argument instead of the logging framework agnostic LogMarker type from pekko-actor
. The most notable difference between the two is that slf4j’s Markers can have child markers, so one can rely more information using them rather than just a single string.