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

Log4j2: add option to fill code attributes (#12592)

This commit is contained in:
Lauri Tulmin 2024-11-14 08:00:56 +02:00 committed by GitHub
parent e91bb38880
commit 15e611e2bb
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
15 changed files with 300 additions and 110 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
instrumentation/log4j/log4j-appender-2.17/javaagent/README.md
View File

@ -1,8 +1,11 @@
# Settings for the Log4j Appender instrumentation
| System property | Type | Default | Description |
|-----------------------------------------------------------------------------------| ------- | ------- |-----------------------------------------------------------------------------------------------------------------------|
| `otel.instrumentation.log4j-appender.experimental-log-attributes` | Boolean | `false` | Enable the capture of experimental log attributes `thread.name` and `thread.id`. |
| `otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
| `otel.instrumentation.log4j-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
| `otel.instrumentation.log4j-appender.experimental.capture-mdc-attributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. |
| System property | Type | Default | Description |
|-----------------------------------------------------------------------------------|---------|---------|-----------------------------------------------------------------------------------------------------------------------------------------------|
| `otel.instrumentation.log4j-appender.experimental-log-attributes` | Boolean | `false` | Enable the capture of experimental log attributes `thread.name` and `thread.id`. |
| `otel.instrumentation.log4j-appender.experimental.capture-code-attributes` | Boolean | `false` | Enable the capture of [source code attributes]. Note that capturing source code attributes at logging sites might add a performance overhead. |
| `otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
| `otel.instrumentation.log4j-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
| `otel.instrumentation.log4j-appender.experimental.capture-mdc-attributes` | String | | 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

5
instrumentation/log4j/log4j-appender-2.17/javaagent/build.gradle.kts
View File

@ -14,7 +14,7 @@ muzzle {
val testLatestDeps = findProperty("testLatestDeps") as Boolean
dependencies {
library("org.apache.logging.log4j:log4j-core:2.17.0")
library("org.apache.logging.log4j:log4j-core:2.0")
compileOnly(project(":javaagent-bootstrap"))
@ -56,9 +56,10 @@ tasks {
tasks.withType<Test>().configureEach {
// TODO run tests both with and without experimental log attributes
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-code-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-map-message-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-mdc-attributes=*")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-marker-attribute=true")
}

7
instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jAppenderInstrumentation.java
View File

@ -73,6 +73,8 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
@Advice.This Logger logger,
@Advice.Argument(0) Level level,
@Advice.Argument(1) Marker marker,
@Advice.Argument(2) String loggerClassName,
@Advice.Argument(3) StackTraceElement location,
@Advice.Argument(4) Message message,
@Advice.Argument(5) Throwable t,
@Advice.Local("otelCallDepth") CallDepth callDepth) {
@ -80,7 +82,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
// logging framework delegates to another
callDepth = CallDepth.forClass(LoggerProvider.class);
if (callDepth.getAndIncrement() == 0) {
Log4jHelper.capture(logger, level, marker, message, t);
Log4jHelper.capture(logger, loggerClassName, location, level, marker, message, t);
}
}
@ -96,6 +98,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void methodEnter(
@Advice.This Logger logger,
@Advice.Argument(0) String loggerClassName,
@Advice.Argument(1) Level level,
@Advice.Argument(2) Marker marker,
@Advice.Argument(3) Message message,
@ -105,7 +108,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
// logging framework delegates to another
callDepth = CallDepth.forClass(LoggerProvider.class);
if (callDepth.getAndIncrement() == 0) {
Log4jHelper.capture(logger, level, marker, message, t);
Log4jHelper.capture(logger, loggerClassName, null, level, marker, message, t);
}
}

60
instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java
View File

@ -14,6 +14,9 @@ import io.opentelemetry.instrumentation.api.incubator.config.internal.Instrument
import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.ContextDataAccessor;
import io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper;
import io.opentelemetry.javaagent.bootstrap.internal.AgentInstrumentationConfig;
import java.lang.invoke.MethodHandle;
import java.lang.invoke.MethodHandles;
import java.lang.invoke.MethodType;
import java.time.Instant;
import java.util.List;
import java.util.Map;
@ -28,14 +31,17 @@ import org.apache.logging.log4j.message.Message;
public final class Log4jHelper {
private static final LogEventMapper<Map<String, String>> mapper;
private static final boolean captureExperimentalAttributes;
private static final MethodHandle stackTraceMethodHandle = getStackTraceMethodHandle();
static {
InstrumentationConfig config = AgentInstrumentationConfig.get();
captureExperimentalAttributes =
config.getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false);
boolean captureCodeAttributes =
config.getBoolean(
"otel.instrumentation.log4j-appender.experimental.capture-code-attributes", false);
boolean captureMapMessageAttributes =
config.getBoolean(
"otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes",
@ -51,13 +57,20 @@ public final class Log4jHelper {
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE,
captureExperimentalAttributes,
captureCodeAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
captureContextDataAttributes);
}
public static void capture(
Logger logger, Level level, Marker marker, Message message, Throwable throwable) {
Logger logger,
String loggerClassName,
StackTraceElement location,
Level level,
Marker marker,
Message message,
Throwable throwable) {
String instrumentationName = logger.getName();
if (instrumentationName == null || instrumentationName.isEmpty()) {
instrumentationName = "ROOT";
@ -86,11 +99,54 @@ public final class Log4jHelper {
contextData,
threadName,
threadId,
() -> location != null ? location : getLocation(loggerClassName),
Context.current());
builder.setTimestamp(Instant.now());
builder.emit();
}
private static StackTraceElement getLocation(String loggerClassName) {
if (stackTraceMethodHandle == null) {
return null;
}
try {
return (StackTraceElement) stackTraceMethodHandle.invoke(loggerClassName);
} catch (Throwable exception) {
return null;
}
}
private static MethodHandle getStackTraceMethodHandle() {
Class<?> stackTraceClass = null;
try {
// since 2.9.0
stackTraceClass = Class.forName("org.apache.logging.log4j.util.StackLocatorUtil");
} catch (ClassNotFoundException exception) {
// ignore
}
if (stackTraceClass == null) {
try {
// before 2.9.0
stackTraceClass = Class.forName("org.apache.logging.log4j.core.impl.Log4jLogEvent");
} catch (ClassNotFoundException exception) {
// ignore
}
}
if (stackTraceClass == null) {
return null;
}
try {
return MethodHandles.lookup()
.findStatic(
stackTraceClass,
"calcLocation",
MethodType.methodType(StackTraceElement.class, String.class));
} catch (Exception exception) {
return null;
}
}
private enum ContextDataAccessorImpl implements ContextDataAccessor<Map<String, String>> {
INSTANCE;

63
instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/Log4j2Test.java
View File

@ -11,6 +11,12 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satis
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FILEPATH;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_NAMESPACE;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
import io.opentelemetry.api.common.AttributeKey;
@ -22,7 +28,6 @@ import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import java.time.Instant;
import java.util.ArrayList;
import java.util.Arrays;
@ -35,6 +40,7 @@ import org.apache.logging.log4j.MarkerManager;
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.message.StringMapMessage;
import org.apache.logging.log4j.message.StructuredDataMessage;
import org.assertj.core.api.AbstractLongAssert;
import org.assertj.core.api.AssertAccess;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;
@ -112,11 +118,12 @@ class Log4j2Test {
List<AttributeAssertion> attributeAsserts =
new ArrayList<>(
Arrays.asList(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "performLogging"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
if (logException) {
attributeAsserts.addAll(
Arrays.asList(
@ -158,9 +165,12 @@ class Log4j2Test {
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "testContextData"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
}
@Test
@ -180,9 +190,12 @@ class Log4j2Test {
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
equalTo(AttributeKey.stringKey("log4j.map_message.key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "testStringMapMessage"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
}
@Test
@ -201,9 +214,12 @@ class Log4j2Test {
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "testStringMapMessageWithSpecialAttribute"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
}
@Test
@ -223,9 +239,12 @@ class Log4j2Test {
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
equalTo(AttributeKey.stringKey("log4j.map_message.key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "testStructuredDataMapMessage"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
}
@Test
@ -238,8 +257,12 @@ class Log4j2Test {
testing.waitAndAssertLogRecords(
logRecord ->
logRecord.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
equalTo(CODE_FUNCTION, "testMarker"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Log4j2Test.java"),
equalTo(AttributeKey.stringKey("log4j.marker"), markerName)));
}

37
instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/Slf4jToLog4jTest.java
View File

@ -11,6 +11,12 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satis
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FILEPATH;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_NAMESPACE;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.logs.Severity;
@ -19,11 +25,11 @@ import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtens
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.stream.Stream;
import org.assertj.core.api.AbstractLongAssert;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;
import org.junit.jupiter.params.ParameterizedTest;
@ -103,11 +109,12 @@ class Slf4jToLog4jTest {
List<AttributeAssertion> attributeAsserts =
new ArrayList<>(
Arrays.asList(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
equalTo(CODE_FUNCTION, "performLogging"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java")));
if (logException) {
attributeAsserts.addAll(
Arrays.asList(
@ -145,14 +152,16 @@ class Slf4jToLog4jTest {
.hasAttributesSatisfyingExactly(
equalTo(AttributeKey.stringKey("key1"), "val1"),
equalTo(AttributeKey.stringKey("key2"), "val2"),
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
equalTo(CODE_FUNCTION, "testMdc"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java")));
}
@Test
public void testMarker() {
String markerName = "aMarker";
Marker marker = MarkerFactory.getMarker(markerName);
@ -161,8 +170,12 @@ class Slf4jToLog4jTest {
testing.waitAndAssertLogRecords(
logRecord ->
logRecord.hasAttributesSatisfyingExactly(
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
equalTo(CODE_FUNCTION, "testMarker"),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java"),
equalTo(AttributeKey.stringKey("log4j.marker"), markerName)));
}

3
instrumentation/log4j/log4j-appender-2.17/library/README.md
View File

@ -95,7 +95,10 @@ The available settings are:
| XML Attribute | Type | Default | Description |
|------------------------------------|---------|---------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental log 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. |
| `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. |
| `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

1
instrumentation/log4j/log4j-appender-2.17/library/build.gradle.kts
View File

@ -18,6 +18,7 @@ dependencies {
tasks {
withType<Test>().configureEach {
systemProperty("testLatestDeps", findProperty("testLatestDeps") as Boolean)
jvmArgs("-Dotel.instrumentation.common.experimental.controller-telemetry.enabled=true")
}

6
instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogEventToReplay.java
View File

@ -36,8 +36,9 @@ class LogEventToReplay implements LogEvent {
private final ReadOnlyStringMap contextData;
private final String threadName;
private final long threadId;
private final StackTraceElement source;
LogEventToReplay(LogEvent logEvent) {
LogEventToReplay(LogEvent logEvent, boolean captureCodeAttributes) {
this.loggerName = logEvent.getLoggerName();
Message messageOrigin = logEvent.getMessage();
if (messageOrigin instanceof StructuredDataMessage) {
@ -64,6 +65,7 @@ class LogEventToReplay implements LogEvent {
this.contextData = new SortedArrayStringMap(logEvent.getContextData());
this.threadName = logEvent.getThreadName();
this.threadId = logEvent.getThreadId();
this.source = captureCodeAttributes ? logEvent.getSource() : null;
}
@Override
@ -125,7 +127,7 @@ class LogEventToReplay implements LogEvent {
@Override
public StackTraceElement getSource() {
return null;
return source;
}
@Override

25
instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java
View File

@ -62,10 +62,9 @@ public class OpenTelemetryAppender extends AbstractAppender {
private volatile OpenTelemetry openTelemetry;
private final BlockingQueue<LogEventToReplay> eventsToReplay;
private final AtomicBoolean replayLimitWarningLogged = new AtomicBoolean();
private final ReadWriteLock lock = new ReentrantReadWriteLock();
private final boolean captureCodeAttributes;
/**
* Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in
@ -98,6 +97,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
implements org.apache.logging.log4j.core.util.Builder<OpenTelemetryAppender> {
@PluginBuilderAttribute private boolean captureExperimentalAttributes;
@PluginBuilderAttribute private boolean captureCodeAttributes;
@PluginBuilderAttribute private boolean captureMapMessageAttributes;
@PluginBuilderAttribute private boolean captureMarkerAttribute;
@PluginBuilderAttribute private String captureContextDataAttributes;
@ -116,6 +116,20 @@ public class OpenTelemetryAppender extends AbstractAppender {
return asBuilder();
}
/**
* 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://logging.apache.org/log4j/2.x/manual/performance.html#layouts-location).
*
* @param captureCodeAttributes To enable or disable the code attributes (file name, class name,
* method name and line number)
*/
@CanIgnoreReturnValue
public B captureCodeAttributes(boolean captureCodeAttributes) {
this.captureCodeAttributes = captureCodeAttributes;
return asBuilder();
}
/** Sets whether log4j {@link MapMessage} attributes should be copied to logs. */
@CanIgnoreReturnValue
public B setCaptureMapMessageAttributes(boolean captureMapMessageAttributes) {
@ -170,6 +184,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
isIgnoreExceptions(),
getPropertyArray(),
captureExperimentalAttributes,
captureCodeAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
captureContextDataAttributes,
@ -185,6 +200,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
boolean ignoreExceptions,
Property[] properties,
boolean captureExperimentalAttributes,
boolean captureCodeAttributes,
boolean captureMapMessageAttributes,
boolean captureMarkerAttribute,
String captureContextDataAttributes,
@ -196,10 +212,12 @@ public class OpenTelemetryAppender extends AbstractAppender {
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE,
captureExperimentalAttributes,
captureCodeAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
splitAndFilterBlanksAndNulls(captureContextDataAttributes));
this.openTelemetry = openTelemetry;
this.captureCodeAttributes = captureCodeAttributes;
if (numLogsCapturedBeforeOtelInstall != 0) {
this.eventsToReplay = new ArrayBlockingQueue<>(numLogsCapturedBeforeOtelInstall);
} else {
@ -257,7 +275,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
return;
}
LogEventToReplay logEventToReplay = new LogEventToReplay(event);
LogEventToReplay logEventToReplay = new LogEventToReplay(event, captureCodeAttributes);
if (!eventsToReplay.offer(logEventToReplay) && !replayLimitWarningLogged.getAndSet(true)) {
String message =
@ -309,6 +327,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
contextData,
event.getThreadName(),
event.getThreadId(),
event::getSource,
context);
Instant timestamp = event.getInstant();

31
instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapper.java
View File

@ -16,6 +16,7 @@ import io.opentelemetry.semconv.ExceptionAttributes;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.List;
import java.util.function.Supplier;
import javax.annotation.Nullable;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
@ -29,6 +30,12 @@ import org.apache.logging.log4j.message.Message;
*/
public final class LogEventMapper<T> {
// copied from CodeIncubatingAttributes
private static final AttributeKey<String> CODE_FILEPATH = AttributeKey.stringKey("code.filepath");
private static final AttributeKey<String> CODE_FUNCTION = AttributeKey.stringKey("code.function");
private static final AttributeKey<Long> CODE_LINENO = AttributeKey.longKey("code.lineno");
private static final AttributeKey<String> CODE_NAMESPACE =
AttributeKey.stringKey("code.namespace");
// copied from ThreadIncubatingAttributes
private static final AttributeKey<Long> THREAD_ID = AttributeKey.longKey("thread.id");
private static final AttributeKey<String> THREAD_NAME = AttributeKey.stringKey("thread.name");
@ -45,6 +52,7 @@ public final class LogEventMapper<T> {
private final ContextDataAccessor<T> contextDataAccessor;
private final boolean captureExperimentalAttributes;
private final boolean captureCodeAttributes;
private final boolean captureMapMessageAttributes;
private final boolean captureMarkerAttribute;
private final List<String> captureContextDataAttributes;
@ -53,11 +61,13 @@ public final class LogEventMapper<T> {
public LogEventMapper(
ContextDataAccessor<T> contextDataAccessor,
boolean captureExperimentalAttributes,
boolean captureCodeAttributes,
boolean captureMapMessageAttributes,
boolean captureMarkerAttribute,
List<String> captureContextDataAttributes) {
this.contextDataAccessor = contextDataAccessor;
this.captureCodeAttributes = captureCodeAttributes;
this.captureExperimentalAttributes = captureExperimentalAttributes;
this.captureMapMessageAttributes = captureMapMessageAttributes;
this.captureMarkerAttribute = captureMarkerAttribute;
@ -71,13 +81,11 @@ public final class LogEventMapper<T> {
*
* <ul>
* <li>Fully qualified class name - {@link LogEvent#getLoggerFqcn()}
* <li>Thread name - {@link LogEvent#getThreadName()}
* <li>Thread id - {@link LogEvent#getThreadId()}
* <li>Thread priority - {@link LogEvent#getThreadPriority()}
* <li>Marker - {@link LogEvent#getMarker()}
* <li>Nested diagnostic context - {@link LogEvent#getContextStack()}
* </ul>
*/
@SuppressWarnings("TooManyParameters")
public void mapLogEvent(
LogRecordBuilder builder,
Message message,
@ -87,6 +95,7 @@ public final class LogEventMapper<T> {
T contextData,
String threadName,
long threadId,
Supplier<StackTraceElement> sourceSupplier,
Context context) {
AttributesBuilder attributes = Attributes.builder();
@ -116,6 +125,22 @@ public final class LogEventMapper<T> {
attributes.put(THREAD_ID, threadId);
}
if (captureCodeAttributes) {
StackTraceElement source = sourceSupplier.get();
if (source != null) {
String fileName = source.getFileName();
if (fileName != null) {
attributes.put(CODE_FILEPATH, fileName);
}
attributes.put(CODE_NAMESPACE, source.getClassName());
attributes.put(CODE_FUNCTION, source.getMethodName());
int lineNumber = source.getLineNumber();
if (lineNumber > 0) {
attributes.put(CODE_LINENO, lineNumber);
}
}
}
builder.setAllAttributes(attributes.build());
builder.setContext(context);
}

108
instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/AbstractOpenTelemetryAppenderTest.java
View File

@ -12,6 +12,12 @@ import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.satis
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FILEPATH;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO;
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_NAMESPACE;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
import io.opentelemetry.api.logs.Severity;
@ -20,8 +26,11 @@ import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.resources.Resource;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import java.time.Instant;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
@ -31,6 +40,7 @@ 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.assertj.core.api.AbstractLongAssert;
import org.assertj.core.api.AssertAccess;
import org.junit.jupiter.api.AfterAll;
import org.junit.jupiter.api.BeforeAll;
@ -96,11 +106,10 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasInstrumentationScope(instrumentationScopeInfo)
.hasBody("log message 1")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
addLocationAttributes(
"logNoSpan",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()))));
}
@Test
@ -130,12 +139,13 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(EXCEPTION_TYPE, IllegalStateException.class.getName()),
equalTo(EXCEPTION_MESSAGE, "Error!"),
satisfies(EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras")));
addLocationAttributes(
"logWithExtras",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(EXCEPTION_TYPE, IllegalStateException.class.getName()),
equalTo(EXCEPTION_MESSAGE, "Error!"),
satisfies(EXCEPTION_STACKTRACE, v -> v.contains("logWithExtras"))));
LogRecordData logRecordData = AssertAccess.getActual(logRecord);
assertThat(logRecordData.getTimestampEpochNanos())
@ -164,13 +174,12 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasInstrumentationScope(instrumentationScopeInfo)
.hasBody("log message 1")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("key1"), "val1"),
equalTo(stringKey("key2"), "val2")));
addLocationAttributes(
"logContextData",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("key1"), "val1"),
equalTo(stringKey("key2"), "val2"))));
}
@Test
@ -189,13 +198,12 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasResource(resource)
.hasInstrumentationScope(instrumentationScopeInfo)
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2")));
addLocationAttributes(
"logStringMapMessage",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2"))));
}
@Test
@ -215,12 +223,11 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasInstrumentationScope(instrumentationScopeInfo)
.hasBody("val2")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1")));
addLocationAttributes(
"logStringMapMessageWithSpecialAttribute",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"))));
}
@Test
@ -255,12 +262,35 @@ abstract class AbstractOpenTelemetryAppenderTest {
.hasInstrumentationScope(instrumentationScopeInfo)
.hasBody("a message")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME,
Thread.currentThread().getName()),
equalTo(
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2")));
addLocationAttributes(
"logStructuredDataMessage",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2"))));
}
private static List<AttributeAssertion> addLocationAttributes(
String methodName, AttributeAssertion... assertions) {
return addLocationAttributes(AbstractOpenTelemetryAppenderTest.class, methodName, assertions);
}
protected static List<AttributeAssertion> addLocationAttributes(
Class<?> testClass, String methodName, AttributeAssertion... assertions) {
String selector = System.getProperty("Log4j2.contextSelector");
boolean async = selector != null && selector.endsWith("AsyncLoggerContextSelector");
if (async && !Boolean.getBoolean("testLatestDeps")) {
// source info is not available by default when async logger is used in non latest dep tests
return Arrays.asList(assertions);
}
List<AttributeAssertion> result = new ArrayList<>(Arrays.asList(assertions));
result.addAll(
Arrays.asList(
equalTo(CODE_NAMESPACE, testClass.getName()),
equalTo(CODE_FUNCTION, methodName),
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
equalTo(CODE_FILEPATH, testClass.getSimpleName() + ".java")));
return result;
}
}

32
instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/LogReplayOpenTelemetryAppenderTest.java
View File

@ -7,10 +7,13 @@ 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 io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.LibraryInstrumentationExtension;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
import java.util.List;
import org.apache.logging.log4j.message.StringMapMessage;
import org.apache.logging.log4j.message.StructuredDataMessage;
import org.junit.jupiter.api.AfterEach;
@ -95,11 +98,12 @@ class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTe
.hasResource(resource)
.hasInstrumentationScope(instrumentationScopeInfo)
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2")));
addLocationAttributes(
"twoLogsStringMapMessage",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2"))));
}
@Test
@ -128,10 +132,16 @@ class LogReplayOpenTelemetryAppenderTest extends AbstractOpenTelemetryAppenderTe
.hasInstrumentationScope(instrumentationScopeInfo)
.hasBody("a message")
.hasAttributesSatisfyingExactly(
equalTo(
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2")));
addLocationAttributes(
"twoLogsStructuredDataMessage",
equalTo(THREAD_NAME, Thread.currentThread().getName()),
equalTo(THREAD_ID, Thread.currentThread().getId()),
equalTo(stringKey("log4j.map_message.key1"), "val1"),
equalTo(stringKey("log4j.map_message.key2"), "val2"))));
}
private static List<AttributeAssertion> addLocationAttributes(
String methodName, AttributeAssertion... assertions) {
return addLocationAttributes(LogReplayOpenTelemetryAppenderTest.class, methodName, assertions);
}
}

15
instrumentation/log4j/log4j-appender-2.17/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/internal/LogEventMapperTest.java
View File

@ -31,7 +31,8 @@ class LogEventMapperTest {
void testDefault() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, false, emptyList());
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, false, emptyList());
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -49,7 +50,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("key2"));
ContextDataAccessorImpl.INSTANCE, false, false, false, false, singletonList("key2"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -67,7 +68,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("*"));
ContextDataAccessorImpl.INSTANCE, false, false, false, false, singletonList("*"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -86,7 +87,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("*"));
ContextDataAccessorImpl.INSTANCE, false, false, false, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -108,7 +109,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, true, false, singletonList("*"));
ContextDataAccessorImpl.INSTANCE, false, false, true, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -130,7 +131,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, true, false, singletonList("*"));
ContextDataAccessorImpl.INSTANCE, false, false, true, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -155,7 +156,7 @@ class LogEventMapperTest {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, true, false, singletonList("*"));
ContextDataAccessorImpl.INSTANCE, false, false, true, false, singletonList("*"));
StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type");
message.put("key1", "value1");

2
instrumentation/log4j/log4j-appender-2.17/library/src/test/resources/log4j2.xml
View File

@ -6,7 +6,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"/>
</Console>
<!-- TODO run tests both with and without experimental log attributes -->
<OpenTelemetry name="OpenTelemetryAppender" numLogsCapturedBeforeOtelInstall="1" captureMapMessageAttributes="true" captureMarkerAttribute="true" captureContextDataAttributes="*" captureExperimentalAttributes="true"/>
<OpenTelemetry name="OpenTelemetryAppender" numLogsCapturedBeforeOtelInstall="1" captureMapMessageAttributes="true" captureMarkerAttribute="true" captureContextDataAttributes="*" captureExperimentalAttributes="true" captureCodeAttributes="true"/>
</Appenders>
<Loggers>
<Logger name="TestLogger" level="All">