Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MdcLoggingDirectives (withMdcLogging, withMdcEntry, withMdcEntries, extractMarkerLog) #3974

Open
wants to merge 10 commits into
base: main
Choose a base branch
from
Open
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
package akka.http.scaladsl.server.directives

import akka.event._
import akka.http.scaladsl.server.RoutingSpec
import akka.testkit.EventFilter

class MdcLoggingDirectivesSpec extends RoutingSpec {
alexklibisz marked this conversation as resolved.
Show resolved Hide resolved

"The `withMarkerLoggingAdapter` directive" should {
"set a DiagnosticMarkerBusLoggingAdapter on the request context and provide the same adapter to the caller" in {
Get() ~> withMarkerLoggingAdapter { provided: MarkerLoggingAdapter =>
extractLog { extracted: LoggingAdapter =>
extracted shouldEqual provided
completeOk
}
} ~> check {
response shouldEqual Ok
}
}
"provides a new DiagnosticMarkerBusLoggingAdapter for each invocation" in {
Get() ~> withMarkerLoggingAdapter { _ =>
extractLog { log1 =>
withMarkerLoggingAdapter { _ =>
extractLog { log2 =>
log1 should not equal log2
completeOk
}
}
}
} ~> check {
response shouldEqual Ok
}
}
}

"The `withMdcEntries` and `withMdcEntry` directives" should {
"incrementally append entries to the LoggingAdapter MDC maps" in {
Get() ~> extractLog { log1 =>
withMdcEntry("foo", "foo entry 1") {
extractLog { log2 =>
withMdcEntries("foo" -> "foo entry 2", "bar" -> "bar entry 1") {
extractLog { log3 =>
log1.mdc shouldBe Map.empty
log2.mdc shouldBe Map("foo" -> "foo entry 1")
log3.mdc shouldBe Map("foo" -> "foo entry 2", "bar" -> "bar entry 1")
completeOk
}
}
}
}
} ~> check {
response shouldEqual Ok
}
}
"include the entries in the LoggingEvents" in {
class EF(n: Int) extends EventFilter(n) {
@volatile
var buf = Vector.empty[Logging.Info2]
override protected def matches(event: Logging.LogEvent): Boolean = event match {
case e: Logging.Info2 =>
buf :+= e
true
case _ => false
}
}
val filter = new EF(3)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd recommend nesting 3 EventFilter.custom instead of the volatile field scheme, looking at the mdc values in the filters instead of after the fact. First log event will go innermost. I think it can match on exact log message and fail explicitly with a scalatest fail if the mdc isn't what it should be to provide extra detail.

filter.intercept {
Get() ~> withMdcEntries("user_id" -> "1234", "request_id" -> "abcd") {
extractLog { log1 =>
log1.info("test 1")
withMdcEntry("status", "200") {
extractLog { log2 =>
log1.info("test 2")
log2.info("test 3")
completeOk
}
}
}
} ~> check {
response shouldEqual Ok
filter.buf.size shouldBe 3
val l1 = filter.buf(0)
val l2 = filter.buf(1)
val l3 = filter.buf(2)
l1.message shouldBe "test 1"
l1.mdc shouldBe Map("user_id" -> "1234", "request_id" -> "abcd")
l2.message shouldBe "test 2"
l2.mdc shouldBe Map("user_id" -> "1234", "request_id" -> "abcd")
l3.message shouldBe "test 3"
l3.mdc shouldBe Map("user_id" -> "1234", "request_id" -> "abcd", "status" -> "200")
}
}
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@ trait Directives extends RouteConcatenation
with WebSocketDirectives
with FramedEntityStreamingDirectives
with AttributeDirectives
with MdcLoggingDirectives

/**
* Collects all default directives into one object for simple importing.
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
package akka.http.scaladsl.server.directives

import akka.event._
import akka.http.scaladsl.server.Directives._
import akka.http.scaladsl.server._

/**
* @groupname mdc Mdc logging directives
* @groupprio mdc 240
*/
trait MdcLoggingDirectives {

import MdcLoggingDirectives.createDiagnosticMarkerLoggingAdapter

def withMarkerLoggingAdapter: Directive1[MarkerLoggingAdapter] = {
createDiagnosticMarkerLoggingAdapter(Map.empty)
.flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter =>
mapRequestContext { ctx =>
ctx.withLog(dmbla)
} & provide {
dmbla: MarkerLoggingAdapter
}
}
}

def withMdcEntries(mdc: (String, Any)*): Directive0 =
johanandren marked this conversation as resolved.
Show resolved Hide resolved
createDiagnosticMarkerLoggingAdapter(mdc.toMap)
.flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter =>
mapRequestContext { ctx =>
ctx.withLog(dmbla)
}
}

def withMdcEntry(key: String, value: Any): Directive0 =
withMdcEntries((key, value))
}

object MdcLoggingDirectives extends MdcLoggingDirectives {
private def createDiagnosticMarkerLoggingAdapter(entries: Map[String, Any]): Directive1[DiagnosticMarkerBusLoggingAdapter] =
extractActorSystem
.flatMap { sys =>
extractRequestContext
.flatMap { ctx =>
provide {
// Convert the existing ctx.log LoggingAdapter to a DiagnosticMarkerBusLoggingAdapter.
// This requires various amounts of effort depending on the type of the current LoggingAdapter.
// In all cases, we create a _new_ DiagnosticMarkerBusLoggingAdapter in order to avoid race conditions,
// where multiple requests could add/remove entries from the same MDC map.
ctx.log match {
case existingAdapter: DiagnosticMarkerBusLoggingAdapter =>
import existingAdapter._
val newAdapter = new DiagnosticMarkerBusLoggingAdapter(bus, logSource, logClass, loggingFilterWithMarker)
newAdapter.mdc(existingAdapter.mdc ++ entries)
alexklibisz marked this conversation as resolved.
Show resolved Hide resolved
newAdapter
case bla: BusLogging =>
val filter = new DefaultLoggingFilter(() => bla.bus.logLevel)
val newAdapter = new DiagnosticMarkerBusLoggingAdapter(bla.bus, bla.logSource, bla.logClass, filter)
newAdapter.mdc(entries)
newAdapter
case _ =>
val (str, cls) = LogSource.fromAnyRef(sys, sys)
val filter = new DefaultLoggingFilter(sys.settings, sys.eventStream)
val newAdapter = new DiagnosticMarkerBusLoggingAdapter(sys.eventStream, str, cls, filter)
johanandren marked this conversation as resolved.
Show resolved Hide resolved
newAdapter.mdc(entries)
newAdapter
}
}
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -158,6 +158,9 @@
|@ref[withExecutionContext](basic-directives/withExecutionContext.md) | Runs its inner route with the given alternative `ExecutionContext` |
|@ref[withLog](basic-directives/withLog.md) | Runs its inner route with the given alternative @apidoc[LoggingAdapter] |
|@ref[withMaterializer](basic-directives/withMaterializer.md) | Runs its inner route with the given alternative @apidoc[Materializer] |
|@ref[withMdcEntries](mdc-logging-directives/withMdcEntries.md) | Adds one or more (key, value) entries to the @apidoc[LoggingAdapter]'s MDC map. All subsequent logs using this @apidoc[LoggingAdapter] will include the given entries. |
|@ref[withMdcEntry](mdc-logging-directives/withMdcEntry.md) | Adds a single (key, value) entry to the @apidoc[LoggingAdapter]'s MDC map. All subsequent logs using this @apidoc[LoggingAdapter] will include the given entries. |
|@ref[withMarkerLoggingAdapter](mdc-logging-directives/withMarkerLoggingAdapter.md) | Replaces the @apidoc[RequestContext]'s existing @apidoc[LoggingAdapter] with a new instance of @apidoc[MarkerLoggingAdapter] and provides the same @apidoc[MarkerLoggingAdapter] to the caller. If the existing @apidoc[LoggingAdapter] already has an MDC map, the directive will copy its entries into the new @apidoc[MarkerLoggingAdapter].|
|@ref[withPrecompressedMediaTypeSupport](coding-directives/withPrecompressedMediaTypeSupport.md) | Adds a `Content-Encoding: gzip` response header if the entity's media-type is precompressed with gzip header |
|@ref[withRangeSupport](range-directives/withRangeSupport.md) | Adds `Accept-Ranges: bytes` to responses to GET requests, produces partial responses if the initial request contained a valid `Range` header |
|@ref[withRequestTimeout](timeout-directives/withRequestTimeout.md) | Configures the @ref[request timeouts](../../common/timeouts.md#request-timeout) for a given route. |
Expand Down
4 changes: 4 additions & 0 deletions docs/src/main/paradox/routing-dsl/directives/by-trait.md
Original file line number Diff line number Diff line change
Expand Up @@ -77,6 +77,9 @@ All predefined directives are organized into traits that form one part of the ov
@ref[TimeoutDirectives](timeout-directives/index.md)
: Configure request timeouts and automatic timeout responses.

@ref[MdcLoggingDirectives](mdc-logging-directives/index.md)
: Directives for mapped diagnostic context logging.

## List of predefined directives by trait

@@toc { depth=1 }
Expand Down Expand Up @@ -109,5 +112,6 @@ All predefined directives are organized into traits that form one part of the ov
* [security-directives/index](security-directives/index.md)
* [websocket-directives/index](websocket-directives/index.md)
* [timeout-directives/index](timeout-directives/index.md)
* [mdc-logging-directives/index](mdc-logging-directives/index.md)

@@@
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
# MdcLoggingDirectives

Directives for request-level mapped diagnostic context logging using the @apidoc[MarkerLoggingAdapter].

These directives provide an API to instantiate a new MDC-compatible logger for every request and append (key, value) MDC entries to be included in any logs emitted from the request.

For example, one might extract a request ID from a header at the beginning of the request and append it as a (key, value) MDC entry.
Any subsequent logs emitted by this request would include the request ID as an entry.

@@toc { depth=1 }

@@@ index

* [withMarkerLoggingAdapter](withMarkerLoggingAdapter.md)
* [withMdcEntries](withMdcEntries.md)
* [withMdcEntry](withMdcEntry.md)

@@@

## Structured JSON MDC Logging

In order to get structured (i.e., JSON) MDC logging, some additional dependencies and configurations are necessary.

One possible configuration is as follows:

1. Add akka-slf4j, logback-classic, and logstash-logback-encoder as dependencies.
2. Add the configuration `akka.loggers = ["akka.event.slf4j.Slf4jLogger"]` to application.conf.
3. Create a `logback.xml` file with an appender that uses the LogstashEncoder:

```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
</appender>
<root level="INFO">
<appender-ref ref="CONSOLE" />
</root>
</configuration>
```
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
# withMarkerLoggingAdapter

@@@ div { .group-scala }

## Signature

@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #withMarkerLoggingAdapter }

@@@

## Description

Replaces the @apidoc[RequestContext]'s existing @apidoc[LoggingAdapter] with a new instance of @apidoc[MarkerLoggingAdapter] and provides the same @apidoc[MarkerLoggingAdapter] to the caller. If the existing @apidoc[LoggingAdapter] already has an MDC map, the directive will copy its entries into the new @apidoc[MarkerLoggingAdapter].

## Example

Scala
: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #withMarkerLoggingAdapter }
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
# withMdcEntries

@@@ div { .group-scala }

## Signature

@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #withMdcEntries }

@@@

## Description

Adds one or more (key, value) entries to the current MDC logging context.

Nested calls will accumulate entries.

## Example

Scala
: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #withMdcEntries }
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
# withMdcEntry

@@@ div { .group-scala }

## Signature

@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #withMdcEntry }

@@@

## Description

Adds a single (key, value) entry to the current MDC logging context.

Nested calls will accumulate entries.

## Example

Scala
: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #withMdcEntry }
Original file line number Diff line number Diff line change
@@ -0,0 +1,49 @@
package docs.http.scaladsl.server.directives

import akka.event._
import akka.http.scaladsl.model.StatusCodes
import akka.http.scaladsl.server.RoutingSpec
import docs.CompileOnlySpec

class MdcLoggingDirectivesExamplesSpec extends RoutingSpec with CompileOnlySpec {

"withMarkerLoggingAdapter" in {
//#withMarkerLoggingAdapter
withMarkerLoggingAdapter { m: MarkerLoggingAdapter =>
// This log.info includes entries for "user_id" and "request_id",
// but subsequent logging calls will not include them.
val marker = LogMarker("", Map("user_id" -> "1234", "request_id" -> "abcd"))
m.info(marker, "completing request")
complete(StatusCodes.OK)
}
//#withMarkerLoggingAdapter
}

"withMdcEntries" in {
//#withMdcEntries
withMdcEntries(("user_id", "1234"), ("request_id", "abcd")) {
extractLog { log =>
// This log.info includes entries for "user_id" and "request_id",
// and subsequent calls will also include them.
log.info("completing request")
complete(StatusCodes.OK)
}
}
//#withMdcEntries
}

"withMdcEntry" in {
//#withMdcEntry
withMdcEntry("user_id", "1234") {
withMdcEntry("request_id", "abcd") {
extractLog { log =>
// This log.info includes entries for "user_id" and "request_id",
// and subsequent calls will also include them.
log.info("completing request")
complete(StatusCodes.OK)
}
}
}
//#withMdcEntry
}
}