open-telemetry
/
opentelemetry-java-instrumentation
mirror of https://github.com/open-telemetry/opentelemetry-java-instrumentation.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Add support for capturing logback mdc attributes (#4968) 

* Add support for capturing logback mdc attributes

* Spotless
This commit is contained in:
Trask Stalnaker 2022-01-03 10:32:49 -08:00 committed by GitHub
parent 4d7a5d5062
commit 1a9b37525c
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 295 additions and 107 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
instrumentation/logback/logback-appender-1.0/javaagent/build.gradle.kts
View File

@ -19,7 +19,14 @@ dependencies {
compileOnly(project(":instrumentation-api-appender"))
implementation(project(":instrumentation:logback:logback-appender-1.0:library"))
latestDepTestLibrary("ch.qos.logback:logback-classic:1.2.+")
testImplementation("org.awaitility:awaitility")
}
tasks.withType<Test>().configureEach {
// TODO run tests both with and without experimental log attributes
jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*")
}

106
instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackHelper.java
View File

@ -1,106 +0,0 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/
package io.opentelemetry.javaagent.instrumentation.logback.appender.v1_0;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.ThrowableProxy;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.common.AttributesBuilder;
import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
import io.opentelemetry.instrumentation.api.appender.LogBuilder;
import io.opentelemetry.instrumentation.api.appender.Severity;
import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.concurrent.TimeUnit;
public final class LogbackHelper {
public static void capture(final ILoggingEvent event) {
LogBuilder builder =
GlobalLogEmitterProvider.get()
.logEmitterBuilder(event.getLoggerName())
.build()
.logBuilder();
mapLoggingEvent(builder, event);
builder.emit();
}
/**
* Map the {@link ILoggingEvent} data model onto the {@link LogBuilder}. Unmapped fields include:
*
* <ul>
* <li>Thread name - {@link ILoggingEvent#getThreadName()}
* <li>Marker - {@link ILoggingEvent#getMarker()}
* <li>Mapped diagnostic context - {@link ILoggingEvent#getMDCPropertyMap()}
* </ul>
*/
private static void mapLoggingEvent(LogBuilder builder, ILoggingEvent loggingEvent) {
// message
String message = loggingEvent.getMessage();
if (message != null) {
builder.setBody(message);
}
// time
long timestamp = loggingEvent.getTimeStamp();
builder.setEpoch(timestamp, TimeUnit.MILLISECONDS);
// level
Level level = loggingEvent.getLevel();
if (level != null) {
builder.setSeverity(levelToSeverity(level));
builder.setSeverityText(level.levelStr);
}
// throwable
Object throwableProxy = loggingEvent.getThrowableProxy();
Throwable throwable = null;
if (throwableProxy instanceof ThrowableProxy) {
// there is only one other subclass of ch.qos.logback.classic.spi.IThrowableProxy
// and it is only used for logging exceptions over the wire
throwable = ((ThrowableProxy) throwableProxy).getThrowable();
}
if (throwable != null) {
AttributesBuilder attributes = Attributes.builder();
// TODO (trask) extract method for recording exception into instrumentation-api-appender
attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName());
attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage());
StringWriter writer = new StringWriter();
throwable.printStackTrace(new PrintWriter(writer));
attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString());
builder.setAttributes(attributes.build());
}
// span context
builder.setContext(Context.current());
}
private static Severity levelToSeverity(Level level) {
switch (level.levelInt) {
case Level.ALL_INT:
case Level.TRACE_INT:
return Severity.TRACE;
case Level.DEBUG_INT:
return Severity.DEBUG;
case Level.INFO_INT:
return Severity.INFO;
case Level.WARN_INT:
return Severity.WARN;
case Level.ERROR_INT:
return Severity.ERROR;
case Level.OFF_INT:
default:
return Severity.UNDEFINED_SEVERITY_NUMBER;
}
}
private LogbackHelper() {}
}

3
instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java
View File

@ -13,6 +13,7 @@ import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
import ch.qos.logback.classic.spi.ILoggingEvent;
import io.opentelemetry.instrumentation.api.appender.LogEmitterProvider;
import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper;
import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer;
import io.opentelemetry.javaagent.instrumentation.api.CallDepth;
@ -49,7 +50,7 @@ class LogbackInstrumentation implements TypeInstrumentation {
// logging framework delegates to another
callDepth = CallDepth.forClass(LogEmitterProvider.class);
if (callDepth.getAndIncrement() == 0) {
LogbackHelper.capture(event);
LoggingEventMapper.INSTANCE.capture(event);
}
}

29
instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy
View File

@ -3,11 +3,13 @@
* SPDX-License-Identifier: Apache-2.0
*/
import io.opentelemetry.api.common.AttributeKey
import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification
import io.opentelemetry.sdk.logs.data.Severity
import io.opentelemetry.semconv.trace.attributes.SemanticAttributes
import org.slf4j.Logger
import org.slf4j.LoggerFactory
import org.slf4j.MDC
import spock.lang.Unroll
import static io.opentelemetry.instrumentation.test.utils.TraceUtils.runUnderTrace
@ -95,4 +97,31 @@ class LogbackTest extends AgentInstrumentationSpecification {
severity = args[3]
severityText = args[4]
}
def "test mdc"() {
when:
MDC.put("key1", "val1")
MDC.put("key2", "val2")
try {
abcLogger.info("xyz")
} finally {
MDC.clear()
}
then:
await()
.untilAsserted(
() -> {
assertThat(logs).hasSize(1)
})
def log = logs.get(0)
assertThat(log.getBody().asString()).isEqualTo("xyz")
assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(2)
assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))).isEqualTo("val2")
}
}

20
instrumentation/logback/logback-appender-1.0/library/build.gradle.kts Normal file
View File

@ -0,0 +1,20 @@
plugins {
id("otel.library-instrumentation")
}
dependencies {
api(project(":instrumentation-api-appender"))
library("ch.qos.logback:logback-classic:0.9.16")
testImplementation(project(":instrumentation-sdk-appender"))
testImplementation("io.opentelemetry:opentelemetry-sdk-logs")
testImplementation("io.opentelemetry:opentelemetry-sdk-testing")
testImplementation("org.mockito:mockito-core")
}
tasks.withType<Test>().configureEach {
// TODO run tests both with and without experimental log attributes
jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*")
}

163
instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java Normal file
View File

@ -0,0 +1,163 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/
package io.opentelemetry.instrumentation.logback.appender.v1_0.internal;
import static java.util.Collections.emptyList;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.ThrowableProxy;
import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.common.AttributesBuilder;
import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
import io.opentelemetry.instrumentation.api.appender.LogBuilder;
import io.opentelemetry.instrumentation.api.appender.Severity;
import io.opentelemetry.instrumentation.api.cache.Cache;
import io.opentelemetry.instrumentation.api.config.Config;
import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.List;
import java.util.Map;
import java.util.concurrent.TimeUnit;
public final class LoggingEventMapper {
public static final LoggingEventMapper INSTANCE = new LoggingEventMapper();
private static final Cache<String, AttributeKey<String>> mdcAttributeKeys = Cache.bounded(100);
private final List<String> captureMdcAttributes;
// cached as an optimization
private final boolean captureAllMdcAttributes;
private LoggingEventMapper() {
this(
Config.get()
.getList(
"otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
emptyList()));
}
// visible for testing
LoggingEventMapper(List<String> captureMdcAttributes) {
this.captureMdcAttributes = captureMdcAttributes;
this.captureAllMdcAttributes =
captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
}
public void capture(final ILoggingEvent event) {
LogBuilder builder =
GlobalLogEmitterProvider.get()
.logEmitterBuilder(event.getLoggerName())
.build()
.logBuilder();
mapLoggingEvent(builder, event);
builder.emit();
}
/**
* Map the {@link ILoggingEvent} data model onto the {@link LogBuilder}. Unmapped fields include:
*
* <ul>
* <li>Thread name - {@link ILoggingEvent#getThreadName()}
* <li>Marker - {@link ILoggingEvent#getMarker()}
* <li>Mapped diagnostic context - {@link ILoggingEvent#getMDCPropertyMap()}
* </ul>
*/
private void mapLoggingEvent(LogBuilder builder, ILoggingEvent loggingEvent) {
// message
String message = loggingEvent.getMessage();
if (message != null) {
builder.setBody(message);
}
// time
long timestamp = loggingEvent.getTimeStamp();
builder.setEpoch(timestamp, TimeUnit.MILLISECONDS);
// level
Level level = loggingEvent.getLevel();
if (level != null) {
builder.setSeverity(levelToSeverity(level));
builder.setSeverityText(level.levelStr);
}
AttributesBuilder attributes = Attributes.builder();
// throwable
Object throwableProxy = loggingEvent.getThrowableProxy();
Throwable throwable = null;
if (throwableProxy instanceof ThrowableProxy) {
// there is only one other subclass of ch.qos.logback.classic.spi.IThrowableProxy
// and it is only used for logging exceptions over the wire
throwable = ((ThrowableProxy) throwableProxy).getThrowable();
}
if (throwable != null) {
setThrowable(attributes, throwable);
}
captureMdcAttributes(attributes, loggingEvent.getMDCPropertyMap());
builder.setAttributes(attributes.build());
// span context
builder.setContext(Context.current());
}
// visible for testing
void captureMdcAttributes(AttributesBuilder attributes, Map<String, String> mdcProperties) {
if (captureAllMdcAttributes) {
for (Map.Entry<String, String> entry : mdcProperties.entrySet()) {
attributes.put(getMdcAttributeKey(entry.getKey()), entry.getValue());
}
return;
}
for (String key : captureMdcAttributes) {
String value = mdcProperties.get(key);
if (value != null) {
attributes.put(getMdcAttributeKey(key), value);
}
}
}
public static AttributeKey<String> getMdcAttributeKey(String key) {
return mdcAttributeKeys.computeIfAbsent(key, k -> AttributeKey.stringKey("logback.mdc." + k));
}
private static void setThrowable(AttributesBuilder attributes, Throwable throwable) {
// TODO (trask) extract method for recording exception into instrumentation-api-appender
attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName());
attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage());
StringWriter writer = new StringWriter();
throwable.printStackTrace(new PrintWriter(writer));
attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString());
}
private static Severity levelToSeverity(Level level) {
switch (level.levelInt) {
case Level.ALL_INT:
case Level.TRACE_INT:
return Severity.TRACE;
case Level.DEBUG_INT:
return Severity.DEBUG;
case Level.INFO_INT:
return Severity.INFO;
case Level.WARN_INT:
return Severity.WARN;
case Level.ERROR_INT:
return Severity.ERROR;
case Level.OFF_INT:
default:
return Severity.UNDEFINED_SEVERITY_NUMBER;
}
}
}

73
instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java Normal file
View File

@ -0,0 +1,73 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/
package io.opentelemetry.instrumentation.logback.appender.v1_0.internal;
import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat;
import static java.util.Collections.emptyList;
import static java.util.Collections.singletonList;
import static org.assertj.core.api.Assertions.entry;
import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.common.AttributesBuilder;
import java.util.HashMap;
import java.util.Map;
import org.junit.Test;
public class LoggingEventMapperTest {
@Test
public void testDefault() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(emptyList());
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
AttributesBuilder attributes = Attributes.builder();
// when
mapper.captureMdcAttributes(attributes, contextData);
// then
assertThat(attributes.build()).isEmpty();
}
@Test
public void testSome() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(singletonList("key2"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
AttributesBuilder attributes = Attributes.builder();
// when
mapper.captureMdcAttributes(attributes, contextData);
// then
assertThat(attributes.build())
.containsOnly(entry(AttributeKey.stringKey("logback.mdc.key2"), "value2"));
}
@Test
public void testAll() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(singletonList("*"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
AttributesBuilder attributes = Attributes.builder();
// when
mapper.captureMdcAttributes(attributes, contextData);
// then
assertThat(attributes.build())
.containsOnly(
entry(AttributeKey.stringKey("logback.mdc.key1"), "value1"),
entry(AttributeKey.stringKey("logback.mdc.key2"), "value2"));
}
}

1
settings.gradle.kts
View File

@ -276,6 +276,7 @@ include(":instrumentation:log4j:log4j-context-data:log4j-context-data-2-common:t
include(":instrumentation:log4j:log4j-appender-2.16:javaagent")
include(":instrumentation:log4j:log4j-appender-2.16:library")
include(":instrumentation:logback:logback-appender-1.0:javaagent")
include(":instrumentation:logback:logback-appender-1.0:library")
include(":instrumentation:logback:logback-mdc-1.0:javaagent")
include(":instrumentation:logback:logback-mdc-1.0:library")
include(":instrumentation:logback:logback-mdc-1.0:testing")