From 979883d48d8f269f1c6769ae28f33f69c521ee45 Mon Sep 17 00:00:00 2001 From: "Heiko W. Rupp" Date: Thu, 28 Jul 2022 17:53:57 +0200 Subject: [PATCH] Provide the ability to log MDC data in access_log. --- docs/src/main/asciidoc/http-reference.adoc | 1 + docs/src/main/asciidoc/opentelemetry.adoc | 5 ++ .../attribute/VertxMDCDataAttribute.java | 52 +++++++++++++++++++ .../filters/accesslog/AccessLogHandler.java | 1 + ...runtime.attribute.ExchangeAttributeBuilder | 2 + .../attribute/VertxMDCDataAttributeTest.java | 29 +++++++++++ 6 files changed, 90 insertions(+) create mode 100644 extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttribute.java create mode 100644 extensions/vertx-http/runtime/src/test/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttributeTest.java diff --git a/docs/src/main/asciidoc/http-reference.adoc b/docs/src/main/asciidoc/http-reference.adoc index a0fe0187ed2df..f0eb801219008 100644 --- a/docs/src/main/asciidoc/http-reference.adoc +++ b/docs/src/main/asciidoc/http-reference.adoc @@ -359,6 +359,7 @@ include::{generated-dir}/config/quarkus-vertx-http-config-group-access-log-confi |Request header | | `%{i,request_header_name}` |Response header | | `%{o,response_header_name}` |Vert.x Routing Context Internal Data | | `%{d,map_key}` +|Vert.x MDC data (e.g. 'traceId' for OpenTelemetry) | | `%{X,mdc-key}` |=== diff --git a/docs/src/main/asciidoc/opentelemetry.adoc b/docs/src/main/asciidoc/opentelemetry.adoc index e915f52c1e524..44d780b56d5f3 100644 --- a/docs/src/main/asciidoc/opentelemetry.adoc +++ b/docs/src/main/asciidoc/opentelemetry.adoc @@ -109,6 +109,9 @@ quarkus.opentelemetry.tracer.exporter.otlp.endpoint=http://localhost:4317 // <3> quarkus.opentelemetry.tracer.exporter.otlp.headers=Authorization=Bearer my_secret // <4> quarkus.log.console.format=%d{HH:mm:ss} %-5p traceId=%X{traceId}, parentId=%X{parentId}, spanId=%X{spanId}, sampled=%X{sampled} [%c{2.}] (%t) %s%e%n // <5> + +# Alternative to the console log +quarkus.http.access-log.pattern="...traceId=%{X,traceId} spanId=%{X,spanId}" // <6> ---- <1> All spans created from the application will include an OpenTelemetry `Resource` indicating the span was created by the `myservice` application. If not set, it will default to the artifact id. @@ -116,6 +119,8 @@ quarkus.log.console.format=%d{HH:mm:ss} %-5p traceId=%X{traceId}, parentId=%X{pa <3> gRPC endpoint for sending spans <4> Optional gRPC headers commonly used for authentication <5> Add tracing information into log message. +<6> You can also only put the trace info into the access log. In this case you must omit the info in the console log format. + == Run the application The first step is to configure and start the https://opentelemetry.io/docs/collector/[OpenTelemetry Collector] to receive, process and export telemetry data to https://www.jaegertracing.io/[Jaeger] that will display the captured traces. diff --git a/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttribute.java b/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttribute.java new file mode 100644 index 0000000000000..550c7ff9747f0 --- /dev/null +++ b/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttribute.java @@ -0,0 +1,52 @@ +package io.quarkus.vertx.http.runtime.attribute; + +import io.quarkus.vertx.core.runtime.VertxMDC; +import io.vertx.ext.web.RoutingContext; + +/** + * Provide entries from the MDC section of the RoutingContext. + * This is especially helpful to put OTel data 'traceId' and 'spanId' + * into the access log. + */ +public class VertxMDCDataAttribute implements ExchangeAttribute { + + private final String dataKey; + + public VertxMDCDataAttribute(String dataKey) { + this.dataKey = dataKey; + } + + @Override + public String readAttribute(RoutingContext exchange) { + VertxMDC mdc = VertxMDC.INSTANCE; + return mdc.get(dataKey); + } + + @Override + public void writeAttribute(RoutingContext exchange, String newValue) throws ReadOnlyAttributeException { + throw new ReadOnlyAttributeException(); + } + + public static final class Builder implements ExchangeAttributeBuilder { + + @Override + public String name() { + return "OTel data"; + } + + @Override + public ExchangeAttribute build(final String token) { + if (token.startsWith("%{X,") && token.endsWith("}")) { + final String dataItemName = token.substring(4, token.length() - 1); + return new VertxMDCDataAttribute(dataItemName); + } + return null; + } + + @Override + public int priority() { + return 0; + } + } + +} diff --git a/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/filters/accesslog/AccessLogHandler.java b/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/filters/accesslog/AccessLogHandler.java index d6f145478a380..41c2f87ec1c62 100644 --- a/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/filters/accesslog/AccessLogHandler.java +++ b/extensions/vertx-http/runtime/src/main/java/io/quarkus/vertx/http/runtime/filters/accesslog/AccessLogHandler.java @@ -85,6 +85,7 @@ *
  • %{r,xxx} xxx is an attribute in the ServletRequest *
  • %{s,xxx} xxx is an attribute in the HttpSession *
  • %{d,xxx} xxx is a data item in the exchange
    • + *
  • %{X,xxx} xxx is a key in the Vert.X MDC
    • * * * @author Stuart Douglas diff --git a/extensions/vertx-http/runtime/src/main/resources/META-INF/services/io.quarkus.vertx.http.runtime.attribute.ExchangeAttributeBuilder b/extensions/vertx-http/runtime/src/main/resources/META-INF/services/io.quarkus.vertx.http.runtime.attribute.ExchangeAttributeBuilder index 1d6374ab9879e..7a6254ca2208a 100644 --- a/extensions/vertx-http/runtime/src/main/resources/META-INF/services/io.quarkus.vertx.http.runtime.attribute.ExchangeAttributeBuilder +++ b/extensions/vertx-http/runtime/src/main/resources/META-INF/services/io.quarkus.vertx.http.runtime.attribute.ExchangeAttributeBuilder @@ -29,3 +29,5 @@ io.quarkus.vertx.http.runtime.attribute.RequestPathAttribute$Builder io.quarkus.vertx.http.runtime.attribute.NullAttribute$Builder io.quarkus.vertx.http.runtime.attribute.AllRequestHeadersAttribute$Builder io.quarkus.vertx.http.runtime.attribute.ExchangeDataAttribute$Builder +io.quarkus.vertx.http.runtime.attribute.VertxMDCDataAttribute$Builder + diff --git a/extensions/vertx-http/runtime/src/test/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttributeTest.java b/extensions/vertx-http/runtime/src/test/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttributeTest.java new file mode 100644 index 0000000000000..08cb7b56fe465 --- /dev/null +++ b/extensions/vertx-http/runtime/src/test/java/io/quarkus/vertx/http/runtime/attribute/VertxMDCDataAttributeTest.java @@ -0,0 +1,29 @@ +package io.quarkus.vertx.http.runtime.attribute; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.junit.jupiter.api.Assertions.assertNull; + +import org.junit.jupiter.api.Test; + +import io.quarkus.vertx.core.runtime.VertxMDC; + +class VertxMDCDataAttributeTest { + + @Test + void returnsCorrectValue() { + VertxMDC mdc = VertxMDC.INSTANCE; + mdc.put("traceId", "123"); + + VertxMDCDataAttribute mdcDataAttribute = new VertxMDCDataAttribute("traceId"); + assertThat(mdcDataAttribute.readAttribute(null)).isEqualTo("123"); + } + + @Test + void returnsNullOnKeyNotInMDC() { + VertxMDC mdc = VertxMDC.INSTANCE; + mdc.put("traceId", "123"); + + VertxMDCDataAttribute mdcDataAttribute = new VertxMDCDataAttribute("spanId"); + assertNull(mdcDataAttribute.readAttribute(null)); + } +}