Skip to content

Commit

Permalink
Add code attributes for Logback (#6591)
Browse files Browse the repository at this point in the history
* 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 <[email protected]>

* Fix test

* Adapt test for Java 18

* codenarc

* Test fix

Co-authored-by: Trask Stalnaker <[email protected]>
Co-authored-by: Mateusz Rzeszutek <[email protected]>
  • Loading branch information
3 people authored Sep 13, 2022
1 parent 512e9f7 commit f135169
Show file tree
Hide file tree
Showing 8 changed files with 76 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -54,4 +54,5 @@ tasks.withType<Test>().configureEach {
// 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-log-attributes=true")
jvmArgs("-Dotel.instrumentation.logback-appender.experimental.capture-code-attributes=true")
}
Original file line number Diff line number Diff line change
Expand Up @@ -21,12 +21,17 @@ public final class LogbackSingletons {
boolean captureExperimentalAttributes =
config.getBoolean(
"otel.instrumentation.logback-appender.experimental-log-attributes", false);
boolean captureCodeAttributes =
config.getBoolean(
"otel.instrumentation.logback-appender.experimental.capture-code-attributes", false);
List<String> captureMdcAttributes =
config.getList(
"otel.instrumentation.logback-appender.experimental.capture-mdc-attributes",
emptyList());

mapper = new LoggingEventMapper(captureExperimentalAttributes, captureMdcAttributes);
mapper =
new LoggingEventMapper(
captureExperimentalAttributes, captureMdcAttributes, captureCodeAttributes);
}

public static LoggingEventMapper mapper() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,13 @@ class LogbackTest extends AgentInstrumentationSpecification {
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) {
await()
.untilAsserted(
Expand All @@ -56,12 +63,12 @@ class LogbackTest extends AgentInstrumentationSpecification {
assertThat(log.getSeverity()).isEqualTo(severity)
assertThat(log.getSeverityText()).isEqualTo(severityText)
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_MESSAGE)).isEqualTo("hello")
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(LogbackTest.name)
} 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_MESSAGE)).isNull()
assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).isNull()
Expand Down Expand Up @@ -123,7 +130,7 @@ class LogbackTest extends AgentInstrumentationSpecification {
assertThat(log.getInstrumentationScopeInfo().getName()).isEqualTo("abc")
assertThat(log.getSeverity()).isEqualTo(Severity.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.key2"))).isEqualTo("val2")
assertThat(log.getAttributes().get(SemanticAttributes.THREAD_NAME)).isEqualTo(Thread.currentThread().getName())
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
new LogEmitterProviderHolder();

private volatile boolean captureExperimentalAttributes = false;
private volatile boolean captureCodeAttributes = false;
private volatile List<String> captureMdcAttributes = emptyList();

private volatile LoggingEventMapper mapper;
Expand All @@ -33,7 +34,9 @@ public OpenTelemetryAppender() {}

@Override
public void start() {
mapper = new LoggingEventMapper(captureExperimentalAttributes, captureMdcAttributes);
mapper =
new LoggingEventMapper(
captureExperimentalAttributes, captureMdcAttributes, captureCodeAttributes);
super.start();
}

Expand Down Expand Up @@ -62,6 +65,18 @@ public void setCaptureExperimentalAttributes(boolean captureExperimentalAttribut
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. */
public void setCaptureMdcAttributes(String attributes) {
if (attributes != null) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -34,10 +34,14 @@ public final class LoggingEventMapper {
private final boolean captureExperimentalAttributes;
private final List<String> captureMdcAttributes;
private final boolean captureAllMdcAttributes;
private final boolean captureCodeAttributes;

public LoggingEventMapper(
boolean captureExperimentalAttributes, List<String> captureMdcAttributes) {
boolean captureExperimentalAttributes,
List<String> captureMdcAttributes,
boolean captureCodeAttributes) {
this.captureExperimentalAttributes = captureExperimentalAttributes;
this.captureCodeAttributes = captureCodeAttributes;
this.captureMdcAttributes = captureMdcAttributes;
this.captureAllMdcAttributes =
captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
Expand Down Expand Up @@ -104,6 +108,23 @@ private void mapLoggingEvent(LogRecordBuilder builder, ILoggingEvent loggingEven
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());

// span context
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,6 @@
import static org.assertj.core.api.AssertionsForInterfaceTypes.assertThat;

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.context.Scope;
Expand Down Expand Up @@ -71,7 +70,7 @@ void logNoSpan() {
assertThat(logData.getResource()).isEqualTo(resource);
assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
assertThat(logData.getBody().asString()).isEqualTo("log message 1");
assertThat(logData.getAttributes()).isEqualTo(Attributes.empty());
assertThat(logData.getAttributes().size()).isEqualTo(4); // 4 code attributes
}

@Test
Expand Down Expand Up @@ -115,13 +114,27 @@ void logWithExtras() {
.isLessThan(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli()));
assertThat(logData.getSeverity()).isEqualTo(Severity.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))
.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("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
Expand All @@ -140,7 +153,7 @@ void logContextData() {
assertThat(logData.getResource()).isEqualTo(resource);
assertThat(logData.getInstrumentationScopeInfo()).isEqualTo(instrumentationScopeInfo);
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(
logData.getAttributes().get(AttributeKey.stringKey("logback.mdc.key1")))
.isEqualTo("val1");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ class LoggingEventMapperTest {
@Test
void testDefault() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList());
LoggingEventMapper mapper = new LoggingEventMapper(false, emptyList(), false);
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
Expand All @@ -38,7 +38,7 @@ void testDefault() {
@Test
void testSome() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("key2"));
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("key2"), false);
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
Expand All @@ -55,7 +55,7 @@ void testSome() {
@Test
void testAll() {
// given
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("*"));
LoggingEventMapper mapper = new LoggingEventMapper(false, singletonList("*"), false);
Map<String, String> contextData = new HashMap<>();
contextData.put("key1", "value1");
contextData.put("key2", "value2");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
<appender name="OpenTelemetry"
class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
<captureExperimentalAttributes>false</captureExperimentalAttributes>
<captureCodeAttributes>true</captureCodeAttributes>
<captureMdcAttributes>*</captureMdcAttributes>
</appender>

Expand Down

0 comments on commit f135169

Please sign in to comment.