From 65eb27263e123377a58967301fcf71c89f8d1d2d Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Tue, 21 Dec 2021 17:47:50 -0500 Subject: [PATCH 1/8] First pass at MdcLoggingDirectives (Scala only) --- .gitignore | 2 + .../directives/MdcLoggingDirectivesSpec.scala | 117 ++++++++++++++++++ .../http/scaladsl/server/Directives.scala | 1 + .../directives/MdcLoggingDirectives.scala | 63 ++++++++++ .../routing-dsl/directives/alphabetically.md | 4 + .../routing-dsl/directives/by-trait.md | 4 + .../extractMarkerLog.md | 20 +++ .../mdc-logging-directives/index.md | 41 ++++++ .../mdc-logging-directives/withMdcEntries.md | 20 +++ .../mdc-logging-directives/withMdcEntry.md | 20 +++ .../mdc-logging-directives/withMdcLogging.md | 20 +++ .../MdcLoggingDirectivesExamplesSpec.scala | 59 +++++++++ 12 files changed, 371 insertions(+) create mode 100644 akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala create mode 100644 akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala create mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md create mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md create mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntries.md create mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntry.md create mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md create mode 100644 docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala diff --git a/.gitignore b/.gitignore index 8cb5b8eec4a..93ee41274e6 100644 --- a/.gitignore +++ b/.gitignore @@ -10,3 +10,5 @@ target .*.swp *.vim .ensime* +.bsp +.tool-versions diff --git a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala new file mode 100644 index 00000000000..24c050b2ce9 --- /dev/null +++ b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala @@ -0,0 +1,117 @@ +package akka.http.scaladsl.server.directives + +import akka.event.{ DiagnosticMarkerBusLoggingAdapter, MarkerLoggingAdapter } +import akka.http.scaladsl.model.StatusCodes +import akka.http.scaladsl.server.RoutingSpec +import scala.jdk.CollectionConverters._ + +class MdcLoggingDirectivesSpec extends RoutingSpec { + + "The `withMdcLogging` directive" should { + "provide a DiagnosticMarkerBusLoggingAdapter" in { + Get() ~> withMdcLogging { + extractLog { + case _: DiagnosticMarkerBusLoggingAdapter => completeOk + case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + } + } ~> check { + response shouldEqual Ok + } + } + "provide a new DiagnosticMarkerBusLoggingAdapter for each request" in { + val route = withMdcLogging { + extractLog { + case l: DiagnosticMarkerBusLoggingAdapter => complete(l.hashCode().toString) + case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + } + } + val reps = 100 + val responseEntities = (1 to reps).map(_ => Get() ~> route ~> check { + status shouldEqual StatusCodes.OK + entityAs[String] + }) + responseEntities.distinct.length shouldBe reps + } + "provide the same DiagnosticMarkerBusLoggingAdapter when nested multiple times" in { + Get() ~> withMdcLogging { + extractLog { log1 => + withMdcLogging { + extractLog { log2 => + if (log1 == log2) completeOk + else failTest(s"$log1 != $log2") + } + } + } + } ~> check { + response shouldEqual Ok + } + } + } + + "The `extractMarkerLog` directive" should { + "provide a MarkerLoggingAdapter" in { + Get() ~> extractMarkerLog { + case _: MarkerLoggingAdapter => completeOk + case other => failTest(s"expected a MarkerLoggingAdapter but found $other") + } + } + "provide a new MarkerLoggingAdapter for each request" in { + val route = extractMarkerLog { + case log: MarkerLoggingAdapter => complete(log.hashCode().toString) + case other => failTest(s"expected a MarkerLoggingAdapter but found $other") + } + val reps = 100 + val responseEntities = (1 to reps).map(_ => Get() ~> route ~> check { + status shouldEqual StatusCodes.OK + entityAs[String] + }) + responseEntities.distinct.length shouldBe reps + } + "provide the same MarkerLoggingAdapter when nested multiple times" in { + Get() ~> extractMarkerLog { log1 => + withMdcLogging { + extractMarkerLog { log2 => + if (log1 == log2) completeOk + else failTest(s"$log1 != $log2") + } + } + } ~> check { + response shouldEqual Ok + } + } + } + + "The `withMdcEntries` directive" should { + "append entries to the DiagnosticMarkerBusLoggingAdapter's MDC map" in { + Get() ~> withMdcEntries(("foo", "foo entry"), ("bar", "bar entry")) { + extractMarkerLog { + case log: DiagnosticMarkerBusLoggingAdapter => + val map = log.getMDC.asScala + if (!map.get("foo").contains("foo entry")) failTest(s"missing or incorrect key 'foo' in $map") + else if (!map.get("bar").contains("bar entry")) failTest(s"missing or incorrect key 'bar' in $map") + else completeOk + case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + } + } ~> check { + response shouldEqual Ok + } + } + "replace entries with same key when nested" in { + Get() ~> withMdcEntries(("foo", "foo entry 1")) { + extractMarkerLog { + case log: DiagnosticMarkerBusLoggingAdapter => + val map = log.getMDC.asScala + if (!map.get("foo").contains("foo entry 1")) failTest(s"'foo' should be 'foo entry 1'") + else withMdcEntries(("foo", "foo entry 2")) { + val map = log.getMDC.asScala + if (!map.get("foo").contains("foo entry 2")) failTest(s"'foo' should be 'foo entry 2'") + else completeOk + } + case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + } + } ~> check { + response shouldEqual Ok + } + } + } +} diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/Directives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/Directives.scala index 37879912133..81c72638ff2 100644 --- a/akka-http/src/main/scala/akka/http/scaladsl/server/Directives.scala +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/Directives.scala @@ -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. diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala new file mode 100644 index 00000000000..ec2b2e6edb7 --- /dev/null +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala @@ -0,0 +1,63 @@ +package akka.http.scaladsl.server.directives + +import akka.event.{ + DefaultLoggingFilter, + DiagnosticMarkerBusLoggingAdapter, + LogSource, + MarkerLoggingAdapter +} +import akka.http.scaladsl.server.Directives._ +import akka.http.scaladsl.server._ + +/** + * @groupname mdc Mdc logging directives + * @groupprio mdc 240 + */ +trait MdcLoggingDirectives { + + def withMdcLogging: Directive0 = + extractActorSystem + .flatMap { sys => + mapRequestContext { ctx => + ctx.log match { + // If it's already a DiagnosticMarkerBusLoggingAdapter, this is a no-op. + case _: DiagnosticMarkerBusLoggingAdapter => ctx + // Otherwise, we need to give the context a DiagnosticLoggingAdapter. + case _ => + val (str, cls) = LogSource.fromAnyRef(sys, sys) + val loggingFilter = + new DefaultLoggingFilter(sys.settings, sys.eventStream) + val dmbla = new DiagnosticMarkerBusLoggingAdapter( + sys.eventStream, + str, + cls, + loggingFilter) + ctx.withLog(dmbla) + } + } + } + + def extractMarkerLog: Directive1[MarkerLoggingAdapter] = + MdcLoggingDirectives.extractDiagnosticMarkerLog + .map(identity[MarkerLoggingAdapter]) + + def withMdcEntries(entries: (String, Any)*): Directive0 = + MdcLoggingDirectives.extractDiagnosticMarkerLog + .map(log => log.mdc(log.mdc ++ entries.toMap)) + + def withMdcEntry(key: String, value: Any): Directive0 = + withMdcEntries((key, value)) +} + +object MdcLoggingDirectives extends MdcLoggingDirectives { + // This is private because the only advantage of a DiagnosticLoggingAdapter is that you can mutate the MDC entries, + // which is better done through the withMdcEntry and withMdcEntries directive. + private val extractDiagnosticMarkerLog: Directive1[DiagnosticMarkerBusLoggingAdapter] = + withMdcLogging.tflatMap { _ => + extractLog.flatMap { log => + // This asInstanceOf is tested and virtually guaranteed to work, but is there any way to do it without casting? + val dmbla = log.asInstanceOf[DiagnosticMarkerBusLoggingAdapter] + provide(dmbla) + } + } +} diff --git a/docs/src/main/paradox/routing-dsl/directives/alphabetically.md b/docs/src/main/paradox/routing-dsl/directives/alphabetically.md index 750dbbe199e..5b5ad166b27 100644 --- a/docs/src/main/paradox/routing-dsl/directives/alphabetically.md +++ b/docs/src/main/paradox/routing-dsl/directives/alphabetically.md @@ -41,6 +41,7 @@ |@ref[extractMaterializer](basic-directives/extractMaterializer.md) | Extracts the @apidoc[Materializer] from the @apidoc[RequestContext] | |@ref[extractHost](host-directives/extractHost.md) | Extracts the hostname part of the Host request header value | |@ref[extractLog](basic-directives/extractLog.md) | Extracts the @apidoc[LoggingAdapter] from the @apidoc[RequestContext] | +|@ref[extractMarkerLog](mdc-logging-directives/extractMarkerLog.md) | Calls @ref[withMdcLogging](mdc-logging-directives/withMdcLogging.md) and provides the resulting @apidoc[MarkerLoggingAdapter] from the @apidoc[RequestContext] | |@ref[extractMethod](method-directives/extractMethod.md) | Extracts the request method | |@ref[extractOfferedWsProtocols](websocket-directives/extractOfferedWsProtocols.md) | Extract the list of websocket subprotocols offered by the client in the `Sec-WebSocket-Protocol` header if this is a websocket request and otherwise rejects with an @apidoc[ExpectedWebSocketRequestRejection$] | |@ref[extractParserSettings](basic-directives/extractParserSettings.md) | Extracts the @apidoc[ParserSettings] from the @apidoc[RequestContext] | @@ -158,6 +159,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 current MDC logging context | +|@ref[withMdcEntry](mdc-logging-directives/withMdcEntry.md) | Adds a single (key, value) entry to the current MDC logging context | +|@ref[withMdcLogging](mdc-logging-directives/withMdcLogging.md) | Replaces the @apidoc[RequestContext]'s existing @apidoc[LoggingAdapter] with an MDC-compatible @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. | diff --git a/docs/src/main/paradox/routing-dsl/directives/by-trait.md b/docs/src/main/paradox/routing-dsl/directives/by-trait.md index 70c5c44b041..c429847e75c 100644 --- a/docs/src/main/paradox/routing-dsl/directives/by-trait.md +++ b/docs/src/main/paradox/routing-dsl/directives/by-trait.md @@ -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 } @@ -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) @@@ diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md new file mode 100644 index 00000000000..fa830793c9f --- /dev/null +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md @@ -0,0 +1,20 @@ +# extractMarkerLog + +@@@ div { .group-scala } + +## Signature + +@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #extractMarkerLog } + +@@@ + +## Description + +Calls @ref[withMdcLogging](./withMdcLogging.md) and provides the resulting @apidoc[MarkerLoggingAdapter] from the @apidoc[RequestContext]. + +Nested calls will provide the same instance of `MarkerLoggingAdapter`. + +## Example + +Scala +: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #extractMarkerLog } diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md new file mode 100644 index 00000000000..f1bc554bcd3 --- /dev/null +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md @@ -0,0 +1,41 @@ +# MdcLoggingDirectives + +Directives for request-level mapped diagnostic context logging using the @apidoc[MarkerLoggingAdapter]. + +These directives provide an API to setup a new MDC-compatible logger for every request and append (key, value) MDC entries to be included in any emitted logs for the duration of 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 + +* [withMdcLogging](withMdcLogging.md) +* [withMdcEntries](withMdcEntries.md) +* [withMdcEntry](withMdcEntry.md) +* [extractMarkerLog](extractMarkerLog.md) + +@@@ + +## Structured JSON MDC Logging + +In order to get structured (i.e., JSON) MDC logging, some additional 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 + + + + + + + + + +``` + diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntries.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntries.md new file mode 100644 index 00000000000..abd2db27042 --- /dev/null +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntries.md @@ -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 } diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntry.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntry.md new file mode 100644 index 00000000000..cb4ad32ee1b --- /dev/null +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcEntry.md @@ -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 } diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md new file mode 100644 index 00000000000..d56d01c3b9f --- /dev/null +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md @@ -0,0 +1,20 @@ +# withMdcLogging + +@@@ div { .group-scala } + +## Signature + +@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #withMdcLogging } + +@@@ + +## Description + +Replaces the @apidoc[RequestContext]'s existing @apidoc[LoggingAdapter] with an MDC-compatible @apidoc[MarkerLoggingAdapter]. + +Nested calls will provide the same instance of `MarkerLoggingAdapter`. + +## Example + +Scala +: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #withMdcLogging } diff --git a/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala b/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala new file mode 100644 index 00000000000..605360d40ba --- /dev/null +++ b/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala @@ -0,0 +1,59 @@ +package docs.http.scaladsl.server.directives + +import akka.event.{ LogMarker, MarkerLoggingAdapter } +import akka.http.scaladsl.model.StatusCodes +import akka.http.scaladsl.server.RoutingSpec +import docs.CompileOnlySpec + +class MdcLoggingDirectivesExamplesSpec extends RoutingSpec with CompileOnlySpec { + + "withMdcLogging" in { + //#withMdcLogging + withMdcLogging { + extractLog { + case m: MarkerLoggingAdapter => + // Logger will be a MarkerLoggingAdapter. + // Log will include entries for "user_id" and "request_id". + m.info(LogMarker("", Map("user_id" -> "1234", "request_id" -> "abcd")), "completing request") + complete(StatusCodes.OK) + } + } + //#withMdcLogging + } + + "withMdcEntries" in { + //#withMdcEntries + withMdcEntries(("user_id", "1234"), ("request_id", "abcd")) { + extractLog { log => + // Log will include entries for "user_id" and "request_id". + log.info("completing request") + complete(StatusCodes.OK) + } + } + //#withMdcEntries + } + + "withMdcEntry" in { + //#withMdcEntry + withMdcEntry("user_id", "1234") { + withMdcEntry("request_id", "abcd") { + extractLog { log => + // Log will include entries for "user_id" and "request_id". + log.info("completing request") + complete(StatusCodes.OK) + } + } + } + //#withMdcEntry + } + + "extractMarkerLog" in { + //#extractMarkerLog + extractMarkerLog { m: MarkerLoggingAdapter => + // Log will include entires for "user_id" and "request_id". + m.info(LogMarker("", Map("user_id" -> "1234", "request_id" -> "abcd")), "completing request") + complete(StatusCodes.OK) + } + //#extractMarkerLog + } +} From 629938feaa7b913ba914c7a6b4ac9ce69e5f2e70 Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Mon, 27 Dec 2021 09:29:57 -0600 Subject: [PATCH 2/8] Rearrange methods to get rid of .asInstanceOf --- .../directives/MdcLoggingDirectives.scala | 63 +++++++++---------- 1 file changed, 31 insertions(+), 32 deletions(-) diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala index ec2b2e6edb7..f1fd83fb236 100644 --- a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala @@ -15,49 +15,48 @@ import akka.http.scaladsl.server._ */ trait MdcLoggingDirectives { - def withMdcLogging: Directive0 = - extractActorSystem - .flatMap { sys => - mapRequestContext { ctx => - ctx.log match { - // If it's already a DiagnosticMarkerBusLoggingAdapter, this is a no-op. - case _: DiagnosticMarkerBusLoggingAdapter => ctx - // Otherwise, we need to give the context a DiagnosticLoggingAdapter. - case _ => - val (str, cls) = LogSource.fromAnyRef(sys, sys) - val loggingFilter = - new DefaultLoggingFilter(sys.settings, sys.eventStream) - val dmbla = new DiagnosticMarkerBusLoggingAdapter( - sys.eventStream, - str, - cls, - loggingFilter) - ctx.withLog(dmbla) - } - } + import MdcLoggingDirectives.extractDiagnosticMarkerLog + + def withMdcLogging: Directive0 = extractDiagnosticMarkerLog + .flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter => + mapRequestContext { ctx => + ctx.withLog(dmbla) } + } def extractMarkerLog: Directive1[MarkerLoggingAdapter] = - MdcLoggingDirectives.extractDiagnosticMarkerLog - .map(identity[MarkerLoggingAdapter]) + withMdcLogging.tflatMap { _ => + extractDiagnosticMarkerLog + .map(identity[MarkerLoggingAdapter]) + } def withMdcEntries(entries: (String, Any)*): Directive0 = - MdcLoggingDirectives.extractDiagnosticMarkerLog - .map(log => log.mdc(log.mdc ++ entries.toMap)) + withMdcLogging.tflatMap { _ => + extractDiagnosticMarkerLog + .map(log => log.mdc(log.mdc ++ entries.toMap)) + } def withMdcEntry(key: String, value: Any): Directive0 = withMdcEntries((key, value)) } object MdcLoggingDirectives extends MdcLoggingDirectives { - // This is private because the only advantage of a DiagnosticLoggingAdapter is that you can mutate the MDC entries, - // which is better done through the withMdcEntry and withMdcEntries directive. private val extractDiagnosticMarkerLog: Directive1[DiagnosticMarkerBusLoggingAdapter] = - withMdcLogging.tflatMap { _ => - extractLog.flatMap { log => - // This asInstanceOf is tested and virtually guaranteed to work, but is there any way to do it without casting? - val dmbla = log.asInstanceOf[DiagnosticMarkerBusLoggingAdapter] - provide(dmbla) + extractActorSystem + .flatMap { sys => + extractRequestContext + .flatMap { ctx => + provide { + ctx.log match { + // If it's already a DiagnosticMarkerBusLoggingAdapter, this is a no-op. + case dmbla: DiagnosticMarkerBusLoggingAdapter => dmbla + // Otherwise, we need to construct a DiagnosticLoggingAdapter. + case _ => + val (str, cls) = LogSource.fromAnyRef(sys, sys) + val filter = new DefaultLoggingFilter(sys.settings, sys.eventStream) + new DiagnosticMarkerBusLoggingAdapter(sys.eventStream, str, cls, filter) + } + } + } } - } } From 6f6c4e001f5d20f63941318149dedfdaee048715 Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Fri, 25 Feb 2022 09:22:24 -0500 Subject: [PATCH 3/8] Move .tool-versions to .git/info/exclude --- .gitignore | 1 - 1 file changed, 1 deletion(-) diff --git a/.gitignore b/.gitignore index 93ee41274e6..d57c4ee89e9 100644 --- a/.gitignore +++ b/.gitignore @@ -11,4 +11,3 @@ target *.vim .ensime* .bsp -.tool-versions From d434e00a7df4f7460a0deec0b61240f5753bf1e5 Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Fri, 25 Feb 2022 09:39:21 -0500 Subject: [PATCH 4/8] Use withMdcLogging & extractDiagnosticMarkerLog where possible --- .../directives/MdcLoggingDirectives.scala | 21 +++++++------------ 1 file changed, 8 insertions(+), 13 deletions(-) diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala index f1fd83fb236..551c81e2c86 100644 --- a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala @@ -17,24 +17,19 @@ trait MdcLoggingDirectives { import MdcLoggingDirectives.extractDiagnosticMarkerLog - def withMdcLogging: Directive0 = extractDiagnosticMarkerLog - .flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter => - mapRequestContext { ctx => - ctx.withLog(dmbla) + def withMdcLogging: Directive0 = + extractDiagnosticMarkerLog + .flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter => + mapRequestContext { ctx => + ctx.withLog(dmbla) + } } - } def extractMarkerLog: Directive1[MarkerLoggingAdapter] = - withMdcLogging.tflatMap { _ => - extractDiagnosticMarkerLog - .map(identity[MarkerLoggingAdapter]) - } + (withMdcLogging & extractDiagnosticMarkerLog).map(identity[MarkerLoggingAdapter]) def withMdcEntries(entries: (String, Any)*): Directive0 = - withMdcLogging.tflatMap { _ => - extractDiagnosticMarkerLog - .map(log => log.mdc(log.mdc ++ entries.toMap)) - } + (withMdcLogging & extractDiagnosticMarkerLog).map(log => log.mdc(log.mdc ++ entries.toMap)) def withMdcEntry(key: String, value: Any): Directive0 = withMdcEntries((key, value)) From 776f4ef37bec392a9afa96ccd10a9b1d64660c9b Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Sat, 14 May 2022 14:42:22 -0400 Subject: [PATCH 5/8] Every directive call creates a new adapter to avoid race conditions - All MDC directives create a new MarkerLoggingAdapter to avoid race conditions. - Combined withMdcLogging and extractMarkerLog into a single directive withMarkerLoggingAdapter. - Updated tests to account for the expectation that ever call to a directive creates a new logging adapter. - Added a test using the EventFilter to verify that the entries are actually being attached. --- .../directives/MdcLoggingDirectivesSpec.scala | 136 +++++++----------- .../directives/MdcLoggingDirectives.scala | 45 +++--- .../routing-dsl/directives/alphabetically.md | 7 +- .../extractMarkerLog.md | 20 --- .../mdc-logging-directives/index.md | 11 +- ...Logging.md => withMarkerLoggingAdapter.md} | 10 +- .../MdcLoggingDirectivesExamplesSpec.scala | 38 ++--- 7 files changed, 107 insertions(+), 160 deletions(-) delete mode 100644 docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md rename docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/{withMdcLogging.md => withMarkerLoggingAdapter.md} (51%) diff --git a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala index 24c050b2ce9..5320c9a0b3c 100644 --- a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala +++ b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala @@ -1,44 +1,31 @@ package akka.http.scaladsl.server.directives -import akka.event.{ DiagnosticMarkerBusLoggingAdapter, MarkerLoggingAdapter } -import akka.http.scaladsl.model.StatusCodes +import akka.event._ import akka.http.scaladsl.server.RoutingSpec -import scala.jdk.CollectionConverters._ +import akka.testkit.EventFilter + +import scala.collection.mutable.ListBuffer class MdcLoggingDirectivesSpec extends RoutingSpec { - "The `withMdcLogging` directive" should { - "provide a DiagnosticMarkerBusLoggingAdapter" in { - Get() ~> withMdcLogging { - extractLog { - case _: DiagnosticMarkerBusLoggingAdapter => completeOk - case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + "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 } } - "provide a new DiagnosticMarkerBusLoggingAdapter for each request" in { - val route = withMdcLogging { - extractLog { - case l: DiagnosticMarkerBusLoggingAdapter => complete(l.hashCode().toString) - case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") - } - } - val reps = 100 - val responseEntities = (1 to reps).map(_ => Get() ~> route ~> check { - status shouldEqual StatusCodes.OK - entityAs[String] - }) - responseEntities.distinct.length shouldBe reps - } - "provide the same DiagnosticMarkerBusLoggingAdapter when nested multiple times" in { - Get() ~> withMdcLogging { + "provides a new DiagnosticMarkerBusLoggingAdapter for each invocation" in { + Get() ~> withMarkerLoggingAdapter { _ => extractLog { log1 => - withMdcLogging { + withMarkerLoggingAdapter { _ => extractLog { log2 => - if (log1 == log2) completeOk - else failTest(s"$log1 != $log2") + log1 should not equal log2 + completeOk } } } @@ -48,69 +35,56 @@ class MdcLoggingDirectivesSpec extends RoutingSpec { } } - "The `extractMarkerLog` directive" should { - "provide a MarkerLoggingAdapter" in { - Get() ~> extractMarkerLog { - case _: MarkerLoggingAdapter => completeOk - case other => failTest(s"expected a MarkerLoggingAdapter but found $other") - } - } - "provide a new MarkerLoggingAdapter for each request" in { - val route = extractMarkerLog { - case log: MarkerLoggingAdapter => complete(log.hashCode().toString) - case other => failTest(s"expected a MarkerLoggingAdapter but found $other") - } - val reps = 100 - val responseEntities = (1 to reps).map(_ => Get() ~> route ~> check { - status shouldEqual StatusCodes.OK - entityAs[String] - }) - responseEntities.distinct.length shouldBe reps - } - "provide the same MarkerLoggingAdapter when nested multiple times" in { - Get() ~> extractMarkerLog { log1 => - withMdcLogging { - extractMarkerLog { log2 => - if (log1 == log2) completeOk - else failTest(s"$log1 != $log2") + "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 { + val buf = ListBuffer.empty[Logging.Info2] + val filter = EventFilter.custom { + case e: Logging.Info2 => buf.append(e).nonEmpty - "The `withMdcEntries` directive" should { - "append entries to the DiagnosticMarkerBusLoggingAdapter's MDC map" in { - Get() ~> withMdcEntries(("foo", "foo entry"), ("bar", "bar entry")) { - extractMarkerLog { - case log: DiagnosticMarkerBusLoggingAdapter => - val map = log.getMDC.asScala - if (!map.get("foo").contains("foo entry")) failTest(s"missing or incorrect key 'foo' in $map") - else if (!map.get("bar").contains("bar entry")) failTest(s"missing or incorrect key 'bar' in $map") - else completeOk - case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") - } - } ~> check { - response shouldEqual Ok } - } - "replace entries with same key when nested" in { - Get() ~> withMdcEntries(("foo", "foo entry 1")) { - extractMarkerLog { - case log: DiagnosticMarkerBusLoggingAdapter => - val map = log.getMDC.asScala - if (!map.get("foo").contains("foo entry 1")) failTest(s"'foo' should be 'foo entry 1'") - else withMdcEntries(("foo", "foo entry 2")) { - val map = log.getMDC.asScala - if (!map.get("foo").contains("foo entry 2")) failTest(s"'foo' should be 'foo entry 2'") - else completeOk + 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 + } } - case other => failTest(s"expected a DiagnosticMarkerBusLoggingAdapter but found $other") + } + } ~> check { + response shouldEqual Ok + buf.size shouldBe 3 + val l1 = buf(0) + val l2 = buf(1) + val l3 = 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") } - } ~> check { - response shouldEqual Ok } } } diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala index 551c81e2c86..de7c59b4b04 100644 --- a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala @@ -1,11 +1,6 @@ package akka.http.scaladsl.server.directives -import akka.event.{ - DefaultLoggingFilter, - DiagnosticMarkerBusLoggingAdapter, - LogSource, - MarkerLoggingAdapter -} +import akka.event._ import akka.http.scaladsl.server.Directives._ import akka.http.scaladsl.server._ @@ -15,41 +10,53 @@ import akka.http.scaladsl.server._ */ trait MdcLoggingDirectives { - import MdcLoggingDirectives.extractDiagnosticMarkerLog + import MdcLoggingDirectives.createDiagnosticMarkerLoggingAdapter - def withMdcLogging: Directive0 = - extractDiagnosticMarkerLog + def withMarkerLoggingAdapter: Directive1[MarkerLoggingAdapter] = { + createDiagnosticMarkerLoggingAdapter(Map.empty) .flatMap { dmbla: DiagnosticMarkerBusLoggingAdapter => mapRequestContext { ctx => ctx.withLog(dmbla) + } & provide { + dmbla: MarkerLoggingAdapter } } + } - def extractMarkerLog: Directive1[MarkerLoggingAdapter] = - (withMdcLogging & extractDiagnosticMarkerLog).map(identity[MarkerLoggingAdapter]) - - def withMdcEntries(entries: (String, Any)*): Directive0 = - (withMdcLogging & extractDiagnosticMarkerLog).map(log => log.mdc(log.mdc ++ entries.toMap)) + def withMdcEntries(mdc: (String, Any)*): Directive0 = + 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 val extractDiagnosticMarkerLog: Directive1[DiagnosticMarkerBusLoggingAdapter] = + private def createDiagnosticMarkerLoggingAdapter(entries: Map[String, Any]): Directive1[DiagnosticMarkerBusLoggingAdapter] = extractActorSystem .flatMap { sys => extractRequestContext .flatMap { ctx => provide { ctx.log match { - // If it's already a DiagnosticMarkerBusLoggingAdapter, this is a no-op. - case dmbla: DiagnosticMarkerBusLoggingAdapter => dmbla - // Otherwise, we need to construct a DiagnosticLoggingAdapter. + // In order to avoid race conditions from using a shared LoggingAdapter, even if the existing adapter + // is a DiagnosticMarkerBusLoggingAdapter, we still create a new one and merge the two entries. + case existingAdapter: DiagnosticMarkerBusLoggingAdapter => + import existingAdapter._ + val newAdapter = new DiagnosticMarkerBusLoggingAdapter(bus, logSource, logClass, loggingFilterWithMarker) + newAdapter.mdc(existingAdapter.mdc ++ entries) + newAdapter + // If the logger is not already a DiagnosticLoggingAdapter, we create a new one with the given entries. case _ => val (str, cls) = LogSource.fromAnyRef(sys, sys) val filter = new DefaultLoggingFilter(sys.settings, sys.eventStream) - new DiagnosticMarkerBusLoggingAdapter(sys.eventStream, str, cls, filter) + val newAdapter = new DiagnosticMarkerBusLoggingAdapter(sys.eventStream, str, cls, filter) + newAdapter.mdc(entries) + newAdapter } } } diff --git a/docs/src/main/paradox/routing-dsl/directives/alphabetically.md b/docs/src/main/paradox/routing-dsl/directives/alphabetically.md index 5b5ad166b27..8b21d34c4ae 100644 --- a/docs/src/main/paradox/routing-dsl/directives/alphabetically.md +++ b/docs/src/main/paradox/routing-dsl/directives/alphabetically.md @@ -41,7 +41,6 @@ |@ref[extractMaterializer](basic-directives/extractMaterializer.md) | Extracts the @apidoc[Materializer] from the @apidoc[RequestContext] | |@ref[extractHost](host-directives/extractHost.md) | Extracts the hostname part of the Host request header value | |@ref[extractLog](basic-directives/extractLog.md) | Extracts the @apidoc[LoggingAdapter] from the @apidoc[RequestContext] | -|@ref[extractMarkerLog](mdc-logging-directives/extractMarkerLog.md) | Calls @ref[withMdcLogging](mdc-logging-directives/withMdcLogging.md) and provides the resulting @apidoc[MarkerLoggingAdapter] from the @apidoc[RequestContext] | |@ref[extractMethod](method-directives/extractMethod.md) | Extracts the request method | |@ref[extractOfferedWsProtocols](websocket-directives/extractOfferedWsProtocols.md) | Extract the list of websocket subprotocols offered by the client in the `Sec-WebSocket-Protocol` header if this is a websocket request and otherwise rejects with an @apidoc[ExpectedWebSocketRequestRejection$] | |@ref[extractParserSettings](basic-directives/extractParserSettings.md) | Extracts the @apidoc[ParserSettings] from the @apidoc[RequestContext] | @@ -159,9 +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 current MDC logging context | -|@ref[withMdcEntry](mdc-logging-directives/withMdcEntry.md) | Adds a single (key, value) entry to the current MDC logging context | -|@ref[withMdcLogging](mdc-logging-directives/withMdcLogging.md) | Replaces the @apidoc[RequestContext]'s existing @apidoc[LoggingAdapter] with an MDC-compatible @apidoc[MarkerLoggingAdapter] | +|@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. | diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md deleted file mode 100644 index fa830793c9f..00000000000 --- a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/extractMarkerLog.md +++ /dev/null @@ -1,20 +0,0 @@ -# extractMarkerLog - -@@@ div { .group-scala } - -## Signature - -@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #extractMarkerLog } - -@@@ - -## Description - -Calls @ref[withMdcLogging](./withMdcLogging.md) and provides the resulting @apidoc[MarkerLoggingAdapter] from the @apidoc[RequestContext]. - -Nested calls will provide the same instance of `MarkerLoggingAdapter`. - -## Example - -Scala -: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #extractMarkerLog } diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md index f1bc554bcd3..8004e39da06 100644 --- a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/index.md @@ -2,7 +2,7 @@ Directives for request-level mapped diagnostic context logging using the @apidoc[MarkerLoggingAdapter]. -These directives provide an API to setup a new MDC-compatible logger for every request and append (key, value) MDC entries to be included in any emitted logs for the duration of the request +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. @@ -11,16 +11,16 @@ Any subsequent logs emitted by this request would include the request ID as an e @@@ index -* [withMdcLogging](withMdcLogging.md) +* [withMarkerLoggingAdapter](withMarkerLoggingAdapter.md) * [withMdcEntries](withMdcEntries.md) * [withMdcEntry](withMdcEntry.md) -* [extractMarkerLog](extractMarkerLog.md) @@@ ## Structured JSON MDC Logging -In order to get structured (i.e., JSON) MDC logging, some additional configurations are necessary. +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. @@ -37,5 +37,4 @@ One possible configuration is as follows: -``` - +``` diff --git a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMarkerLoggingAdapter.md similarity index 51% rename from docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md rename to docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMarkerLoggingAdapter.md index d56d01c3b9f..1eb9006d19c 100644 --- a/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMdcLogging.md +++ b/docs/src/main/paradox/routing-dsl/directives/mdc-logging-directives/withMarkerLoggingAdapter.md @@ -1,20 +1,18 @@ -# withMdcLogging +# withMarkerLoggingAdapter @@@ div { .group-scala } ## Signature -@@signature [MdcLoggingDirectives.scala](/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala) { #withMdcLogging } +@@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 an MDC-compatible @apidoc[MarkerLoggingAdapter]. - -Nested calls will provide the same instance of `MarkerLoggingAdapter`. +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) { #withMdcLogging } +: @@snip [MdcLoggingDirectivesExamplesSpec.scala](/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala) { #withMarkerLoggingAdapter } diff --git a/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala b/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala index 605360d40ba..04d7eb5cb5c 100644 --- a/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala +++ b/docs/src/test/scala/docs/http/scaladsl/server/directives/MdcLoggingDirectivesExamplesSpec.scala @@ -1,31 +1,30 @@ package docs.http.scaladsl.server.directives -import akka.event.{ LogMarker, MarkerLoggingAdapter } +import akka.event._ import akka.http.scaladsl.model.StatusCodes import akka.http.scaladsl.server.RoutingSpec import docs.CompileOnlySpec class MdcLoggingDirectivesExamplesSpec extends RoutingSpec with CompileOnlySpec { - "withMdcLogging" in { - //#withMdcLogging - withMdcLogging { - extractLog { - case m: MarkerLoggingAdapter => - // Logger will be a MarkerLoggingAdapter. - // Log will include entries for "user_id" and "request_id". - m.info(LogMarker("", Map("user_id" -> "1234", "request_id" -> "abcd")), "completing request") - complete(StatusCodes.OK) - } + "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) } - //#withMdcLogging + //#withMarkerLoggingAdapter } "withMdcEntries" in { //#withMdcEntries withMdcEntries(("user_id", "1234"), ("request_id", "abcd")) { extractLog { log => - // Log will include entries for "user_id" and "request_id". + // 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) } @@ -38,7 +37,8 @@ class MdcLoggingDirectivesExamplesSpec extends RoutingSpec with CompileOnlySpec withMdcEntry("user_id", "1234") { withMdcEntry("request_id", "abcd") { extractLog { log => - // Log will include entries for "user_id" and "request_id". + // 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) } @@ -46,14 +46,4 @@ class MdcLoggingDirectivesExamplesSpec extends RoutingSpec with CompileOnlySpec } //#withMdcEntry } - - "extractMarkerLog" in { - //#extractMarkerLog - extractMarkerLog { m: MarkerLoggingAdapter => - // Log will include entires for "user_id" and "request_id". - m.info(LogMarker("", Map("user_id" -> "1234", "request_id" -> "abcd")), "completing request") - complete(StatusCodes.OK) - } - //#extractMarkerLog - } } From d0ac46e9dd03478e75c0c0d30b03100b59ef6e7c Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Mon, 26 Dec 2022 12:03:28 -0600 Subject: [PATCH 6/8] Add a case for converting an instance of BusLogging to DiagnosticMarkerBusLoggingAdapter - Based on suggestion here: https://github.com/akka/akka-http/pull/3974/files/776f4ef37bec392a9afa96ccd10a9b1d64660c9b#r875025973 - This is not yet adequately tested. - Had to slightly tweak a test because behavior of EventFilter seems to have changed. --- .../server/directives/MdcLoggingDirectivesSpec.scala | 2 +- .../server/directives/MdcLoggingDirectives.scala | 12 +++++++++--- 2 files changed, 10 insertions(+), 4 deletions(-) diff --git a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala index 5320c9a0b3c..be1e7c56349 100644 --- a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala +++ b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala @@ -58,7 +58,7 @@ class MdcLoggingDirectivesSpec extends RoutingSpec { val buf = ListBuffer.empty[Logging.Info2] val filter = EventFilter.custom { case e: Logging.Info2 => buf.append(e).nonEmpty - + case _ => false } filter.intercept { Get() ~> withMdcEntries("user_id" -> "1234", "request_id" -> "abcd") { diff --git a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala index de7c59b4b04..46af16f9f91 100644 --- a/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala +++ b/akka-http/src/main/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectives.scala @@ -42,15 +42,21 @@ object MdcLoggingDirectives extends MdcLoggingDirectives { 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 { - // In order to avoid race conditions from using a shared LoggingAdapter, even if the existing adapter - // is a DiagnosticMarkerBusLoggingAdapter, we still create a new one and merge the two entries. case existingAdapter: DiagnosticMarkerBusLoggingAdapter => import existingAdapter._ val newAdapter = new DiagnosticMarkerBusLoggingAdapter(bus, logSource, logClass, loggingFilterWithMarker) newAdapter.mdc(existingAdapter.mdc ++ entries) newAdapter - // If the logger is not already a DiagnosticLoggingAdapter, we create a new one with the given entries. + 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) From e2f0da6fe9954140ced3e75f8a318561d151ae99 Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Tue, 30 May 2023 11:36:18 -0700 Subject: [PATCH 7/8] Get tests to compile on 2.12 --- .../server/directives/MdcLoggingDirectivesSpec.scala | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala index be1e7c56349..bde9166e74c 100644 --- a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala +++ b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala @@ -57,8 +57,10 @@ class MdcLoggingDirectivesSpec extends RoutingSpec { "include the entries in the LoggingEvents" in { val buf = ListBuffer.empty[Logging.Info2] val filter = EventFilter.custom { - case e: Logging.Info2 => buf.append(e).nonEmpty - case _ => false + case e: Logging.Info2 => + buf.append(e) + true + case _ => false } filter.intercept { Get() ~> withMdcEntries("user_id" -> "1234", "request_id" -> "abcd") { From 17c654019ce0bff974e724b78b820435314dc4d2 Mon Sep 17 00:00:00 2001 From: Alex Klibisz Date: Tue, 30 May 2023 12:30:29 -0700 Subject: [PATCH 8/8] Use custom EventFilter class with @volatile buffer to fix test race condition --- .../directives/MdcLoggingDirectivesSpec.scala | 26 ++++++++++--------- 1 file changed, 14 insertions(+), 12 deletions(-) diff --git a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala index bde9166e74c..4d27f91c50e 100644 --- a/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala +++ b/akka-http-tests/src/test/scala/akka/http/scaladsl/server/directives/MdcLoggingDirectivesSpec.scala @@ -4,8 +4,6 @@ import akka.event._ import akka.http.scaladsl.server.RoutingSpec import akka.testkit.EventFilter -import scala.collection.mutable.ListBuffer - class MdcLoggingDirectivesSpec extends RoutingSpec { "The `withMarkerLoggingAdapter` directive" should { @@ -55,13 +53,17 @@ class MdcLoggingDirectivesSpec extends RoutingSpec { } } "include the entries in the LoggingEvents" in { - val buf = ListBuffer.empty[Logging.Info2] - val filter = EventFilter.custom { - case e: Logging.Info2 => - buf.append(e) - true - case _ => false + 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) filter.intercept { Get() ~> withMdcEntries("user_id" -> "1234", "request_id" -> "abcd") { extractLog { log1 => @@ -76,10 +78,10 @@ class MdcLoggingDirectivesSpec extends RoutingSpec { } } ~> check { response shouldEqual Ok - buf.size shouldBe 3 - val l1 = buf(0) - val l2 = buf(1) - val l3 = buf(2) + 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"