spring-bootlogbackopen-telemetrymdc

Open Telemetry Logger MDC auto-instrumentation


The following Open Telemetry starters have been added to the Spring Boot project (v2.7.2) to instrument the application:

<dependency>
    <groupId>io.opentelemetry.instrumentation</groupId>
    <artifactId>opentelemetry-spring-boot-starter</artifactId>
    <version>1.22.1-alpha</version>
</dependency>
<dependency>
    <groupId>io.opentelemetry.instrumentation</groupId>
    <artifactId>opentelemetry-jaeger-spring-boot-starter</artifactId>
    <version>1.22.1-alpha</version>
</dependency>

Traces and spans are successfully exported to a Jaeger collector. The problem is those traces and spans cannot be correlated with log statements because logs don't contain the current trace_id and span_id.

By following the documentation I added the logging.pattern.level property to application.properties but it seems like information about the current span is not injected into the logging event's MDC copy.

logging.pattern.level = trace_id=%mdc{trace_id} span_id=%mdc{span_id} trace_flags=%mdc{trace_flags} %5p

For example:

log.info(
    "traceId: {}, spanId: {}",
    Span.current().getSpanContext().getTraceId(),
    Span.current().getSpanContext().getSpanId());

2023-01-25 12:21:36.774 trace_id= span_id= trace_flags= INFO 34272 --- [nio-8080-exec-2] h.c.DemoController : traceId: 1bccb6a4fea8345026ca87a202f0091f, spanId: c59a5d44ee40cd2c

Have I missed anything?


Solution

  • opentelemetry-spring-boot-starter is missing this feature right now (version 1.22.1-alpha), but it can be added very easily.

    Firstly, MDC Instrumentation for Logback dependency should be added to the project.

      <dependency>
        <groupId>io.opentelemetry.instrumentation</groupId>
        <artifactId>opentelemetry-logback-mdc-1.0</artifactId>
        <version>OPENTELEMETRY_VERSION</version>
      </dependency>
    

    Then add a custom logback.xml configuration to the classpath, which will automatically inject context information from the span context to logging events.

    <?xml version="1.0" encoding="UTF-8"?>
    <configuration>
        <!--    Default logback configuration    -->
        <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
        <property name="LOG_FILE" value="${LOG_FILE:-${LOG_PATH:-${LOG_TEMP:-${java.io.tmpdir:-/tmp}}}/spring.log}"/>
        <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
        <include resource="org/springframework/boot/logging/logback/file-appender.xml"/>
        <!--   -->
        <appender name="OTEL" class="io.opentelemetry.instrumentation.logback.v1_0.OpenTelemetryAppender">
            <appender-ref ref="CONSOLE"/>
            <appender-ref ref="FILE"/>
        </appender>
        <root level="INFO">
            <appender-ref ref="OTEL"/>
        </root>
    </configuration>
    

    Finally, add the property to application.properties (as mentioned in the question):

    logging.pattern.level = trace_id=%mdc{trace_id} span_id=%mdc{span_id} trace_flags=%mdc{trace_flags} %5p