Add code attributes for Logback (#6591)

* Add code attributes for Logback

* Rename property

* Add a note about performance

* Add null check on file name

* Add check on line number

* Fix test following new behavior

* spotless

* Update instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java

Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>

* Fix test

* Adapt test for Java 18

* codenarc

* Test fix

Co-authored-by: Trask Stalnaker <trask.stalnaker@gmail.com>
Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>
This commit is contained in:
Jean Bisutti 2022-09-13 09:25:52 -07:00 committed by GitHub
parent 512e9f700c
commit f135169f1d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 76 additions and 13 deletions

View File

@ -54,4 +54,5 @@ tasks.withType<Test>().configureEach {
// TODO run tests both with and without experimental log attributes // TODO run tests both with and without experimental log attributes
jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*") jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-mdc-attributes=*")
jvmArgs("-Dotel.instrumentation.logback-appender.experimental-log-attributes=true") jvmArgs("-Dotel.instrumentation.logback-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-code-attributes=true")
} }

View File

@ -21,12 +21,17 @@ public final class LogbackSingletons {
boolean captureExperimentalAttributes = boolean captureExperimentalAttributes =
config.getBoolean( config.getBoolean(
"otel.instrumentation.logback-appender.experimental-log-attributes", false); "otel.instrumentation.logback-appender.experimental-log-attributes", false);
boolean captureCodeAttributes =
config.getBoolean(
"otel.instrumentation.logback-appender.experimental.capture-code-attributes", false);
List<String> captureMdcAttributes = List<String> captureMdcAttributes =
config.getList( config.getList(
"otel.instrumentation.logback-appender.experimental.capture-mdc-attributes", "otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
emptyList()); emptyList());
mapper = new LoggingEventMapper(captureExperimentalAttributes, captureMdcAttributes); mapper =
new LoggingEventMapper(
captureExperimentalAttributes, captureMdcAttributes, captureCodeAttributes);
} }
public static LoggingEventMapper mapper() { public static LoggingEventMapper mapper() {

View File

@ -44,6 +44,13 @@ class LogbackTest extends AgentInstrumentationSpecification {
waitForTraces(1) waitForTraces(1)
} }
String jvmVersion = System.getProperty("java.vm.specification.version")
int codeAttributes = 3
boolean jvmVersionGreaterThanOrEqualTo18 = !jvmVersion.startsWith("1.8") && Integer.parseInt(jvmVersion) >= 18
if (jvmVersionGreaterThanOrEqualTo18) {
codeAttributes = 4 // Java 18 specificity on line number (lineNumber > 0 check)
}
if (severity != null) { if (severity != null) {
await() await()
.untilAsserted( .untilAsserted(
@ -56,12 +63,12 @@ class LogbackTest extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(severity) assertThat(log.getSeverity()).isEqualTo(severity)
assertThat(log.getSeverityText()).isEqualTo(severityText) assertThat(log.getSeverityText()).isEqualTo(severityText)
if (exception) { if (exception) {
assertThat(log.getAttributes().size()).isEqualTo(5) assertThat(log.getAttributes().size()).isEqualTo(5 + codeAttributes)
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isEqualTo(IllegalStateException.getName()) 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_MESSAGE)).isEqualTo("hello")
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(LogbackTest.name) assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(LogbackTest.name)
} else { } else {
assertThat(log.getAttributes().size()).isEqualTo(2) assertThat(log.getAttributes().size()).isEqualTo(2 + codeAttributes)
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isNull() assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isNull()
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isNull() assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isNull()
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).isNull() assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).isNull()
@ -123,7 +130,7 @@ class LogbackTest extends AgentInstrumentationSpecification {
assertThat(log.getInstrumentationScopeInfo().getName()).isEqualTo("abc") assertThat(log.getInstrumentationScopeInfo().getName()).isEqualTo("abc")
assertThat(log.getSeverity()).isEqualTo(Severity.INFO) assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
assertThat(log.getSeverityText()).isEqualTo("INFO") assertThat(log.getSeverityText()).isEqualTo("INFO")
assertThat(log.getAttributes().size()).isEqualTo(4) assertThat(log.getAttributes().size()).isEqualTo(3 + 3) // 3 code attributes
assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))).isEqualTo("val1") assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))).isEqualTo("val1")
assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))).isEqualTo("val2") assertThat(log.getAttributes().get(AttributeKey.stringKey("logback.mdc.key2"))).isEqualTo("val2")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName()) assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())

View File

@ -25,6 +25,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
new LogEmitterProviderHolder(); new LogEmitterProviderHolder();
private volatile boolean captureExperimentalAttributes = false; private volatile boolean captureExperimentalAttributes = false;
private volatile boolean captureCodeAttributes = false;
private volatile List<String> captureMdcAttributes = emptyList(); private volatile List<String> captureMdcAttributes = emptyList();
private volatile LoggingEventMapper mapper; private volatile LoggingEventMapper mapper;
@ -33,7 +34,9 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
@Override @Override
public void start() { public void start() {
mapper = new LoggingEventMapper(captureExperimentalAttributes, captureMdcAttributes); mapper =
new LoggingEventMapper(
captureExperimentalAttributes, captureMdcAttributes, captureCodeAttributes);
super.start(); super.start();
} }
@ -62,6 +65,18 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
this.captureExperimentalAttributes = captureExperimentalAttributes; this.captureExperimentalAttributes = captureExperimentalAttributes;
} }
/**
* 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;
}
/** Configures the {@link MDC} attributes that will be copied to logs. */ /** Configures the {@link MDC} attributes that will be copied to logs. */
public void setCaptureMdcAttributes(String attributes) { public void setCaptureMdcAttributes(String attributes) {
if (attributes != null) { if (attributes != null) {

View File

@ -34,10 +34,14 @@ public final class LoggingEventMapper {
private final boolean captureExperimentalAttributes; private final boolean captureExperimentalAttributes;
private final List<String> captureMdcAttributes; private final List<String> captureMdcAttributes;
private final boolean captureAllMdcAttributes; private final boolean captureAllMdcAttributes;
private final boolean captureCodeAttributes;
public LoggingEventMapper( public LoggingEventMapper(
boolean captureExperimentalAttributes, List<String> captureMdcAttributes) { boolean captureExperimentalAttributes,
List<String> captureMdcAttributes,
boolean captureCodeAttributes) {
this.captureExperimentalAttributes = captureExperimentalAttributes; this.captureExperimentalAttributes = captureExperimentalAttributes;
this.captureCodeAttributes = captureCodeAttributes;
this.captureMdcAttributes = captureMdcAttributes; this.captureMdcAttributes = captureMdcAttributes;
this.captureAllMdcAttributes = this.captureAllMdcAttributes =
captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*"); captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
@ -104,6 +108,23 @@ public final class LoggingEventMapper {
attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId()); attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId());
} }
if (captureCodeAttributes) {
StackTraceElement[] callerData = loggingEvent.getCallerData();
if (callerData != null && callerData.length > 0) {
StackTraceElement firstStackElement = callerData[0];
String fileName = firstStackElement.getFileName();
if (fileName != null) {
attributes.put(SemanticAttributes.CODE_FILEPATH, fileName);
}
attributes.put(SemanticAttributes.CODE_NAMESPACE, firstStackElement.getClassName());
attributes.put(SemanticAttributes.CODE_FUNCTION, firstStackElement.getMethodName());
int lineNumber = firstStackElement.getLineNumber();
if (lineNumber > 0) {
attributes.put(SemanticAttributes.CODE_LINENO, lineNumber);
}
}
}
builder.setAllAttributes(attributes.build()); builder.setAllAttributes(attributes.build());
// span context // span context

View File

@ -8,7 +8,6 @@ package io.opentelemetry.instrumentation.logback.appender.v1_0;
import static org.assertj.core.api.AssertionsForInterfaceTypes.assertThat; import static org.assertj.core.api.AssertionsForInterfaceTypes.assertThat;
import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.context.Scope; import io.opentelemetry.context.Scope;
@ -71,7 +70,7 @@ class OpenTelemetryAppenderConfigTest {
assertThat(logData.getResource()).isEqualTo(resource); assertThat(logData.getResource()).isEqualTo(resource);
assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo); assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
assertThat(logData.getBody().asString()).isEqualTo("log message 1"); assertThat(logData.getBody().asString()).isEqualTo("log message 1");
assertThat(logData.getAttributes()).isEqualTo(Attributes.empty()); assertThat(logData.getAttributes().size()).isEqualTo(4); // 4 code attributes
} }
@Test @Test
@ -115,13 +114,27 @@ class OpenTelemetryAppenderConfigTest {
.isLessThan(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli())); .isLessThan(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli()));
assertThat(logData.getSeverity()).isEqualTo(Severity.INFO); assertThat(logData.getSeverity()).isEqualTo(Severity.INFO);
assertThat(logData.getSeverityText()).isEqualTo("INFO"); assertThat(logData.getSeverityText()).isEqualTo("INFO");
assertThat(logData.getAttributes().size()).isEqualTo(3); assertThat(logData.getAttributes().size()).isEqualTo(3 + 4); // 4 code attributes
assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)) assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE))
.isEqualTo(IllegalStateException.class.getName()); .isEqualTo(IllegalStateException.class.getName());
assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)) assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE))
.isEqualTo("Error!"); .isEqualTo("Error!");
assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)) assertThat(logData.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE))
.contains("logWithExtras"); .contains("logWithExtras");
String file = logData.getAttributes().get(SemanticAttributes.CODE_FILEPATH);
assertThat(file).isEqualTo("OpenTelemetryAppenderConfigTest.java");
String codeClass = logData.getAttributes().get(SemanticAttributes.CODE_NAMESPACE);
assertThat(codeClass)
.isEqualTo(
"io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppenderConfigTest");
String method = logData.getAttributes().get(SemanticAttributes.CODE_FUNCTION);
assertThat(method).isEqualTo("logWithExtras");
Long lineNumber = logData.getAttributes().get(SemanticAttributes.CODE_LINENO);
assertThat(lineNumber).isGreaterThan(1);
} }
@Test @Test
@ -140,7 +153,7 @@ class OpenTelemetryAppenderConfigTest {
assertThat(logData.getResource()).isEqualTo(resource); assertThat(logData.getResource()).isEqualTo(resource);
assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo); assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
assertThat(logData.getBody().asString()).isEqualTo("log message 1"); assertThat(logData.getBody().asString()).isEqualTo("log message 1");
assertThat(logData.getAttributes().size()).isEqualTo(2); assertThat(logData.getAttributes().size()).isEqualTo(2 + 4); // 4 code attributes
AssertionsForClassTypes.assertThat( AssertionsForClassTypes.assertThat(
logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1"))) logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1")))
.isEqualTo("val1"); .isEqualTo("val1");

View File

@ -22,7 +22,7 @@ class LoggingEventMapperTest {
@Test @Test
void testDefault() { void testDefault() {
// given // given
LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList()); LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList(), false);
Map<String, String> contextData = new HashMap<>(); Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1"); contextData.put("key1", "value1");
contextData.put("key2", "value2"); contextData.put("key2", "value2");
@ -38,7 +38,7 @@ class LoggingEventMapperTest {
@Test @Test
void testSome() { void testSome() {
// given // given
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("key2")); LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("key2"), false);
Map<String, String> contextData = new HashMap<>(); Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1"); contextData.put("key1", "value1");
contextData.put("key2", "value2"); contextData.put("key2", "value2");
@ -55,7 +55,7 @@ class LoggingEventMapperTest {
@Test @Test
void testAll() { void testAll() {
// given // given
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("*")); LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("*"), false);
Map<String, String> contextData = new HashMap<>(); Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1"); contextData.put("key1", "value1");
contextData.put("key2", "value2"); contextData.put("key2", "value2");

View File

@ -11,6 +11,7 @@
<appender name="OpenTelemetry" <appender name="OpenTelemetry"
class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender"> class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
<captureExperimentalAttributes>false</captureExperimentalAttributes> <captureExperimentalAttributes>false</captureExperimentalAttributes>
<captureCodeAttributes>true</captureCodeAttributes>
<captureMdcAttributes>*</captureMdcAttributes> <captureMdcAttributes>*</captureMdcAttributes>
</appender> </appender>