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

Add marker attribute for Log4j 2 (#6680) 

Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>
This commit is contained in:
Jean Bisutti 2022-09-22 18:54:37 +02:00 committed by GitHub
parent e7dd21477d
commit 429f083cf7
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
9 changed files with 115 additions and 33 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

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

@ -40,4 +40,5 @@ tasks.withType<Test>().configureEach {
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-map-message-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-context-data-attributes=*")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-marker-attribute=true")
}

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

@ -23,6 +23,7 @@ import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.message.Message;
class Log4jAppenderInstrumentation implements TypeInstrumentation {
@ -60,6 +61,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
public static void methodEnter(
@Advice.This Logger logger,
@Advice.Argument(0) Level level,
@Advice.Argument(1) Marker marker,
@Advice.Argument(4) Message message,
@Advice.Argument(5) Throwable t,
@Advice.Local("otelCallDepth") CallDepth callDepth) {
@ -67,7 +69,7 @@ class Log4jAppenderInstrumentation implements TypeInstrumentation {
// logging framework delegates to another
callDepth = CallDepth.forClass(LogEmitterProvider.class);
if (callDepth.getAndIncrement() == 0) {
Log4jHelper.capture(logger, level, message, t);
Log4jHelper.capture(logger, level, marker, message, t);
}
}

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

@ -18,6 +18,7 @@ import java.util.function.BiConsumer;
import javax.annotation.Nullable;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.message.Message;
@ -34,6 +35,9 @@ public final class Log4jHelper {
config.getBoolean(
"otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes",
false);
boolean captureMarkerAttribute =
config.getBoolean(
"otel.instrumentation.log4j-appender.experimental.capture-marker-attribute", false);
List<String> captureContextDataAttributes =
config.getList(
"otel.instrumentation.log4j-appender.experimental.capture-context-data-attributes",
@ -44,10 +48,12 @@ public final class Log4jHelper {
ContextDataAccessorImpl.INSTANCE,
captureExperimentalAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
captureContextDataAttributes);
}
public static void capture(Logger logger, Level level, Message message, Throwable throwable) {
public static void capture(
Logger logger, Level level, Marker marker, Message message, Throwable throwable) {
String instrumentationName = logger.getName();
if (instrumentationName == null || instrumentationName.isEmpty()) {
instrumentationName = "ROOT";
@ -55,7 +61,7 @@ public final class Log4jHelper {
LogRecordBuilder builder =
AgentLogEmitterProvider.get().logEmitterBuilder(instrumentationName).build().logBuilder();
Map<String, String> contextData = ThreadContext.getImmutableContext();
mapper.mapLogEvent(builder, message, level, throwable, contextData);
mapper.mapLogEvent(builder, message, level, marker, throwable, contextData);
builder.emit();
}

61
instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/groovy/Log4j2Test.groovy
View File

@ -3,12 +3,13 @@
* SPDX-License-Identifier: Apache-2.0
*/
import io.opentelemetry.api.common.AttributeKey
import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification
import io.opentelemetry.sdk.logs.data.Severity
import io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions
import io.opentelemetry.semconv.trace.attributes.SemanticAttributes
import org.apache.logging.log4j.LogManager
import org.apache.logging.log4j.Logger
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
@ -58,17 +59,17 @@ class Log4j2Test extends AgentInstrumentationSpecification {
assertThat(log.getSeverityText()).isEqualTo(severityText)
if (exception) {
assertThat(log.getAttributes().size()).isEqualTo(5)
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isEqualTo(IllegalStateException.getName())
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isEqualTo("hello")
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(Log4j2Test.name)
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.EXCEPTION_TYPE, IllegalStateException.getName())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.EXCEPTION_MESSAGE, "hello")
OpenTelemetryAssertions.assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(Log4j2Test.name)
} else {
assertThat(log.getAttributes().size()).isEqualTo(2)
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isNull()
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isNull()
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).isNull()
}
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_ID, Thread.currentThread().getId())
if (parent) {
assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
} else {
@ -119,10 +120,10 @@ class Log4j2Test extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(4)
assertThat(log.getAttributes().get(AttributeKey.stringKey("log4j.context_data.key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(AttributeKey.stringKey("log4j.context_data.key2"))).isEqualTo("val2")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("log4j.context_data.key1", "val1")
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("log4j.context_data.key2", "val2")
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_ID, Thread.currentThread().getId())
}
def "test string map message"() {
@ -145,10 +146,10 @@ class Log4j2Test extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(4)
assertThat(log.getAttributes().get(AttributeKey.stringKey("key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(AttributeKey.stringKey("key2"))).isEqualTo("val2")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("key1", "val1")
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("key2", "val2")
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_ID, Thread.currentThread().getId())
}
def "test string map message with special attribute"() {
@ -171,9 +172,9 @@ class Log4j2Test extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(3)
assertThat(log.getAttributes().get(AttributeKey.stringKey("key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("key1", "val1")
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName())
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry(SemanticAttributes.THREAD_ID, Thread.currentThread().getId())
}
def "test structured data map message"() {
@ -196,9 +197,27 @@ class Log4j2Test extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(4)
assertThat(log.getAttributes().get(AttributeKey.stringKey("key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(AttributeKey.stringKey("key2"))).isEqualTo("val2")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
OpenTelemetryAssertions.assertThat(log.getAttributes())
.containsEntry("key1","val1")
.containsEntry("key2", "val2")
.containsEntry(SemanticAttributes.THREAD_NAME, Thread.currentThread().getName())
.containsEntry(SemanticAttributes.THREAD_ID, Thread.currentThread().getId())
}
@Unroll
def "marker test"() {
def markerName = "aMarker"
def marker = MarkerManager.getMarker(markerName)
when:
logger.info(marker, "message")
then:
await()
.untilAsserted(
() -> {
assertThat(logs).hasSize(1)
def log = logs.get(0)
OpenTelemetryAssertions.assertThat(log.getAttributes()).containsEntry("log4j.marker", markerName)
})
}
}

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

@ -59,6 +59,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
@PluginBuilderAttribute private boolean captureExperimentalAttributes;
@PluginBuilderAttribute private boolean captureMapMessageAttributes;
@PluginBuilderAttribute private boolean captureMarkerAttribute;
@PluginBuilderAttribute private String captureContextDataAttributes;
/**
@ -77,6 +78,16 @@ public class OpenTelemetryAppender extends AbstractAppender {
return asBuilder();
}
/**
* Sets whether the marker attribute should be set to logs.
*
* @param captureMarkerAttribute To enable or disable the marker attribute
*/
public B setCaptureMarkerAttribute(boolean captureMarkerAttribute) {
this.captureMarkerAttribute = captureMarkerAttribute;
return asBuilder();
}
/** Configures the {@link ThreadContext} attributes that will be copied to logs. */
public B setCaptureContextDataAttributes(String captureContextDataAttributes) {
this.captureContextDataAttributes = captureContextDataAttributes;
@ -93,6 +104,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
getPropertyArray(),
captureExperimentalAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
captureContextDataAttributes);
}
}
@ -105,6 +117,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
Property[] properties,
boolean captureExperimentalAttributes,
boolean captureMapMessageAttributes,
boolean captureMarkerAttribute,
String captureContextDataAttributes) {
super(name, filter, layout, ignoreExceptions, properties);
@ -113,6 +126,7 @@ public class OpenTelemetryAppender extends AbstractAppender {
ContextDataAccessorImpl.INSTANCE,
captureExperimentalAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
splitAndFilterBlanksAndNulls(captureContextDataAttributes));
}
@ -136,7 +150,12 @@ public class OpenTelemetryAppender extends AbstractAppender {
logEmitterProviderHolder.get().logEmitterBuilder(instrumentationName).build().logBuilder();
ReadOnlyStringMap contextData = event.getContextData();
mapper.mapLogEvent(
builder, event.getMessage(), event.getLevel(), event.getThrown(), contextData);
builder,
event.getMessage(),
event.getLevel(),
event.getMarker(),
event.getThrown(),
contextData);
Instant timestamp = event.getInstant();
if (timestamp != null) {

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

@ -18,6 +18,7 @@ import java.io.StringWriter;
import java.util.List;
import javax.annotation.Nullable;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.message.MapMessage;
import org.apache.logging.log4j.message.Message;
@ -35,10 +36,13 @@ public final class LogEventMapper<T> {
private static final Cache<String, AttributeKey<String>> mapMessageAttributeKeyCache =
Cache.bounded(100);
private static final AttributeKey<String> LOG_MARKER = AttributeKey.stringKey("log4j.marker");
private final ContextDataAccessor<T> contextDataAccessor;
private final boolean captureExperimentalAttributes;
private final boolean captureMapMessageAttributes;
private final boolean captureMarkerAttribute;
private final List<String> captureContextDataAttributes;
private final boolean captureAllContextDataAttributes;
@ -46,11 +50,13 @@ public final class LogEventMapper<T> {
ContextDataAccessor<T> contextDataAccessor,
boolean captureExperimentalAttributes,
boolean captureMapMessageAttributes,
boolean captureMarkerAttribute,
List<String> captureContextDataAttributes) {
this.contextDataAccessor = contextDataAccessor;
this.captureExperimentalAttributes = captureExperimentalAttributes;
this.captureMapMessageAttributes = captureMapMessageAttributes;
this.captureMarkerAttribute = captureMarkerAttribute;
this.captureContextDataAttributes = captureContextDataAttributes;
this.captureAllContextDataAttributes =
captureContextDataAttributes.size() == 1 && captureContextDataAttributes.get(0).equals("*");
@ -72,6 +78,7 @@ public final class LogEventMapper<T> {
LogRecordBuilder builder,
Message message,
Level level,
@Nullable Marker marker,
@Nullable Throwable throwable,
T contextData) {
@ -79,6 +86,13 @@ public final class LogEventMapper<T> {
captureMessage(builder, attributes, message);
if (captureMarkerAttribute) {
if (marker != null) {
String markerName = marker.getName();
attributes.put(LOG_MARKER, markerName);
}
}
if (level != null) {
builder.setSeverity(levelToSeverity(level));
builder.setSeverityText(level.name());

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

@ -26,6 +26,8 @@ import java.util.List;
import java.util.concurrent.TimeUnit;
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.message.StringMapMessage;
import org.apache.logging.log4j.message.StructuredDataMessage;
@ -184,6 +186,19 @@ class OpenTelemetryAppenderConfigTest {
assertThat(logData.getAttributes().get(AttributeKey.stringKey("key1"))).isEqualTo("val1");
}
@Test
void testCaptureMarkerAttribute() {
String markerName = "aMarker";
Marker marker = MarkerManager.getMarker(markerName);
logger.info(marker, "Message");
List<LogData> logDataList = logExporter.getFinishedLogItems();
LogData logData = logDataList.get(0);
assertThat(logData.getAttributes().get(AttributeKey.stringKey("log4j.marker")))
.isEqualTo(markerName);
}
@Test
void logStructuredDataMessage() {
StructuredDataMessage message = new StructuredDataMessage("an id", "a message", "a type");

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

@ -32,7 +32,7 @@ class LogEventMapperTest {
void testDefault() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, emptyList());
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, false, emptyList());
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -49,7 +49,8 @@ class LogEventMapperTest {
void testSome() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, singletonList("key2"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("key2"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -67,7 +68,8 @@ class LogEventMapperTest {
void testAll() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, singletonList("*"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("*"));
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
@ -87,7 +89,8 @@ class LogEventMapperTest {
void testCaptureMapMessageDisabled() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, false, singletonList("*"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, false, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -108,7 +111,8 @@ class LogEventMapperTest {
void testCaptureMapMessageWithSpecialAttribute() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, true, singletonList("*"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, true, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -129,7 +133,8 @@ class LogEventMapperTest {
void testCaptureMapMessageWithoutSpecialAttribute() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, true, singletonList("*"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, false, true, false, singletonList("*"));
StringMapMessage message = new StringMapMessage();
message.put("key1", "value1");
@ -153,7 +158,8 @@ class LogEventMapperTest {
void testCaptureStructuredDataMessage() {
// given
LogEventMapper<Map<String, String>> mapper =
new LogEventMapper<>(ContextDataAccessorImpl.INSTANCE, false, true, singletonList("*"));
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE, 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-test.xml
View File

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