From f5a873945ccb28d4807fdbb4204bfe3c57255749 Mon Sep 17 00:00:00 2001 From: Lauri Tulmin Date: Mon, 25 Sep 2023 13:29:55 +0300 Subject: [PATCH] Capture logback logger context properties --- .../logback-appender-1.0/javaagent/README.md | 1 + .../appender/v1_0/LogbackSingletons.java | 6 ++- .../logback-appender-1.0/library/README.md | 3 +- .../appender/v1_0/OpenTelemetryAppender.java | 17 +++++-- .../v1_0/internal/LoggingEventMapper.java | 24 +++++++-- .../v1_0/OpenTelemetryAppenderTest.java | 50 +++++++++++++++++++ .../v1_0/internal/LoggingEventMapperTest.java | 7 +-- .../src/test/resources/logback-test.xml | 1 + 8 files changed, 98 insertions(+), 11 deletions(-) diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/README.md b/instrumentation/logback/logback-appender-1.0/javaagent/README.md index df4012adde22..d29091469455 100644 --- a/instrumentation/logback/logback-appender-1.0/javaagent/README.md +++ b/instrumentation/logback/logback-appender-1.0/javaagent/README.md @@ -6,6 +6,7 @@ | `otel.instrumentation.logback-appender.experimental.capture-code-attributes` | Boolean | `false` | Enable the capture of [source code attributes]. Note that capturing source code attributes at logging sites might add a performance overhead. | | `otel.instrumentation.logback-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. | | `otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | +| `otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes` | Boolean | `false` | Enable the capture of Logback logger context properties as attributes. | | `otel.instrumentation.logback-appender.experimental.capture-mdc-attributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | [source code attributes]: https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/span-general.md#source-code-attributes diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackSingletons.java b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackSingletons.java index 509498142d50..8932f93d4b3b 100644 --- a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackSingletons.java +++ b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackSingletons.java @@ -31,6 +31,9 @@ public final class LogbackSingletons { config.getBoolean( "otel.instrumentation.logback-appender.experimental.capture-key-value-pair-attributes", false); + boolean captureLoggerContext = config.getBoolean( + "otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes", + false); List captureMdcAttributes = config.getList( "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes", @@ -42,7 +45,8 @@ public final class LogbackSingletons { captureMdcAttributes, captureCodeAttributes, captureMarkerAttribute, - captureKeyValuePairAttributes); + captureKeyValuePairAttributes, + captureLoggerContext); } public static LoggingEventMapper mapper() { diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index 3ada2205138f..82b756886db0 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -95,11 +95,12 @@ Settings can be configured in `logback.xml`, for example: The available settings are: | XML Element | Type | Default | Description | -| ------------------------------- | ------- | ------- | --------------------------------------------------------------------------------------------------------------------------------------------- | +|---------------------------------| ------- | ------- |-----------------------------------------------------------------------------------------------------------------------------------------------| | `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. | | `captureCodeAttributes` | Boolean | `false` | Enable the capture of [source code attributes]. Note that capturing source code attributes at logging sites might add a performance overhead. | | `captureMarkerAttribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. | | `captureKeyValuePairAttributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | +| `captureLoggerContext` | Boolean | `false` | Enable the capture of Logback logger context properties as attributes. | | `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | [source code attributes]: https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/span-general.md#source-code-attributes diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java index b39e5b6d7201..211f27d84c99 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java @@ -25,6 +25,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase captureMdcAttributes = emptyList(); private OpenTelemetry openTelemetry; @@ -62,7 +63,8 @@ public void start() { captureMdcAttributes, captureCodeAttributes, captureMarkerAttribute, - captureKeyValuePairAttributes); + captureKeyValuePairAttributes, + captureLoggerContext); if (openTelemetry == null) { openTelemetry = OpenTelemetry.noop(); } @@ -98,7 +100,7 @@ public void setCaptureCodeAttributes(boolean captureCodeAttributes) { /** * Sets whether the marker attribute should be set to logs. * - * @param captureMarkerAttribute To enable or disable the marker attribute + * @param captureMarkerAttribute To enable or disable capturing the marker attribute */ public void setCaptureMarkerAttribute(boolean captureMarkerAttribute) { this.captureMarkerAttribute = captureMarkerAttribute; @@ -107,12 +109,21 @@ public void setCaptureMarkerAttribute(boolean captureMarkerAttribute) { /** * Sets whether the key value pair attributes should be set to logs. * - * @param captureKeyValuePairAttributes To enable or disable the marker attribute + * @param captureKeyValuePairAttributes To enable or disable capturing key value pairs */ public void setCaptureKeyValuePairAttributes(boolean captureKeyValuePairAttributes) { this.captureKeyValuePairAttributes = captureKeyValuePairAttributes; } + /** + * Sets whether the logger context properties should be set to logs. + * + * @param captureLoggerContext To enable or disable capturing logger context properties + */ + public void setCaptureLoggerContext(boolean captureLoggerContext) { + this.captureLoggerContext = captureLoggerContext; + } + /** Configures the {@link MDC} attributes that will be copied to logs. */ public void setCaptureMdcAttributes(String attributes) { if (attributes != null) { diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java index d49ac069b1a6..0dfceae4f6b9 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java @@ -36,6 +36,7 @@ public final class LoggingEventMapper { private static final boolean supportsKeyValuePairs = supportsKeyValuePairs(); private static final boolean supportsMultipleMarkers = supportsMultipleMarkers(); private static final Cache> mdcAttributeKeys = Cache.bounded(100); + private static final Cache> attributeKeys = Cache.bounded(100); private static final AttributeKey> LOG_MARKER = AttributeKey.stringArrayKey("logback.marker"); @@ -46,18 +47,21 @@ public final class LoggingEventMapper { private final boolean captureCodeAttributes; private final boolean captureMarkerAttribute; private final boolean captureKeyValuePairAttributes; + private final boolean captureLoggerContext; public LoggingEventMapper( boolean captureExperimentalAttributes, List captureMdcAttributes, boolean captureCodeAttributes, boolean captureMarkerAttribute, - boolean captureKeyValuePairAttributes) { + boolean captureKeyValuePairAttributes, + boolean captureLoggerContext) { this.captureExperimentalAttributes = captureExperimentalAttributes; this.captureCodeAttributes = captureCodeAttributes; this.captureMdcAttributes = captureMdcAttributes; this.captureMarkerAttribute = captureMarkerAttribute; this.captureKeyValuePairAttributes = captureKeyValuePairAttributes; + this.captureLoggerContext = captureLoggerContext; this.captureAllMdcAttributes = captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); } @@ -148,6 +152,10 @@ private void mapLoggingEvent(LogRecordBuilder builder, ILoggingEvent loggingEven captureKeyValuePairAttributes(attributes, loggingEvent); } + if (captureLoggerContext) { + captureLoggerContext(attributes, loggingEvent.getLoggerContextVO().getPropertyMap()); + } + builder.setAllAttributes(attributes.build()); // span context @@ -156,7 +164,6 @@ private void mapLoggingEvent(LogRecordBuilder builder, ILoggingEvent loggingEven // visible for testing void captureMdcAttributes(AttributesBuilder attributes, Map mdcProperties) { - if (captureAllMdcAttributes) { for (Map.Entry entry : mdcProperties.entrySet()) { attributes.put(getMdcAttributeKey(entry.getKey()), entry.getValue()); @@ -212,12 +219,23 @@ private static void captureKeyValuePairAttributes( if (keyValuePairs != null) { for (KeyValuePair keyValuePair : keyValuePairs) { if (keyValuePair.value != null) { - attributes.put(keyValuePair.key, keyValuePair.value.toString()); + attributes.put(getAttributeKey(keyValuePair.key), keyValuePair.value.toString()); } } } } + private static void captureLoggerContext( + AttributesBuilder attributes, Map loggerContextProperties) { + for (Map.Entry entry : loggerContextProperties.entrySet()) { + attributes.put(getAttributeKey(entry.getKey()), entry.getValue()); + } + } + + public static AttributeKey getAttributeKey(String key) { + return attributeKeys.computeIfAbsent(key, k -> AttributeKey.stringKey(k)); + } + private static boolean supportsKeyValuePairs() { try { Class.forName("org.slf4j.event.KeyValuePair"); diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderTest.java index 08a481d1a6cb..1f78bda0f254 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderTest.java @@ -7,6 +7,8 @@ import static org.assertj.core.api.Assertions.assertThat; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.core.ContextBase; import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.logs.Severity; import io.opentelemetry.api.trace.Span; @@ -21,9 +23,12 @@ import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.semconv.SemanticAttributes; +import java.lang.reflect.Field; +import java.lang.reflect.Method; import java.time.Instant; import java.util.Arrays; import java.util.List; +import java.util.Map; import java.util.concurrent.TimeUnit; import org.junit.jupiter.api.BeforeAll; import org.junit.jupiter.api.BeforeEach; @@ -57,6 +62,30 @@ static void setupAll() { OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); OpenTelemetryAppender.install(openTelemetrySdk); + + // by default LoggerContext contains HOSTNAME property we clear it to start with empty context + resetLoggerContext(); + } + + private static void resetLoggerContext() { + try { + LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); + Field field = ContextBase.class.getDeclaredField("propertyMap"); + field.setAccessible(true); + Map map = (Map) field.get(loggerContext); + map.clear(); + + Method method; + try { + method = LoggerContext.class.getDeclaredMethod("syncRemoteView"); + } catch (NoSuchMethodException noSuchMethodException) { + method = LoggerContext.class.getDeclaredMethod("updateLoggerContextVO"); + } + method.setAccessible(true); + method.invoke(loggerContext); + } catch (Exception exception) { + throw new IllegalStateException("Failed to reset logger context", exception); + } } @BeforeEach @@ -170,4 +199,25 @@ void logContextData() { assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) .isEqualTo("val2"); } + + @Test + void logLoggerContext() { + LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); + loggerContext.putProperty("test-property", "test-value"); + try { + logger.info("log message 1"); + } finally { + resetLoggerContext(); + } + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + LogRecordData logData = logDataList.get(0); + assertThat(logData.getResource()).isEqualTo(resource); + assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo); + assertThat(logData.getBody().asString()).isEqualTo("log message 1"); + assertThat(logData.getAttributes().size()).isEqualTo(1 + 4); // 4 code attributes + assertThat(logData.getAttributes().get(AttributeKey.stringKey("test-property"))) + .isEqualTo("test-value"); + } } diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java index 84b53284b512..6df19d9ce2ac 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapperTest.java @@ -22,7 +22,8 @@ class LoggingEventMapperTest { @Test void testDefault() { // given - LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList(), false, false, false); + LoggingEventMapper mapper = + new LoggingEventMapper(false, emptyList(), false, false, false, false); Map contextData = new HashMap<>(); contextData.put("key1", "value1"); contextData.put("key2", "value2"); @@ -39,7 +40,7 @@ void testDefault() { void testSome() { // given LoggingEventMapper mapper = - new LoggingEventMapper(false, singletonList("key2"), false, false, false); + new LoggingEventMapper(false, singletonList("key2"), false, false, false, false); Map contextData = new HashMap<>(); contextData.put("key1", "value1"); contextData.put("key2", "value2"); @@ -57,7 +58,7 @@ void testSome() { void testAll() { // given LoggingEventMapper mapper = - new LoggingEventMapper(false, singletonList("*"), false, false, false); + new LoggingEventMapper(false, singletonList("*"), false, false, false, false); Map contextData = new HashMap<>(); contextData.put("key1", "value1"); contextData.put("key2", "value2"); diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/resources/logback-test.xml b/instrumentation/logback/logback-appender-1.0/library/src/test/resources/logback-test.xml index a3a4273a1222..75f950d46d0f 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/resources/logback-test.xml +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/resources/logback-test.xml @@ -13,6 +13,7 @@ false true true + true *