Add java.util.logging javaagent instrumentation (#4941)

* java.util.logging

* Update instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentationModule.java

* sync

* Update instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingHelper.java

Co-authored-by: Anuraag Agrawal <anuraaga@gmail.com>

* Remove unused code

* Simplification

* Remove JBoss logger instrumentation

* Spotless

* Unroll

* Remove unused dependency

Co-authored-by: Anuraag Agrawal <anuraaga@gmail.com>

gradle-plugins/src/main/kotlin/io.opentelemetry.instrumentation.javaagent-shadowing.gradle.kts

@@ -33,4 +33,7 @@ tasks.withType<ShadowJar>().configureEach {
 
   // this is for instrumentation on opentelemetry-api itself
   relocate("application.io.opentelemetry", "io.opentelemetry")
+
+  // this is for instrumentation on java.util.logging (since java.util.logging itself is shaded above)
+  relocate("application.java.util.logging", "java.util.logging")
 }

instrumentation/java-util-logging/javaagent/build.gradle.kts

@@ -0,0 +1,11 @@
+plugins {
+  id("otel.javaagent-instrumentation")
+}
+
+dependencies {
+  compileOnly(project(":instrumentation:java-util-logging:shaded-stub-for-instrumenting"))
+
+  compileOnly(project(":instrumentation-api-appender"))
+
+  testImplementation("org.awaitility:awaitility")
+}

instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingHelper.java

@@ -0,0 +1,126 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.jul;
+
+import application.java.util.logging.Logger;
+import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.api.common.AttributesBuilder;
+import io.opentelemetry.context.Context;
+import io.opentelemetry.instrumentation.api.appender.GlobalLogEmitterProvider;
+import io.opentelemetry.instrumentation.api.appender.LogBuilder;
+import io.opentelemetry.instrumentation.api.appender.Severity;
+import io.opentelemetry.semconv.trace.attributes.SemanticAttributes;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.concurrent.TimeUnit;
+import java.util.logging.Formatter;
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+
+public final class JavaUtilLoggingHelper {
+
+  private static final Formatter FORMATTER = new AccessibleFormatter();
+
+  public static void capture(Logger logger, LogRecord logRecord) {
+
+    if (!logger.isLoggable(logRecord.getLevel())) {
+      // this is already checked in most cases, except if Logger.log(LogRecord) was called directly
+      return;
+    }
+
+    LogBuilder builder =
+        GlobalLogEmitterProvider.get()
+            .logEmitterBuilder(logRecord.getLoggerName())
+            .build()
+            .logBuilder();
+    mapLogRecord(builder, logRecord);
+    builder.emit();
+  }
+
+  /**
+   * Map the {@link LogRecord} data model onto the {@link LogBuilder}. Unmapped fields include:
+   *
+   * <ul>
+   *   <li>Fully qualified class name - {@link LogRecord#getSourceClassName()}
+   *   <li>Fully qualified method name - {@link LogRecord#getSourceMethodName()}
+   *   <li>Thread id - {@link LogRecord#getThreadID()}
+   * </ul>
+   */
+  private static void mapLogRecord(LogBuilder builder, LogRecord logRecord) {
+    // message
+    String message = FORMATTER.formatMessage(logRecord);
+    if (message != null) {
+      builder.setBody(message);
+    }
+
+    // time
+    // TODO (trask) use getInstant() for more precision on Java 9
+    long timestamp = logRecord.getMillis();
+    builder.setEpoch(timestamp, TimeUnit.MILLISECONDS);
+
+    // level
+    Level level = logRecord.getLevel();
+    if (level != null) {
+      builder.setSeverity(levelToSeverity(level));
+      builder.setSeverityText(logRecord.getLevel().getName());
+    }
+
+    // throwable
+    Throwable throwable = logRecord.getThrown();
+    if (throwable != null) {
+      AttributesBuilder attributes = Attributes.builder();
+
+      // TODO (trask) extract method for recording exception into instrumentation-api-appender
+      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());
+    }
+
+    // span context
+    builder.setContext(Context.current());
+  }
+
+  private static Severity levelToSeverity(Level level) {
+    int lev = level.intValue();
+    if (lev <= Level.FINEST.intValue()) {
+      return Severity.TRACE;
+    }
+    if (lev <= Level.FINER.intValue()) {
+      return Severity.DEBUG;
+    }
+    if (lev <= Level.FINE.intValue()) {
+      return Severity.DEBUG2;
+    }
+    if (lev <= Level.CONFIG.intValue()) {
+      return Severity.DEBUG3;
+    }
+    if (lev <= Level.INFO.intValue()) {
+      return Severity.INFO;
+    }
+    if (lev <= Level.WARNING.intValue()) {
+      return Severity.WARN;
+    }
+    if (lev <= Level.SEVERE.intValue()) {
+      return Severity.ERROR;
+    }
+    return Severity.FATAL;
+  }
+
+  // this is just needed for calling formatMessage in abstract super class
+  private static class AccessibleFormatter extends Formatter {
+
+    @Override
+    public String format(final LogRecord record) {
+      throw new UnsupportedOperationException();
+    }
+  }
+
+  private JavaUtilLoggingHelper() {}
+}

instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentation.java

@@ -0,0 +1,64 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.jul;
+
+import static io.opentelemetry.javaagent.extension.matcher.AgentElementMatchers.extendsClass;
+import static net.bytebuddy.matcher.ElementMatchers.isMethod;
+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 application.java.util.logging.Logger;
+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 java.util.logging.LogRecord;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+
+class JavaUtilLoggingInstrumentation implements TypeInstrumentation {
+
+  @Override
+  public ElementMatcher<TypeDescription> typeMatcher() {
+    return extendsClass(named("application.java.util.logging.Logger"));
+  }
+
+  @Override
+  public void transform(TypeTransformer transformer) {
+    transformer.applyAdviceToMethod(
+        isMethod()
+            .and(isPublic())
+            .and(named("log"))
+            .and(takesArguments(1))
+            .and(takesArgument(0, named("java.util.logging.LogRecord"))),
+        JavaUtilLoggingInstrumentation.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 LogRecord logRecord,
+        @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) {
+        JavaUtilLoggingHelper.capture(logger, logRecord);
+      }
+    }
+
+    @Advice.OnMethodExit(onThrowable = Throwable.class, suppress = Throwable.class)
+    public static void methodExit(@Advice.Local("otelCallDepth") CallDepth callDepth) {
+      callDepth.decrementAndGet();
+    }
+  }
+}

instrumentation/java-util-logging/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/jul/JavaUtilLoggingInstrumentationModule.java

@@ -0,0 +1,26 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.javaagent.instrumentation.jul;
+
+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 JavaUtilLoggingInstrumentationModule extends InstrumentationModule {
+
+  public JavaUtilLoggingInstrumentationModule() {
+    super("java-util-logging");
+  }
+
+  @Override
+  public List<TypeInstrumentation> typeInstrumentations() {
+    return singletonList(new JavaUtilLoggingInstrumentation());
+  }
+}

instrumentation/java-util-logging/javaagent/src/test/groovy/JavaUtilLoggingTest.groovy

@@ -0,0 +1,92 @@
+/*
+ * 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 spock.lang.Unroll
+
+import java.util.logging.Level
+import java.util.logging.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 JavaUtilLoggingTest extends AgentInstrumentationSpecification {
+
+  private static final Logger logger = Logger.getLogger("abc")
+
+  @Unroll
+  def "test method=#testMethod with exception=#exception and parent=#parent"() {
+    when:
+    if (parent) {
+      runUnderTrace("parent") {
+        if (exception) {
+          logger.log(Level."${testMethod.toUpperCase()}", "xyz", new IllegalStateException("hello"))
+        } else {
+          logger."$testMethod"("xyz")
+        }
+      }
+    } else {
+      if (exception) {
+        logger.log(Level."${testMethod.toUpperCase()}", "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(JavaUtilLoggingTest.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 log is captured
+      logs.size() == 0
+    }
+
+    where:
+    [args, exception, parent] << [
+      [
+        ["fine", null, null],
+        ["info", Severity.INFO, "INFO"],
+        ["warning", Severity.WARN, "WARNING"],
+        ["severe", Severity.ERROR, "SEVERE"]
+      ],
+      [true, false],
+      [true, false]
+    ].combinations()
+
+    testMethod = args[0]
+    severity = args[1]
+    severityText = args[2]
+  }
+}

instrumentation/java-util-logging/shaded-stub-for-instrumenting/build.gradle.kts

@@ -0,0 +1,3 @@
+plugins {
+  id("otel.java-conventions")
+}

instrumentation/java-util-logging/shaded-stub-for-instrumenting/src/main/java/application/java/util/logging/Logger.java

@@ -0,0 +1,18 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package application.java.util.logging;
+
+import java.util.logging.Level;
+
+// java.util.logging.Logger shaded so that it can be used in instrumentation
+// of java.util.logging.Logger itself, and then its usage can be unshaded
+// after java.util.logging.Logger is shaded to the "PatchLogger"
+public class Logger {
+
+  public boolean isLoggable(@SuppressWarnings("unused") Level level) {
+    throw new UnsupportedOperationException();
+  }
+}

settings.gradle.kts

@@ -199,6 +199,8 @@ include(":instrumentation:hibernate:hibernate-procedure-call-4.3:javaagent")
 include(":instrumentation:http-url-connection:javaagent")
 include(":instrumentation:hystrix-1.4:javaagent")
 include(":instrumentation:java-http-client:javaagent")
+include(":instrumentation:java-util-logging:javaagent")
+include(":instrumentation:java-util-logging:shaded-stub-for-instrumenting")
 include(":instrumentation:jaxrs:jaxrs-common:bootstrap")
 include(":instrumentation:jaxrs:jaxrs-1.0:javaagent")
 include(":instrumentation:jaxrs:jaxrs-2.0:jaxrs-2.0-arquillian-testing")