From 5956df90214179db2e61ddda1e4ff4c6fc2c581a Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 15:31:27 +0100 Subject: [PATCH 01/53] Ability to instrument logs before OTel injection into OTel appenders --- .../log4j-appender-2.17/library/README.md | 3 +- .../appender/v2_17/LogEventToReplay.java | 158 ++++++++++++++++++ .../appender/v2_17/OpenTelemetryAppender.java | 54 +++++- .../ContextDataAttributesResolver.java | 23 +++ .../v2_17/internal/LogEventMapper.java | 3 +- .../v2_17/OpenTelemetryAppenderTest.java | 140 +++++++++++++++- .../library/src/test/resources/log4j2.xml | 2 +- .../logback-appender-1.0/library/README.md | 15 +- .../appender/v1_0/LoggingEventToReplay.java | 130 ++++++++++++++ .../appender/v1_0/OpenTelemetryAppender.java | 36 ++++ .../v1_0/OpenTelemetryAppenderTest.java | 130 ++++++++++++-- .../src/test/resources/logback-test.xml | 1 + .../smoketest/OtelSpringStarterSmokeTest.java | 11 +- 13 files changed, 681 insertions(+), 25 deletions(-) create mode 100644 instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java create mode 100644 instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java create mode 100644 instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java diff --git a/instrumentation/log4j/log4j-appender-2.17/library/README.md b/instrumentation/log4j/log4j-appender-2.17/library/README.md index f7d6377f3e1f..93e309c9a456 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/README.md +++ b/instrumentation/log4j/log4j-appender-2.17/library/README.md @@ -94,10 +94,11 @@ Setting can be configured as XML attributes, for example: The available settings are: | XML Attribute | Type | Default | Description | -| ------------------------------- | ------- | ------- | --------------------------------------------------------------------------------------------------------------------- | +|---------------------------------|---------|---------| --------------------------------------------------------------------------------------------------------------------- | | `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. | | `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | | `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | | `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | +| `firstLogsCacheSize ` | Integer | 50 | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java new file mode 100644 index 000000000000..9a2d8482a5c8 --- /dev/null +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -0,0 +1,158 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.log4j.appender.v2_17; + +import java.util.Map; +import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.impl.ThrowableProxy; +import org.apache.logging.log4j.core.time.Instant; +import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.ReadOnlyStringMap; + +class LogEventToReplay implements LogEvent { + + private static final long serialVersionUID = -3639807661256104630L; + private final LogEvent logEvent; + + private final String loggerName; + + private final Message message; + private final Level level; + private final Instant instant; + private final Throwable thrown; + private final Marker marker; + private ReadOnlyStringMap contextData; + + LogEventToReplay(LogEvent logEvent, boolean captureAllContextDataAttributes) { + this.logEvent = logEvent; + this.loggerName = logEvent.getLoggerName(); + this.message = logEvent.getMessage(); + this.level = logEvent.getLevel(); + this.instant = logEvent.getInstant(); + this.thrown = logEvent.getThrown(); + this.marker = logEvent.getMarker(); + if (captureAllContextDataAttributes) { + this.contextData = logEvent.getContextData(); + } + } + + @Override + public LogEvent toImmutable() { + return logEvent.toImmutable(); + } + + @SuppressWarnings("deprecation") // Delegate + @Override + public Map getContextMap() { + return logEvent.getContextMap(); + } + + @Override + public ReadOnlyStringMap getContextData() { + if (contextData != null) { + return contextData; + } + return logEvent.getContextData(); + } + + @Override + public ThreadContext.ContextStack getContextStack() { + return logEvent.getContextStack(); + } + + @Override + public String getLoggerFqcn() { + return logEvent.getLoggerFqcn(); + } + + @Override + public Level getLevel() { + return level; + } + + @Override + public String getLoggerName() { + return loggerName; + } + + @Override + public Marker getMarker() { + return marker; + } + + @Override + public Message getMessage() { + return message; + } + + @Override + public long getTimeMillis() { + return logEvent.getTimeMillis(); + } + + @Override + public Instant getInstant() { + return instant; + } + + @Override + public StackTraceElement getSource() { + return logEvent.getSource(); + } + + @Override + public String getThreadName() { + return logEvent.getThreadName(); + } + + @Override + public long getThreadId() { + return logEvent.getThreadId(); + } + + @Override + public int getThreadPriority() { + return logEvent.getThreadPriority(); + } + + @Override + public Throwable getThrown() { + return thrown; + } + + @Override + public ThrowableProxy getThrownProxy() { + return logEvent.getThrownProxy(); + } + + @Override + public boolean isEndOfBatch() { + return logEvent.isEndOfBatch(); + } + + @Override + public boolean isIncludeLocation() { + return logEvent.isIncludeLocation(); + } + + @Override + public void setEndOfBatch(boolean endOfBatch) { + logEvent.setEndOfBatch(endOfBatch); + } + + @Override + public void setIncludeLocation(boolean locationRequired) { + logEvent.setIncludeLocation(locationRequired); + } + + @Override + public long getNanoTime() { + return logEvent.getNanoTime(); + } +} diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index d8b1c7cbe311..4a47fbfb80d6 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -11,10 +11,13 @@ import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.logs.LogRecordBuilder; import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAccessor; +import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAttributesResolver; import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper; import java.io.Serializable; import java.util.Arrays; import java.util.List; +import java.util.concurrent.ArrayBlockingQueue; +import java.util.concurrent.BlockingQueue; import java.util.concurrent.TimeUnit; import java.util.function.BiConsumer; import java.util.stream.Collectors; @@ -48,6 +51,12 @@ public class OpenTelemetryAppender extends AbstractAppender { private final LogEventMapper mapper; private volatile OpenTelemetry openTelemetry; + private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(50); + + private boolean logCacheWarningDisplayed; + + private final boolean captureAllContextDataAttributes; + /** * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in * the {@link LoggerContext}. @@ -82,6 +91,7 @@ public static class Builder> extends AbstractAppender.Build @PluginBuilderAttribute private boolean captureMapMessageAttributes; @PluginBuilderAttribute private boolean captureMarkerAttribute; @PluginBuilderAttribute private String captureContextDataAttributes; + @PluginBuilderAttribute private int firstLogsCacheSize; @Nullable private OpenTelemetry openTelemetry; @@ -121,6 +131,17 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) { return asBuilder(); } + /** + * Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with + * an {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used + * to replay the first logs. + */ + @CanIgnoreReturnValue + public B setFirstLogsCacheSize(int firstLogsCacheSize) { + this.firstLogsCacheSize = firstLogsCacheSize; + return asBuilder(); + } + /** Configures the {@link OpenTelemetry} used to append logs. */ @CanIgnoreReturnValue public B setOpenTelemetry(OpenTelemetry openTelemetry) { @@ -144,6 +165,7 @@ public OpenTelemetryAppender build() { captureMapMessageAttributes, captureMarkerAttribute, captureContextDataAttributes, + firstLogsCacheSize, openTelemetry); } } @@ -158,17 +180,26 @@ private OpenTelemetryAppender( boolean captureMapMessageAttributes, boolean captureMarkerAttribute, String captureContextDataAttributes, + int firstLogsCacheSize, OpenTelemetry openTelemetry) { super(name, filter, layout, ignoreExceptions, properties); + List captureContextDataAttributesAsList = + splitAndFilterBlanksAndNulls(captureContextDataAttributes); this.mapper = new LogEventMapper<>( ContextDataAccessorImpl.INSTANCE, captureExperimentalAttributes, captureMapMessageAttributes, captureMarkerAttribute, - splitAndFilterBlanksAndNulls(captureContextDataAttributes)); + captureContextDataAttributesAsList); this.openTelemetry = openTelemetry; + this.captureAllContextDataAttributes = + ContextDataAttributesResolver.resolveCaptureAllContextDataAttributes( + captureContextDataAttributesAsList); + if (firstLogsCacheSize != 0) { + this.eventsToReplay = new ArrayBlockingQueue<>(firstLogsCacheSize); + } } private static List splitAndFilterBlanksAndNulls(String value) { @@ -187,10 +218,31 @@ private static List splitAndFilterBlanksAndNulls(String value) { */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { this.openTelemetry = openTelemetry; + while (!eventsToReplay.isEmpty()) { + try { + LogEvent eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); + append(eventToReplay); + } catch (InterruptedException e) { + // Ignore + } + } } @Override public void append(LogEvent event) { + if (openTelemetry == OpenTelemetry.noop()) { + if (eventsToReplay.remainingCapacity() > 0) { + LogEventToReplay logEventToReplay = + new LogEventToReplay(event, captureAllContextDataAttributes); + eventsToReplay.offer(logEventToReplay); + } else if (!logCacheWarningDisplayed) { + logCacheWarningDisplayed = true; + System.err.println( + "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased"); + } + return; + } + String instrumentationName = event.getLoggerName(); if (instrumentationName == null || instrumentationName.isEmpty()) { instrumentationName = "ROOT"; diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java new file mode 100644 index 000000000000..bef3511fd3de --- /dev/null +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java @@ -0,0 +1,23 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.log4j.appender.v2_17.internal; + +import java.util.List; + +/** + * This class is internal and is hence not for public use. Its APIs are unstable and can change at + * any time. + */ +public class ContextDataAttributesResolver { + + private ContextDataAttributesResolver() {} + + public static boolean resolveCaptureAllContextDataAttributes( + List captureContextDataAttributes) { + return captureContextDataAttributes.size() == 1 + && captureContextDataAttributes.get(0).equals("*"); + } +} diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java index 2f76fdd11dee..7adba72c26be 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java @@ -59,7 +59,8 @@ public LogEventMapper( this.captureMarkerAttribute = captureMarkerAttribute; this.captureContextDataAttributes = captureContextDataAttributes; this.captureAllContextDataAttributes = - captureContextDataAttributes.size() == 1 && captureContextDataAttributes.get(0).equals("*"); + ContextDataAttributesResolver.resolveCaptureAllContextDataAttributes( + captureContextDataAttributes); } /** diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java index 770f5b7379d4..3881be2db7db 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java @@ -64,13 +64,13 @@ static void setupAll() { .build(); openTelemetry = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); - OpenTelemetryAppender.install(openTelemetry); } @BeforeEach void setup() { logRecordExporter.reset(); ThreadContext.clearAll(); + OpenTelemetryAppender.install(openTelemetry); } @AfterAll @@ -111,6 +111,23 @@ void logNoSpan() { .hasAttributes(Attributes.empty()); } + @Test + void replayLogsDuringOpenTelemetryInstallation() { + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + logger.info("log message 1"); + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1"); + } + @Test void logWithSpan() { Span span1 = runWithSpan("span1", () -> logger.info("log message 1")); @@ -159,6 +176,35 @@ void logWithExtras() { .isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli())); } + @Test + void logWithExtrasAndLogReplay() { + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + Instant start = Instant.now(); + logger.info("log message 1", new IllegalStateException("Error!")); + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasSeverity(Severity.INFO) + .hasSeverityText("INFO") + .hasAttributesSatisfyingExactly( + equalTo(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()), + equalTo(SemanticAttributes.EXCEPTION_MESSAGE, "Error!"), + satisfies(SemanticAttributes.EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras"))); + + assertThat(logDataList.get(0).getTimestampEpochNanos()) + .isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli())) + .isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli())); + } + @Test void logContextData() { ThreadContext.put("key1", "val1"); @@ -180,6 +226,33 @@ void logContextData() { equalTo(stringKey("log4j.context_data.key2"), "val2")); } + @Test + void logContextDataAndLogReplay() { + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + ThreadContext.put("key1", "val1"); + ThreadContext.put("key2", "val2"); + try { + logger.info("log message 1"); + } finally { + ThreadContext.clearMap(); + } + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.context_data.key1"), "val1"), + equalTo(stringKey("log4j.context_data.key2"), "val2")); + } + @Test void logStringMapMessage() { StringMapMessage message = new StringMapMessage(); @@ -197,6 +270,30 @@ void logStringMapMessage() { equalTo(stringKey("log4j.map_message.key2"), "val2")); } + @Test + void logStringMapMessageWithLogReplay() { + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + StringMapMessage message = new StringMapMessage(); + message.put("key1", "val1"); + message.put("key2", "val2"); + + logger.info(message); + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } + @Test void logStringMapMessageWithSpecialAttribute() { StringMapMessage message = new StringMapMessage(); @@ -225,6 +322,23 @@ void testCaptureMarkerAttribute() { assertThat(logData.getAttributes().get(stringKey("log4j.marker"))).isEqualTo(markerName); } + @Test + void testCaptureMarkerAttributeAndLogReplay() { + String markerName = "aMarker"; + Marker marker = MarkerManager.getMarker(markerName); + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + logger.info(marker, "Message"); + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + LogRecordData logData = logDataList.get(0); + assertThat(logData.getAttributes().get(stringKey("log4j.marker"))).isEqualTo(markerName); + } + @Test void logStructuredDataMessage() { StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); @@ -242,4 +356,28 @@ void logStructuredDataMessage() { equalTo(stringKey("log4j.map_message.key1"), "val1"), equalTo(stringKey("log4j.map_message.key2"), "val2")); } + + @Test + void logStructuredDataMessageAndLogReplay() { + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); + message.put("key1", "val1"); + message.put("key2", "val2"); + logger.info(message); + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("a message") + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } } diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml b/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml index 47be48e7ccac..3617ee3cf600 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml @@ -7,7 +7,7 @@ pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} traceId: %X{trace_id} spanId: %X{span_id} flags: %X{trace_flags} - %msg%n"/> - + diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index c3e540995bba..9e9c9cac610a 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -93,12 +93,13 @@ 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. | -| `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | +| 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. | +| `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | +| `firstLogsCacheSize` | Integer | 50 | Log telemetry is displayed after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java new file mode 100644 index 000000000000..355eec6fb207 --- /dev/null +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java @@ -0,0 +1,130 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.logback.appender.v1_0; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.IThrowableProxy; +import ch.qos.logback.classic.spi.LoggerContextVO; +import java.util.List; +import java.util.Map; +import org.slf4j.Marker; +import org.slf4j.event.KeyValuePair; + +class LoggingEventToReplay implements ILoggingEvent { + + private final ILoggingEvent loggingEvent; + private final long timeStamp; + private StackTraceElement[] callerData; + + LoggingEventToReplay(ILoggingEvent loggingEvent, boolean captureCodeAttributes) { + this.loggingEvent = loggingEvent; + this.timeStamp = loggingEvent.getTimeStamp(); + if (captureCodeAttributes) { + callerData = loggingEvent.getCallerData(); + } + } + + @Override + public String getThreadName() { + return loggingEvent.getThreadName(); + } + + @Override + public Level getLevel() { + return loggingEvent.getLevel(); + } + + @Override + public String getMessage() { + return loggingEvent.getMessage(); + } + + @Override + public Object[] getArgumentArray() { + return loggingEvent.getArgumentArray(); + } + + @Override + public String getFormattedMessage() { + return loggingEvent.getFormattedMessage(); + } + + @Override + public String getLoggerName() { + return loggingEvent.getLoggerName(); + } + + @Override + public LoggerContextVO getLoggerContextVO() { + return loggingEvent.getLoggerContextVO(); + } + + @Override + public IThrowableProxy getThrowableProxy() { + return loggingEvent.getThrowableProxy(); + } + + @Override + public StackTraceElement[] getCallerData() { + if (callerData != null) { + return callerData; + } + return loggingEvent.getCallerData(); + } + + @Override + public boolean hasCallerData() { + return loggingEvent.hasCallerData(); + } + + @SuppressWarnings("deprecation") // Delegate + @Override + public Marker getMarker() { + return loggingEvent.getMarker(); + } + + @Override + public List getMarkerList() { + return loggingEvent.getMarkerList(); + } + + @Override + public Map getMDCPropertyMap() { + return loggingEvent.getMDCPropertyMap(); + } + + @SuppressWarnings("deprecation") // Delegate + @Override + public Map getMdc() { + return loggingEvent.getMdc(); + } + + @Override + public long getTimeStamp() { + return timeStamp; + } + + @Override + public int getNanoseconds() { + return loggingEvent.getNanoseconds(); + } + + @Override + public long getSequenceNumber() { + return loggingEvent.getSequenceNumber(); + } + + @Override + public List getKeyValuePairs() { + return loggingEvent.getKeyValuePairs(); + } + + @Override + public void prepareForDeferredProcessing() { + loggingEvent.prepareForDeferredProcessing(); + } +} 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 17ff5d16a4ab..389afe185e7b 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 @@ -14,6 +14,9 @@ import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper; import java.util.Arrays; import java.util.List; +import java.util.concurrent.ArrayBlockingQueue; +import java.util.concurrent.BlockingQueue; +import java.util.concurrent.TimeUnit; import java.util.stream.Collectors; import org.slf4j.ILoggerFactory; import org.slf4j.LoggerFactory; @@ -30,6 +33,9 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(50); + private boolean logCacheWarningDisplayed; + public OpenTelemetryAppender() {} /** @@ -71,6 +77,19 @@ public void start() { @Override protected void append(ILoggingEvent event) { + if (openTelemetry == OpenTelemetry.noop()) { + if (eventsToReplay.remainingCapacity() > 0) { + LoggingEventToReplay logEventToReplay = + new LoggingEventToReplay(event, captureCodeAttributes); + eventsToReplay.offer(logEventToReplay); + } else if (!logCacheWarningDisplayed) { + logCacheWarningDisplayed = true; + String message = + "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; + System.err.println(message); + } + return; + } mapper.emit(openTelemetry.getLogsBridge(), event); } @@ -122,12 +141,29 @@ public void setCaptureMdcAttributes(String attributes) { } } + /** + * Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an + * {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used to + * replay the first logs. + */ + public void setFirstLogsCacheSize(int size) { + eventsToReplay = new ArrayBlockingQueue<>(size); + } + /** * Configures the {@link OpenTelemetry} used to append logs. This MUST be called for the appender * to function. See {@link #install(OpenTelemetry)} for simple installation option. */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { this.openTelemetry = openTelemetry; + while (!eventsToReplay.isEmpty()) { + try { + ILoggingEvent eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); + mapper.emit(openTelemetry.getLogsBridge(), eventToReplay); + } catch (InterruptedException e) { + // Ignore + } + } } // copied from SDK's DefaultConfigProperties 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..64182cc3151a 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,7 @@ import static org.assertj.core.api.Assertions.assertThat; +import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.logs.Severity; import io.opentelemetry.api.trace.Span; @@ -18,6 +19,7 @@ import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; import io.opentelemetry.sdk.resources.Resource; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.semconv.SemanticAttributes; @@ -42,26 +44,25 @@ class OpenTelemetryAppenderTest { private static Resource resource; private static InstrumentationScopeInfo instrumentationScopeInfo; + private static OpenTelemetrySdk openTelemetrySdk; + @BeforeAll static void setupAll() { logRecordExporter = InMemoryLogRecordExporter.create(); resource = Resource.getDefault(); instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger"); - SdkLoggerProvider loggerProvider = SdkLoggerProvider.builder() .setResource(resource) .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) .build(); - OpenTelemetrySdk openTelemetrySdk = - OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); - - OpenTelemetryAppender.install(openTelemetrySdk); + openTelemetrySdk = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); } @BeforeEach void setup() { logRecordExporter.reset(); + OpenTelemetryAppender.install(openTelemetrySdk); } @Test @@ -71,10 +72,34 @@ void logNoSpan() { 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(4); // 4 code attributes + + OpenTelemetryAssertions.assertThat(logData) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasTotalAttributeCount(4); + } + + @Test + void replayLogsDuringOpenTelemetryInstallation() { + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + logger.info("log message 1"); + logger.info( + "log message 2"); // Won't be instrumented because cache size is 1 (see logback-test.xml + // file) + + OpenTelemetryAppender.install(openTelemetrySdk); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + LogRecordData logData = logDataList.get(0); + OpenTelemetryAssertions.assertThat(logData) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasTotalAttributeCount(4); } @Test @@ -87,9 +112,9 @@ void logWithSpan() { List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(3); - assertThat(logDataList.get(0).getSpanContext()).isEqualTo(span1.getSpanContext()); - assertThat(logDataList.get(1).getSpanContext()).isEqualTo(SpanContext.getInvalid()); - assertThat(logDataList.get(2).getSpanContext()).isEqualTo(span2.getSpanContext()); + OpenTelemetryAssertions.assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); + OpenTelemetryAssertions.assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); + OpenTelemetryAssertions.assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); } private static Span runWithSpan(String spanName, Runnable runnable) { @@ -148,6 +173,58 @@ void logWithExtras() { assertThat(logMarker).isEqualTo(Arrays.asList(markerName)); } + @Test + void logWithExtrasAndLogReplay() { + Instant start = Instant.now(); + String markerName = "aMarker"; + Marker marker = MarkerFactory.getMarker(markerName); + + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + logger.info(marker, "log message 1", new IllegalStateException("Error!")); + + OpenTelemetryAppender.install(openTelemetrySdk); + + 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.getTimestampEpochNanos()) + .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(start.toEpochMilli())) + .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli())); + assertThat(logData.getSeverity()).isEqualTo(Severity.INFO); + assertThat(logData.getSeverityText()).isEqualTo("INFO"); + assertThat(logData.getAttributes().size()) + .isEqualTo(3 + 4 + 1); // 3 exception attributes, 4 code attributes, 1 marker attribute + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)) + .isEqualTo(IllegalStateException.class.getName()); + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)) + .isEqualTo("Error!"); + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)) + .contains("logWithExtras"); + + String file = logData.getAttributes().get(SemanticAttributes.CODE_FILEPATH); + assertThat(file).isEqualTo("OpenTelemetryAppenderTest.java"); + + String codeClass = logData.getAttributes().get(SemanticAttributes.CODE_NAMESPACE); + assertThat(codeClass) + .isEqualTo( + "io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppenderTest"); + + String method = logData.getAttributes().get(SemanticAttributes.CODE_FUNCTION); + assertThat(method).isEqualTo("logWithExtrasAndLogReplay"); + + Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO); + assertThat(lineNumber).isGreaterThan(1); + + List logMarker = + logData.getAttributes().get(AttributeKey.stringArrayKey("logback.marker")); + assertThat(logMarker).isEqualTo(Arrays.asList(markerName)); + } + @Test void logContextData() { MDC.put("key1", "val1"); @@ -170,4 +247,33 @@ void logContextData() { assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) .isEqualTo("val2"); } + + @Test + void logContextDataAndLogReplay() { + // Uninstall OpenTelemetry + OpenTelemetryAppender.install(OpenTelemetry.noop()); + + MDC.put("key1", "val1"); + MDC.put("key2", "val2"); + + try { + logger.info("log message 1"); + } finally { + MDC.clear(); + } + + OpenTelemetryAppender.install(openTelemetrySdk); + + 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(2 + 4); // 4 code attributes + assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))) + .isEqualTo("val1"); + assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) + .isEqualTo("val2"); + } } 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..fb0d4e6f348b 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 @@ -14,6 +14,7 @@ true true * + 1 diff --git a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java index 2131991d9f09..73c04456dd0a 100644 --- a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java +++ b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java @@ -8,6 +8,7 @@ import static org.assertj.core.api.Assertions.assertThat; import io.opentelemetry.api.trace.SpanKind; +import io.opentelemetry.sdk.logs.data.Body; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.logs.export.LogRecordExporter; import io.opentelemetry.sdk.metrics.data.AggregationTemporality; @@ -23,6 +24,7 @@ import io.opentelemetry.spring.smoketest.OtelSpringStarterSmokeTestApplication; import io.opentelemetry.spring.smoketest.OtelSpringStarterSmokeTestController; import java.util.List; +import java.util.stream.Collectors; import org.junit.jupiter.api.Test; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.test.context.SpringBootTest; @@ -112,9 +114,16 @@ void shouldSendTelemetry() throws InterruptedException { // Log List logs = LOG_RECORD_EXPORTER.getFinishedLogRecordItems(); + int logSize = logs.size(); + System.out.println("logSize = " + logSize); + + System.out.println("logs = " + logs); + List logsBody = logs.stream().map(log -> log.getBody()).collect(Collectors.toList()); + System.out.println("logsBody = " + logsBody); + LogRecordData firstLog = logs.get(0); assertThat(firstLog.getBody().asString()) .as("Should instrument logs") - .isEqualTo("Initializing Spring DispatcherServlet 'dispatcherServlet'"); + .startsWith("Starting ").contains(this.getClass().getSimpleName()); } } From 6943526fa1650f7bcbaff2fedc67f2131af91c2d Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 15:37:02 +0100 Subject: [PATCH 02/53] Fix Readme --- instrumentation/log4j/log4j-appender-2.17/library/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/README.md b/instrumentation/log4j/log4j-appender-2.17/library/README.md index 93e309c9a456..0a7d81fe4f9a 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/README.md +++ b/instrumentation/log4j/log4j-appender-2.17/library/README.md @@ -99,6 +99,6 @@ The available settings are: | `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | | `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | | `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize ` | Integer | 50 | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | +| `firstLogsCacheSize` | Integer | 50 | Log telemetry is displayed after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes From 1c6776f1983f517a9eccaa358147d6991ca75bb1 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 15:39:13 +0100 Subject: [PATCH 03/53] Readme improvement --- .../log4j/log4j-appender-2.17/library/README.md | 14 +++++++------- .../logback/logback-appender-1.0/library/README.md | 2 +- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/README.md b/instrumentation/log4j/log4j-appender-2.17/library/README.md index 0a7d81fe4f9a..801915c70412 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/README.md +++ b/instrumentation/log4j/log4j-appender-2.17/library/README.md @@ -93,12 +93,12 @@ Setting can be configured as XML attributes, for example: The available settings are: -| XML Attribute | Type | Default | Description | -|---------------------------------|---------|---------| --------------------------------------------------------------------------------------------------------------------- | -| `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. | -| `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | -| `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | -| `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 50 | Log telemetry is displayed after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| XML Attribute | Type | Default | Description | +|---------------------------------|---------|---------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| +| `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. | +| `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | +| `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | +| `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | +| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index 9e9c9cac610a..d7c5a2d35413 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -100,6 +100,6 @@ The available settings are: | `captureMarkerAttribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. | | `captureKeyValuePairAttributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | | `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 50 | Log telemetry is displayed after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes From 8c91e7368ce7fcf3354be93f3c23518d4890ddd9 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 15:49:16 +0100 Subject: [PATCH 04/53] spotless --- .../io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java index 73c04456dd0a..91bcb4d6ec9b 100644 --- a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java +++ b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java @@ -124,6 +124,7 @@ void shouldSendTelemetry() throws InterruptedException { LogRecordData firstLog = logs.get(0); assertThat(firstLog.getBody().asString()) .as("Should instrument logs") - .startsWith("Starting ").contains(this.getClass().getSimpleName()); + .startsWith("Starting ") + .contains(this.getClass().getSimpleName()); } } From 086cddd633d6ee4dcac73123516671595955e768 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 16:01:37 +0100 Subject: [PATCH 05/53] suppress warning --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 1 + .../logback/appender/v1_0/OpenTelemetryAppender.java | 1 + 2 files changed, 2 insertions(+) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 4a47fbfb80d6..6f4e4d9754c7 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -228,6 +228,7 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { } } + @SuppressWarnings("SystemOut") @Override public void append(LogEvent event) { if (openTelemetry == OpenTelemetry.noop()) { 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 389afe185e7b..b3f261afc6fc 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 @@ -75,6 +75,7 @@ public void start() { super.start(); } + @SuppressWarnings("SystemOut") @Override protected void append(ILoggingEvent event) { if (openTelemetry == OpenTelemetry.noop()) { From 65416b9da4b0881b2fe415b5f7747954cafa1c47 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 16:22:27 +0100 Subject: [PATCH 06/53] clean test --- .../smoketest/OtelSpringStarterSmokeTest.java | 7 ------- 1 file changed, 7 deletions(-) diff --git a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java index 91bcb4d6ec9b..2e07036a3e1d 100644 --- a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java +++ b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java @@ -114,13 +114,6 @@ void shouldSendTelemetry() throws InterruptedException { // Log List logs = LOG_RECORD_EXPORTER.getFinishedLogRecordItems(); - int logSize = logs.size(); - System.out.println("logSize = " + logSize); - - System.out.println("logs = " + logs); - List logsBody = logs.stream().map(log -> log.getBody()).collect(Collectors.toList()); - System.out.println("logsBody = " + logsBody); - LogRecordData firstLog = logs.get(0); assertThat(firstLog.getBody().asString()) .as("Should instrument logs") From 65ab541f20809f002ae40eb494746f95034ed21e Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 16:29:53 +0100 Subject: [PATCH 07/53] spotless --- .../io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java | 2 -- 1 file changed, 2 deletions(-) diff --git a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java index 2e07036a3e1d..8e1d74ec8d6d 100644 --- a/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java +++ b/smoke-tests-otel-starter/src/test/java/io/opentelemetry/smoketest/OtelSpringStarterSmokeTest.java @@ -8,7 +8,6 @@ import static org.assertj.core.api.Assertions.assertThat; import io.opentelemetry.api.trace.SpanKind; -import io.opentelemetry.sdk.logs.data.Body; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.logs.export.LogRecordExporter; import io.opentelemetry.sdk.metrics.data.AggregationTemporality; @@ -24,7 +23,6 @@ import io.opentelemetry.spring.smoketest.OtelSpringStarterSmokeTestApplication; import io.opentelemetry.spring.smoketest.OtelSpringStarterSmokeTestController; import java.util.List; -import java.util.stream.Collectors; import org.junit.jupiter.api.Test; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.test.context.SpringBootTest; From 718300c8eaf51690287817ebf7cbb6a52b8e149b Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 2 Nov 2023 16:35:18 +0100 Subject: [PATCH 08/53] Fix typo in Readme --- instrumentation/logback/logback-appender-1.0/library/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index d7c5a2d35413..eac734c4f4fb 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -100,6 +100,6 @@ The available settings are: | `captureMarkerAttribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. | | `captureKeyValuePairAttributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | | `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes From 29e6023587ace94315df33e0aa045b4ce86e52af Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 12:35:10 +0100 Subject: [PATCH 09/53] Change default cache size --- instrumentation/log4j/log4j-appender-2.17/library/README.md | 2 +- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 2 +- instrumentation/logback/logback-appender-1.0/library/README.md | 2 +- .../logback/appender/v1_0/OpenTelemetryAppender.java | 2 +- 4 files changed, 4 insertions(+), 4 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/README.md b/instrumentation/log4j/log4j-appender-2.17/library/README.md index 801915c70412..3b97c8ef0a39 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/README.md +++ b/instrumentation/log4j/log4j-appender-2.17/library/README.md @@ -99,6 +99,6 @@ The available settings are: | `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | | `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | | `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 6f4e4d9754c7..c23f4bf3b16c 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -51,7 +51,7 @@ public class OpenTelemetryAppender extends AbstractAppender { private final LogEventMapper mapper; private volatile OpenTelemetry openTelemetry; - private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(50); + private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); private boolean logCacheWarningDisplayed; diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index eac734c4f4fb..02eea35c3d0c 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -100,6 +100,6 @@ The available settings are: | `captureMarkerAttribute` | Boolean | `false` | Enable the capture of Logback markers as attributes. | | `captureKeyValuePairAttributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | | `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 50 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.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 b3f261afc6fc..a78c6f7f5779 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 @@ -33,7 +33,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(50); + private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); private boolean logCacheWarningDisplayed; public OpenTelemetryAppender() {} From 7f092ba30c1d50664cc82da2f0395c885a79801b Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 12:41:17 +0100 Subject: [PATCH 10/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java Co-authored-by: Trask Stalnaker --- .../log4j/appender/v2_17/LogEventToReplay.java | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 9a2d8482a5c8..b3b73c8cb42f 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -37,9 +37,7 @@ class LogEventToReplay implements LogEvent { this.instant = logEvent.getInstant(); this.thrown = logEvent.getThrown(); this.marker = logEvent.getMarker(); - if (captureAllContextDataAttributes) { - this.contextData = logEvent.getContextData(); - } + this.contextData = logEvent.getContextData(); } @Override From 1253bca1d54def8bbbe156e4e64ab27c8ce1fbcb Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 12:45:03 +0100 Subject: [PATCH 11/53] Code cleaning --- .../log4j/appender/v2_17/LogEventToReplay.java | 7 ++----- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 3 +-- 2 files changed, 3 insertions(+), 7 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index b3b73c8cb42f..974bf83bbd27 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -29,7 +29,7 @@ class LogEventToReplay implements LogEvent { private final Marker marker; private ReadOnlyStringMap contextData; - LogEventToReplay(LogEvent logEvent, boolean captureAllContextDataAttributes) { + LogEventToReplay(LogEvent logEvent) { this.logEvent = logEvent; this.loggerName = logEvent.getLoggerName(); this.message = logEvent.getMessage(); @@ -53,10 +53,7 @@ public Map getContextMap() { @Override public ReadOnlyStringMap getContextData() { - if (contextData != null) { - return contextData; - } - return logEvent.getContextData(); + return contextData; } @Override diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index c23f4bf3b16c..488e9b7f3ff3 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -233,8 +233,7 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { public void append(LogEvent event) { if (openTelemetry == OpenTelemetry.noop()) { if (eventsToReplay.remainingCapacity() > 0) { - LogEventToReplay logEventToReplay = - new LogEventToReplay(event, captureAllContextDataAttributes); + LogEventToReplay logEventToReplay = new LogEventToReplay(event); eventsToReplay.offer(logEventToReplay); } else if (!logCacheWarningDisplayed) { logCacheWarningDisplayed = true; From fedcd9e16285a4a8756c73e6cfaec7504057e387 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 12:51:26 +0100 Subject: [PATCH 12/53] Atomic boolean --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 488e9b7f3ff3..3c027104874c 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -19,6 +19,7 @@ import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.BlockingQueue; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.function.BiConsumer; import java.util.stream.Collectors; import javax.annotation.Nullable; @@ -53,7 +54,7 @@ public class OpenTelemetryAppender extends AbstractAppender { private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); - private boolean logCacheWarningDisplayed; + private AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); private final boolean captureAllContextDataAttributes; @@ -235,8 +236,7 @@ public void append(LogEvent event) { if (eventsToReplay.remainingCapacity() > 0) { LogEventToReplay logEventToReplay = new LogEventToReplay(event); eventsToReplay.offer(logEventToReplay); - } else if (!logCacheWarningDisplayed) { - logCacheWarningDisplayed = true; + } else if (!logCacheWarningDisplayed.getAndSet(true)) { System.err.println( "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased"); } From 6fb666b2da9e447e4959532e9e90a45d604af79d Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 12:58:29 +0100 Subject: [PATCH 13/53] Remove unnecessary code --- .../appender/v2_17/OpenTelemetryAppender.java | 6 ----- .../ContextDataAttributesResolver.java | 23 ------------------- .../v2_17/internal/LogEventMapper.java | 3 +-- 3 files changed, 1 insertion(+), 31 deletions(-) delete mode 100644 instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 3c027104874c..6416a8673421 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -11,7 +11,6 @@ import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.logs.LogRecordBuilder; import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAccessor; -import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAttributesResolver; import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper; import java.io.Serializable; import java.util.Arrays; @@ -56,8 +55,6 @@ public class OpenTelemetryAppender extends AbstractAppender { private AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); - private final boolean captureAllContextDataAttributes; - /** * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in * the {@link LoggerContext}. @@ -195,9 +192,6 @@ private OpenTelemetryAppender( captureMarkerAttribute, captureContextDataAttributesAsList); this.openTelemetry = openTelemetry; - this.captureAllContextDataAttributes = - ContextDataAttributesResolver.resolveCaptureAllContextDataAttributes( - captureContextDataAttributesAsList); if (firstLogsCacheSize != 0) { this.eventsToReplay = new ArrayBlockingQueue<>(firstLogsCacheSize); } diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java deleted file mode 100644 index bef3511fd3de..000000000000 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/ContextDataAttributesResolver.java +++ /dev/null @@ -1,23 +0,0 @@ -/* - * Copyright The OpenTelemetry Authors - * SPDX-License-Identifier: Apache-2.0 - */ - -package io.opentelemetry.instrumentation.log4j.appender.v2_17.internal; - -import java.util.List; - -/** - * This class is internal and is hence not for public use. Its APIs are unstable and can change at - * any time. - */ -public class ContextDataAttributesResolver { - - private ContextDataAttributesResolver() {} - - public static boolean resolveCaptureAllContextDataAttributes( - List captureContextDataAttributes) { - return captureContextDataAttributes.size() == 1 - && captureContextDataAttributes.get(0).equals("*"); - } -} diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java index 7adba72c26be..2f76fdd11dee 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java @@ -59,8 +59,7 @@ public LogEventMapper( this.captureMarkerAttribute = captureMarkerAttribute; this.captureContextDataAttributes = captureContextDataAttributes; this.captureAllContextDataAttributes = - ContextDataAttributesResolver.resolveCaptureAllContextDataAttributes( - captureContextDataAttributes); + captureContextDataAttributes.size() == 1 && captureContextDataAttributes.get(0).equals("*"); } /** From c4662e7266a8683a8c9cef075b3778d6e6ff2c3a Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 15:29:11 +0100 Subject: [PATCH 14/53] FIx thread name and thread id values of replayed logs --- .../log4j/appender/v2_17/Log4jHelper.java | 20 ++- .../appender/v2_17/LogEventToReplay.java | 13 +- .../appender/v2_17/OpenTelemetryAppender.java | 6 +- .../v2_17/internal/LogEventMapper.java | 9 +- .../appender/v1_0/LogbackInstrumentation.java | 3 +- .../appender/v1_0/LoggingEventToReplay.java | 28 ++-- .../appender/v1_0/OpenTelemetryAppender.java | 7 +- .../v1_0/internal/LoggingEventMapper.java | 9 +- .../internal/LoggingEventWithThreadId.java | 17 +++ .../v1_0/internal/LoggingEventWrapper.java | 131 ++++++++++++++++++ 10 files changed, 213 insertions(+), 30 deletions(-) create mode 100644 instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java create mode 100644 instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java diff --git a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java index 6a31624a42bf..d54d386f7efe 100644 --- a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java @@ -27,10 +27,12 @@ public final class Log4jHelper { private static final LogEventMapper> mapper; + private static final boolean captureExperimentalAttributes; + static { InstrumentationConfig config = InstrumentationConfig.get(); - boolean captureExperimentalAttributes = + captureExperimentalAttributes = config.getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false); boolean captureMapMessageAttributes = config.getBoolean( @@ -66,7 +68,21 @@ public static void capture( .build() .logRecordBuilder(); Map contextData = ThreadContext.getImmutableContext(); - mapper.mapLogEvent(builder, message, level, marker, throwable, contextData); + + if (captureExperimentalAttributes) { + Thread currentThread = Thread.currentThread(); + mapper.mapLogEvent( + builder, + message, + level, + marker, + throwable, + contextData, + currentThread.getName(), + currentThread.getId()); + } else { + mapper.mapLogEvent(builder, message, level, marker, throwable, contextData, null, -1); + } builder.setTimestamp(Instant.now()); builder.emit(); } diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 974bf83bbd27..7255eed6e39a 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -18,16 +18,17 @@ class LogEventToReplay implements LogEvent { private static final long serialVersionUID = -3639807661256104630L; - private final LogEvent logEvent; + private final LogEvent logEvent; private final String loggerName; - private final Message message; private final Level level; private final Instant instant; private final Throwable thrown; private final Marker marker; - private ReadOnlyStringMap contextData; + private final ReadOnlyStringMap contextData; + private final String threadName; + private final long threadId; LogEventToReplay(LogEvent logEvent) { this.logEvent = logEvent; @@ -38,6 +39,8 @@ class LogEventToReplay implements LogEvent { this.thrown = logEvent.getThrown(); this.marker = logEvent.getMarker(); this.contextData = logEvent.getContextData(); + this.threadName = logEvent.getThreadName(); + this.threadId = logEvent.getThreadId(); } @Override @@ -103,12 +106,12 @@ public StackTraceElement getSource() { @Override public String getThreadName() { - return logEvent.getThreadName(); + return threadName; } @Override public long getThreadId() { - return logEvent.getThreadId(); + return threadId; } @Override diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 6416a8673421..3c65642f500f 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -53,7 +53,7 @@ public class OpenTelemetryAppender extends AbstractAppender { private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); - private AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); + private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); /** * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in @@ -255,7 +255,9 @@ public void append(LogEvent event) { event.getLevel(), event.getMarker(), event.getThrown(), - contextData); + contextData, + event.getThreadName(), + event.getThreadId()); Instant timestamp = event.getInstant(); if (timestamp != null) { diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java index 2f76fdd11dee..ac0a0b3046e7 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java @@ -80,7 +80,9 @@ public void mapLogEvent( Level level, @Nullable Marker marker, @Nullable Throwable throwable, - T contextData) { + T contextData, + String threadName, + long threadId) { AttributesBuilder attributes = Attributes.builder(); @@ -105,9 +107,8 @@ public void mapLogEvent( captureContextDataAttributes(attributes, contextData); if (captureExperimentalAttributes) { - Thread currentThread = Thread.currentThread(); - attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName()); - attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId()); + attributes.put(SemanticAttributes.THREAD_NAME, threadName); + attributes.put(SemanticAttributes.THREAD_ID, threadId); } builder.setAllAttributes(attributes.build()); diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java index cbd366729750..6ee18b45c1f6 100644 --- a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java +++ b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java @@ -15,6 +15,7 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.logs.LoggerProvider; +import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWrapper; import io.opentelemetry.javaagent.bootstrap.CallDepth; import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation; import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer; @@ -51,7 +52,7 @@ public static void methodEnter( // logging framework delegates to another callDepth = CallDepth.forClass(LoggerProvider.class); if (callDepth.getAndIncrement() == 0) { - mapper().emit(GlobalOpenTelemetry.get().getLogsBridge(), event); + mapper().emit(GlobalOpenTelemetry.get().getLogsBridge(), new LoggingEventWrapper(event)); } } diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java index 355eec6fb207..f70aedad7bbd 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java @@ -9,28 +9,43 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.classic.spi.IThrowableProxy; import ch.qos.logback.classic.spi.LoggerContextVO; +import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWithThreadId; import java.util.List; import java.util.Map; import org.slf4j.Marker; import org.slf4j.event.KeyValuePair; -class LoggingEventToReplay implements ILoggingEvent { +class LoggingEventToReplay implements LoggingEventWithThreadId { private final ILoggingEvent loggingEvent; private final long timeStamp; private StackTraceElement[] callerData; + private String threadName; + private long threadId; - LoggingEventToReplay(ILoggingEvent loggingEvent, boolean captureCodeAttributes) { + LoggingEventToReplay( + ILoggingEvent loggingEvent, + boolean captureExperimentalAttributes, + boolean captureCodeAttributes) { this.loggingEvent = loggingEvent; this.timeStamp = loggingEvent.getTimeStamp(); + if (captureExperimentalAttributes) { + this.threadName = loggingEvent.getThreadName(); + this.threadId = Thread.currentThread().getId(); + } if (captureCodeAttributes) { - callerData = loggingEvent.getCallerData(); + this.callerData = loggingEvent.getCallerData(); } } @Override public String getThreadName() { - return loggingEvent.getThreadName(); + return threadName; + } + + @Override + public long getThreadId() { + return threadId; } @Override @@ -70,10 +85,7 @@ public IThrowableProxy getThrowableProxy() { @Override public StackTraceElement[] getCallerData() { - if (callerData != null) { - return callerData; - } - return loggingEvent.getCallerData(); + return callerData; } @Override 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 a78c6f7f5779..924b7e0c7da8 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 @@ -12,6 +12,7 @@ import ch.qos.logback.core.UnsynchronizedAppenderBase; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper; +import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWrapper; import java.util.Arrays; import java.util.List; import java.util.concurrent.ArrayBlockingQueue; @@ -81,7 +82,7 @@ protected void append(ILoggingEvent event) { if (openTelemetry == OpenTelemetry.noop()) { if (eventsToReplay.remainingCapacity() > 0) { LoggingEventToReplay logEventToReplay = - new LoggingEventToReplay(event, captureCodeAttributes); + new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); eventsToReplay.offer(logEventToReplay); } else if (!logCacheWarningDisplayed) { logCacheWarningDisplayed = true; @@ -91,7 +92,7 @@ protected void append(ILoggingEvent event) { } return; } - mapper.emit(openTelemetry.getLogsBridge(), event); + mapper.emit(openTelemetry.getLogsBridge(), new LoggingEventWrapper(event)); } /** @@ -159,7 +160,7 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { this.openTelemetry = openTelemetry; while (!eventsToReplay.isEmpty()) { try { - ILoggingEvent eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); + LoggingEventToReplay eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); mapper.emit(openTelemetry.getLogsBridge(), eventToReplay); } catch (InterruptedException e) { // Ignore 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..a1d4fe0c3ebc 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 @@ -62,7 +62,7 @@ public LoggingEventMapper( captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); } - public void emit(LoggerProvider loggerProvider, ILoggingEvent event) { + public void emit(LoggerProvider loggerProvider, LoggingEventWithThreadId event) { String instrumentationName = event.getLoggerName(); if (instrumentationName == null || instrumentationName.isEmpty()) { instrumentationName = "ROOT"; @@ -83,7 +83,7 @@ public void emit(LoggerProvider loggerProvider, ILoggingEvent event) { *
  • Mapped diagnostic context - {@link ILoggingEvent#getMDCPropertyMap()} * */ - private void mapLoggingEvent(LogRecordBuilder builder, ILoggingEvent loggingEvent) { + private void mapLoggingEvent(LogRecordBuilder builder, LoggingEventWithThreadId loggingEvent) { // message String message = loggingEvent.getFormattedMessage(); if (message != null) { @@ -118,9 +118,8 @@ private void mapLoggingEvent(LogRecordBuilder builder, ILoggingEvent loggingEven captureMdcAttributes(attributes, loggingEvent.getMDCPropertyMap()); if (captureExperimentalAttributes) { - Thread currentThread = Thread.currentThread(); - attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName()); - attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId()); + attributes.put(SemanticAttributes.THREAD_NAME, loggingEvent.getThreadName()); + attributes.put(SemanticAttributes.THREAD_ID, loggingEvent.getThreadId()); } if (captureCodeAttributes) { diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java new file mode 100644 index 000000000000..df18e722dc79 --- /dev/null +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java @@ -0,0 +1,17 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.logback.appender.v1_0.internal; + +import ch.qos.logback.classic.spi.ILoggingEvent; + +/** + * This class is internal and is hence not for public use. Its APIs are unstable and can change at + * any time. + */ +public interface LoggingEventWithThreadId extends ILoggingEvent { + + long getThreadId(); +} diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java new file mode 100644 index 000000000000..bbf767fa7049 --- /dev/null +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java @@ -0,0 +1,131 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.logback.appender.v1_0.internal; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.IThrowableProxy; +import ch.qos.logback.classic.spi.LoggerContextVO; +import java.util.List; +import java.util.Map; +import org.slf4j.Marker; +import org.slf4j.event.KeyValuePair; + +/** + * This class is internal and is hence not for public use. Its APIs are unstable and can change at + * any time. + */ +public class LoggingEventWrapper implements LoggingEventWithThreadId { + + private final ILoggingEvent loggingEvent; + + public LoggingEventWrapper(ILoggingEvent loggingEvent) { + this.loggingEvent = loggingEvent; + } + + @Override + public String getThreadName() { + return loggingEvent.getThreadName(); + } + + @Override + public long getThreadId() { + Thread currentThread = Thread.currentThread(); + return currentThread.getId(); + } + + @Override + public Level getLevel() { + return loggingEvent.getLevel(); + } + + @Override + public String getMessage() { + return loggingEvent.getMessage(); + } + + @Override + public Object[] getArgumentArray() { + return loggingEvent.getArgumentArray(); + } + + @Override + public String getFormattedMessage() { + return loggingEvent.getFormattedMessage(); + } + + @Override + public String getLoggerName() { + return loggingEvent.getLoggerName(); + } + + @Override + public LoggerContextVO getLoggerContextVO() { + return loggingEvent.getLoggerContextVO(); + } + + @Override + public IThrowableProxy getThrowableProxy() { + return loggingEvent.getThrowableProxy(); + } + + @Override + public StackTraceElement[] getCallerData() { + return loggingEvent.getCallerData(); + } + + @Override + public boolean hasCallerData() { + return loggingEvent.hasCallerData(); + } + + @SuppressWarnings("deprecation") // Delegate + @Override + public Marker getMarker() { + return loggingEvent.getMarker(); + } + + @Override + public List getMarkerList() { + return loggingEvent.getMarkerList(); + } + + @Override + public Map getMDCPropertyMap() { + return loggingEvent.getMDCPropertyMap(); + } + + @SuppressWarnings("deprecation") // Delegate + @Override + public Map getMdc() { + return loggingEvent.getMdc(); + } + + @Override + public long getTimeStamp() { + return loggingEvent.getTimeStamp(); + } + + @Override + public int getNanoseconds() { + return loggingEvent.getNanoseconds(); + } + + @Override + public long getSequenceNumber() { + return loggingEvent.getSequenceNumber(); + } + + @Override + public List getKeyValuePairs() { + return loggingEvent.getKeyValuePairs(); + } + + @Override + public void prepareForDeferredProcessing() { + loggingEvent.prepareForDeferredProcessing(); + } +} From 669d45586820ff0fabee674354ec4f7eb5cbe9d6 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 15:35:40 +0100 Subject: [PATCH 15/53] AtomicBoolean for Logback --- .../logback/appender/v1_0/OpenTelemetryAppender.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) 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 924b7e0c7da8..ef1b5c614488 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 @@ -18,6 +18,7 @@ import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.BlockingQueue; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.stream.Collectors; import org.slf4j.ILoggerFactory; import org.slf4j.LoggerFactory; @@ -35,7 +36,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(1000); - private boolean logCacheWarningDisplayed; + private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); public OpenTelemetryAppender() {} @@ -84,8 +85,7 @@ protected void append(ILoggingEvent event) { LoggingEventToReplay logEventToReplay = new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); eventsToReplay.offer(logEventToReplay); - } else if (!logCacheWarningDisplayed) { - logCacheWarningDisplayed = true; + } else if (!logCacheWarningDisplayed.getAndSet(true)) { String message = "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; System.err.println(message); From 5e259bfd320add99a46a58fa7f335e8631efa6b6 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 15:54:37 +0100 Subject: [PATCH 16/53] One Log4j test was not complete. FIx the test. --- .../appender/v2_17/LogEventToReplay.java | 39 ++++++++++++++++++- .../v2_17/OpenTelemetryAppenderTest.java | 3 ++ 2 files changed, 41 insertions(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 7255eed6e39a..a8b2cb7dde27 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -30,10 +30,47 @@ class LogEventToReplay implements LogEvent { private final String threadName; private final long threadId; + // Log4j 2 seems to reuse Message objects + private static class MessageCopy implements Message { + + private static final long serialVersionUID = 6921483958779195777L; + private final String formattedMessage; + private final String format; + private final Object[] parameters; + private final Throwable throwable; + + public MessageCopy(Message message) { + this.formattedMessage = message.getFormattedMessage(); + this.format = message.getFormat(); + this.parameters = message.getParameters(); + this.throwable = message.getThrowable(); + } + + @Override + public String getFormattedMessage() { + return formattedMessage; + } + + @Override + public String getFormat() { + return format; + } + + @Override + public Object[] getParameters() { + return parameters; + } + + @Override + public Throwable getThrowable() { + return throwable; + } + } + LogEventToReplay(LogEvent logEvent) { this.logEvent = logEvent; this.loggerName = logEvent.getLoggerName(); - this.message = logEvent.getMessage(); + this.message = new MessageCopy(logEvent.getMessage()); this.level = logEvent.getLevel(); this.instant = logEvent.getInstant(); this.thrown = logEvent.getThrown(); diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java index 3881be2db7db..38fdd08898d2 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java @@ -117,6 +117,9 @@ void replayLogsDuringOpenTelemetryInstallation() { OpenTelemetryAppender.install(OpenTelemetry.noop()); logger.info("log message 1"); + logger.info( + "log message 2"); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + // file) OpenTelemetryAppender.install(openTelemetry); From e703d6e8f674b5e41019cbc5a1695c8737582c28 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 15:59:31 +0100 Subject: [PATCH 17/53] Fix typo --- .../log4j/appender/v2_17/OpenTelemetryAppenderTest.java | 1 - 1 file changed, 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java index 38fdd08898d2..4c8065a06a2f 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java @@ -119,7 +119,6 @@ void replayLogsDuringOpenTelemetryInstallation() { logger.info("log message 1"); logger.info( "log message 2"); // Won't be instrumented because cache size is 1 (see log4j2.xml file) - // file) OpenTelemetryAppender.install(openTelemetry); From 77acb855e11beaea08f48a2e6b57a91207451dc2 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 18:41:34 +0100 Subject: [PATCH 18/53] Improve the tests and fix them --- .../log4j/appender/v2_17/LogEventToReplay.java | 18 +++++++++++++++++- .../v2_17/OpenTelemetryAppenderTest.java | 12 ++++++++++++ 2 files changed, 29 insertions(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index a8b2cb7dde27..1314d6e6f546 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -13,6 +13,8 @@ import org.apache.logging.log4j.core.impl.ThrowableProxy; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.message.StringMapMessage; +import org.apache.logging.log4j.message.StructuredDataMessage; import org.apache.logging.log4j.util.ReadOnlyStringMap; class LogEventToReplay implements LogEvent { @@ -70,7 +72,21 @@ public Throwable getThrowable() { LogEventToReplay(LogEvent logEvent) { this.logEvent = logEvent; this.loggerName = logEvent.getLoggerName(); - this.message = new MessageCopy(logEvent.getMessage()); + Message messageOrigin = logEvent.getMessage(); + if (messageOrigin instanceof StructuredDataMessage) { + StructuredDataMessage structuredDataMessage = (StructuredDataMessage) messageOrigin; + this.message = + new StructuredDataMessage( + structuredDataMessage.getId(), + structuredDataMessage.getFormat(), + structuredDataMessage.getType(), + structuredDataMessage.getData()); + } else if (messageOrigin instanceof StringMapMessage) { + this.message = messageOrigin; + } else { + this.message = new MessageCopy(logEvent.getMessage()); + } + this.level = logEvent.getLevel(); this.instant = logEvent.getInstant(); this.thrown = logEvent.getThrown(); diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java index 4c8065a06a2f..e1ade2bfa213 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java @@ -284,6 +284,12 @@ void logStringMapMessageWithLogReplay() { logger.info(message); + StringMapMessage message2 = new StringMapMessage(); + message2.put("key1-2", "val1-2"); + message2.put("key2-2", "val2-2"); + + logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + OpenTelemetryAppender.install(openTelemetry); List logDataList = logRecordExporter.getFinishedLogRecordItems(); @@ -370,6 +376,12 @@ void logStructuredDataMessageAndLogReplay() { message.put("key2", "val2"); logger.info(message); + StructuredDataMessage message2 = + new StructuredDataMessage("an id 2", "a message 2", "a type 2"); + message.put("key1-2", "val1-2"); + message.put("key2-2", "val2-2"); + logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + OpenTelemetryAppender.install(openTelemetry); List logDataList = logRecordExporter.getFinishedLogRecordItems(); From b030088fe800076ec97ddcaabb9cc1df737aad2b Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 3 Nov 2023 22:56:19 +0100 Subject: [PATCH 19/53] Do not capture thread.id attribute with Logback instrumentation library --- .../appender/v1_0/LogbackInstrumentation.java | 4 +- .../logback-appender-1.0/library/README.md | 16 +-- .../appender/v1_0/LoggingEventToReplay.java | 10 +- .../appender/v1_0/OpenTelemetryAppender.java | 8 +- .../v1_0/internal/LoggingEventMapper.java | 11 +- .../internal/LoggingEventWithThreadId.java | 17 --- .../v1_0/internal/LoggingEventWrapper.java | 131 ------------------ 7 files changed, 23 insertions(+), 174 deletions(-) delete mode 100644 instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java delete mode 100644 instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java index 6ee18b45c1f6..1e1052707a31 100644 --- a/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java +++ b/instrumentation/logback/logback-appender-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/appender/v1_0/LogbackInstrumentation.java @@ -15,7 +15,6 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.logs.LoggerProvider; -import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWrapper; import io.opentelemetry.javaagent.bootstrap.CallDepth; import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation; import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer; @@ -52,7 +51,8 @@ public static void methodEnter( // logging framework delegates to another callDepth = CallDepth.forClass(LoggerProvider.class); if (callDepth.getAndIncrement() == 0) { - mapper().emit(GlobalOpenTelemetry.get().getLogsBridge(), new LoggingEventWrapper(event)); + mapper() + .emit(GlobalOpenTelemetry.get().getLogsBridge(), event, Thread.currentThread().getId()); } } diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index 02eea35c3d0c..794744d1c464 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -93,13 +93,13 @@ 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. | -| `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| 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. | +| `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | +| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. thread.id attribute is not captured. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java index f70aedad7bbd..bef7eb6585e2 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java @@ -9,19 +9,17 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import ch.qos.logback.classic.spi.IThrowableProxy; import ch.qos.logback.classic.spi.LoggerContextVO; -import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWithThreadId; import java.util.List; import java.util.Map; import org.slf4j.Marker; import org.slf4j.event.KeyValuePair; -class LoggingEventToReplay implements LoggingEventWithThreadId { +class LoggingEventToReplay implements ILoggingEvent { private final ILoggingEvent loggingEvent; private final long timeStamp; private StackTraceElement[] callerData; private String threadName; - private long threadId; LoggingEventToReplay( ILoggingEvent loggingEvent, @@ -31,7 +29,6 @@ class LoggingEventToReplay implements LoggingEventWithThreadId { this.timeStamp = loggingEvent.getTimeStamp(); if (captureExperimentalAttributes) { this.threadName = loggingEvent.getThreadName(); - this.threadId = Thread.currentThread().getId(); } if (captureCodeAttributes) { this.callerData = loggingEvent.getCallerData(); @@ -43,11 +40,6 @@ public String getThreadName() { return threadName; } - @Override - public long getThreadId() { - return threadId; - } - @Override public Level getLevel() { return loggingEvent.getLevel(); 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 ef1b5c614488..6133acbbcce1 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 @@ -12,7 +12,6 @@ import ch.qos.logback.core.UnsynchronizedAppenderBase; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper; -import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventWrapper; import java.util.Arrays; import java.util.List; import java.util.concurrent.ArrayBlockingQueue; @@ -92,7 +91,10 @@ protected void append(ILoggingEvent event) { } return; } - mapper.emit(openTelemetry.getLogsBridge(), new LoggingEventWrapper(event)); + mapper.emit( + openTelemetry.getLogsBridge(), + new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes), + -1); } /** @@ -161,7 +163,7 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { while (!eventsToReplay.isEmpty()) { try { LoggingEventToReplay eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); - mapper.emit(openTelemetry.getLogsBridge(), eventToReplay); + mapper.emit(openTelemetry.getLogsBridge(), eventToReplay, -1); } catch (InterruptedException e) { // Ignore } 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 a1d4fe0c3ebc..63e01976002f 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 @@ -62,14 +62,14 @@ public LoggingEventMapper( captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); } - public void emit(LoggerProvider loggerProvider, LoggingEventWithThreadId event) { + public void emit(LoggerProvider loggerProvider, ILoggingEvent event, long threadId) { String instrumentationName = event.getLoggerName(); if (instrumentationName == null || instrumentationName.isEmpty()) { instrumentationName = "ROOT"; } LogRecordBuilder builder = loggerProvider.loggerBuilder(instrumentationName).build().logRecordBuilder(); - mapLoggingEvent(builder, event); + mapLoggingEvent(builder, event, threadId); builder.emit(); } @@ -83,7 +83,8 @@ public void emit(LoggerProvider loggerProvider, LoggingEventWithThreadId event) *
  • Mapped diagnostic context - {@link ILoggingEvent#getMDCPropertyMap()} * */ - private void mapLoggingEvent(LogRecordBuilder builder, LoggingEventWithThreadId loggingEvent) { + private void mapLoggingEvent( + LogRecordBuilder builder, ILoggingEvent loggingEvent, long threadId) { // message String message = loggingEvent.getFormattedMessage(); if (message != null) { @@ -119,7 +120,9 @@ private void mapLoggingEvent(LogRecordBuilder builder, LoggingEventWithThreadId if (captureExperimentalAttributes) { attributes.put(SemanticAttributes.THREAD_NAME, loggingEvent.getThreadName()); - attributes.put(SemanticAttributes.THREAD_ID, loggingEvent.getThreadId()); + if (threadId != -1) { + attributes.put(SemanticAttributes.THREAD_ID, threadId); + } } if (captureCodeAttributes) { diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java deleted file mode 100644 index df18e722dc79..000000000000 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWithThreadId.java +++ /dev/null @@ -1,17 +0,0 @@ -/* - * Copyright The OpenTelemetry Authors - * SPDX-License-Identifier: Apache-2.0 - */ - -package io.opentelemetry.instrumentation.logback.appender.v1_0.internal; - -import ch.qos.logback.classic.spi.ILoggingEvent; - -/** - * This class is internal and is hence not for public use. Its APIs are unstable and can change at - * any time. - */ -public interface LoggingEventWithThreadId extends ILoggingEvent { - - long getThreadId(); -} diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java deleted file mode 100644 index bbf767fa7049..000000000000 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventWrapper.java +++ /dev/null @@ -1,131 +0,0 @@ -/* - * Copyright The OpenTelemetry Authors - * SPDX-License-Identifier: Apache-2.0 - */ - -package io.opentelemetry.instrumentation.logback.appender.v1_0.internal; - -import ch.qos.logback.classic.Level; -import ch.qos.logback.classic.spi.ILoggingEvent; -import ch.qos.logback.classic.spi.IThrowableProxy; -import ch.qos.logback.classic.spi.LoggerContextVO; -import java.util.List; -import java.util.Map; -import org.slf4j.Marker; -import org.slf4j.event.KeyValuePair; - -/** - * This class is internal and is hence not for public use. Its APIs are unstable and can change at - * any time. - */ -public class LoggingEventWrapper implements LoggingEventWithThreadId { - - private final ILoggingEvent loggingEvent; - - public LoggingEventWrapper(ILoggingEvent loggingEvent) { - this.loggingEvent = loggingEvent; - } - - @Override - public String getThreadName() { - return loggingEvent.getThreadName(); - } - - @Override - public long getThreadId() { - Thread currentThread = Thread.currentThread(); - return currentThread.getId(); - } - - @Override - public Level getLevel() { - return loggingEvent.getLevel(); - } - - @Override - public String getMessage() { - return loggingEvent.getMessage(); - } - - @Override - public Object[] getArgumentArray() { - return loggingEvent.getArgumentArray(); - } - - @Override - public String getFormattedMessage() { - return loggingEvent.getFormattedMessage(); - } - - @Override - public String getLoggerName() { - return loggingEvent.getLoggerName(); - } - - @Override - public LoggerContextVO getLoggerContextVO() { - return loggingEvent.getLoggerContextVO(); - } - - @Override - public IThrowableProxy getThrowableProxy() { - return loggingEvent.getThrowableProxy(); - } - - @Override - public StackTraceElement[] getCallerData() { - return loggingEvent.getCallerData(); - } - - @Override - public boolean hasCallerData() { - return loggingEvent.hasCallerData(); - } - - @SuppressWarnings("deprecation") // Delegate - @Override - public Marker getMarker() { - return loggingEvent.getMarker(); - } - - @Override - public List getMarkerList() { - return loggingEvent.getMarkerList(); - } - - @Override - public Map getMDCPropertyMap() { - return loggingEvent.getMDCPropertyMap(); - } - - @SuppressWarnings("deprecation") // Delegate - @Override - public Map getMdc() { - return loggingEvent.getMdc(); - } - - @Override - public long getTimeStamp() { - return loggingEvent.getTimeStamp(); - } - - @Override - public int getNanoseconds() { - return loggingEvent.getNanoseconds(); - } - - @Override - public long getSequenceNumber() { - return loggingEvent.getSequenceNumber(); - } - - @Override - public List getKeyValuePairs() { - return loggingEvent.getKeyValuePairs(); - } - - @Override - public void prepareForDeferredProcessing() { - loggingEvent.prepareForDeferredProcessing(); - } -} From 32ac4b1ae3d0886f084c8b1cee4742e5f72c74aa Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Mon, 13 Nov 2023 14:17:23 +0100 Subject: [PATCH 20/53] Update comment --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 1314d6e6f546..729864c63ab3 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -32,7 +32,6 @@ class LogEventToReplay implements LogEvent { private final String threadName; private final long threadId; - // Log4j 2 seems to reuse Message objects private static class MessageCopy implements Message { private static final long serialVersionUID = 6921483958779195777L; @@ -69,6 +68,8 @@ public Throwable getThrowable() { } } + // Log4j 2 reuses LogEvent object, so we make a copy to be able to + // replay the log event later. LogEventToReplay(LogEvent logEvent) { this.logEvent = logEvent; this.loggerName = logEvent.getLoggerName(); From c05c785aac9376df3065a8af4a60b173fc27c33f Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Mon, 13 Nov 2023 14:20:39 +0100 Subject: [PATCH 21/53] Update serial version uid --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 729864c63ab3..196ebdc72004 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -19,7 +19,7 @@ class LogEventToReplay implements LogEvent { - private static final long serialVersionUID = -3639807661256104630L; + private static final long serialVersionUID = 1L; private final LogEvent logEvent; private final String loggerName; From 316ac45e5569ecd7dd36a032dfdc096fd6aae699 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Mon, 13 Nov 2023 14:52:45 +0100 Subject: [PATCH 22/53] Remove reference to LogEvent --- .../appender/v2_17/LogEventToReplay.java | 35 +++++++++---------- 1 file changed, 16 insertions(+), 19 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 196ebdc72004..1aca4fae4bd9 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -5,7 +5,9 @@ package io.opentelemetry.instrumentation.log4j.appender.v2_17; +import java.util.Collections; import java.util.Map; +import javax.annotation.Nullable; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Marker; import org.apache.logging.log4j.ThreadContext; @@ -21,7 +23,6 @@ class LogEventToReplay implements LogEvent { private static final long serialVersionUID = 1L; - private final LogEvent logEvent; private final String loggerName; private final Message message; private final Level level; @@ -71,7 +72,6 @@ public Throwable getThrowable() { // Log4j 2 reuses LogEvent object, so we make a copy to be able to // replay the log event later. LogEventToReplay(LogEvent logEvent) { - this.logEvent = logEvent; this.loggerName = logEvent.getLoggerName(); Message messageOrigin = logEvent.getMessage(); if (messageOrigin instanceof StructuredDataMessage) { @@ -99,13 +99,13 @@ public Throwable getThrowable() { @Override public LogEvent toImmutable() { - return logEvent.toImmutable(); + return null; } @SuppressWarnings("deprecation") // Delegate @Override public Map getContextMap() { - return logEvent.getContextMap(); + return Collections.emptyMap(); } @Override @@ -113,14 +113,15 @@ public ReadOnlyStringMap getContextData() { return contextData; } + @Nullable @Override public ThreadContext.ContextStack getContextStack() { - return logEvent.getContextStack(); + return null; } @Override public String getLoggerFqcn() { - return logEvent.getLoggerFqcn(); + return null; } @Override @@ -145,7 +146,7 @@ public Message getMessage() { @Override public long getTimeMillis() { - return logEvent.getTimeMillis(); + return 0; } @Override @@ -155,7 +156,7 @@ public Instant getInstant() { @Override public StackTraceElement getSource() { - return logEvent.getSource(); + return null; } @Override @@ -170,7 +171,7 @@ public long getThreadId() { @Override public int getThreadPriority() { - return logEvent.getThreadPriority(); + return 0; } @Override @@ -180,31 +181,27 @@ public Throwable getThrown() { @Override public ThrowableProxy getThrownProxy() { - return logEvent.getThrownProxy(); + return null; } @Override public boolean isEndOfBatch() { - return logEvent.isEndOfBatch(); + return false; } @Override public boolean isIncludeLocation() { - return logEvent.isIncludeLocation(); + return false; } @Override - public void setEndOfBatch(boolean endOfBatch) { - logEvent.setEndOfBatch(endOfBatch); - } + public void setEndOfBatch(boolean endOfBatch) {} @Override - public void setIncludeLocation(boolean locationRequired) { - logEvent.setIncludeLocation(locationRequired); - } + public void setIncludeLocation(boolean locationRequired) {} @Override public long getNanoTime() { - return logEvent.getNanoTime(); + return 0; } } From 1f263fd947b5857952812652727a90c656a2df50 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Mon, 13 Nov 2023 22:42:53 +0100 Subject: [PATCH 23/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java Co-authored-by: Trask Stalnaker --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 1aca4fae4bd9..0e692d9b6963 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -35,7 +35,7 @@ class LogEventToReplay implements LogEvent { private static class MessageCopy implements Message { - private static final long serialVersionUID = 6921483958779195777L; + private static final long serialVersionUID = 1L; private final String formattedMessage; private final String format; private final Object[] parameters; From 5a936f9dda13bd30963425cb1391ad3ad2f52d45 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Mon, 13 Nov 2023 22:57:57 +0100 Subject: [PATCH 24/53] Add comment --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 1 + 1 file changed, 1 insertion(+) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 0e692d9b6963..0de365e1de6e 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -77,6 +77,7 @@ public Throwable getThrowable() { if (messageOrigin instanceof StructuredDataMessage) { StructuredDataMessage structuredDataMessage = (StructuredDataMessage) messageOrigin; this.message = + // Log4j 2 reuses StructuredDataMessage object new StructuredDataMessage( structuredDataMessage.getId(), structuredDataMessage.getFormat(), From 5daf6d168e39ec954a57daf35ab9f8c328603bf5 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 18:03:13 +0100 Subject: [PATCH 25/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java Co-authored-by: Trask Stalnaker --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 3c65642f500f..b0af336d9a4f 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -132,7 +132,7 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) { /** * Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with * an {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used - * to replay the first logs. + * to replay the logs that were emitted prior to setting the OpenTelemetry instance into the Logback appender. */ @CanIgnoreReturnValue public B setFirstLogsCacheSize(int firstLogsCacheSize) { From e1656abcaba068f8604df3ae4c63e822df00caf6 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 18:14:30 +0100 Subject: [PATCH 26/53] Update instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java Co-authored-by: Trask Stalnaker --- .../log4j/appender/v2_17/Log4jHelper.java | 16 +++++----------- 1 file changed, 5 insertions(+), 11 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java index d54d386f7efe..6d2da05a5ce2 100644 --- a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java @@ -69,20 +69,14 @@ public static void capture( .logRecordBuilder(); Map contextData = ThreadContext.getImmutableContext(); + String threadName = null; + int threadId = -1; if (captureExperimentalAttributes) { Thread currentThread = Thread.currentThread(); - mapper.mapLogEvent( - builder, - message, - level, - marker, - throwable, - contextData, - currentThread.getName(), - currentThread.getId()); - } else { - mapper.mapLogEvent(builder, message, level, marker, throwable, contextData, null, -1); + threadName = currentThread.getName(); + threadId = currentThread.getId(); } + mapper.mapLogEvent(builder, message, level, marker, throwable, contextData, threadName, threadId); builder.setTimestamp(Instant.now()); builder.emit(); } From 6bef8a613c6adb0d72ef5da813726f180e1cd3de Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 18:29:50 +0100 Subject: [PATCH 27/53] spotless --- .../instrumentation/log4j/appender/v2_17/Log4jHelper.java | 3 ++- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 3 ++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java index 6d2da05a5ce2..8d42a06993e2 100644 --- a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java @@ -76,7 +76,8 @@ public static void capture( threadName = currentThread.getName(); threadId = currentThread.getId(); } - mapper.mapLogEvent(builder, message, level, marker, throwable, contextData, threadName, threadId); + mapper.mapLogEvent( + builder, message, level, marker, throwable, contextData, threadName, threadId); builder.setTimestamp(Instant.now()); builder.emit(); } diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index b0af336d9a4f..e47ef3fe9455 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -132,7 +132,8 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) { /** * Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with * an {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used - * to replay the logs that were emitted prior to setting the OpenTelemetry instance into the Logback appender. + * to replay the logs that were emitted prior to setting the OpenTelemetry instance into the + * Logback appender. */ @CanIgnoreReturnValue public B setFirstLogsCacheSize(int firstLogsCacheSize) { From 9e8fdd0165b3f5f9dd531a1e1c3a43cad791d249 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:01:44 +0100 Subject: [PATCH 28/53] Update instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java Co-authored-by: Trask Stalnaker --- .../logback/appender/v1_0/OpenTelemetryAppender.java | 10 +++------- 1 file changed, 3 insertions(+), 7 deletions(-) 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 6133acbbcce1..0bd271c3b702 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 @@ -160,13 +160,9 @@ public void setFirstLogsCacheSize(int size) { */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { this.openTelemetry = openTelemetry; - while (!eventsToReplay.isEmpty()) { - try { - LoggingEventToReplay eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); - mapper.emit(openTelemetry.getLogsBridge(), eventToReplay, -1); - } catch (InterruptedException e) { - // Ignore - } + LoggingEventToReplay eventToReplay; + while ((eventToReplay = eventsToReplay.poll()) != null) { + mapper.emit(openTelemetry.getLogsBridge(), eventToReplay, -1); } } From cae893623b3795799700b6e6c3369f50d56cfe0c Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:06:40 +0100 Subject: [PATCH 29/53] poll update --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 10 +++------- .../logback/appender/v1_0/OpenTelemetryAppender.java | 1 - 2 files changed, 3 insertions(+), 8 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index e47ef3fe9455..3b71ac09d299 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -214,13 +214,9 @@ private static List splitAndFilterBlanksAndNulls(String value) { */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { this.openTelemetry = openTelemetry; - while (!eventsToReplay.isEmpty()) { - try { - LogEvent eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS); - append(eventToReplay); - } catch (InterruptedException e) { - // Ignore - } + LogEventToReplay eventToReplay; + while ((eventToReplay = eventsToReplay.poll()) != null) { + append(eventToReplay); } } 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 0bd271c3b702..932aa498d64b 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 @@ -16,7 +16,6 @@ import java.util.List; import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.BlockingQueue; -import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.stream.Collectors; import org.slf4j.ILoggerFactory; From b7374638de6a1f6fcc81a6b6bcc8a1343e9e53a5 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:15:53 +0100 Subject: [PATCH 30/53] static import otel assertions --- .../appender/v1_0/OpenTelemetryAppenderTest.java | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) 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 64182cc3151a..f7b4f1e6b8b6 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 @@ -5,7 +5,7 @@ package io.opentelemetry.instrumentation.logback.appender.v1_0; -import static org.assertj.core.api.Assertions.assertThat; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.common.AttributeKey; @@ -19,7 +19,6 @@ import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; import io.opentelemetry.sdk.resources.Resource; -import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.semconv.SemanticAttributes; @@ -73,7 +72,7 @@ void logNoSpan() { assertThat(logDataList).hasSize(1); LogRecordData logData = logDataList.get(0); - OpenTelemetryAssertions.assertThat(logData) + assertThat(logData) .hasResource(resource) .hasInstrumentationScope(instrumentationScopeInfo) .hasBody("log message 1") @@ -95,7 +94,7 @@ void replayLogsDuringOpenTelemetryInstallation() { List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(1); LogRecordData logData = logDataList.get(0); - OpenTelemetryAssertions.assertThat(logData) + assertThat(logData) .hasResource(resource) .hasInstrumentationScope(instrumentationScopeInfo) .hasBody("log message 1") @@ -112,9 +111,9 @@ void logWithSpan() { List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(3); - OpenTelemetryAssertions.assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); - OpenTelemetryAssertions.assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); - OpenTelemetryAssertions.assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); + assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); + assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); + assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); } private static Span runWithSpan(String spanName, Runnable runnable) { From 4f4a275ee4ca82a846dca7e5f14520dfc64013a4 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:19:38 +0100 Subject: [PATCH 31/53] comment added --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 1 + 1 file changed, 1 insertion(+) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 0de365e1de6e..a3c7cde303bf 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -84,6 +84,7 @@ public Throwable getThrowable() { structuredDataMessage.getType(), structuredDataMessage.getData()); } else if (messageOrigin instanceof StringMapMessage) { + // StringMapMessage objects are not reused by Log4j 2 this.message = messageOrigin; } else { this.message = new MessageCopy(logEvent.getMessage()); From 8712a4b99955ad0ae6a2fa8daa2e8c043b826fa9 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:43:20 +0100 Subject: [PATCH 32/53] fix compilation issue --- .../instrumentation/log4j/appender/v2_17/Log4jHelper.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java index 8d42a06993e2..a5faaf0e8d69 100644 --- a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java @@ -70,7 +70,7 @@ public static void capture( Map contextData = ThreadContext.getImmutableContext(); String threadName = null; - int threadId = -1; + long threadId = -1; if (captureExperimentalAttributes) { Thread currentThread = Thread.currentThread(); threadName = currentThread.getName(); From cec387771e758eca27eee676399fdc049bb2603b Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Tue, 14 Nov 2023 19:49:12 +0100 Subject: [PATCH 33/53] move nested class at the bottom --- .../log4j/appender/v2_17/Log4jHelper.java | 2 +- .../appender/v2_17/LogEventToReplay.java | 72 +++++++++---------- 2 files changed, 37 insertions(+), 37 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java index a5faaf0e8d69..0bd3cbeee8f1 100644 --- a/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java +++ b/instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java @@ -70,7 +70,7 @@ public static void capture( Map contextData = ThreadContext.getImmutableContext(); String threadName = null; - long threadId = -1; + long threadId = -1; if (captureExperimentalAttributes) { Thread currentThread = Thread.currentThread(); threadName = currentThread.getName(); diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index a3c7cde303bf..577b5d08bfaa 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -33,42 +33,6 @@ class LogEventToReplay implements LogEvent { private final String threadName; private final long threadId; - private static class MessageCopy implements Message { - - private static final long serialVersionUID = 1L; - private final String formattedMessage; - private final String format; - private final Object[] parameters; - private final Throwable throwable; - - public MessageCopy(Message message) { - this.formattedMessage = message.getFormattedMessage(); - this.format = message.getFormat(); - this.parameters = message.getParameters(); - this.throwable = message.getThrowable(); - } - - @Override - public String getFormattedMessage() { - return formattedMessage; - } - - @Override - public String getFormat() { - return format; - } - - @Override - public Object[] getParameters() { - return parameters; - } - - @Override - public Throwable getThrowable() { - return throwable; - } - } - // Log4j 2 reuses LogEvent object, so we make a copy to be able to // replay the log event later. LogEventToReplay(LogEvent logEvent) { @@ -206,4 +170,40 @@ public void setIncludeLocation(boolean locationRequired) {} public long getNanoTime() { return 0; } + + private static class MessageCopy implements Message { + + private static final long serialVersionUID = 1L; + private final String formattedMessage; + private final String format; + private final Object[] parameters; + private final Throwable throwable; + + public MessageCopy(Message message) { + this.formattedMessage = message.getFormattedMessage(); + this.format = message.getFormat(); + this.parameters = message.getParameters(); + this.throwable = message.getThrowable(); + } + + @Override + public String getFormattedMessage() { + return formattedMessage; + } + + @Override + public String getFormat() { + return format; + } + + @Override + public Object[] getParameters() { + return parameters; + } + + @Override + public Throwable getThrowable() { + return throwable; + } + } } From 43f9376456057c0bf590ffe410b55abbd3dc303e Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Wed, 15 Nov 2023 16:42:56 +0100 Subject: [PATCH 34/53] Document race condition --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 4 ++++ .../logback/appender/v1_0/OpenTelemetryAppender.java | 4 ++++ 2 files changed, 8 insertions(+) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 3b71ac09d299..be34a5708ce3 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -223,6 +223,10 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { @SuppressWarnings("SystemOut") @Override public void append(LogEvent event) { + // TODO(jean): Race condition to fix + // time=1 append() thread gets the no-op instance + // time=2 install() thread updates the instance and flushes the queue + // time=3 append() thread adds the log event to the queue if (openTelemetry == OpenTelemetry.noop()) { if (eventsToReplay.remainingCapacity() > 0) { LogEventToReplay logEventToReplay = new LogEventToReplay(event); 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 932aa498d64b..a3a51a11ccc3 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 @@ -78,6 +78,10 @@ public void start() { @SuppressWarnings("SystemOut") @Override protected void append(ILoggingEvent event) { + // TODO(jean): Race condition to fix + // time=1 append() thread gets the no-op instance + // time=2 install() thread updates the instance and flushes the queue + // time=3 append() thread adds the log event to the queue if (openTelemetry == OpenTelemetry.noop()) { if (eventsToReplay.remainingCapacity() > 0) { LoggingEventToReplay logEventToReplay = From 2e32147fc6baacb71af857b137427c474f940b42 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Wed, 15 Nov 2023 16:53:23 +0100 Subject: [PATCH 35/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java Co-authored-by: Trask Stalnaker --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 577b5d08bfaa..3262ebbd9c50 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -68,7 +68,7 @@ public LogEvent toImmutable() { return null; } - @SuppressWarnings("deprecation") // Delegate + @SuppressWarnings("deprecation") // Override @Override public Map getContextMap() { return Collections.emptyMap(); From 5497b5da13e5e2993e44f159b2fa0cccdfaa6a51 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Wed, 15 Nov 2023 16:55:18 +0100 Subject: [PATCH 36/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java Co-authored-by: Trask Stalnaker --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 3 +++ 1 file changed, 3 insertions(+) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 3262ebbd9c50..4302df0fa5fb 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -23,6 +23,9 @@ class LogEventToReplay implements LogEvent { private static final long serialVersionUID = 1L; + // Log4j 2 reuses LogEvent object, so we make a copy of all the fields that are used during export + // in order to be able to replay the log event later. + private final String loggerName; private final Message message; private final Level level; From 6a6ed85aa87b3d4bb5c65d2340a353e6ecec18aa Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Wed, 15 Nov 2023 22:26:02 +0100 Subject: [PATCH 37/53] Refactor tests --- .../AbstractOpenTelemetryAppenderTest.java | 243 ++++++++++++ .../LogReplayOpenTelemetryAppenderTest.java | 101 +++++ .../v2_17/OpenTelemetryAppenderTest.java | 366 +----------------- .../AbstractOpenTelemetryAppenderTest.java | 148 +++++++ .../LogReplayOpenTelemetryAppenderTest.java | 48 +++ .../v1_0/OpenTelemetryAppenderTest.java | 247 +----------- 6 files changed, 562 insertions(+), 591 deletions(-) create mode 100644 instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/AbstractOpenTelemetryAppenderTest.java create mode 100644 instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java create mode 100644 instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java create mode 100644 instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/AbstractOpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/AbstractOpenTelemetryAppenderTest.java new file mode 100644 index 000000000000..c013573c0465 --- /dev/null +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/AbstractOpenTelemetryAppenderTest.java @@ -0,0 +1,243 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.log4j.appender.v2_17; + +import static io.opentelemetry.api.common.AttributeKey.stringKey; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satisfies; +import static java.util.concurrent.TimeUnit.MILLISECONDS; + +import io.opentelemetry.api.OpenTelemetry; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.logs.Severity; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.common.InstrumentationScopeInfo; +import io.opentelemetry.sdk.logs.SdkLoggerProvider; +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; +import io.opentelemetry.sdk.resources.Resource; +import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; +import io.opentelemetry.semconv.SemanticAttributes; +import java.time.Instant; +import java.util.List; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.Marker; +import org.apache.logging.log4j.MarkerManager; +import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.core.impl.Log4jLogEvent; +import org.apache.logging.log4j.message.FormattedMessage; +import org.apache.logging.log4j.message.StringMapMessage; +import org.apache.logging.log4j.message.StructuredDataMessage; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; + +abstract class AbstractOpenTelemetryAppenderTest { + + static final Logger logger = LogManager.getLogger("TestLogger"); + + static InMemoryLogRecordExporter logRecordExporter; + static Resource resource; + static InstrumentationScopeInfo instrumentationScopeInfo; + static OpenTelemetry openTelemetry; + + void executeAfterLogsExecution() {} + + @BeforeAll + static void setupAll() { + logRecordExporter = InMemoryLogRecordExporter.create(); + resource = Resource.getDefault(); + instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger"); + + SdkLoggerProvider loggerProvider = + SdkLoggerProvider.builder() + .setResource(resource) + .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) + .build(); + + openTelemetry = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); + } + + static void generalBeforeEachSetup() { + logRecordExporter.reset(); + ThreadContext.clearAll(); + } + + @AfterAll + static void cleanupAll() { + // This is to make sure that other test classes don't have issues with the logger provider set + OpenTelemetryAppender.install(null); + } + + @Test + void initializeWithBuilder() { + OpenTelemetryAppender appender = + OpenTelemetryAppender.builder() + .setName("OpenTelemetryAppender") + .setOpenTelemetry(openTelemetry) + .build(); + appender.start(); + + appender.append( + Log4jLogEvent.newBuilder() + .setMessage(new FormattedMessage("log message 1", (Object) null)) + .build()); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList) + .satisfiesExactly(logRecordData -> assertThat(logDataList.get(0)).hasBody("log message 1")); + } + + @Test + void logNoSpan() { + logger.info("log message 1"); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasAttributes(Attributes.empty()); + } + + @Test + void logWithSpanInvalid() { + logger.info("log message"); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0).getSpanContext()).isEqualTo(SpanContext.getInvalid()); + } + + @Test + void logWithExtras() { + Instant start = Instant.now(); + logger.info("log message 1", new IllegalStateException("Error!")); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasSeverity(Severity.INFO) + .hasSeverityText("INFO") + .hasAttributesSatisfyingExactly( + equalTo(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()), + equalTo(SemanticAttributes.EXCEPTION_MESSAGE, "Error!"), + satisfies(SemanticAttributes.EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras"))); + + assertThat(logDataList.get(0).getTimestampEpochNanos()) + .isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli())) + .isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli())); + } + + @Test + void logContextData() { + ThreadContext.put("key1", "val1"); + ThreadContext.put("key2", "val2"); + try { + logger.info("log message 1"); + } finally { + ThreadContext.clearMap(); + } + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.context_data.key1"), "val1"), + equalTo(stringKey("log4j.context_data.key2"), "val2")); + } + + @Test + void logStringMapMessage() { + StringMapMessage message = new StringMapMessage(); + message.put("key1", "val1"); + message.put("key2", "val2"); + logger.info(message); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } + + @Test + void logStringMapMessageWithSpecialAttribute() { + StringMapMessage message = new StringMapMessage(); + message.put("key1", "val1"); + message.put("message", "val2"); + logger.info(message); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("val2") + .hasAttributesSatisfyingExactly(equalTo(stringKey("log4j.map_message.key1"), "val1")); + } + + @Test + void testCaptureMarkerAttribute() { + String markerName = "aMarker"; + Marker marker = MarkerManager.getMarker(markerName); + + logger.info(marker, "Message"); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + LogRecordData logData = logDataList.get(0); + assertThat(logData.getAttributes().get(stringKey("log4j.marker"))).isEqualTo(markerName); + } + + @Test + void logStructuredDataMessage() { + StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); + message.put("key1", "val1"); + message.put("key2", "val2"); + logger.info(message); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("a message") + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } +} diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java new file mode 100644 index 000000000000..e16e46fa1a13 --- /dev/null +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java @@ -0,0 +1,101 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.log4j.appender.v2_17; + +import static io.opentelemetry.api.common.AttributeKey.stringKey; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo; +import static org.assertj.core.api.Assertions.assertThat; + +import io.opentelemetry.api.OpenTelemetry; +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; +import java.util.List; +import org.apache.logging.log4j.message.StringMapMessage; +import org.apache.logging.log4j.message.StructuredDataMessage; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { + + @BeforeEach + void setup() { + generalBeforeEachSetup(); + OpenTelemetryAppender.install(OpenTelemetry.noop()); + } + + @Override + void executeAfterLogsExecution() { + OpenTelemetryAppender.install(openTelemetry); + } + + @Test + void twoLogs() { + logger.info("log message 1"); + logger.info( + "log message 2"); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + OpenTelemetryAssertions.assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1"); + } + + @Test + void twoLogsStringMapMessage() { + StringMapMessage message = new StringMapMessage(); + message.put("key1", "val1"); + message.put("key2", "val2"); + + logger.info(message); + + StringMapMessage message2 = new StringMapMessage(); + message2.put("key1-2", "val1-2"); + message2.put("key2-2", "val2-2"); + + logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + OpenTelemetryAssertions.assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } + + @Test + void twoLogsStructuredDataMessage() { + StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); + message.put("key1", "val1"); + message.put("key2", "val2"); + logger.info(message); + + StructuredDataMessage message2 = + new StructuredDataMessage("an id 2", "a message 2", "a type 2"); + message.put("key1-2", "val1-2"); + message.put("key2-2", "val2-2"); + logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) + + OpenTelemetryAppender.install(openTelemetry); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + OpenTelemetryAssertions.assertThat(logDataList.get(0)) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("a message") + .hasAttributesSatisfyingExactly( + equalTo(stringKey("log4j.map_message.key1"), "val1"), + equalTo(stringKey("log4j.map_message.key2"), "val2")); + } +} diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java index e1ade2bfa213..bcc8a1290e56 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppenderTest.java @@ -5,144 +5,36 @@ package io.opentelemetry.instrumentation.log4j.appender.v2_17; -import static io.opentelemetry.api.common.AttributeKey.stringKey; -import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; -import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo; -import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satisfies; -import static java.util.concurrent.TimeUnit.MILLISECONDS; +import static org.assertj.core.api.Assertions.assertThat; -import io.opentelemetry.api.OpenTelemetry; -import io.opentelemetry.api.common.Attributes; -import io.opentelemetry.api.logs.Severity; import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.context.Scope; -import io.opentelemetry.sdk.OpenTelemetrySdk; -import io.opentelemetry.sdk.common.InstrumentationScopeInfo; -import io.opentelemetry.sdk.logs.SdkLoggerProvider; import io.opentelemetry.sdk.logs.data.LogRecordData; -import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; -import io.opentelemetry.sdk.resources.Resource; -import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; import io.opentelemetry.sdk.trace.SdkTracerProvider; -import io.opentelemetry.semconv.SemanticAttributes; -import java.time.Instant; import java.util.List; -import org.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.Marker; -import org.apache.logging.log4j.MarkerManager; -import org.apache.logging.log4j.ThreadContext; -import org.apache.logging.log4j.core.impl.Log4jLogEvent; -import org.apache.logging.log4j.message.FormattedMessage; -import org.apache.logging.log4j.message.StringMapMessage; -import org.apache.logging.log4j.message.StructuredDataMessage; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.BeforeAll; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; -class OpenTelemetryAppenderTest { - - private static final Logger logger = LogManager.getLogger("TestLogger"); - - private static InMemoryLogRecordExporter logRecordExporter; - private static Resource resource; - private static InstrumentationScopeInfo instrumentationScopeInfo; - private static OpenTelemetry openTelemetry; - - @BeforeAll - static void setupAll() { - logRecordExporter = InMemoryLogRecordExporter.create(); - resource = Resource.getDefault(); - instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger"); - - SdkLoggerProvider loggerProvider = - SdkLoggerProvider.builder() - .setResource(resource) - .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) - .build(); - - openTelemetry = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); - } +class OpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { @BeforeEach void setup() { - logRecordExporter.reset(); - ThreadContext.clearAll(); + generalBeforeEachSetup(); OpenTelemetryAppender.install(openTelemetry); } - @AfterAll - static void cleanupAll() { - // This is to make sure that other test classes don't have issues with the logger provider set - OpenTelemetryAppender.install(null); - } - @Test - void initializeWithBuilder() { - OpenTelemetryAppender appender = - OpenTelemetryAppender.builder() - .setName("OpenTelemetryAppender") - .setOpenTelemetry(openTelemetry) - .build(); - appender.start(); + void logWithSpan() { // Does not work for log replay but it is not likely to occur because + // the log replay is related to the case where an OpenTelemetry object is not yet available + // at the time the log is executed (and if no OpenTelemetry is available, the context + // propagation can't happen) + Span span1 = runWithSpan("span1", () -> logger.info("log message")); - appender.append( - Log4jLogEvent.newBuilder() - .setMessage(new FormattedMessage("log message 1", (Object) null)) - .build()); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList) - .satisfiesExactly(logRecordData -> assertThat(logDataList.get(0)).hasBody("log message 1")); - } - - @Test - void logNoSpan() { - logger.info("log message 1"); + executeAfterLogsExecution(); List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasAttributes(Attributes.empty()); - } - - @Test - void replayLogsDuringOpenTelemetryInstallation() { - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - logger.info("log message 1"); - logger.info( - "log message 2"); // Won't be instrumented because cache size is 1 (see log4j2.xml file) - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1"); - } - - @Test - void logWithSpan() { - Span span1 = runWithSpan("span1", () -> logger.info("log message 1")); - - logger.info("log message 2"); - - Span span2 = runWithSpan("span2", () -> logger.info("log message 3")); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(3); assertThat(logDataList.get(0).getSpanContext()).isEqualTo(span1.getSpanContext()); - assertThat(logDataList.get(1).getSpanContext()).isEqualTo(SpanContext.getInvalid()); - assertThat(logDataList.get(2).getSpanContext()).isEqualTo(span2.getSpanContext()); } private static Span runWithSpan(String spanName, Runnable runnable) { @@ -154,244 +46,4 @@ private static Span runWithSpan(String spanName, Runnable runnable) { } return span; } - - @Test - void logWithExtras() { - Instant start = Instant.now(); - logger.info("log message 1", new IllegalStateException("Error!")); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasSeverity(Severity.INFO) - .hasSeverityText("INFO") - .hasAttributesSatisfyingExactly( - equalTo(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()), - equalTo(SemanticAttributes.EXCEPTION_MESSAGE, "Error!"), - satisfies(SemanticAttributes.EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras"))); - - assertThat(logDataList.get(0).getTimestampEpochNanos()) - .isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli())) - .isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli())); - } - - @Test - void logWithExtrasAndLogReplay() { - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - Instant start = Instant.now(); - logger.info("log message 1", new IllegalStateException("Error!")); - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasSeverity(Severity.INFO) - .hasSeverityText("INFO") - .hasAttributesSatisfyingExactly( - equalTo(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.class.getName()), - equalTo(SemanticAttributes.EXCEPTION_MESSAGE, "Error!"), - satisfies(SemanticAttributes.EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras"))); - - assertThat(logDataList.get(0).getTimestampEpochNanos()) - .isGreaterThanOrEqualTo(MILLISECONDS.toNanos(start.toEpochMilli())) - .isLessThanOrEqualTo(MILLISECONDS.toNanos(Instant.now().toEpochMilli())); - } - - @Test - void logContextData() { - ThreadContext.put("key1", "val1"); - ThreadContext.put("key2", "val2"); - try { - logger.info("log message 1"); - } finally { - ThreadContext.clearMap(); - } - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.context_data.key1"), "val1"), - equalTo(stringKey("log4j.context_data.key2"), "val2")); - } - - @Test - void logContextDataAndLogReplay() { - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - ThreadContext.put("key1", "val1"); - ThreadContext.put("key2", "val2"); - try { - logger.info("log message 1"); - } finally { - ThreadContext.clearMap(); - } - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.context_data.key1"), "val1"), - equalTo(stringKey("log4j.context_data.key2"), "val2")); - } - - @Test - void logStringMapMessage() { - StringMapMessage message = new StringMapMessage(); - message.put("key1", "val1"); - message.put("key2", "val2"); - logger.info(message); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.map_message.key1"), "val1"), - equalTo(stringKey("log4j.map_message.key2"), "val2")); - } - - @Test - void logStringMapMessageWithLogReplay() { - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - StringMapMessage message = new StringMapMessage(); - message.put("key1", "val1"); - message.put("key2", "val2"); - - logger.info(message); - - StringMapMessage message2 = new StringMapMessage(); - message2.put("key1-2", "val1-2"); - message2.put("key2-2", "val2-2"); - - logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.map_message.key1"), "val1"), - equalTo(stringKey("log4j.map_message.key2"), "val2")); - } - - @Test - void logStringMapMessageWithSpecialAttribute() { - StringMapMessage message = new StringMapMessage(); - message.put("key1", "val1"); - message.put("message", "val2"); - logger.info(message); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("val2") - .hasAttributesSatisfyingExactly(equalTo(stringKey("log4j.map_message.key1"), "val1")); - } - - @Test - void testCaptureMarkerAttribute() { - String markerName = "aMarker"; - Marker marker = MarkerManager.getMarker(markerName); - - logger.info(marker, "Message"); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - LogRecordData logData = logDataList.get(0); - assertThat(logData.getAttributes().get(stringKey("log4j.marker"))).isEqualTo(markerName); - } - - @Test - void testCaptureMarkerAttributeAndLogReplay() { - String markerName = "aMarker"; - Marker marker = MarkerManager.getMarker(markerName); - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - logger.info(marker, "Message"); - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - LogRecordData logData = logDataList.get(0); - assertThat(logData.getAttributes().get(stringKey("log4j.marker"))).isEqualTo(markerName); - } - - @Test - void logStructuredDataMessage() { - StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); - message.put("key1", "val1"); - message.put("key2", "val2"); - logger.info(message); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("a message") - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.map_message.key1"), "val1"), - equalTo(stringKey("log4j.map_message.key2"), "val2")); - } - - @Test - void logStructuredDataMessageAndLogReplay() { - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type"); - message.put("key1", "val1"); - message.put("key2", "val2"); - logger.info(message); - - StructuredDataMessage message2 = - new StructuredDataMessage("an id 2", "a message 2", "a type 2"); - message.put("key1-2", "val1-2"); - message.put("key2-2", "val2-2"); - logger.info(message2); // Won't be instrumented because cache size is 1 (see log4j2.xml file) - - OpenTelemetryAppender.install(openTelemetry); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - assertThat(logDataList.get(0)) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("a message") - .hasAttributesSatisfyingExactly( - equalTo(stringKey("log4j.map_message.key1"), "val1"), - equalTo(stringKey("log4j.map_message.key2"), "val2")); - } } diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java new file mode 100644 index 000000000000..f677d726bd20 --- /dev/null +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java @@ -0,0 +1,148 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.logback.appender.v1_0; + +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; + +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.logs.Severity; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.common.InstrumentationScopeInfo; +import io.opentelemetry.sdk.logs.SdkLoggerProvider; +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; +import io.opentelemetry.sdk.resources.Resource; +import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; +import io.opentelemetry.semconv.SemanticAttributes; +import java.time.Instant; +import java.util.Arrays; +import java.util.List; +import java.util.concurrent.TimeUnit; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; +import org.slf4j.Marker; +import org.slf4j.MarkerFactory; + +abstract class AbstractOpenTelemetryAppenderTest { + + static final Logger logger = LoggerFactory.getLogger("TestLogger"); + + static InMemoryLogRecordExporter logRecordExporter; + static Resource resource; + static InstrumentationScopeInfo instrumentationScopeInfo; + + static OpenTelemetrySdk openTelemetrySdk; + + void executeAfterLogsExecution() {} + + @BeforeAll + static void setupAll() { + logRecordExporter = InMemoryLogRecordExporter.create(); + resource = Resource.getDefault(); + instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger"); + SdkLoggerProvider loggerProvider = + SdkLoggerProvider.builder() + .setResource(resource) + .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) + .build(); + openTelemetrySdk = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); + } + + static void generalBeforeEachSetup() { + logRecordExporter.reset(); + } + + @Test + void logNoSpan() { + logger.info("log message 1"); + + executeAfterLogsExecution(); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + LogRecordData logData = logDataList.get(0); + + assertThat(logData) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasTotalAttributeCount(4); + } + + @Test + void logWithExtras() { + Instant start = Instant.now(); + String markerName = "aMarker"; + Marker marker = MarkerFactory.getMarker(markerName); + logger.info(marker, "log message 1", new IllegalStateException("Error!")); + + executeAfterLogsExecution(); + + 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.getTimestampEpochNanos()) + .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(start.toEpochMilli())) + .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli())); + assertThat(logData.getSeverity()).isEqualTo(Severity.INFO); + assertThat(logData.getSeverityText()).isEqualTo("INFO"); + assertThat(logData.getAttributes().size()) + .isEqualTo(3 + 4 + 1); // 3 exception attributes, 4 code attributes, 1 marker attribute + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)) + .isEqualTo(IllegalStateException.class.getName()); + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)) + .isEqualTo("Error!"); + assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)) + .contains("logWithExtras"); + + String file = logData.getAttributes().get(SemanticAttributes.CODE_FILEPATH); + assertThat(file).isEqualTo(AbstractOpenTelemetryAppenderTest.class.getSimpleName() + ".java"); + + String codeClass = logData.getAttributes().get(SemanticAttributes.CODE_NAMESPACE); + assertThat(codeClass).isEqualTo(AbstractOpenTelemetryAppenderTest.class.getName()); + + String method = logData.getAttributes().get(SemanticAttributes.CODE_FUNCTION); + assertThat(method).isEqualTo("logWithExtras"); + + Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO); + assertThat(lineNumber).isGreaterThan(1); + + List logMarker = + logData.getAttributes().get(AttributeKey.stringArrayKey("logback.marker")); + assertThat(logMarker).isEqualTo(Arrays.asList(markerName)); + } + + @Test + void logContextData() { + MDC.put("key1", "val1"); + MDC.put("key2", "val2"); + try { + logger.info("log message 1"); + } finally { + MDC.clear(); + } + + executeAfterLogsExecution(); + + 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(2 + 4); // 4 code attributes + assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))) + .isEqualTo("val1"); + assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) + .isEqualTo("val2"); + } +} diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java new file mode 100644 index 000000000000..fdb8674a78b3 --- /dev/null +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java @@ -0,0 +1,48 @@ +/* + * Copyright The OpenTelemetry Authors + * SPDX-License-Identifier: Apache-2.0 + */ + +package io.opentelemetry.instrumentation.logback.appender.v1_0; + +import static org.assertj.core.api.Assertions.assertThat; + +import io.opentelemetry.api.OpenTelemetry; +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; +import java.util.List; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { + + @BeforeEach + void setup() { + generalBeforeEachSetup(); + OpenTelemetryAppender.install(OpenTelemetry.noop()); + } + + @Override + void executeAfterLogsExecution() { + OpenTelemetryAppender.install(openTelemetrySdk); + } + + @Test + void twoLogs() { + logger.info("log message 1"); + logger.info( + "log message 2"); // Won't be instrumented because cache size is 1 (see logback-test.xml + // file) + + OpenTelemetryAppender.install(openTelemetrySdk); + + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(1); + LogRecordData logData = logDataList.get(0); + OpenTelemetryAssertions.assertThat(logData) + .hasResource(resource) + .hasInstrumentationScope(instrumentationScopeInfo) + .hasBody("log message 1") + .hasTotalAttributeCount(4); + } +} 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 f7b4f1e6b8b6..7a06887ee639 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 @@ -5,115 +5,44 @@ package io.opentelemetry.instrumentation.logback.appender.v1_0; -import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; +import static org.assertj.core.api.Assertions.assertThat; -import io.opentelemetry.api.OpenTelemetry; -import io.opentelemetry.api.common.AttributeKey; -import io.opentelemetry.api.logs.Severity; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.context.Scope; -import io.opentelemetry.sdk.OpenTelemetrySdk; -import io.opentelemetry.sdk.common.InstrumentationScopeInfo; -import io.opentelemetry.sdk.logs.SdkLoggerProvider; import io.opentelemetry.sdk.logs.data.LogRecordData; -import io.opentelemetry.sdk.logs.export.SimpleLogRecordProcessor; -import io.opentelemetry.sdk.resources.Resource; -import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import io.opentelemetry.sdk.trace.SdkTracerProvider; -import io.opentelemetry.semconv.SemanticAttributes; -import java.time.Instant; -import java.util.Arrays; import java.util.List; -import java.util.concurrent.TimeUnit; -import org.junit.jupiter.api.BeforeAll; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; -import org.slf4j.MDC; -import org.slf4j.Marker; -import org.slf4j.MarkerFactory; -class OpenTelemetryAppenderTest { - - private static final Logger logger = LoggerFactory.getLogger("TestLogger"); - - private static InMemoryLogRecordExporter logRecordExporter; - private static Resource resource; - private static InstrumentationScopeInfo instrumentationScopeInfo; - - private static OpenTelemetrySdk openTelemetrySdk; - - @BeforeAll - static void setupAll() { - logRecordExporter = InMemoryLogRecordExporter.create(); - resource = Resource.getDefault(); - instrumentationScopeInfo = InstrumentationScopeInfo.create("TestLogger"); - SdkLoggerProvider loggerProvider = - SdkLoggerProvider.builder() - .setResource(resource) - .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) - .build(); - openTelemetrySdk = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); - } +class OpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { @BeforeEach void setup() { - logRecordExporter.reset(); + generalBeforeEachSetup(); OpenTelemetryAppender.install(openTelemetrySdk); } @Test - void logNoSpan() { - logger.info("log message 1"); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - LogRecordData logData = logDataList.get(0); - - assertThat(logData) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasTotalAttributeCount(4); - } - - @Test - void replayLogsDuringOpenTelemetryInstallation() { - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - logger.info("log message 1"); - logger.info( - "log message 2"); // Won't be instrumented because cache size is 1 (see logback-test.xml - // file) - - OpenTelemetryAppender.install(openTelemetrySdk); - - List logDataList = logRecordExporter.getFinishedLogRecordItems(); - assertThat(logDataList).hasSize(1); - LogRecordData logData = logDataList.get(0); - assertThat(logData) - .hasResource(resource) - .hasInstrumentationScope(instrumentationScopeInfo) - .hasBody("log message 1") - .hasTotalAttributeCount(4); - } - - @Test - void logWithSpan() { + void logWithSpan() { // Does not work for log replay but it is not likely to occur because + // the log replay is related to the case where an OpenTelemetry object is not yet available + // at the time the log is executed (and if no OpenTelemetry is available, the context + // propagation can't happen) Span span1 = runWithSpan("span1", () -> logger.info("log message 1")); logger.info("log message 2"); + executeAfterLogsExecution(); + Span span2 = runWithSpan("span2", () -> logger.info("log message 3")); List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(3); - assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); - assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); - assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); + OpenTelemetryAssertions.assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); + OpenTelemetryAssertions.assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); + OpenTelemetryAssertions.assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); } private static Span runWithSpan(String spanName, Runnable runnable) { @@ -125,154 +54,4 @@ private static Span runWithSpan(String spanName, Runnable runnable) { } return span; } - - @Test - void logWithExtras() { - Instant start = Instant.now(); - String markerName = "aMarker"; - Marker marker = MarkerFactory.getMarker(markerName); - logger.info(marker, "log message 1", new IllegalStateException("Error!")); - - 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.getTimestampEpochNanos()) - .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(start.toEpochMilli())) - .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli())); - assertThat(logData.getSeverity()).isEqualTo(Severity.INFO); - assertThat(logData.getSeverityText()).isEqualTo("INFO"); - assertThat(logData.getAttributes().size()) - .isEqualTo(3 + 4 + 1); // 3 exception attributes, 4 code attributes, 1 marker attribute - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)) - .isEqualTo(IllegalStateException.class.getName()); - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)) - .isEqualTo("Error!"); - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)) - .contains("logWithExtras"); - - String file = logData.getAttributes().get(SemanticAttributes.CODE_FILEPATH); - assertThat(file).isEqualTo("OpenTelemetryAppenderTest.java"); - - String codeClass = logData.getAttributes().get(SemanticAttributes.CODE_NAMESPACE); - assertThat(codeClass) - .isEqualTo( - "io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppenderTest"); - - String method = logData.getAttributes().get(SemanticAttributes.CODE_FUNCTION); - assertThat(method).isEqualTo("logWithExtras"); - - Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO); - assertThat(lineNumber).isGreaterThan(1); - - List logMarker = - logData.getAttributes().get(AttributeKey.stringArrayKey("logback.marker")); - assertThat(logMarker).isEqualTo(Arrays.asList(markerName)); - } - - @Test - void logWithExtrasAndLogReplay() { - Instant start = Instant.now(); - String markerName = "aMarker"; - Marker marker = MarkerFactory.getMarker(markerName); - - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - logger.info(marker, "log message 1", new IllegalStateException("Error!")); - - OpenTelemetryAppender.install(openTelemetrySdk); - - 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.getTimestampEpochNanos()) - .isGreaterThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(start.toEpochMilli())) - .isLessThanOrEqualTo(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli())); - assertThat(logData.getSeverity()).isEqualTo(Severity.INFO); - assertThat(logData.getSeverityText()).isEqualTo("INFO"); - assertThat(logData.getAttributes().size()) - .isEqualTo(3 + 4 + 1); // 3 exception attributes, 4 code attributes, 1 marker attribute - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)) - .isEqualTo(IllegalStateException.class.getName()); - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)) - .isEqualTo("Error!"); - assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)) - .contains("logWithExtras"); - - String file = logData.getAttributes().get(SemanticAttributes.CODE_FILEPATH); - assertThat(file).isEqualTo("OpenTelemetryAppenderTest.java"); - - String codeClass = logData.getAttributes().get(SemanticAttributes.CODE_NAMESPACE); - assertThat(codeClass) - .isEqualTo( - "io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppenderTest"); - - String method = logData.getAttributes().get(SemanticAttributes.CODE_FUNCTION); - assertThat(method).isEqualTo("logWithExtrasAndLogReplay"); - - Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO); - assertThat(lineNumber).isGreaterThan(1); - - List logMarker = - logData.getAttributes().get(AttributeKey.stringArrayKey("logback.marker")); - assertThat(logMarker).isEqualTo(Arrays.asList(markerName)); - } - - @Test - void logContextData() { - MDC.put("key1", "val1"); - MDC.put("key2", "val2"); - try { - logger.info("log message 1"); - } finally { - MDC.clear(); - } - - 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(2 + 4); // 4 code attributes - assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))) - .isEqualTo("val1"); - assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) - .isEqualTo("val2"); - } - - @Test - void logContextDataAndLogReplay() { - // Uninstall OpenTelemetry - OpenTelemetryAppender.install(OpenTelemetry.noop()); - - MDC.put("key1", "val1"); - MDC.put("key2", "val2"); - - try { - logger.info("log message 1"); - } finally { - MDC.clear(); - } - - OpenTelemetryAppender.install(openTelemetrySdk); - - 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(2 + 4); // 4 code attributes - assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))) - .isEqualTo("val1"); - assertThat(logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))) - .isEqualTo("val2"); - } } From efc39db229114ebcf72d0dcfc2c227a037b8690c Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 16:38:43 +0100 Subject: [PATCH 38/53] Fix merge conflicts --- .../AbstractOpenTelemetryAppenderTest.java | 50 +++++ .../v1_0/OpenTelemetryAppenderTest.java | 194 ++++-------------- 2 files changed, 86 insertions(+), 158 deletions(-) diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java index f677d726bd20..fceab63edbc4 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java @@ -7,6 +7,8 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.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.sdk.OpenTelemetrySdk; @@ -17,9 +19,12 @@ import io.opentelemetry.sdk.resources.Resource; import io.opentelemetry.sdk.testing.exporter.InMemoryLogRecordExporter; 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.Test; @@ -52,6 +57,29 @@ static void setupAll() { .addLogRecordProcessor(SimpleLogRecordProcessor.create(logRecordExporter)) .build(); openTelemetrySdk = OpenTelemetrySdk.builder().setLoggerProvider(loggerProvider).build(); + // 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); + } } static void generalBeforeEachSetup() { @@ -145,4 +173,26 @@ 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"); + executeAfterLogsExecution(); + } 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/OpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderTest.java index a3a51a11ccc3..7a06887ee639 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 @@ -5,175 +5,53 @@ package io.opentelemetry.instrumentation.logback.appender.v1_0; -import static java.util.Collections.emptyList; - -import ch.qos.logback.classic.LoggerContext; -import ch.qos.logback.classic.spi.ILoggingEvent; -import ch.qos.logback.core.UnsynchronizedAppenderBase; -import io.opentelemetry.api.OpenTelemetry; -import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper; -import java.util.Arrays; +import static org.assertj.core.api.Assertions.assertThat; + +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.context.Scope; +import io.opentelemetry.sdk.logs.data.LogRecordData; +import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; +import io.opentelemetry.sdk.trace.SdkTracerProvider; import java.util.List; -import java.util.concurrent.ArrayBlockingQueue; -import java.util.concurrent.BlockingQueue; -import java.util.concurrent.atomic.AtomicBoolean; -import java.util.stream.Collectors; -import org.slf4j.ILoggerFactory; -import org.slf4j.LoggerFactory; -import org.slf4j.MDC; - -public class OpenTelemetryAppender extends UnsynchronizedAppenderBase { - - private boolean captureExperimentalAttributes = false; - private boolean captureCodeAttributes = false; - private boolean captureMarkerAttribute = false; - private boolean captureKeyValuePairAttributes = false; - private List captureMdcAttributes = emptyList(); - - private volatile OpenTelemetry openTelemetry; - private LoggingEventMapper mapper; - - private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); - private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); - - public OpenTelemetryAppender() {} - - /** - * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in - * the {@link LoggerContext}. - */ - public static void install(OpenTelemetry openTelemetry) { - ILoggerFactory loggerFactorySpi = LoggerFactory.getILoggerFactory(); - if (!(loggerFactorySpi instanceof LoggerContext)) { - return; - } - LoggerContext loggerContext = (LoggerContext) loggerFactorySpi; - for (ch.qos.logback.classic.Logger logger : loggerContext.getLoggerList()) { - logger - .iteratorForAppenders() - .forEachRemaining( - appender -> { - if (appender instanceof OpenTelemetryAppender) { - ((OpenTelemetryAppender) appender).setOpenTelemetry(openTelemetry); - } - }); - } - } - - @Override - public void start() { - mapper = - new LoggingEventMapper( - captureExperimentalAttributes, - captureMdcAttributes, - captureCodeAttributes, - captureMarkerAttribute, - captureKeyValuePairAttributes); - if (openTelemetry == null) { - openTelemetry = OpenTelemetry.noop(); - } - super.start(); - } +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; - @SuppressWarnings("SystemOut") - @Override - protected void append(ILoggingEvent event) { - // TODO(jean): Race condition to fix - // time=1 append() thread gets the no-op instance - // time=2 install() thread updates the instance and flushes the queue - // time=3 append() thread adds the log event to the queue - if (openTelemetry == OpenTelemetry.noop()) { - if (eventsToReplay.remainingCapacity() > 0) { - LoggingEventToReplay logEventToReplay = - new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); - eventsToReplay.offer(logEventToReplay); - } else if (!logCacheWarningDisplayed.getAndSet(true)) { - String message = - "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; - System.err.println(message); - } - return; - } - mapper.emit( - openTelemetry.getLogsBridge(), - new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes), - -1); - } +class OpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { - /** - * Sets whether experimental attributes should be set to logs. These attributes may be changed or - * removed in the future, so only enable this if you know you do not require attributes filled by - * this instrumentation to be stable across versions. - */ - public void setCaptureExperimentalAttributes(boolean captureExperimentalAttributes) { - this.captureExperimentalAttributes = captureExperimentalAttributes; + @BeforeEach + void setup() { + generalBeforeEachSetup(); + OpenTelemetryAppender.install(openTelemetrySdk); } - /** - * Sets whether the code attributes (file name, class name, method name and line number) should be - * set to logs. Enabling these attributes can potentially impact performance (see - * https://logback.qos.ch/manual/layouts.html). - * - * @param captureCodeAttributes To enable or disable the code attributes (file name, class name, - * method name and line number) - */ - public void setCaptureCodeAttributes(boolean captureCodeAttributes) { - this.captureCodeAttributes = captureCodeAttributes; - } + @Test + void logWithSpan() { // Does not work for log replay but it is not likely to occur because + // the log replay is related to the case where an OpenTelemetry object is not yet available + // at the time the log is executed (and if no OpenTelemetry is available, the context + // propagation can't happen) + Span span1 = runWithSpan("span1", () -> logger.info("log message 1")); - /** - * Sets whether the marker attribute should be set to logs. - * - * @param captureMarkerAttribute To enable or disable the marker attribute - */ - public void setCaptureMarkerAttribute(boolean captureMarkerAttribute) { - this.captureMarkerAttribute = captureMarkerAttribute; - } + logger.info("log message 2"); - /** - * Sets whether the key value pair attributes should be set to logs. - * - * @param captureKeyValuePairAttributes To enable or disable the marker attribute - */ - public void setCaptureKeyValuePairAttributes(boolean captureKeyValuePairAttributes) { - this.captureKeyValuePairAttributes = captureKeyValuePairAttributes; - } + executeAfterLogsExecution(); - /** Configures the {@link MDC} attributes that will be copied to logs. */ - public void setCaptureMdcAttributes(String attributes) { - if (attributes != null) { - captureMdcAttributes = filterBlanksAndNulls(attributes.split(",")); - } else { - captureMdcAttributes = emptyList(); - } - } + Span span2 = runWithSpan("span2", () -> logger.info("log message 3")); - /** - * Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an - * {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used to - * replay the first logs. - */ - public void setFirstLogsCacheSize(int size) { - eventsToReplay = new ArrayBlockingQueue<>(size); + List logDataList = logRecordExporter.getFinishedLogRecordItems(); + assertThat(logDataList).hasSize(3); + OpenTelemetryAssertions.assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); + OpenTelemetryAssertions.assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); + OpenTelemetryAssertions.assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); } - /** - * Configures the {@link OpenTelemetry} used to append logs. This MUST be called for the appender - * to function. See {@link #install(OpenTelemetry)} for simple installation option. - */ - public void setOpenTelemetry(OpenTelemetry openTelemetry) { - this.openTelemetry = openTelemetry; - LoggingEventToReplay eventToReplay; - while ((eventToReplay = eventsToReplay.poll()) != null) { - mapper.emit(openTelemetry.getLogsBridge(), eventToReplay, -1); + private static Span runWithSpan(String spanName, Runnable runnable) { + Span span = SdkTracerProvider.builder().build().get("tracer").spanBuilder(spanName).startSpan(); + try (Scope ignored = span.makeCurrent()) { + runnable.run(); + } finally { + span.end(); } - } - - // copied from SDK's DefaultConfigProperties - private static List filterBlanksAndNulls(String[] values) { - return Arrays.stream(values) - .map(String::trim) - .filter(s -> !s.isEmpty()) - .collect(Collectors.toList()); + return span; } } From 4a528195a6a2deefa2afdff9cb381d3d3ee5827d Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 16:56:12 +0100 Subject: [PATCH 39/53] Rename configuration property --- instrumentation/log4j/log4j-appender-2.17/library/README.md | 2 +- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 2 +- .../log4j-appender-2.17/library/src/test/resources/log4j2.xml | 2 +- instrumentation/logback/logback-appender-1.0/library/README.md | 2 +- .../logback/appender/v1_0/OpenTelemetryAppender.java | 2 +- .../library/src/test/resources/logback-test.xml | 2 +- 6 files changed, 6 insertions(+), 6 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/README.md b/instrumentation/log4j/log4j-appender-2.17/library/README.md index 3b97c8ef0a39..dc301b888b94 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/README.md +++ b/instrumentation/log4j/log4j-appender-2.17/library/README.md @@ -99,6 +99,6 @@ The available settings are: | `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. | | `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. | | `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. | -| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | +| `numLogsCapturedBeforeOtelInstall` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index be34a5708ce3..920e058f6027 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -136,7 +136,7 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) { * Logback appender. */ @CanIgnoreReturnValue - public B setFirstLogsCacheSize(int firstLogsCacheSize) { + public B setNumLogsCapturedBeforeOtelInstall(int firstLogsCacheSize) { this.firstLogsCacheSize = firstLogsCacheSize; return asBuilder(); } diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml b/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml index 3617ee3cf600..818a1c3623c8 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml @@ -7,7 +7,7 @@ pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} traceId: %X{trace_id} spanId: %X{span_id} flags: %X{trace_flags} - %msg%n"/> - + diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index d23c0ba94275..14cbbabe8885 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -101,7 +101,7 @@ The available settings are: | `captureKeyValuePairAttributes` | Boolean | `false` | Enable the capture of Logback key value pairs as attributes. | | `captureMdcAttributes` | String | | Comma separated list of MDC attributes to capture. Use the wildcard character `*` to capture all attributes. | | `otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes` | Boolean | `false` | Enable the capture of Logback logger context properties as attributes. | -| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. thread.id attribute is not captured. | +| `numLogsCapturedBeforeOtelInstall`| Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. thread.id attribute is not captured. | [source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.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 b3a0a6c3ebb9..09e84bdab9eb 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 @@ -164,7 +164,7 @@ public void setCaptureMdcAttributes(String attributes) { * {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used to * replay the first logs. */ - public void setFirstLogsCacheSize(int size) { + public void setNumLogsCapturedBeforeOtelInstall(int size) { eventsToReplay = new ArrayBlockingQueue<>(size); } 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 a97c43062fb0..7bc078e69050 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 @@ -15,7 +15,7 @@ true true * - 1 + 1 From dcb0530ce9177906519b377352715d46f633390d Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 16:57:56 +0100 Subject: [PATCH 40/53] Update instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java Co-authored-by: Trask Stalnaker --- .../instrumentation/log4j/appender/v2_17/LogEventToReplay.java | 2 -- 1 file changed, 2 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java index 4302df0fa5fb..d0b887450703 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java @@ -36,8 +36,6 @@ class LogEventToReplay implements LogEvent { private final String threadName; private final long threadId; - // Log4j 2 reuses LogEvent object, so we make a copy to be able to - // replay the log event later. LogEventToReplay(LogEvent logEvent) { this.loggerName = logEvent.getLoggerName(); Message messageOrigin = logEvent.getMessage(); From 352f8437943224b8734069557e07a497cbd994f7 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 17:03:52 +0100 Subject: [PATCH 41/53] Renaming --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 4 ++-- .../logback/appender/v1_0/OpenTelemetryAppender.java | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 920e058f6027..01043eac30b5 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -53,7 +53,7 @@ public class OpenTelemetryAppender extends AbstractAppender { private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); - private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); + private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); /** * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in @@ -231,7 +231,7 @@ public void append(LogEvent event) { if (eventsToReplay.remainingCapacity() > 0) { LogEventToReplay logEventToReplay = new LogEventToReplay(event); eventsToReplay.offer(logEventToReplay); - } else if (!logCacheWarningDisplayed.getAndSet(true)) { + } else if (!replayLimitWarningLogged.getAndSet(true)) { System.err.println( "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased"); } 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 09e84bdab9eb..34552fae0c4f 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 @@ -35,7 +35,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(1000); - private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean(); + private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); public OpenTelemetryAppender() {} @@ -89,7 +89,7 @@ protected void append(ILoggingEvent event) { LoggingEventToReplay logEventToReplay = new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); eventsToReplay.offer(logEventToReplay); - } else if (!logCacheWarningDisplayed.getAndSet(true)) { + } else if (!replayLimitWarningLogged.getAndSet(true)) { String message = "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; System.err.println(message); From a5343559aa04cc99069604ad71463945341f9439 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 17:07:01 +0100 Subject: [PATCH 42/53] Add comment --- .../logback/appender/v1_0/LoggingEventToReplay.java | 1 + 1 file changed, 1 insertion(+) diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java index bef7eb6585e2..01fe84084f7d 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java @@ -26,6 +26,7 @@ class LoggingEventToReplay implements ILoggingEvent { boolean captureExperimentalAttributes, boolean captureCodeAttributes) { this.loggingEvent = loggingEvent; + // The values are copied because the current values are not more available when the log is replayed this.timeStamp = loggingEvent.getTimeStamp(); if (captureExperimentalAttributes) { this.threadName = loggingEvent.getThreadName(); From 8ecbde10910cfd0f8d9af80ef1689c00952c2e5f Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 17:10:06 +0100 Subject: [PATCH 43/53] Static import --- .../logback/appender/v1_0/LoggingEventToReplay.java | 3 ++- .../logback/appender/v1_0/OpenTelemetryAppenderTest.java | 9 ++++----- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java index 01fe84084f7d..ae19b2185704 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LoggingEventToReplay.java @@ -26,7 +26,8 @@ class LoggingEventToReplay implements ILoggingEvent { boolean captureExperimentalAttributes, boolean captureCodeAttributes) { this.loggingEvent = loggingEvent; - // The values are copied because the current values are not more available when the log is replayed + // The values are copied because the current values are not more available when the log is + // replayed this.timeStamp = loggingEvent.getTimeStamp(); if (captureExperimentalAttributes) { this.threadName = loggingEvent.getThreadName(); 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 7a06887ee639..0b85ea22d4bc 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 @@ -5,13 +5,12 @@ package io.opentelemetry.instrumentation.logback.appender.v1_0; -import static org.assertj.core.api.Assertions.assertThat; +import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.context.Scope; import io.opentelemetry.sdk.logs.data.LogRecordData; -import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import io.opentelemetry.sdk.trace.SdkTracerProvider; import java.util.List; import org.junit.jupiter.api.BeforeEach; @@ -40,9 +39,9 @@ void logWithSpan() { // Does not work for log replay but it is not likely to occ List logDataList = logRecordExporter.getFinishedLogRecordItems(); assertThat(logDataList).hasSize(3); - OpenTelemetryAssertions.assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); - OpenTelemetryAssertions.assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); - OpenTelemetryAssertions.assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); + assertThat(logDataList.get(0)).hasSpanContext(span1.getSpanContext()); + assertThat(logDataList.get(1)).hasSpanContext(SpanContext.getInvalid()); + assertThat(logDataList.get(2)).hasSpanContext(span2.getSpanContext()); } private static Span runWithSpan(String spanName, Runnable runnable) { From 08d85a9d0c12191ba77a374cb023c30a1767f1a5 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 17:22:51 +0100 Subject: [PATCH 44/53] final --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 01043eac30b5..da2bcdc058e8 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -51,7 +51,7 @@ public class OpenTelemetryAppender extends AbstractAppender { private final LogEventMapper mapper; private volatile OpenTelemetry openTelemetry; - private BlockingQueue eventsToReplay = new ArrayBlockingQueue<>(1000); + private final BlockingQueue eventsToReplay; private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); @@ -195,6 +195,8 @@ private OpenTelemetryAppender( this.openTelemetry = openTelemetry; if (firstLogsCacheSize != 0) { this.eventsToReplay = new ArrayBlockingQueue<>(firstLogsCacheSize); + } else { + this.eventsToReplay = new ArrayBlockingQueue<>(1000); } } From 839216ae649d7a3f8315957a4c8208b82f864180 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Thu, 16 Nov 2023 19:27:38 +0100 Subject: [PATCH 45/53] Fix merge issue --- instrumentation/logback/logback-appender-1.0/library/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/instrumentation/logback/logback-appender-1.0/library/README.md b/instrumentation/logback/logback-appender-1.0/library/README.md index 14cbbabe8885..1cfa458571ac 100644 --- a/instrumentation/logback/logback-appender-1.0/library/README.md +++ b/instrumentation/logback/logback-appender-1.0/library/README.md @@ -99,8 +99,8 @@ The available settings are: | `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. | -| `otel.instrumentation.logback-appender.experimental.capture-logger-context-attributes` | Boolean | `false` | Enable the capture of Logback logger context properties as attributes. | | `numLogsCapturedBeforeOtelInstall`| Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. thread.id attribute is not captured. | From fcb95bedc9c2b225eb000706c4dc4f3acbf42ee5 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Thu, 16 Nov 2023 19:02:14 -0800 Subject: [PATCH 46/53] use readwritelock --- .../appender/v1_0/OpenTelemetryAppender.java | 60 ++++++++++++------- .../AbstractOpenTelemetryAppenderTest.java | 2 +- .../LogReplayOpenTelemetryAppenderTest.java | 21 ++++++- 3 files changed, 57 insertions(+), 26 deletions(-) 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 34552fae0c4f..11eee9af7190 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 @@ -12,11 +12,15 @@ import ch.qos.logback.core.UnsynchronizedAppenderBase; import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.instrumentation.logback.appender.v1_0.internal.LoggingEventMapper; +import java.util.ArrayList; import java.util.Arrays; import java.util.List; import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.BlockingQueue; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.locks.Lock; +import java.util.concurrent.locks.ReadWriteLock; +import java.util.concurrent.locks.ReentrantReadWriteLock; import java.util.stream.Collectors; import org.slf4j.ILoggerFactory; import org.slf4j.LoggerFactory; @@ -37,6 +41,8 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(1000); private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); + private final ReadWriteLock lock = new ReentrantReadWriteLock(); + public OpenTelemetryAppender() {} /** @@ -71,35 +77,32 @@ public void start() { captureMarkerAttribute, captureKeyValuePairAttributes, captureLoggerContext); - if (openTelemetry == null) { - openTelemetry = OpenTelemetry.noop(); - } super.start(); } @SuppressWarnings("SystemOut") @Override protected void append(ILoggingEvent event) { - // TODO(jean): Race condition to fix - // time=1 append() thread gets the no-op instance - // time=2 install() thread updates the instance and flushes the queue - // time=3 append() thread adds the log event to the queue - if (openTelemetry == OpenTelemetry.noop()) { - if (eventsToReplay.remainingCapacity() > 0) { - LoggingEventToReplay logEventToReplay = - new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); - eventsToReplay.offer(logEventToReplay); - } else if (!replayLimitWarningLogged.getAndSet(true)) { + Lock readLock = lock.readLock(); + readLock.lock(); + try { + OpenTelemetry openTelemetry = this.openTelemetry; + if (openTelemetry != null) { + emit(openTelemetry, event); + return; + } + + LoggingEventToReplay logEventToReplay = + new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes); + + if (!eventsToReplay.offer(logEventToReplay) && !replayLimitWarningLogged.getAndSet(true)) { String message = "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; System.err.println(message); } - return; + } finally { + readLock.unlock(); } - mapper.emit( - openTelemetry.getLogsBridge(), - new LoggingEventToReplay(event, captureExperimentalAttributes, captureCodeAttributes), - -1); } /** @@ -173,13 +176,26 @@ public void setNumLogsCapturedBeforeOtelInstall(int size) { * to function. See {@link #install(OpenTelemetry)} for simple installation option. */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { - this.openTelemetry = openTelemetry; - LoggingEventToReplay eventToReplay; - while ((eventToReplay = eventsToReplay.poll()) != null) { - mapper.emit(openTelemetry.getLogsBridge(), eventToReplay, -1); + List eventsToReplay = new ArrayList<>(); + Lock writeLock = lock.writeLock(); + writeLock.lock(); + try { + // minimize scope of write lock + this.openTelemetry = openTelemetry; + this.eventsToReplay.drainTo(eventsToReplay); + } finally { + writeLock.unlock(); + } + // now emit + for (LoggingEventToReplay eventToReplay : eventsToReplay) { + emit(openTelemetry, eventToReplay); } } + private void emit(OpenTelemetry openTelemetry, ILoggingEvent event) { + mapper.emit(openTelemetry.getLogsBridge(), event, -1); + } + // copied from SDK's DefaultConfigProperties private static List filterBlanksAndNulls(String[] values) { return Arrays.stream(values) diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java index fceab63edbc4..dea7610db9f3 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/AbstractOpenTelemetryAppenderTest.java @@ -61,7 +61,7 @@ static void setupAll() { resetLoggerContext(); } - private static void resetLoggerContext() { + static void resetLoggerContext() { try { LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); Field field = ContextBase.class.getDeclaredField("propertyMap"); diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java index fdb8674a78b3..f398fe2b0c31 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java @@ -7,19 +7,34 @@ import static org.assertj.core.api.Assertions.assertThat; -import io.opentelemetry.api.OpenTelemetry; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.util.ContextInitializer; +import ch.qos.logback.core.joran.spi.JoranException; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; +import java.net.URL; import java.util.List; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { @BeforeEach - void setup() { + void setup() throws JoranException { generalBeforeEachSetup(); - OpenTelemetryAppender.install(OpenTelemetry.noop()); + // to make sure we start fresh with a new OpenTelemetryAppender for each test + reloadLoggerConfiguration(); + } + + private static void reloadLoggerConfiguration() throws JoranException { + LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); + ContextInitializer ci = new ContextInitializer(loggerContext); + URL url = ci.findURLOfDefaultConfigurationFile(true); + loggerContext.reset(); + ci.configureByResource(url); + // by default LoggerContext contains HOSTNAME property we clear it to start with empty context + resetLoggerContext(); } @Override From 9f473db049791286705cb355bf72d3ccacb8c9a0 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 17 Nov 2023 14:09:47 +0100 Subject: [PATCH 47/53] Fix tests --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index da2bcdc058e8..4cc203338015 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -89,7 +89,7 @@ public static class Builder> extends AbstractAppender.Build @PluginBuilderAttribute private boolean captureMapMessageAttributes; @PluginBuilderAttribute private boolean captureMarkerAttribute; @PluginBuilderAttribute private String captureContextDataAttributes; - @PluginBuilderAttribute private int firstLogsCacheSize; + @PluginBuilderAttribute private int numLogsCapturedBeforeOtelInstall; @Nullable private OpenTelemetry openTelemetry; @@ -136,8 +136,8 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) { * Logback appender. */ @CanIgnoreReturnValue - public B setNumLogsCapturedBeforeOtelInstall(int firstLogsCacheSize) { - this.firstLogsCacheSize = firstLogsCacheSize; + public B setNumLogsCapturedBeforeOtelInstall(int numLogsCapturedBeforeOtelInstall) { + this.numLogsCapturedBeforeOtelInstall = numLogsCapturedBeforeOtelInstall; return asBuilder(); } @@ -164,7 +164,7 @@ public OpenTelemetryAppender build() { captureMapMessageAttributes, captureMarkerAttribute, captureContextDataAttributes, - firstLogsCacheSize, + numLogsCapturedBeforeOtelInstall, openTelemetry); } } From d2eff966824df6451fc9028dc8721d21fa777bbb Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 17 Nov 2023 14:50:54 +0100 Subject: [PATCH 48/53] Create queue in the start() method + renaming --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 8 ++++---- .../logback/appender/v1_0/OpenTelemetryAppender.java | 9 ++++++--- 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 4cc203338015..fb537405704a 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -179,7 +179,7 @@ private OpenTelemetryAppender( boolean captureMapMessageAttributes, boolean captureMarkerAttribute, String captureContextDataAttributes, - int firstLogsCacheSize, + int numLogsCapturedBeforeOtelInstall, OpenTelemetry openTelemetry) { super(name, filter, layout, ignoreExceptions, properties); @@ -193,8 +193,8 @@ private OpenTelemetryAppender( captureMarkerAttribute, captureContextDataAttributesAsList); this.openTelemetry = openTelemetry; - if (firstLogsCacheSize != 0) { - this.eventsToReplay = new ArrayBlockingQueue<>(firstLogsCacheSize); + if (numLogsCapturedBeforeOtelInstall != 0) { + this.eventsToReplay = new ArrayBlockingQueue<>(numLogsCapturedBeforeOtelInstall); } else { this.eventsToReplay = new ArrayBlockingQueue<>(1000); } @@ -235,7 +235,7 @@ public void append(LogEvent event) { eventsToReplay.offer(logEventToReplay); } else if (!replayLimitWarningLogged.getAndSet(true)) { System.err.println( - "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased"); + "numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small."); } return; } 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 11eee9af7190..5218fc57f2d5 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 @@ -38,7 +38,9 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase eventsToReplay = new ArrayBlockingQueue<>(1000); + private int numLogsCapturedBeforeOtelInstall = 1000; + private BlockingQueue eventsToReplay = + new ArrayBlockingQueue<>(numLogsCapturedBeforeOtelInstall); private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); private final ReadWriteLock lock = new ReentrantReadWriteLock(); @@ -77,6 +79,7 @@ public void start() { captureMarkerAttribute, captureKeyValuePairAttributes, captureLoggerContext); + eventsToReplay = new ArrayBlockingQueue<>(numLogsCapturedBeforeOtelInstall); super.start(); } @@ -97,7 +100,7 @@ protected void append(ILoggingEvent event) { if (!eventsToReplay.offer(logEventToReplay) && !replayLimitWarningLogged.getAndSet(true)) { String message = - "Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased;"; + "numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small."; System.err.println(message); } } finally { @@ -168,7 +171,7 @@ public void setCaptureMdcAttributes(String attributes) { * replay the first logs. */ public void setNumLogsCapturedBeforeOtelInstall(int size) { - eventsToReplay = new ArrayBlockingQueue<>(size); + this.numLogsCapturedBeforeOtelInstall = size; } /** From 55c3367888e992530c2c96c47cb3262db8dab1c6 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 17 Nov 2023 15:07:52 +0100 Subject: [PATCH 49/53] remove local variable (version on main) --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index fb537405704a..3970032071f7 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -183,15 +183,13 @@ private OpenTelemetryAppender( OpenTelemetry openTelemetry) { super(name, filter, layout, ignoreExceptions, properties); - List captureContextDataAttributesAsList = - splitAndFilterBlanksAndNulls(captureContextDataAttributes); this.mapper = new LogEventMapper<>( ContextDataAccessorImpl.INSTANCE, captureExperimentalAttributes, captureMapMessageAttributes, captureMarkerAttribute, - captureContextDataAttributesAsList); + splitAndFilterBlanksAndNulls(captureContextDataAttributes)); this.openTelemetry = openTelemetry; if (numLogsCapturedBeforeOtelInstall != 0) { this.eventsToReplay = new ArrayBlockingQueue<>(numLogsCapturedBeforeOtelInstall); From fe088b8aff67f0594a4e0015c7ec589c875af0cf Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 17 Nov 2023 16:54:39 +0100 Subject: [PATCH 50/53] Locking for Log4j 2 --- .../appender/v2_17/OpenTelemetryAppender.java | 56 +++++++++++++------ .../LogReplayOpenTelemetryAppenderTest.java | 3 +- 2 files changed, 40 insertions(+), 19 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 3970032071f7..21174074b6b7 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -13,12 +13,16 @@ import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAccessor; import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper; import java.io.Serializable; +import java.util.ArrayList; import java.util.Arrays; import java.util.List; import java.util.concurrent.ArrayBlockingQueue; import java.util.concurrent.BlockingQueue; import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.locks.Lock; +import java.util.concurrent.locks.ReadWriteLock; +import java.util.concurrent.locks.ReentrantReadWriteLock; import java.util.function.BiConsumer; import java.util.stream.Collectors; import javax.annotation.Nullable; @@ -55,6 +59,8 @@ public class OpenTelemetryAppender extends AbstractAppender { private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean(); + private final ReadWriteLock lock = new ReentrantReadWriteLock(); + /** * Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in * the {@link LoggerContext}. @@ -213,38 +219,54 @@ private static List splitAndFilterBlanksAndNulls(String value) { * to function. See {@link #install(OpenTelemetry)} for simple installation option. */ public void setOpenTelemetry(OpenTelemetry openTelemetry) { - this.openTelemetry = openTelemetry; - LogEventToReplay eventToReplay; - while ((eventToReplay = eventsToReplay.poll()) != null) { - append(eventToReplay); + List eventsToReplay = new ArrayList<>(); + Lock writeLock = lock.writeLock(); + writeLock.lock(); + try { + // minimize scope of write lock + this.openTelemetry = openTelemetry; + this.eventsToReplay.drainTo(eventsToReplay); + } finally { + writeLock.unlock(); + } + // now emit + for (LogEventToReplay eventToReplay : eventsToReplay) { + emit(openTelemetry, eventToReplay); } } @SuppressWarnings("SystemOut") @Override public void append(LogEvent event) { - // TODO(jean): Race condition to fix - // time=1 append() thread gets the no-op instance - // time=2 install() thread updates the instance and flushes the queue - // time=3 append() thread adds the log event to the queue - if (openTelemetry == OpenTelemetry.noop()) { - if (eventsToReplay.remainingCapacity() > 0) { - LogEventToReplay logEventToReplay = new LogEventToReplay(event); - eventsToReplay.offer(logEventToReplay); - } else if (!replayLimitWarningLogged.getAndSet(true)) { - System.err.println( - "numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small."); + Lock readLock = lock.readLock(); + readLock.lock(); + try { + OpenTelemetry openTelemetry = this.openTelemetry; + if (openTelemetry != null) { + emit(openTelemetry, event); + return; } - return; + + LogEventToReplay logEventToReplay = new LogEventToReplay(event); + + if (!eventsToReplay.offer(logEventToReplay) && !replayLimitWarningLogged.getAndSet(true)) { + String message = + "numLogsCapturedBeforeOtelInstall value of the OpenTelemetry appender is too small."; + System.err.println(message); + } + } finally { + readLock.unlock(); } + } + private void emit(OpenTelemetry openTelemetry, LogEvent event) { String instrumentationName = event.getLoggerName(); if (instrumentationName == null || instrumentationName.isEmpty()) { instrumentationName = "ROOT"; } LogRecordBuilder builder = - this.openTelemetry + openTelemetry .getLogsBridge() .loggerBuilder(instrumentationName) .build() diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java index e16e46fa1a13..8c65f7761b6b 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java @@ -9,7 +9,6 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.equalTo; import static org.assertj.core.api.Assertions.assertThat; -import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import java.util.List; @@ -23,7 +22,7 @@ class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTe @BeforeEach void setup() { generalBeforeEachSetup(); - OpenTelemetryAppender.install(OpenTelemetry.noop()); + OpenTelemetryAppender.install(null); } @Override From dbb3b7696e2818e4eecbd76fc470fe7984855739 Mon Sep 17 00:00:00 2001 From: Jean Bisutti Date: Fri, 17 Nov 2023 16:59:49 +0100 Subject: [PATCH 51/53] fix spotless --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index 21174074b6b7..ac7fbcf1a501 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -266,11 +266,7 @@ private void emit(OpenTelemetry openTelemetry, LogEvent event) { } LogRecordBuilder builder = - openTelemetry - .getLogsBridge() - .loggerBuilder(instrumentationName) - .build() - .logRecordBuilder(); + openTelemetry.getLogsBridge().loggerBuilder(instrumentationName).build().logRecordBuilder(); ReadOnlyStringMap contextData = event.getContextData(); mapper.mapLogEvent( builder, From e3168ba2c42e6530f8c50292e893b73283edca23 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Fri, 17 Nov 2023 09:00:48 -0800 Subject: [PATCH 52/53] Fix test latest deps --- .../LogReplayOpenTelemetryAppenderTest.java | 27 +++++++++++++------ 1 file changed, 19 insertions(+), 8 deletions(-) diff --git a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java index f398fe2b0c31..50625dcd14ef 100644 --- a/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java +++ b/instrumentation/logback/logback-appender-1.0/library/src/test/java/io/opentelemetry/instrumentation/logback/appender/v1_0/LogReplayOpenTelemetryAppenderTest.java @@ -9,7 +9,7 @@ import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.util.ContextInitializer; -import ch.qos.logback.core.joran.spi.JoranException; +import ch.qos.logback.core.spi.ContextAware; import io.opentelemetry.sdk.logs.data.LogRecordData; import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions; import java.net.URL; @@ -21,20 +21,31 @@ class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTest { @BeforeEach - void setup() throws JoranException { + void setup() throws Exception { generalBeforeEachSetup(); // to make sure we start fresh with a new OpenTelemetryAppender for each test reloadLoggerConfiguration(); } - private static void reloadLoggerConfiguration() throws JoranException { + private static void reloadLoggerConfiguration() throws Exception { LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory(); - ContextInitializer ci = new ContextInitializer(loggerContext); - URL url = ci.findURLOfDefaultConfigurationFile(true); loggerContext.reset(); - ci.configureByResource(url); - // by default LoggerContext contains HOSTNAME property we clear it to start with empty context - resetLoggerContext(); + try { + Class configuratorClass = + Class.forName("ch.qos.logback.classic.util.DefaultJoranConfigurator"); + Object configurator = configuratorClass.getConstructor().newInstance(); + ((ContextAware) configurator).setContext(loggerContext); + configuratorClass + .getMethod("configure", LoggerContext.class) + .invoke(configurator, loggerContext); + } catch (Exception e) { + // logback versions prior to 1.3.0 + ContextInitializer ci = new ContextInitializer(loggerContext); + URL url = LogReplayOpenTelemetryAppenderTest.class.getResource("/logback-test.xml"); + ContextInitializer.class.getMethod("configureByResource", URL.class).invoke(ci, url); + // by default LoggerContext contains HOSTNAME property we clear it to start with empty context + resetLoggerContext(); + } } @Override From 18d33860d076f0376486c4c2a84da381cbf03ef9 Mon Sep 17 00:00:00 2001 From: Trask Stalnaker Date: Fri, 17 Nov 2023 09:06:06 -0800 Subject: [PATCH 53/53] optimization --- .../log4j/appender/v2_17/OpenTelemetryAppender.java | 9 ++++++++- .../logback/appender/v1_0/OpenTelemetryAppender.java | 9 ++++++++- 2 files changed, 16 insertions(+), 2 deletions(-) diff --git a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java index ac7fbcf1a501..3877296fcf6f 100644 --- a/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java +++ b/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java @@ -238,10 +238,17 @@ public void setOpenTelemetry(OpenTelemetry openTelemetry) { @SuppressWarnings("SystemOut") @Override public void append(LogEvent event) { + OpenTelemetry openTelemetry = this.openTelemetry; + if (openTelemetry != null) { + // optimization to avoid locking after the OpenTelemetry instance is set + emit(openTelemetry, event); + return; + } + Lock readLock = lock.readLock(); readLock.lock(); try { - OpenTelemetry openTelemetry = this.openTelemetry; + openTelemetry = this.openTelemetry; if (openTelemetry != null) { emit(openTelemetry, event); return; 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 5218fc57f2d5..de49ee4f0da4 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 @@ -86,10 +86,17 @@ public void start() { @SuppressWarnings("SystemOut") @Override protected void append(ILoggingEvent event) { + OpenTelemetry openTelemetry = this.openTelemetry; + if (openTelemetry != null) { + // optimization to avoid locking after the OpenTelemetry instance is set + emit(openTelemetry, event); + return; + } + Lock readLock = lock.readLock(); readLock.lock(); try { - OpenTelemetry openTelemetry = this.openTelemetry; + openTelemetry = this.openTelemetry; if (openTelemetry != null) { emit(openTelemetry, event); return;