Add settings to use context.log for internal ESB logging (#30202)

* add settings to use context.log for internal ESB logging

* only force ctx.log if needed

* removed hardcoded value

* fix compilation
This commit is contained in:
Renato Cavalcanti 2021-04-27 15:22:53 +02:00 committed by GitHub
parent fc4e84a322
commit 571aa85a36
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 59 additions and 18 deletions

View file

@ -15,6 +15,7 @@ import akka.persistence.typed.EventSourcedBehaviorLoggingSpec.ChattyEventSourcin
import akka.persistence.typed.scaladsl.Effect import akka.persistence.typed.scaladsl.Effect
import akka.persistence.typed.scaladsl.EventSourcedBehavior import akka.persistence.typed.scaladsl.EventSourcedBehavior
import akka.serialization.jackson.CborSerializable import akka.serialization.jackson.CborSerializable
import com.typesafe.config.{ Config, ConfigFactory }
import org.scalatest.wordspec.AnyWordSpecLike import org.scalatest.wordspec.AnyWordSpecLike
object EventSourcedBehaviorLoggingSpec { object EventSourcedBehaviorLoggingSpec {
@ -47,17 +48,20 @@ object EventSourcedBehaviorLoggingSpec {
} }
} }
class EventSourcedBehaviorLoggingSpec abstract class EventSourcedBehaviorLoggingSpec(config: Config)
extends ScalaTestWithActorTestKit(PersistenceTestKitPlugin.config) extends ScalaTestWithActorTestKit(config)
with AnyWordSpecLike with AnyWordSpecLike
with LogCapturing { with LogCapturing {
import EventSourcedBehaviorLoggingSpec._ import EventSourcedBehaviorLoggingSpec._
"Chatty behavior" must { def loggerName: String
def loggerId: String
s"Chatty behavior ($loggerId)" must {
val myId = PersistenceId("Chatty", "chat-1") val myId = PersistenceId("Chatty", "chat-1")
val chattyActor = spawn(ChattyEventSourcingBehavior(myId)) val chattyActor = spawn(ChattyEventSourcingBehavior(myId))
"log user message in context.log" in { "always log user message in context.log" in {
LoggingTestKit LoggingTestKit
.info("received message 'Mary'") .info("received message 'Mary'")
.withLoggerName("akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$") .withLoggerName("akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$")
@ -66,32 +70,32 @@ class EventSourcedBehaviorLoggingSpec
} }
} }
"log internal messages in 'Internal' logger without logging user data (Persist)" in { s"log internal messages in '$loggerId' logger without logging user data (Persist)" in {
LoggingTestKit LoggingTestKit
.debug( .debug(
"Handled command [akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Hello], " + "Handled command [akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Hello], " +
"resulting effect: [Persist(akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event)], side effects: [0]") "resulting effect: [Persist(akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event)], side effects: [0]")
.withLoggerName("akka.persistence.typed.internal.EventSourcedBehaviorImpl") .withLoggerName(loggerName)
.expect { .expect {
chattyActor ! Hello("Joe") chattyActor ! Hello("Joe")
} }
} }
"log internal messages in 'Internal' logger without logging user data (PersistAll)" in { s"log internal messages in '$loggerId' logger without logging user data (PersistAll)" in {
LoggingTestKit LoggingTestKit
.debug("Handled command [akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Hellos], " + .debug("Handled command [akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Hellos], " +
"resulting effect: [PersistAll(akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event," + "resulting effect: [PersistAll(akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event," +
"akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event)], side effects: [0]") "akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$Event)], side effects: [0]")
.withLoggerName("akka.persistence.typed.internal.EventSourcedBehaviorImpl") .withLoggerName(loggerName)
.expect { .expect {
chattyActor ! Hellos("Mary", "Joe") chattyActor ! Hellos("Mary", "Joe")
} }
} }
"Internal logger preserves MDC source" in { s"log in '$loggerId' while preserving MDC source" in {
LoggingTestKit LoggingTestKit
.debug("Handled command ") .debug("Handled command ")
.withLoggerName("akka.persistence.typed.internal.EventSourcedBehaviorImpl") .withLoggerName(loggerName)
.withMdc(Map("persistencePhase" -> "running-cmd", "persistenceId" -> "Chatty|chat-1")) .withMdc(Map("persistencePhase" -> "running-cmd", "persistenceId" -> "Chatty|chat-1"))
.expect { .expect {
chattyActor ! Hello("Mary") chattyActor ! Hello("Mary")
@ -99,3 +103,21 @@ class EventSourcedBehaviorLoggingSpec
} }
} }
} }
class EventSourcedBehaviorLoggingInternalLoggerSpec
extends EventSourcedBehaviorLoggingSpec(PersistenceTestKitPlugin.config) {
override def loggerName = "akka.persistence.typed.internal.EventSourcedBehaviorImpl"
override def loggerId = "internal.log"
}
object EventSourcedBehaviorLoggingContextLoggerSpec {
val config =
ConfigFactory
.parseString("akka.persistence.typed.use-context-logger-for-internal-logging = true")
.withFallback(PersistenceTestKitPlugin.config)
}
class EventSourcedBehaviorLoggingContextLoggerSpec
extends EventSourcedBehaviorLoggingSpec(EventSourcedBehaviorLoggingContextLoggerSpec.config) {
override def loggerName = "akka.persistence.typed.EventSourcedBehaviorLoggingSpec$ChattyEventSourcingBehavior$"
override def loggerId = "context.log"
}

View file

@ -0,0 +1,5 @@
# settings to fallback to actor's context.log for internal EventSourcedBehavior logging
ProblemFilters.exclude[DirectMissingMethodProblem]("akka.persistence.typed.internal.EventSourcedSettings.apply")
ProblemFilters.exclude[IncompatibleSignatureProblem]("akka.persistence.typed.internal.EventSourcedSettings.unapply")
ProblemFilters.exclude[DirectMissingMethodProblem]("akka.persistence.typed.internal.EventSourcedSettings.copy")
ProblemFilters.exclude[DirectMissingMethodProblem]("akka.persistence.typed.internal.EventSourcedSettings.this")

View file

@ -39,6 +39,12 @@ akka.persistence.typed {
# enables automatic DEBUG level logging of messages stashed automatically by an EventSourcedBehavior, # enables automatic DEBUG level logging of messages stashed automatically by an EventSourcedBehavior,
# this may happen while it receives commands while it is recovering events or while it is persisting events # this may happen while it receives commands while it is recovering events or while it is persisting events
log-stashing = off log-stashing = off
# By default, internal event sourced behavior logging are sent to
# akka.persistence.typed.internal.EventSourcedBehaviorImpl
# this can be changed by setting this to 'true' in which case the internal logging is sent to
# the actor context logger.
use-context-logger-for-internal-logging = false
} }
akka.reliable-delivery { akka.reliable-delivery {

View file

@ -108,7 +108,7 @@ private[akka] final case class EventSourcedBehaviorImpl[Command, Event, State](
throw new IllegalArgumentException("persistenceId must not be null") throw new IllegalArgumentException("persistenceId must not be null")
// Don't use it directly, but instead call internalLogger() (see below) // Don't use it directly, but instead call internalLogger() (see below)
private val logger = LoggerFactory.getLogger(this.getClass) private val loggerForInternal = LoggerFactory.getLogger(this.getClass)
override def apply(context: typed.TypedActorContext[Command]): Behavior[Command] = { override def apply(context: typed.TypedActorContext[Command]): Behavior[Command] = {
val ctx = context.asScala val ctx = context.asScala
@ -124,10 +124,13 @@ private[akka] final case class EventSourcedBehaviorImpl[Command, Event, State](
// This method ensures that the MDC is set before we use the internal logger // This method ensures that the MDC is set before we use the internal logger
def internalLogger() = { def internalLogger() = {
if (settings.useContextLoggerForInternalLogging) ctx.log
else {
// MDC is cleared (if used) from aroundReceive in ActorAdapter after processing each message, // MDC is cleared (if used) from aroundReceive in ActorAdapter after processing each message,
// but important to call `context.log` to mark MDC as used // but important to call `context.log` to mark MDC as used
ctx.log ctx.log
logger loggerForInternal
}
} }
val actualSignalHandler: PartialFunction[(State, Signal), Unit] = signalHandler.orElse { val actualSignalHandler: PartialFunction[(State, Signal), Unit] = signalHandler.orElse {

View file

@ -41,6 +41,8 @@ import akka.persistence.Persistence
val recoveryEventTimeout: FiniteDuration = val recoveryEventTimeout: FiniteDuration =
journalConfig.getDuration("recovery-event-timeout", TimeUnit.MILLISECONDS).millis journalConfig.getDuration("recovery-event-timeout", TimeUnit.MILLISECONDS).millis
val useContextLoggerForInternalLogging = typedConfig.getBoolean("use-context-logger-for-internal-logging")
Persistence.verifyPluginConfigExists(config, snapshotPluginId, "Snapshot store") Persistence.verifyPluginConfigExists(config, snapshotPluginId, "Snapshot store")
EventSourcedSettings( EventSourcedSettings(
@ -49,7 +51,8 @@ import akka.persistence.Persistence
logOnStashing = logOnStashing, logOnStashing = logOnStashing,
recoveryEventTimeout, recoveryEventTimeout,
journalPluginId, journalPluginId,
snapshotPluginId) snapshotPluginId,
useContextLoggerForInternalLogging)
} }
private def journalConfigFor(config: Config, journalPluginId: String): Config = { private def journalConfigFor(config: Config, journalPluginId: String): Config = {
@ -76,7 +79,8 @@ private[akka] final case class EventSourcedSettings(
logOnStashing: Boolean, logOnStashing: Boolean,
recoveryEventTimeout: FiniteDuration, recoveryEventTimeout: FiniteDuration,
journalPluginId: String, journalPluginId: String,
snapshotPluginId: String) { snapshotPluginId: String,
useContextLoggerForInternalLogging: Boolean) {
require(journalPluginId != null, "journal plugin id must not be null; use empty string for 'default' journal") require(journalPluginId != null, "journal plugin id must not be null; use empty string for 'default' journal")
require( require(

View file

@ -66,6 +66,7 @@ class StashStateSpec extends ScalaTestWithActorTestKit with AnyWordSpecLike with
logOnStashing = false, logOnStashing = false,
recoveryEventTimeout = 3.seconds, recoveryEventTimeout = 3.seconds,
journalPluginId = "", journalPluginId = "",
snapshotPluginId = "") snapshotPluginId = "",
useContextLoggerForInternalLogging = false)
} }