JUL log correlation (#2724)

Co-authored-by: eyalkoren <41850454+eyalkoren@users.noreply.github.com>

Author: SylvainJuge

CHANGELOG.asciidoc

@@ -28,7 +28,7 @@ endif::[]
 
 [float]
 ===== Features
-* Cool new feature: {pull}2526[#2526]
+* Add support for log correlation for `java.util.logging` (JUL) - {pull}2724[#2724]
 
 [float]
 ===== Bug fixes

apm-agent-attach-cli/pom.xml

@@ -42,7 +42,7 @@
         <dependency>
             <groupId>co.elastic.logging</groupId>
             <artifactId>log4j2-ecs-layout</artifactId>
-            <version>${version.log4j2-ecs-layout}</version>
+            <version>${version.ecs.logging}</version>
         </dependency>
         <dependency>
             <groupId>org.bouncycastle</groupId>

apm-agent-core/pom.xml

@@ -77,7 +77,7 @@
         <dependency>
             <groupId>co.elastic.logging</groupId>
             <artifactId>log4j2-ecs-layout</artifactId>
-            <version>${version.log4j2-ecs-layout}</version>
+            <version>${version.ecs.logging}</version>
         </dependency>
 
         <dependency>

apm-agent-core/src/main/java/co/elastic/apm/agent/bci/bytebuddy/ClassLoaderNameMatcher.java

@@ -47,8 +47,6 @@ public boolean matches(ClassLoader target) {
         };
     }
 
-
-
     public static ElementMatcher.Junction<ClassLoader> isReflectionClassLoader() {
         return classLoaderWithName("sun.reflect.DelegatingClassLoader")
             .or(classLoaderWithName("jdk.internal.reflect.DelegatingClassLoader"));

apm-agent-core/src/main/java/co/elastic/apm/agent/bci/bytebuddy/CustomElementMatchers.java

@@ -53,13 +53,23 @@
 public class CustomElementMatchers {
 
     private static final Logger logger = LoggerFactory.getLogger(CustomElementMatchers.class);
+
     private static final ElementMatcher.Junction.AbstractBase<ClassLoader> AGENT_CLASS_LOADER_MATCHER = new ElementMatcher.Junction.AbstractBase<ClassLoader>() {
         @Override
         public boolean matches(@Nullable ClassLoader classLoader) {
             return ClassLoaderUtils.isAgentClassLoader(classLoader);
         }
     };
 
+    private static final ElementMatcher.Junction.AbstractBase<ClassLoader> INTERNAL_PLUGIN_CLASS_LOADER_MATCHER = new ElementMatcher.Junction.AbstractBase<ClassLoader>() {
+        @Override
+        public boolean matches(@Nullable ClassLoader classLoader) {
+
+            boolean result = ClassLoaderUtils.isInternalPluginClassLoader(classLoader);
+            return result;
+        }
+    };
+
     public static ElementMatcher.Junction<NamedElement> isInAnyPackage(Collection<String> includedPackages,
                                                                        ElementMatcher.Junction<NamedElement> defaultIfEmpty) {
         if (includedPackages.isEmpty()) {
@@ -74,6 +84,7 @@ public static ElementMatcher.Junction<NamedElement> isInAnyPackage(Collection<St
 
     /**
      * Matches the target class loader to a given class loader by instance comparison
+     *
      * @param other the class loader to match to
      * @return {@code true} if {@code other} is the same class loader instance as the target class loader
      */
@@ -86,7 +97,6 @@ public boolean matches(@Nullable ClassLoader target) {
         };
     }
 
-
     /**
      * Matches only class loaders which can load a certain class.
      * <p>
@@ -188,6 +198,10 @@ public static ElementMatcher.Junction<ClassLoader> isAgentClassLoader() {
         return AGENT_CLASS_LOADER_MATCHER;
     }
 
+    public static ElementMatcher.Junction<ClassLoader> isInternalPluginClassLoader() {
+        return INTERNAL_PLUGIN_CLASS_LOADER_MATCHER;
+    }
+
     private enum Matcher {
         LTE {
             @Override
@@ -202,6 +216,7 @@ <T extends Comparable<T>> boolean match(T c1, T c2) {
 
             }
         };
+
         abstract <T extends Comparable<T>> boolean match(T c1, T c2);
     }
 

apm-agent-core/src/main/java/co/elastic/apm/agent/util/ClassLoaderUtils.java

@@ -18,31 +18,12 @@
  */
 package co.elastic.apm.agent.util;
 
+import co.elastic.apm.agent.bci.classloading.IndyPluginClassLoader;
+
 import javax.annotation.Nullable;
 
 public class ClassLoaderUtils {
 
-    /**
-     * Checks whether the provided {@link ClassLoader} may be unloaded like a web application class loader, for example.
-     * <p>
-     * If the class loader can't be unloaded, it is safe to use {@link ThreadLocal}s and to reuse the {@code WeakConcurrentMap.LookupKey}.
-     * Otherwise, the use of {@link ThreadLocal}s may lead to class loader leaks as it prevents the class loader this class
-     * is loaded by to unload.
-     * </p>
-     *
-     * @param classLoader The class loader to check.
-     * @return {@code true} if the provided class loader can be unloaded.
-     */
-    public static boolean isPersistentClassLoader(@Nullable ClassLoader classLoader) {
-        try {
-            return classLoader == null // bootstrap class loader
-                || classLoader == ClassLoader.getSystemClassLoader()
-                || classLoader == ClassLoader.getSystemClassLoader().getParent(); // ext/platfrom class loader;
-        } catch (Throwable ignored) {
-            return false;
-        }
-    }
-
     public static boolean isAgentClassLoader(@Nullable ClassLoader classLoader) {
         return (classLoader != null && classLoader.getClass().getName().startsWith("co.elastic.apm")) ||
             // This one also covers unit tests, where the app class loader loads the agent
@@ -52,4 +33,11 @@ public static boolean isAgentClassLoader(@Nullable ClassLoader classLoader) {
     public static boolean isBootstrapClassLoader(@Nullable ClassLoader classLoader) {
         return classLoader == null;
     }
+
+    public static boolean isInternalPluginClassLoader(@Nullable ClassLoader classLoader) {
+        if (classLoader == null) {
+            return false;
+        }
+        return IndyPluginClassLoader.class.getName().equals(classLoader.getClass().getName());
+    }
 }

apm-agent-plugins/apm-ecs-logging-plugin/pom.xml

@@ -19,13 +19,25 @@
         <dependency>
             <groupId>co.elastic.logging</groupId>
             <artifactId>log4j-ecs-layout</artifactId>
-            <version>1.4.0</version>
+            <version>${version.ecs.logging}</version>
             <scope>provided</scope>
         </dependency>
         <dependency>
             <groupId>co.elastic.logging</groupId>
             <artifactId>log4j2-ecs-layout</artifactId>
-            <version>1.4.0</version>
+            <version>${version.ecs.logging}</version>
+            <scope>provided</scope>
+        </dependency>
+        <dependency>
+            <groupId>co.elastic.logging</groupId>
+            <artifactId>jul-ecs-formatter</artifactId>
+            <version>${version.ecs.logging}</version>
+            <scope>provided</scope>
+        </dependency>
+        <dependency>
+            <groupId>co.elastic.apm</groupId>
+            <artifactId>apm-logging-plugin-common</artifactId>
+            <version>${project.version}</version>
             <scope>provided</scope>
         </dependency>
         <dependency>
@@ -39,6 +51,7 @@
             <artifactId>ivy</artifactId>
             <scope>test</scope>
         </dependency>
+
     </dependencies>
 
 </project>

apm-agent-plugins/apm-ecs-logging-plugin/src/main/java/co/elastic/apm/agent/ecs_logging/JulEcsFormatterInstrumentation.java

@@ -0,0 +1,77 @@
+/*
+ * Licensed to Elasticsearch B.V. under one or more contributor
+ * license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright
+ * ownership. Elasticsearch B.V. licenses this file to you under
+ * the Apache License, Version 2.0 (the "License"); you may
+ * not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package co.elastic.apm.agent.ecs_logging;
+
+import co.elastic.apm.agent.bci.TracerAwareInstrumentation;
+import co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers;
+import co.elastic.apm.agent.loginstr.correlation.CorrelationIdMapAdapter;
+import co.elastic.logging.jul.EcsFormatter;
+import net.bytebuddy.asm.Advice;
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.description.type.TypeDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+
+import java.util.Arrays;
+import java.util.Collection;
+import java.util.Map;
+
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static net.bytebuddy.matcher.ElementMatchers.not;
+
+/**
+ * Instruments {@link EcsFormatter#getMdcEntries()} to provide correlation IDs at runtime.
+ * Application(s) copies of ecs-logging and the one in the agent will be instrumented, hence providing log correlation
+ * for all of them.
+ */
+@SuppressWarnings("JavadocReference")
+public class JulEcsFormatterInstrumentation extends TracerAwareInstrumentation {
+
+    @Override
+    public ElementMatcher.Junction<ClassLoader> getClassLoaderMatcher() {
+        // ECS formatter that is loaded within the agent should not be instrumented
+        return not(CustomElementMatchers.isInternalPluginClassLoader());
+    }
+
+    @Override
+    public Collection<String> getInstrumentationGroupNames() {
+        return Arrays.asList("logging", "jul-ecs");
+    }
+
+    @Override
+    public ElementMatcher<? super TypeDescription> getTypeMatcher() {
+        return named("co.elastic.logging.jul.EcsFormatter");
+    }
+
+    @Override
+    public ElementMatcher<? super MethodDescription> getMethodMatcher() {
+        return named("getMdcEntries");
+    }
+
+    public static class AdviceClass {
+
+        @Advice.AssignReturned.ToReturned
+        @Advice.OnMethodExit(suppress = Throwable.class, onThrowable = Throwable.class, inline = false)
+        public static Map<String, String> onExit() {
+            return CorrelationIdMapAdapter.get();
+        }
+
+    }
+
+
+}

apm-agent-plugins/apm-ecs-logging-plugin/src/main/resources/META-INF/services/co.elastic.apm.agent.sdk.ElasticApmInstrumentation

@@ -1,2 +1,4 @@
 co.elastic.apm.agent.ecs_logging.Log4j2ServiceNameInstrumentation
 co.elastic.apm.agent.ecs_logging.Log4j2ServiceVersionInstrumentation
+
+co.elastic.apm.agent.ecs_logging.JulEcsFormatterInstrumentation

apm-agent-plugins/apm-ecs-logging-plugin/src/test/java/co/elastic/apm/agent/ecs_logging/JulEcsFormatterInstrumentationTest.java

@@ -0,0 +1,82 @@
+/*
+ * Licensed to Elasticsearch B.V. under one or more contributor
+ * license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright
+ * ownership. Elasticsearch B.V. licenses this file to you under
+ * the Apache License, Version 2.0 (the "License"); you may
+ * not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied.  See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package co.elastic.apm.agent.ecs_logging;
+
+import co.elastic.apm.agent.AbstractInstrumentationTest;
+import co.elastic.apm.agent.impl.error.ErrorCapture;
+import co.elastic.apm.agent.impl.transaction.Transaction;
+import co.elastic.logging.jul.EcsFormatter;
+import com.fasterxml.jackson.core.JsonProcessingException;
+import com.fasterxml.jackson.databind.JsonNode;
+import com.fasterxml.jackson.databind.ObjectMapper;
+import org.junit.jupiter.api.Test;
+
+import java.util.logging.Level;
+import java.util.logging.LogRecord;
+
+import static co.elastic.apm.agent.testutils.assertions.Assertions.assertThat;
+
+public class JulEcsFormatterInstrumentationTest extends AbstractInstrumentationTest {
+
+    @Test
+    void testNoCorrelation() {
+        JsonNode logLine = logSomething();
+
+        assertThat(logLine.get("transaction.id")).isNull();
+        assertThat(logLine.get("trace.id")).isNull();
+    }
+
+    @Test
+    void testActiveTransaction() {
+        Transaction transaction = startTestRootTransaction("log");
+        try {
+            JsonNode logLine = logSomething();
+
+            assertThat(logLine.get("transaction.id").textValue()).isEqualTo(transaction.getTraceContext().getTransactionId().toString());
+            assertThat(logLine.get("trace.id").textValue()).isEqualTo(transaction.getTraceContext().getTraceId().toString());
+        } finally {
+            transaction.deactivate().end();
+        }
+    }
+
+    @Test
+    void testActiveError() {
+        ErrorCapture error = new ErrorCapture(tracer);
+
+        error.activate();
+        try {
+            JsonNode logLine = logSomething();
+
+            assertThat(logLine.get("error.id").textValue()).isEqualTo(error.getTraceContext().getId().toString());
+        } finally {
+            error.deactivate();
+        }
+
+    }
+
+    private static JsonNode logSomething() {
+        EcsFormatter formatter = new EcsFormatter();
+        LogRecord record = new LogRecord(Level.INFO, "msg");
+        try {
+            return new ObjectMapper().readTree(formatter.format(record));
+        } catch (JsonProcessingException e) {
+            throw new RuntimeException(e);
+        }
+    }
+}