Skip to content

Add logback mdc instrumentation to spring boot starter #12515

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

Merged
merged 4 commits into from
Oct 29, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -204,7 +204,10 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) {
try {
// minimize scope of write lock
this.openTelemetry = openTelemetry;
this.eventsToReplay.drainTo(eventsToReplay);
// tests set openTelemetry to null, ignore it
if (openTelemetry != null) {
this.eventsToReplay.drainTo(eventsToReplay);
}
} finally {
writeLock.unlock();
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,7 @@ dependencies {
implementation(project(":instrumentation:log4j:log4j-appender-2.17:library"))
compileOnly("org.apache.logging.log4j:log4j-core:2.17.0")
implementation(project(":instrumentation:logback:logback-appender-1.0:library"))
implementation(project(":instrumentation:logback:logback-mdc-1.0:library"))
compileOnly("ch.qos.logback:logback-classic:1.0.0")
implementation(project(":instrumentation:jdbc:library"))

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,19 @@
class LogbackAppenderInstaller {

static void install(ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
Optional<OpenTelemetryAppender> existingOpenTelemetryAppender = findOpenTelemetryAppender();
Optional<io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender>
existingMdcAppender =
findAppender(
io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender.class);
if (existingMdcAppender.isPresent()) {
initializeMdcAppenderFromProperties(
applicationEnvironmentPreparedEvent, existingMdcAppender.get());
} else if (isLogbackMdcAppenderAddable(applicationEnvironmentPreparedEvent)) {
addMdcAppender(applicationEnvironmentPreparedEvent);
}

Optional<OpenTelemetryAppender> existingOpenTelemetryAppender =
findAppender(OpenTelemetryAppender.class);
if (existingOpenTelemetryAppender.isPresent()) {
reInitializeOpenTelemetryAppender(
existingOpenTelemetryAppender, applicationEnvironmentPreparedEvent);
Expand All @@ -30,13 +42,22 @@ static void install(ApplicationEnvironmentPreparedEvent applicationEnvironmentPr

private static boolean isLogbackAppenderAddable(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
return isAppenderAddable(
applicationEnvironmentPreparedEvent, "otel.instrumentation.logback-appender.enabled");
}

private static boolean isLogbackMdcAppenderAddable(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
return isAppenderAddable(
applicationEnvironmentPreparedEvent, "otel.instrumentation.logback-mdc.enabled");
}

private static boolean isAppenderAddable(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent, String property) {
boolean otelSdkDisabled =
evaluateBooleanProperty(applicationEnvironmentPreparedEvent, "otel.sdk.disabled", false);
boolean logbackInstrumentationEnabled =
evaluateBooleanProperty(
applicationEnvironmentPreparedEvent,
"otel.instrumentation.logback-appender.enabled",
true);
evaluateBooleanProperty(applicationEnvironmentPreparedEvent, property, true);
return !otelSdkDisabled && logbackInstrumentationEnabled;
}

Expand Down Expand Up @@ -133,6 +154,58 @@ private static void initializeOpenTelemetryAppenderFromProperties(
}
}

private static void addMdcAppender(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent) {
ch.qos.logback.classic.Logger logger =
(ch.qos.logback.classic.Logger)
LoggerFactory.getILoggerFactory().getLogger(Logger.ROOT_LOGGER_NAME);
io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender openTelemetryAppender =
new io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender();
initializeMdcAppenderFromProperties(applicationEnvironmentPreparedEvent, openTelemetryAppender);
openTelemetryAppender.start();
logger.addAppender(openTelemetryAppender);
}

private static void initializeMdcAppenderFromProperties(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent,
io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender
openTelemetryAppender) {

// Implemented in the same way as the
// org.springframework.boot.context.logging.LoggingApplicationListener, config properties not
// available
Boolean addBaggage =
evaluateBooleanProperty(
applicationEnvironmentPreparedEvent, "otel.instrumentation.logback-mdc.add-baggage");
if (addBaggage != null) {
openTelemetryAppender.setAddBaggage(addBaggage);
}

String traceIdKey =
applicationEnvironmentPreparedEvent
.getEnvironment()
.getProperty("otel.instrumentation.common.logging.trace-id", String.class);
if (traceIdKey != null) {
openTelemetryAppender.setTraceIdKey(traceIdKey);
}

String spanIdKey =
applicationEnvironmentPreparedEvent
.getEnvironment()
.getProperty("otel.instrumentation.common.logging.span-id", String.class);
if (spanIdKey != null) {
openTelemetryAppender.setSpanIdKey(spanIdKey);
}

String traceFlagsKey =
applicationEnvironmentPreparedEvent
.getEnvironment()
.getProperty("otel.instrumentation.common.logging.trace-flags", String.class);
if (traceFlagsKey != null) {
openTelemetryAppender.setTraceFlagsKey(traceFlagsKey);
}
}

private static Boolean evaluateBooleanProperty(
ApplicationEnvironmentPreparedEvent applicationEnvironmentPreparedEvent, String property) {
return applicationEnvironmentPreparedEvent
Expand All @@ -149,7 +222,7 @@ private static boolean evaluateBooleanProperty(
.getProperty(property, Boolean.class, defaultValue);
}

private static Optional<OpenTelemetryAppender> findOpenTelemetryAppender() {
private static <T> Optional<T> findAppender(Class<T> appenderClass) {
ILoggerFactory loggerFactorySpi = LoggerFactory.getILoggerFactory();
if (!(loggerFactorySpi instanceof LoggerContext)) {
return Optional.empty();
Expand All @@ -159,8 +232,8 @@ private static Optional<OpenTelemetryAppender> findOpenTelemetryAppender() {
Iterator<Appender<ILoggingEvent>> appenderIterator = logger.iteratorForAppenders();
while (appenderIterator.hasNext()) {
Appender<ILoggingEvent> appender = appenderIterator.next();
if (appender instanceof OpenTelemetryAppender) {
OpenTelemetryAppender openTelemetryAppender = (OpenTelemetryAppender) appender;
if (appenderClass.isInstance(appender)) {
T openTelemetryAppender = appenderClass.cast(appender);
return Optional.of(openTelemetryAppender);
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -416,6 +416,36 @@
"type": "java.util.List<java.lang.String>",
"description": "MDC attributes to capture. Use the wildcard character <code>*</code> to capture all attributes."
},
{
"name": "otel.instrumentation.logback-mdc.enabled",
"type": "java.lang.Boolean",
"description": "Enable the Logback MDC instrumentation.",
"defaultValue": true
},
{
"name": "otel.instrumentation.logback-mdc.add-baggage",
"type": "java.lang.Boolean",
"description": "Enable exposing baggage attributes through MDC.",
"defaultValue": false
},
{
"name": "otel.instrumentation.common.logging.trace-id",
"type": "java.lang.String",
"description": "Customize MDC key name for the trace id.",
"defaultValue": "trace_id"
},
{
"name": "otel.instrumentation.common.logging.span-id",
"type": "java.lang.String",
"description": "Customize MDC key name for the span id.",
"defaultValue": "span_id"
},
{
"name": "otel.instrumentation.common.logging.trace-flags",
"type": "java.lang.String",
"description": "Customize MDC key name for the trace flags.",
"defaultValue": "trace_flags"
},
{
"name": "otel.instrumentation.micrometer.enabled",
"type": "java.lang.Boolean",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,15 @@

import static org.assertj.core.api.Assertions.assertThat;

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import ch.qos.logback.core.spi.AppenderAttachable;
import io.opentelemetry.api.OpenTelemetry;
import io.opentelemetry.api.baggage.Baggage;
import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.context.Scope;
import io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender;
import io.opentelemetry.instrumentation.testing.internal.AutoCleanupExtension;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
Expand All @@ -21,6 +27,7 @@
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.boot.SpringApplication;
Expand Down Expand Up @@ -66,6 +73,9 @@ void shouldInitializeAppender() {
ConfigurableApplicationContext context = app.run();
cleanup.deferCleanup(context);

ListAppender<ILoggingEvent> listAppender = getListAppender();
listAppender.list.clear();

MDC.put("key1", "val1");
MDC.put("key2", "val2");
try {
Expand All @@ -91,6 +101,14 @@ void shouldInitializeAppender() {
.containsEntry(AttributeKey.stringKey("key1"), "val1")
.containsEntry(AttributeKey.stringKey("key2"), "val2");
});

assertThat(listAppender.list)
.satisfiesExactly(
event ->
assertThat(event)
.satisfies(
e -> assertThat(e.getMessage()).isEqualTo("test log message"),
e -> assertThat(e.getMDCPropertyMap()).containsOnlyKeys("key1", "key2")));
}

@Test
Expand All @@ -110,4 +128,123 @@ void shouldNotInitializeAppenderWhenDisabled() {

assertThat(testing.logRecords()).isEmpty();
}

@Test
void mdcAppender() {
Map<String, Object> properties = new HashMap<>();
properties.put("logging.config", "classpath:logback-test.xml");
properties.put("otel.instrumentation.logback-appender.enabled", "false");
properties.put("otel.instrumentation.logback-mdc.add-baggage", "true");
properties.put("otel.instrumentation.common.logging.trace-id", "traceid");
properties.put("otel.instrumentation.common.logging.span-id", "spanid");
properties.put("otel.instrumentation.common.logging.trace-flags", "traceflags");

SpringApplication app =
new SpringApplication(
TestingOpenTelemetryConfiguration.class, OpenTelemetryAppenderAutoConfiguration.class);
app.setDefaultProperties(properties);
ConfigurableApplicationContext context = app.run();
cleanup.deferCleanup(context);

ListAppender<ILoggingEvent> listAppender = getListAppender();
listAppender.list.clear();

try (Scope ignore = Baggage.current().toBuilder().put("key", "value").build().makeCurrent()) {
Span span = testing.getOpenTelemetry().getTracer("test").spanBuilder("test").startSpan();
try (Scope ignore2 = span.makeCurrent()) {
LoggerFactory.getLogger("test").info("test log message");
}
}

assertThat(testing.logRecords()).isEmpty();
assertThat(listAppender.list)
.satisfiesExactly(
event ->
assertThat(event)
.satisfies(
e -> assertThat(e.getMessage()).isEqualTo("test log message"),
e ->
assertThat(e.getMDCPropertyMap())
.containsOnlyKeys(
"traceid", "spanid", "traceflags", "baggage.key")));
}

@Test
void shouldInitializeMdcAppender() {
Map<String, Object> properties = new HashMap<>();
properties.put("logging.config", "classpath:logback-no-otel-appenders.xml");
properties.put("otel.instrumentation.logback-appender.enabled", "false");

SpringApplication app =
new SpringApplication(
TestingOpenTelemetryConfiguration.class, OpenTelemetryAppenderAutoConfiguration.class);
app.setDefaultProperties(properties);
ConfigurableApplicationContext context = app.run();
cleanup.deferCleanup(context);

ListAppender<ILoggingEvent> listAppender = getListAppender();
listAppender.list.clear();

Span span = testing.getOpenTelemetry().getTracer("test").spanBuilder("test").startSpan();
try (Scope ignore = span.makeCurrent()) {
LoggerFactory.getLogger("test").info("test log message");
}

assertThat(testing.logRecords()).isEmpty();
assertThat(listAppender.list)
.satisfiesExactly(
event ->
assertThat(event)
.satisfies(
e -> assertThat(e.getMessage()).isEqualTo("test log message"),
e ->
assertThat(e.getMDCPropertyMap())
.containsOnlyKeys("trace_id", "span_id", "trace_flags")));
}

@Test
void shouldNotInitializeMdcAppenderWhenDisabled() {
Map<String, Object> properties = new HashMap<>();
properties.put("logging.config", "classpath:logback-no-otel-appenders.xml");
properties.put("otel.instrumentation.logback-appender.enabled", "false");
properties.put("otel.instrumentation.logback-mdc.enabled", "false");

SpringApplication app =
new SpringApplication(
TestingOpenTelemetryConfiguration.class, OpenTelemetryAppenderAutoConfiguration.class);
app.setDefaultProperties(properties);
ConfigurableApplicationContext context = app.run();
cleanup.deferCleanup(context);

ListAppender<ILoggingEvent> listAppender = getListAppender();
listAppender.list.clear();

Span span = testing.getOpenTelemetry().getTracer("test").spanBuilder("test").startSpan();
try (Scope ignore = span.makeCurrent()) {
LoggerFactory.getLogger("test").info("test log message");
}

assertThat(testing.logRecords()).isEmpty();
assertThat(listAppender.list)
.satisfiesExactly(
event ->
assertThat(event)
.satisfies(
e -> assertThat(e.getMessage()).isEqualTo("test log message"),
e -> assertThat(e.getMDCPropertyMap()).isEmpty()));
}

@SuppressWarnings("unchecked")
private static ListAppender<ILoggingEvent> getListAppender() {
Logger logger = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
ch.qos.logback.classic.Logger logbackLogger = (ch.qos.logback.classic.Logger) logger;
ListAppender<ILoggingEvent> listAppender =
(ListAppender<ILoggingEvent>) logbackLogger.getAppender("List");
if (listAppender != null) {
return listAppender;
}
AppenderAttachable<?> mdcAppender =
(AppenderAttachable<?>) logbackLogger.getAppender("OpenTelemetryMdc");
return (ListAppender<ILoggingEvent>) mdcAppender.getAppender("List");
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>
%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
</pattern>
</encoder>
</appender>
<appender name="List" class="ch.qos.logback.core.read.ListAppender" />

<root level="INFO">
<appender-ref ref="console"/>
<appender-ref ref="List"/>
</root>

</configuration>
Original file line number Diff line number Diff line change
Expand Up @@ -12,10 +12,16 @@
class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
<captureCodeAttributes>true</captureCodeAttributes>
</appender>
<appender name="List" class="ch.qos.logback.core.read.ListAppender" />
<appender name="OpenTelemetryMdc"
class="io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender">
<appender-ref ref="List"/>
</appender>

<root level="INFO">
<appender-ref ref="console"/>
<appender-ref ref="OpenTelemetry"/>
<appender-ref ref="OpenTelemetryMdc"/>
</root>

</configuration>
Loading