Add log4j2 appender javaagent instrumentation

instrumentation/log4j/log4j-appender-2.16/javaagent/build.gradle.kts

@@ -0,0 +1,45 @@
+plugins {
+  id("otel.javaagent-instrumentation")
+}
+
+muzzle {
+  pass {
+    group.set("org.apache.logging.log4j")
+    module.set("log4j-core")
+    versions.set("[2.11.0,)")
+    assertInverse.set(true)
+  }
+}
+
+dependencies {
+  library("org.apache.logging.log4j:log4j-core:2.16.0")
+
+  compileOnly(project(":instrumentation-api-appender"))
+
+  implementation(project(":instrumentation:log4j:log4j-appender-2.16:library"))
+
+  testImplementation("org.awaitility:awaitility")
+
+  testImplementation("com.lmax:disruptor:3.4.2")
+}
+
+configurations {
+  configurations {
+    testImplementation {
+      // In order to test the real log4j library we need to remove the log4j transitive
+      // dependency "log4j-over-slf4j" brought in by :testing-common which would shadow
+      // the log4j module under test using a proxy to slf4j instead.
+      exclude("org.slf4j", "log4j-over-slf4j")
+    }
+  }
+}
+
+tasks {
+  val testAsync by registering(Test::class) {
+    jvmArgs("-DLog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector")
+  }
+
+  named<Test>("test") {
+    dependsOn(testAsync)
+  }
+}

instrumentation/log4j/log4j-appender-2.16/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_0/Log4jAppenderInstrumentation.java

@@ -0,0 +1,79 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.log4j.appender.v2_0;
+
+import static io.opentelemetry.javaagent.extension.matcher.AgentElementMatchers.extendsClass;
+import static io.opentelemetry.javaagent.extension.matcher.AgentElementMatchers.hasClassesNamed;
+import static net.bytebuddy.matcher.ElementMatchers.isMethod;
+import static net.bytebuddy.matcher.ElementMatchers.isProtected;
+import static net.bytebuddy.matcher.ElementMatchers.isPublic;
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static net.bytebuddy.matcher.ElementMatchers.takesArgument;
+import static net.bytebuddy.matcher.ElementMatchers.takesArguments;
+
+import io.opentelemetry.instrumentation.api.appender.LogEmitterProvider;
+import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
+import io.opentelemetry.javaagent.extension.instrumentation.TypeTransformer;
+import io.opentelemetry.javaagent.instrumentation.api.CallDepth;
+import net.bytebuddy.asm.Advice;
+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.message.Message;
+
+class Log4jAppenderInstrumentation implements TypeInstrumentation {
+
+  @Override
+  public ElementMatcher<TypeDescription> typeMatcher() {
+    return extendsClass(named("org.apache.logging.log4j.spi.AbstractLogger"));
+  }
+
+  @Override
+  public ElementMatcher<ClassLoader> classLoaderOptimization() {
+    return hasClassesNamed("org.apache.logging.log4j.spi.AbstractLogger");
+  }
+
+  @Override
+  public void transform(TypeTransformer transformer) {
+    transformer.applyAdviceToMethod(
+        isMethod()
+            .and(isProtected().or(isPublic()))
+            .and(named("log"))
+            .and(takesArguments(6))
+            .and(takesArgument(0, named("org.apache.logging.log4j.Level")))
+            .and(takesArgument(1, named("org.apache.logging.log4j.Marker")))
+            .and(takesArgument(2, named("java.lang.String")))
+            .and(takesArgument(3, named("java.lang.StackTraceElement")))
+            .and(takesArgument(4, named("org.apache.logging.log4j.message.Message")))
+            .and(takesArgument(5, named("java.lang.Throwable"))),
+        Log4jAppenderInstrumentation.class.getName() + "$LogAdvice");
+  }
+
+  @SuppressWarnings("unused")
+  public static class LogAdvice {
+
+    @Advice.OnMethodEnter(suppress = Throwable.class)
+    public static void methodEnter(
+        @Advice.This final Logger logger,
+        @Advice.Argument(0) final Level level,
+        @Advice.Argument(4) final Message message,
+        @Advice.Argument(5) final Throwable t,
+        @Advice.Local("otelCallDepth") CallDepth callDepth) {
+      // need to track call depth across all loggers in order to avoid double capture when one
+      // logging framework delegates to another
+      callDepth = CallDepth.forClass(LogEmitterProvider.class);
+      if (callDepth.getAndIncrement() == 0) {
+        Log4jHelper.capture(logger, level, message, t);
+      }
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Local("otelCallDepth") CallDepth callDepth) {
+      callDepth.decrementAndGet();
+    }
+  }
+}

instrumentation/log4j/log4j-appender-2.16/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_0/Log4jAppenderInstrumentationModule.java

@@ -0,0 +1,26 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.log4j.appender.v2_0;
+
+import static java.util.Collections.singletonList;
+
+import com.google.auto.service.AutoService;
+import io.opentelemetry.javaagent.extension.instrumentation.InstrumentationModule;
+import io.opentelemetry.javaagent.extension.instrumentation.TypeInstrumentation;
+import java.util.List;
+
+@AutoService(InstrumentationModule.class)
+public class Log4jAppenderInstrumentationModule extends InstrumentationModule {
+
+  public Log4jAppenderInstrumentationModule() {
+    super("log4j-appender", "log4j-appender-2.0");
+  }
+
+  @Override
+  public List<TypeInstrumentation> typeInstrumentations() {
+    return singletonList(new Log4jAppenderInstrumentation());
+  }
+}

instrumentation/log4j/log4j-appender-2.16/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_0/Log4jHelper.java

@@ -0,0 +1,29 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.log4j.appender.v2_0;
+
+import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
+import io.opentelemetry.instrumentation.api.appender.LogBuilder;
+import io.opentelemetry.instrumentation.log4j.appender.v2_16.internal.LogEventMapper;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.message.Message;
+
+public class Log4jHelper {
+
+  public static void capture(Logger logger, Level level, Message message, Throwable throwable) {
+
+    LogBuilder builder =
+        GlobalLogEmitterProvider.get().logEmitterBuilder(logger.getName()).build().logBuilder();
+
+    LogEventMapper.setBody(builder, message);
+    LogEventMapper.setSeverity(builder, level);
+    LogEventMapper.setThrowable(builder, throwable);
+    LogEventMapper.setContext(builder);
+
+    builder.emit();
+  }
+}

instrumentation/log4j/log4j-appender-2.16/javaagent/src/test/groovy/Log4j2Test.groovy

@@ -0,0 +1,89 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+import io.opentelemetry.instrumentation.test.AgentInstrumentationSpecification
+import io.opentelemetry.sdk.logs.data.Severity
+import io.opentelemetry.semconv.trace.attributes.SemanticAttributes
+import org.apache.logging.log4j.LogManager
+import org.apache.logging.log4j.Logger
+
+import static io.opentelemetry.instrumentation.test.utils.TraceUtils.runUnderTrace
+import static org.assertj.core.api.Assertions.assertThat
+import static org.awaitility.Awaitility.await
+
+class Log4j2Test extends AgentInstrumentationSpecification {
+
+  private static final Logger logger = LogManager.getLogger("abc")
+
+  def "test method=#testMethod with exception=#exception and parent=#parent"() {
+    when:
+    if (parent) {
+      runUnderTrace("parent") {
+        if (exception) {
+          logger."$testMethod"("xyz", new IllegalStateException("hello"))
+        } else {
+          logger."$testMethod"("xyz")
+        }
+      }
+    } else {
+      if (exception) {
+        logger."$testMethod"("xyz", new IllegalStateException("hello"))
+      } else {
+        logger."$testMethod"("xyz")
+      }
+    }
+
+    then:
+    if (parent) {
+      waitForTraces(1)
+    }
+
+    if (severity != null) {
+      await()
+        .untilAsserted(
+          () -> {
+            assertThat(logs).hasSize(1)
+          })
+      def log = logs.get(0)
+      assertThat(log.getBody().asString()).isEqualTo("xyz")
+      assertThat(log.getInstrumentationLibraryInfo().getName()).isEqualTo("abc")
+      assertThat(log.getSeverity()).isEqualTo(severity)
+      assertThat(log.getSeverityText()).isEqualTo(severityText)
+      if (exception) {
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isEqualTo(IllegalStateException.class.getName())
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isEqualTo("hello")
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(Log4j2Test.name)
+      } else {
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isNull()
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isNull()
+        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).isNull()
+      }
+      if (parent) {
+        assertThat(log.getSpanContext()).isEqualTo(traces.get(0).get(0).getSpanContext())
+      } else {
+        assertThat(log.getSpanContext().isValid()).isFalse()
+      }
+    } else {
+      Thread.sleep(500) // sleep a bit just to make sure no span is captured
+      logs.size() == 0
+    }
+
+    where:
+    [args, exception, parent] << [
+      [
+        ["debug", null, null],
+        ["info", Severity.INFO, "INFO"],
+        ["warn", Severity.WARN, "WARN"],
+        ["error", Severity.ERROR, "ERROR"]
+      ],
+      [true, false],
+      [true, false]
+    ].combinations()
+
+    testMethod = args[0]
+    severity = args[1]
+    severityText = args[2]
+  }
+}

instrumentation/log4j/log4j-appender-2.16/javaagent/src/test/resources/log4j2.xml

@@ -0,0 +1,14 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!DOCTYPE Configuration>
+<Configuration status="WARN">
+  <Appenders>
+    <Console name="Console" target="SYSTEM_OUT">
+      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
+    </Console>
+  </Appenders>
+  <Loggers>
+    <Root level="info">
+      <AppenderRef ref="Console"/>
+    </Root>
+  </Loggers>
+</Configuration>

instrumentation/log4j/log4j-appender-2.16/library/src/main/java/io/opentelemetry/instrumentation/log4j/v2_16/OpenTelemetryAppender.java → instrumentation/log4j/log4j-appender-2.16/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_16/OpenTelemetryAppender.java

@@ -3,10 +3,11 @@
  * SPDX-License-Identifier: Apache-2.0
  */
 
-package io.opentelemetry.instrumentation.log4j.v2_16;
+package io.opentelemetry.instrumentation.log4j.appender.v2_16;
 
 import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
 import io.opentelemetry.instrumentation.api.appender.LogBuilder;
+import io.opentelemetry.instrumentation.log4j.appender.v2_16.internal.LogEventMapper;
 import java.io.Serializable;
 import org.apache.logging.log4j.core.Appender;
 import org.apache.logging.log4j.core.Core;

instrumentation/log4j/log4j-appender-2.16/library/src/main/java/io/opentelemetry/instrumentation/log4j/v2_16/LogEventMapper.java → instrumentation/log4j/log4j-appender-2.16/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_16/internal/LogEventMapper.java

@@ -3,7 +3,7 @@
  * SPDX-License-Identifier: Apache-2.0
  */
 
-package io.opentelemetry.instrumentation.log4j.v2_16;
+package io.opentelemetry.instrumentation.log4j.appender.v2_16.internal;
 
 import io.opentelemetry.api.common.Attributes;
 import io.opentelemetry.api.common.AttributesBuilder;
@@ -19,7 +19,7 @@
 import org.apache.logging.log4j.core.time.Instant;
 import org.apache.logging.log4j.message.Message;
 
-final class LogEventMapper {
+public final class LogEventMapper {
 
   /**
    * Map the {@link LogEvent} data model onto the {@link LogBuilder}. Unmapped fields include:
@@ -34,12 +34,11 @@ final class LogEventMapper {
    *   <li>Mapped diagnostic context - {@link LogEvent#getContextData()}
    * </ul>
    */
-  static void mapLogEvent(LogBuilder builder, LogEvent logEvent) {
-    // message
-    Message message = logEvent.getMessage();
-    if (message != null) {
-      builder.setBody(message.getFormattedMessage());
-    }
+  public static void mapLogEvent(LogBuilder builder, LogEvent logEvent) {
+    setBody(builder, logEvent.getMessage());
+    setSeverity(builder, logEvent.getLevel());
+    setThrowable(builder, logEvent.getThrown());
+    setContext(builder);
 
     // time
     Instant instant = logEvent.getInstant();
@@ -49,16 +48,22 @@ static void mapLogEvent(LogBuilder builder, LogEvent logEvent) {
               + instant.getNanoOfMillisecond(),
           TimeUnit.NANOSECONDS);
     }
+  }
 
-    // level
-    Level level = logEvent.getLevel();
+  public static void setBody(LogBuilder builder, Message message) {
+    if (message != null) {
+      builder.setBody(message.getFormattedMessage());
+    }
+  }
+
+  public static void setSeverity(LogBuilder builder, Level level) {
     if (level != null) {
       builder.setSeverity(levelToSeverity(level));
-      builder.setSeverityText(logEvent.getLevel().name());
+      builder.setSeverityText(level.name());
     }
+  }
 
-    // throwable
-    Throwable throwable = logEvent.getThrown();
+  public static void setThrowable(LogBuilder builder, Throwable throwable) {
     if (throwable != null) {
       AttributesBuilder attributes = Attributes.builder();
 
@@ -71,8 +76,9 @@ static void mapLogEvent(LogBuilder builder, LogEvent logEvent) {
 
       builder.setAttributes(attributes.build());
     }
+  }
 
-    // span context
+  public static void setContext(LogBuilder builder) {
     builder.setContext(Context.current());
   }
 

instrumentation/log4j/log4j-appender-2.16/library/src/test/java/io/opentelemetry/instrumentation/log4j/v2_16/OpenTelemetryAppenderConfigTest.java → instrumentation/log4j/log4j-appender-2.16/library/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_16/OpenTelemetryAppenderConfigTest.java

@@ -3,7 +3,7 @@
  * SPDX-License-Identifier: Apache-2.0
  */
 
-package io.opentelemetry.instrumentation.log4j.v2_16;
+package io.opentelemetry.instrumentation.log4j.appender.v2_16;
 
 import static org.assertj.core.api.AssertionsForInterfaceTypes.assertThat;
 

instrumentation/log4j/log4j-appender-2.16/library/src/test/resources/log4j2-test.xml

@@ -1,6 +1,6 @@
 <?xml version="1.0" encoding="UTF-8"?>
 <Configuration status="WARN"
-  packages="com.example.appender,io.opentelemetry.instrumentation.log4j.v2_16">
+  packages="com.example.appender,io.opentelemetry.instrumentation.log4j.appender.v2_16">
   <Appenders>
     <Console name="Console" target="SYSTEM_OUT">
       <PatternLayout