Add MDC to log4j

This commit is contained in:
2025-03-16 01:42:57 +01:00
parent ca95344ca9
commit 804ccd785e
14 changed files with 196 additions and 244 deletions

View File

@@ -11,6 +11,7 @@ import eventDemo.app.notification.Notification
import eventDemo.libs.command.CommandId import eventDemo.libs.command.CommandId
import eventDemo.libs.command.CommandStreamChannel import eventDemo.libs.command.CommandStreamChannel
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import kotlinx.coroutines.channels.ReceiveChannel import kotlinx.coroutines.channels.ReceiveChannel
import kotlinx.coroutines.channels.SendChannel import kotlinx.coroutines.channels.SendChannel
import java.util.UUID import java.util.UUID
@@ -56,19 +57,14 @@ class GameCommandHandler(
player: Player, player: Player,
incomingCommandChannel: ReceiveChannel<GameCommand>, incomingCommandChannel: ReceiveChannel<GameCommand>,
channelNotification: SendChannel<Notification>, channelNotification: SendChannel<Notification>,
) = ) {
commandStreamChannel.process(incomingCommandChannel) { command -> commandStreamChannel.process(incomingCommandChannel) { command ->
withLoggingContext("command" to command.toString()) {
if (command.payload.player.id != player.id) { if (command.payload.player.id != player.id) {
logger.atWarn { logger.warn { "Handle command Refuse, the player of the command is not the same" }
message = "Handle command Refuse, the player of the command is not the same: $command"
payload = mapOf("command" to command)
}
channelNotification.sendError(command)("You are not the author of this command\n") channelNotification.sendError(command)("You are not the author of this command\n")
} else { } else {
logger.atInfo { logger.info { "Handle command" }
message = "Handle command: $command"
payload = mapOf("command" to command)
}
try { try {
val eventBuilder = runner.run(command) val eventBuilder = runner.run(command)
@@ -77,49 +73,38 @@ class GameCommandHandler(
.also { eventCommandMap.set(it.eventId, channelNotification, command.id) } .also { eventCommandMap.set(it.eventId, channelNotification, command.id) }
} }
} catch (e: CommandException) { } catch (e: CommandException) {
logger.atWarn { logger.warn(e) { e.message }
message = e.message
payload = mapOf("command" to command)
}
channelNotification.sendError(command)(e.message) channelNotification.sendError(command)(e.message)
} }
} }
} }
} }
}
}
private fun SendChannel<Notification>.sendSuccess(commandId: CommandId): suspend () -> Unit = private fun SendChannel<Notification>.sendSuccess(commandId: CommandId): suspend () -> Unit =
{ {
val logger = KotlinLogging.logger { } val logger = KotlinLogging.logger { }
CommandSuccessNotification(commandId = commandId) CommandSuccessNotification(commandId = commandId)
.also { notification -> .also { notification ->
logger.atDebug { withLoggingContext("notification" to notification.toString(), "commandId" to commandId.toString()) {
message = "Notification SUCCESS sent" logger.debug { "Notification SUCCESS sent" }
payload =
mapOf(
"notification" to notification,
"commandId" to commandId,
)
}
send(notification) send(notification)
} }
} }
}
private fun SendChannel<Notification>.sendError(command: GameCommand): suspend (String) -> Unit = private fun SendChannel<Notification>.sendError(command: GameCommand): suspend (String) -> Unit =
{ {
val logger = KotlinLogging.logger { } val logger = KotlinLogging.logger { }
CommandErrorNotification(message = it, command = command) CommandErrorNotification(message = it, command = command)
.also { notification -> .also { notification ->
logger.atWarn { withLoggingContext("notification" to notification.toString(), "command" to command.toString()) {
message = "Notification ERROR sent: ${notification.message}" logger.warn { "Notification ERROR sent: ${notification.message}" }
payload =
mapOf(
"notification" to notification,
"command" to command,
)
}
send(notification) send(notification)
} }
} }
}
/** /**
* Map to record the command that triggered the event. * Map to record the command that triggered the event.

View File

@@ -5,6 +5,7 @@ import eventDemo.app.eventListener.PlayerNotificationEventListener
import eventDemo.app.notification.Notification import eventDemo.app.notification.Notification
import eventDemo.libs.fromFrameChannel import eventDemo.libs.fromFrameChannel
import eventDemo.libs.toObjectChannel import eventDemo.libs.toObjectChannel
import io.github.oshai.kotlinlogging.withLoggingContext
import io.ktor.server.application.ApplicationCall import io.ktor.server.application.ApplicationCall
import io.ktor.server.auth.authenticate import io.ktor.server.auth.authenticate
import io.ktor.server.auth.jwt.JWTPrincipal import io.ktor.server.auth.jwt.JWTPrincipal
@@ -25,6 +26,7 @@ fun Route.gameSocket(
webSocket("/game") { webSocket("/game") {
val currentPlayer = call.getPlayer() val currentPlayer = call.getPlayer()
val outgoingFrameChannel: SendChannel<Notification> = fromFrameChannel(outgoing) val outgoingFrameChannel: SendChannel<Notification> = fromFrameChannel(outgoing)
withLoggingContext("currentPlayer" to currentPlayer.toString()) {
GlobalScope.launch { GlobalScope.launch {
commandHandler.handle( commandHandler.handle(
currentPlayer, currentPlayer,
@@ -36,6 +38,7 @@ fun Route.gameSocket(
} }
} }
} }
}
private fun ApplicationCall.getPlayer() = private fun ApplicationCall.getPlayer() =
principal<JWTPrincipal>()!!.run { principal<JWTPrincipal>()!!.run {

View File

@@ -3,6 +3,7 @@ package eventDemo.app.event
import eventDemo.app.entity.GameId import eventDemo.app.entity.GameId
import eventDemo.app.event.event.GameEvent import eventDemo.app.event.event.GameEvent
import eventDemo.libs.event.VersionBuilder import eventDemo.libs.event.VersionBuilder
import io.github.oshai.kotlinlogging.withLoggingContext
import java.util.concurrent.ConcurrentHashMap import java.util.concurrent.ConcurrentHashMap
import java.util.concurrent.ConcurrentLinkedQueue import java.util.concurrent.ConcurrentLinkedQueue
import java.util.concurrent.locks.ReentrantLock import java.util.concurrent.locks.ReentrantLock
@@ -31,6 +32,7 @@ class GameEventHandler(
aggregateId: GameId, aggregateId: GameId,
buildEvent: (version: Int) -> GameEvent, buildEvent: (version: Int) -> GameEvent,
): GameEvent = ): GameEvent =
withLoggingContext("aggregateId" to aggregateId.toString()) {
locks locks
// Get lock for the aggregate // Get lock for the aggregate
.computeIfAbsent(aggregateId) { ReentrantLock() } .computeIfAbsent(aggregateId) { ReentrantLock() }
@@ -38,13 +40,20 @@ class GameEventHandler(
// Build event with the version // Build event with the version
buildEvent(versionBuilder.buildNextVersion(aggregateId)) buildEvent(versionBuilder.buildNextVersion(aggregateId))
// then publish it to the event store // then publish it to the event store
.also { eventStore.publish(it) } .also {
withLoggingContext("event" to it.toString()) {
eventStore.publish(it)
}
}
}.also { event -> }.also { event ->
withLoggingContext("event" to event.toString()) {
// Build the projections // Build the projections
projectionsBuilders.forEach { it(event) } projectionsBuilders.forEach { it(event) }
// Publish to the bus // Publish to the bus
eventBus.publish(event) eventBus.publish(event)
} }
} }
}
}
typealias GameProjectionBuilder = (GameEvent) -> Unit typealias GameProjectionBuilder = (GameEvent) -> Unit

View File

@@ -1,15 +0,0 @@
package eventDemo.app.event
import eventDemo.app.event.event.GameEvent
import eventDemo.libs.event.EventStream
/**
* A stream to publish and read the played card event.
*/
class GameEventStream(
private val eventStream: EventStream<GameEvent>,
) : EventStream<GameEvent> by eventStream {
override fun publish(event: GameEvent) {
eventStream.publish(event)
}
}

View File

@@ -18,7 +18,7 @@ fun GameState.apply(event: GameEvent): GameState =
if (event is PlayerActionEvent) { if (event is PlayerActionEvent) {
if (state.currentPlayerTurn != event.player) { if (state.currentPlayerTurn != event.player) {
logger.atError { logger.atError {
message = "Inconsistent player turn. CurrentPlayerTurn: $state.currentPlayerTurn | Player: ${event.player}" message = "Inconsistent player turn"
payload = payload =
mapOf( mapOf(
"CurrentPlayerTurn" to (state.currentPlayerTurn ?: "No currentPlayerTurn"), "CurrentPlayerTurn" to (state.currentPlayerTurn ?: "No currentPlayerTurn"),

View File

@@ -5,6 +5,7 @@ import eventDemo.libs.event.Event
import eventDemo.libs.event.EventStore import eventDemo.libs.event.EventStore
import eventDemo.libs.event.EventStream import eventDemo.libs.event.EventStream
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import kotlinx.datetime.Clock import kotlinx.datetime.Clock
import kotlinx.datetime.Instant import kotlinx.datetime.Instant
import java.util.concurrent.ConcurrentHashMap import java.util.concurrent.ConcurrentHashMap
@@ -176,13 +177,13 @@ class ProjectionSnapshotRepositoryInMemory<E : Event<ID>, P : Projection<ID>, ID
aggregateId: ID, aggregateId: ID,
eventsToApply: Set<E>, eventsToApply: Set<E>,
): P = ): P =
eventsToApply eventsToApply.fold(this ?: initialStateBuilder(aggregateId), applyToProjectionSecure)
.fold(this ?: initialStateBuilder(aggregateId), applyToProjectionSecure)
/** /**
* Wrap the [applyToProjection] lambda to avoid duplicate apply of the same event. * Wrap the [applyToProjection] lambda to avoid duplicate apply of the same event.
*/ */
private val applyToProjectionSecure: P.(event: E) -> P = { event -> private val applyToProjectionSecure: P.(event: E) -> P = { event ->
withLoggingContext("event" to event.toString(), "projection" to this.toString()) {
if (event.version == lastEventVersion + 1) { if (event.version == lastEventVersion + 1) {
applyToProjection(event) applyToProjection(event)
} else if (event.version <= lastEventVersion) { } else if (event.version <= lastEventVersion) {
@@ -193,3 +194,4 @@ class ProjectionSnapshotRepositoryInMemory<E : Event<ID>, P : Projection<ID>, ID
} }
} }
} }
}

View File

@@ -24,6 +24,7 @@ import eventDemo.app.notification.TheGameWasStartedNotification
import eventDemo.app.notification.WelcomeToTheGameNotification import eventDemo.app.notification.WelcomeToTheGameNotification
import eventDemo.app.notification.YourNewCardNotification import eventDemo.app.notification.YourNewCardNotification
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import kotlinx.coroutines.channels.SendChannel import kotlinx.coroutines.channels.SendChannel
import kotlinx.coroutines.channels.trySendBlocking import kotlinx.coroutines.channels.trySendBlocking
@@ -38,22 +39,19 @@ class PlayerNotificationEventListener(
currentPlayer: Player, currentPlayer: Player,
) { ) {
eventBus.subscribe { event: GameEvent -> eventBus.subscribe { event: GameEvent ->
withLoggingContext("event" to event.toString()) {
val currentState = gameStateRepository.getUntil(event) val currentState = gameStateRepository.getUntil(event)
fun Notification.send() { fun Notification.send() {
withLoggingContext("notification" to this.toString()) {
if (currentState.players.contains(currentPlayer)) { if (currentState.players.contains(currentPlayer)) {
// Only notify players who have already joined the game. // Only notify players who have already joined the game.
outgoingNotificationChannel.trySendBlocking(this) outgoingNotificationChannel.trySendBlocking(this)
logger.atInfo { logger.info { "Notification was SEND" }
message = "Notification for player ${currentPlayer.name} was SEND: ${this@send}"
payload = mapOf("notification" to this@send, "event" to event)
}
} else { } else {
// Rare use case, when a connexion is created with the channel, // Rare use case, when a connexion is created with the channel,
// but the player was not already join in the game // but the player was not already join in the game
logger.atWarn { logger.warn { "Notification was SKIP, no player on the game" }
message = "Notification for player ${currentPlayer.name} was SKIP, No player on the game: ${this@send}"
payload = mapOf("notification" to this@send, "event" to event)
} }
} }
} }
@@ -143,3 +141,4 @@ class PlayerNotificationEventListener(
} }
} }
} }
}

View File

@@ -9,6 +9,7 @@ import eventDemo.app.event.event.PlayerWinEvent
import eventDemo.app.event.projection.GameState import eventDemo.app.event.projection.GameState
import eventDemo.app.event.projection.GameStateRepository import eventDemo.app.event.projection.GameStateRepository
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
class ReactionEventListener( class ReactionEventListener(
private val eventBus: GameEventBus, private val eventBus: GameEventBus,
@@ -24,13 +25,15 @@ class ReactionEventListener(
fun init() { fun init() {
eventBus.subscribe(priority) { event: GameEvent -> eventBus.subscribe(priority) { event: GameEvent ->
withLoggingContext("event" to event.toString()) {
val state = gameStateRepository.getUntil(event) val state = gameStateRepository.getUntil(event)
sendStartGameEvent(state, event) sendStartGameEvent(state, event)
sendWinnerEvent(state, event) sendWinnerEvent(state)
}
} }
} }
private suspend fun sendStartGameEvent( private fun sendStartGameEvent(
state: GameState, state: GameState,
event: GameEvent, event: GameEvent,
) { ) {
@@ -44,12 +47,8 @@ class ReactionEventListener(
) )
} }
logger.atInfo { logger.atInfo {
message = "Reaction event was Send $reactionEvent on reaction of: $event" message = "Reaction event was Send"
payload = payload = mapOf("reactionEvent" to reactionEvent)
mapOf(
"event" to event,
"reactionEvent" to reactionEvent,
)
} }
} else { } else {
if (event is PlayerReadyEvent) { if (event is PlayerReadyEvent) {
@@ -58,10 +57,7 @@ class ReactionEventListener(
} }
} }
private fun sendWinnerEvent( private fun sendWinnerEvent(state: GameState) {
state: GameState,
event: GameEvent,
) {
val winner = state.playerHasNoCardLeft().firstOrNull() val winner = state.playerHasNoCardLeft().firstOrNull()
if (winner != null) { if (winner != null) {
val reactionEvent = val reactionEvent =
@@ -74,12 +70,8 @@ class ReactionEventListener(
} }
logger.atInfo { logger.atInfo {
message = "Reaction event was Send $reactionEvent on reaction of: $event" message = "Reaction event was Send"
payload = payload = mapOf("reactionEvent" to reactionEvent)
mapOf(
"event" to event,
"reactionEvent" to reactionEvent,
)
} }
} }
} }

View File

@@ -1,24 +0,0 @@
package eventDemo.app.eventListener
import eventDemo.app.notification.CommandSuccessNotification
import eventDemo.app.notification.Notification
import eventDemo.libs.command.CommandId
import io.github.oshai.kotlinlogging.KotlinLogging
import kotlinx.coroutines.channels.SendChannel
private fun SendChannel<Notification>.successNotifier(commandId: CommandId): suspend () -> Unit =
{
val logger = KotlinLogging.logger { }
CommandSuccessNotification(commandId = commandId)
.let { notification ->
logger.atDebug {
message = "Notification SUCCESS sent"
payload =
mapOf(
"notification" to notification,
"commandId" to commandId,
)
}
send(notification)
}
}

View File

@@ -1,6 +1,7 @@
package eventDemo.libs.command package eventDemo.libs.command
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import kotlinx.coroutines.channels.ReceiveChannel import kotlinx.coroutines.channels.ReceiveChannel
/** /**
@@ -20,15 +21,14 @@ class CommandStreamChannel<C : Command>(
action: CommandBlock<C>, action: CommandBlock<C>,
) { ) {
for (command in incoming) { for (command in incoming) {
withLoggingContext("command" to command.toString()) {
try { try {
controller.runOnlyOnce(command) { controller.runOnlyOnce(command) {
// Wrap action to add logs // Wrap action to add logs
runAndLogStatus(command, action) runAndLogStatus(command, action)
} }
} catch (e: CommandRunnerController.Exception) { } catch (e: CommandRunnerController.Exception) {
logger.atWarn { logger.warn { e.message }
message = e.message
payload = mapOf("command" to command)
} }
} }
} }
@@ -40,16 +40,9 @@ class CommandStreamChannel<C : Command>(
) { ) {
val actionResult = runCatching { action(command) } val actionResult = runCatching { action(command) }
if (actionResult.isFailure) { if (actionResult.isFailure) {
logger.atWarn { logger.warn(actionResult.exceptionOrNull()) { "Compute command FAILED" }
message = "Compute command FAILED: $command"
payload = mapOf("command" to command)
cause = actionResult.exceptionOrNull()
}
} else if (actionResult.isSuccess) { } else if (actionResult.isSuccess) {
logger.atInfo { logger.info { "Compute command SUCCESS" }
message = "Compute command SUCCESS: $command"
payload = mapOf("command" to command)
}
} }
} }
} }

View File

@@ -1,5 +1,6 @@
package eventDemo.libs.event package eventDemo.libs.event
import io.github.oshai.kotlinlogging.withLoggingContext
import kotlinx.coroutines.runBlocking import kotlinx.coroutines.runBlocking
class EventBusInMemory<E : Event<ID>, ID : AggregateId> : EventBus<E, ID> { class EventBusInMemory<E : Event<ID>, ID : AggregateId> : EventBus<E, ID> {
@@ -10,10 +11,12 @@ class EventBusInMemory<E : Event<ID>, ID : AggregateId> : EventBus<E, ID> {
.sortedByDescending { (priority, _) -> priority } .sortedByDescending { (priority, _) -> priority }
.forEach { (_, block) -> .forEach { (_, block) ->
runBlocking { runBlocking {
withLoggingContext("event" to event.toString()) {
block(event) block(event)
} }
} }
} }
}
override fun subscribe( override fun subscribe(
priority: Int, priority: Int,

View File

@@ -1,6 +1,7 @@
package eventDemo.libs.event package eventDemo.libs.event
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import java.util.Queue import java.util.Queue
import java.util.concurrent.ConcurrentLinkedQueue import java.util.concurrent.ConcurrentLinkedQueue
@@ -16,15 +17,16 @@ class EventStreamInMemory<E : Event<*>> : EventStream<E> {
override fun publish(event: E) { override fun publish(event: E) {
if (events.none { it.eventId == event.eventId }) { if (events.none { it.eventId == event.eventId }) {
events.add(event) events.add(event)
logger.atInfo { logger.info { "Event published" }
message = "Event published: $event"
payload = mapOf("event" to event)
}
} }
} }
override fun publish(vararg events: E) { override fun publish(vararg events: E) {
events.forEach { publish(it) } events.forEach {
withLoggingContext("event" to it.toString()) {
publish(it)
}
}
} }
override fun readAll(): Set<E> = override fun readAll(): Set<E> =

View File

@@ -1,6 +1,7 @@
package eventDemo.libs.event package eventDemo.libs.event
import io.github.oshai.kotlinlogging.KotlinLogging import io.github.oshai.kotlinlogging.KotlinLogging
import io.github.oshai.kotlinlogging.withLoggingContext
import java.util.concurrent.ConcurrentHashMap import java.util.concurrent.ConcurrentHashMap
import java.util.concurrent.atomic.AtomicInteger import java.util.concurrent.atomic.AtomicInteger
@@ -9,9 +10,11 @@ class VersionBuilderLocal : VersionBuilder {
private val versions: ConcurrentHashMap<AggregateId, AtomicInteger> = ConcurrentHashMap() private val versions: ConcurrentHashMap<AggregateId, AtomicInteger> = ConcurrentHashMap()
override fun buildNextVersion(aggregateId: AggregateId): Int = override fun buildNextVersion(aggregateId: AggregateId): Int =
withLoggingContext("aggregateId" to aggregateId.toString()) {
versionOfAggregate(aggregateId) versionOfAggregate(aggregateId)
.addAndGet(1) .addAndGet(1)
.also { logger.debug { "New version $it" } } .also { logger.debug { "New event version $it" } }
}
override fun getLastVersion(aggregateId: AggregateId): Int = override fun getLastVersion(aggregateId: AggregateId): Int =
versionOfAggregate(aggregateId).toInt() versionOfAggregate(aggregateId).toInt()

View File

@@ -1,7 +1,7 @@
<configuration> <configuration>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder> <encoder>
<pattern>%d{YYYY-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> <pattern>%d{YYYY-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n > MDC=%mdc%n</pattern>
</encoder> </encoder>
</appender> </appender>
<root level="trace"> <root level="trace">