Add experimental thread attributes for logs (#5474)

open-telemetry · Mar 2, 2022 · 627f5d3 · 627f5d3
1 parent 399b39e
commit 627f5d3
Show file tree

Hide file tree

Showing 12 changed files with 91 additions and 11 deletions.
diff --git a/instrumentation/java-util-logging/javaagent/build.gradle.kts b/instrumentation/java-util-logging/javaagent/build.gradle.kts
@@ -9,3 +9,8 @@ dependencies {
 
  testImplementation("org.awaitility:awaitility")
 }
+
+tasks.withType<Test>().configureEach {
+ // TODO run tests both with and without experimental log attributes
+ jvmArgs("-Dotel.instrumentation.java-util-logging.experimental-log-attributes=true")
+}
diff --git a/...t/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingHelper.java b/...t/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingHelper.java
@@ -11,6 +11,7 @@
 import io.opentelemetry.context.Context;
 import io.opentelemetry.instrumentation.api.appender.internal.LogBuilder;
 import io.opentelemetry.instrumentation.api.appender.internal.Severity;
+import io.opentelemetry.instrumentation.api.config.Config;
 import io.opentelemetry.javaagent.instrumentation.api.appender.internal.AgentLogEmitterProvider;
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
 import java.io.PrintWriter;
@@ -24,6 +25,10 @@ public final class JavaUtilLoggingHelper {
 
  private static final Formatter FORMATTER = new AccessibleFormatter();
 
+ private static final boolean captureExperimentalAttributes =
+ Config.get()
+ .getBoolean("otel.instrumentation.java-util-logging.experimental-log-attributes", false);
+
  public static void capture(Logger logger, LogRecord logRecord) {
 
  if (!logger.isLoggable(logRecord.getLevel())) {
@@ -69,22 +74,28 @@ private static void mapLogRecord(LogBuilder builder, LogRecord logRecord) {
  builder.setSeverityText(logRecord.getLevel().getName());
  }
 
+ AttributesBuilder attributes = Attributes.builder();
+
  // throwable
  Throwable throwable = logRecord.getThrown();
  if (throwable != null) {
- AttributesBuilder attributes = Attributes.builder();
-
  // TODO (trask) extract method for recording exception into
  // instrumentation-appender-api-internal
  attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName());
  attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage());
  StringWriter writer = new StringWriter();
  throwable.printStackTrace(new PrintWriter(writer));
  attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString());
+ }
 
- builder.setAttributes(attributes.build());
+ if (captureExperimentalAttributes) {
+ Thread currentThread = Thread.currentThread();
+ attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName());
+ attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId());
  }
 
+ builder.setAttributes(attributes.build());
+
  // span context
  builder.setContext(Context.current());
  }

diff --git a/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy b/instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy
@@ -54,14 +54,18 @@ class JavaUtilLoggingTest extends AgentInstrumentationSpecification {
  assertThat(log.getSeverity()).isEqualTo(severity)
  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(JavaUtilLoggingTest.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())
  if (parent) {
  assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
  } else {

diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts b/instrumentation/log4j/log4j-appender-1.2/javaagent/build.gradle.kts
@@ -29,3 +29,8 @@ configurations {
  exclude("org.slf4j", "log4j-over-slf4j")
  }
 }
+
+tasks.withType<Test>().configureEach {
+ // TODO run tests both with and without experimental log attributes
+ jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
+}
diff --git a/...main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jHelper.java b/...main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jHelper.java
@@ -10,6 +10,7 @@
 import io.opentelemetry.context.Context;
 import io.opentelemetry.instrumentation.api.appender.internal.LogBuilder;
 import io.opentelemetry.instrumentation.api.appender.internal.Severity;
+import io.opentelemetry.instrumentation.api.config.Config;
 import io.opentelemetry.javaagent.instrumentation.api.appender.internal.AgentLogEmitterProvider;
 import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
 import java.io.PrintWriter;
@@ -22,6 +23,10 @@ public final class Log4jHelper {
  // copied from org.apache.log4j.Level because it was only introduced in 1.2.12
  private static final int TRACE_INT = 5000;
 
+ private static final boolean captureExperimentalAttributes =
+ Config.get()
+ .getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false);
+
  // TODO (trask) capture MDC
  public static void capture(Category logger, Priority level, Object message, Throwable throwable) {
  String instrumentationName = logger.getName();
@@ -42,21 +47,27 @@ public static void capture(Category logger, Priority level, Object message, Thro
  builder.setSeverityText(level.toString());
  }
 
+ AttributesBuilder attributes = Attributes.builder();
+
  // throwable
  if (throwable != null) {
- AttributesBuilder attributes = Attributes.builder();
-
  // TODO (trask) extract method for recording exception into
  // instrumentation-appender-api-internal
  attributes.put(SemanticAttributes.EXCEPTION_TYPE, throwable.getClass().getName());
  attributes.put(SemanticAttributes.EXCEPTION_MESSAGE, throwable.getMessage());
  StringWriter writer = new StringWriter();
  throwable.printStackTrace(new PrintWriter(writer));
  attributes.put(SemanticAttributes.EXCEPTION_STACKTRACE, writer.toString());
+ }
 
- builder.setAttributes(attributes.build());
+ if (captureExperimentalAttributes) {
+ Thread currentThread = Thread.currentThread();
+ attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName());
+ attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId());
  }
 
+ builder.setAttributes(attributes.build());
+
  // span context
  builder.setContext(Context.current());
 

diff --git a/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy b/instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/groovy/Log4j1Test.groovy
@@ -52,14 +52,18 @@ class Log4j1Test extends AgentInstrumentationSpecification {
  assertThat(log.getSeverity()).isEqualTo(severity)
  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(Log4j1Test.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())
  if (parent) {
  assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
  } else {

diff --git a/instrumentation/log4j/log4j-appender-2.16/javaagent/build.gradle.kts b/instrumentation/log4j/log4j-appender-2.16/javaagent/build.gradle.kts
@@ -38,4 +38,5 @@ tasks.withType<Test>().configureEach {
  // TODO run tests both with and without experimental log attributes
  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")
 }
diff --git a/instrumentation/log4j/log4j-appender-2.16/javaagent/src/test/groovy/Log4j2Test.groovy b/instrumentation/log4j/log4j-appender-2.16/javaagent/src/test/groovy/Log4j2Test.groovy
@@ -57,14 +57,18 @@ class Log4j2Test extends AgentInstrumentationSpecification {
  assertThat(log.getSeverity()).isEqualTo(severity)
  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)
  } 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())
  if (parent) {
  assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
  } else {
@@ -114,9 +118,11 @@ class Log4j2Test extends AgentInstrumentationSpecification {
  assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
  assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
  assertThat(log.getSeverityText()).isEqualTo("INFO")
- assertThat(log.getAttributes().size()).isEqualTo(2)
+ 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())
  }
 
  def "test string map message"() {
@@ -138,9 +144,11 @@ class Log4j2Test extends AgentInstrumentationSpecification {
  assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
  assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
  assertThat(log.getSeverityText()).isEqualTo("INFO")
- assertThat(log.getAttributes().size()).isEqualTo(2)
+ 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())
  }
 
  def "test string map message with special attribute"() {
@@ -162,8 +170,10 @@ class Log4j2Test extends AgentInstrumentationSpecification {
  assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
  assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
  assertThat(log.getSeverityText()).isEqualTo("INFO")
- assertThat(log.getAttributes().size()).isEqualTo(1)
+ 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())
  }
 
  def "test structured data map message"() {
@@ -185,8 +195,10 @@ class Log4j2Test extends AgentInstrumentationSpecification {
  assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
  assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
  assertThat(log.getSeverityText()).isEqualTo("INFO")
- assertThat(log.getAttributes().size()).isEqualTo(2)
+ 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())
  }
 }
diff --git a/...n/java/io/opentelemetry/instrumentation/log4j/appender/v2_16/internal/LogEventMapper.java b/...n/java/io/opentelemetry/instrumentation/log4j/appender/v2_16/internal/LogEventMapper.java
@@ -35,6 +35,10 @@ public final class LogEventMapper<T> {
 
  private static final String SPECIAL_MAP_MESSAGE_ATTRIBUTE = "message";
 
+ private static final boolean captureExperimentalAttributes =
+ Config.get()
+ .getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false);
+
  private static final Cache<String, AttributeKey<String>> contextDataAttributeKeyCache =
  Cache.bounded(100);
  private static final Cache<String, AttributeKey<String>> mapMessageAttributeKeyCache =
@@ -110,6 +114,12 @@ public void mapLogEvent(
 
  captureContextDataAttributes(attributes, contextData);
 
+ if (captureExperimentalAttributes) {
+ Thread currentThread = Thread.currentThread();
+ attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName());
+ attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId());
+ }
+
  builder.setAttributes(attributes.build());
 
  builder.setContext(Context.current());

diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/build.gradle.kts b/instrumentation/logback/logback-appender-1.0/javaagent/build.gradle.kts
@@ -27,4 +27,5 @@ dependencies {
 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")
 }
diff --git a/instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy b/instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy
@@ -56,14 +56,18 @@ 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().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().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())
  if (parent) {
  assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
  } else {
@@ -119,8 +123,10 @@ class LogbackTest extends AgentInstrumentationSpecification {
  assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
  assertThat(log.getSeverity()).isEqualTo(Severity.INFO)
  assertThat(log.getSeverityText()).isEqualTo("INFO")
- assertThat(log.getAttributes().size()).isEqualTo(2)
+ assertThat(log.getAttributes().size()).isEqualTo(4)
  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())
+ assertThat(log.getAttributes().get(SemanticAttributes.THREAD_ID)).isEqualTo(Thread.currentThread().getId())
  }
 }
diff --git a/...a/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java b/...a/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java
@@ -34,6 +34,10 @@ public final class LoggingEventMapper {
 
  public static final LoggingEventMapper INSTANCE = new LoggingEventMapper();
 
+ private static final boolean captureExperimentalAttributes =
+ Config.get()
+ .getBoolean("otel.instrumentation.logback-appender.experimental-log-attributes", false);
+
  private static final Cache<String, AttributeKey<String>> mdcAttributeKeys = Cache.bounded(100);
 
  private final List<String> captureMdcAttributes;
@@ -110,6 +114,12 @@ private void mapLoggingEvent(LogBuilder builder, ILoggingEvent loggingEvent) {
 
  captureMdcAttributes(attributes, loggingEvent.getMDCPropertyMap());
 
+ if (captureExperimentalAttributes) {
+ Thread currentThread = Thread.currentThread();
+ attributes.put(SemanticAttributes.THREAD_NAME, currentThread.getName());
+ attributes.put(SemanticAttributes.THREAD_ID, currentThread.getId());
+ }
+
  builder.setAttributes(attributes.build());
 
  // span context