Log4j2 support AsyncRoot print tid. All versions above 2.0 supported (#3284)

* Log4j2 support AsyncRoot print tid
Support AsyncRoot print tid of all versions of log4j2 2.1+

apm-sniffer/apm-agent/src/main/java/org/apache/skywalking/apm/agent/SkyWalkingAgent.java

@@ -90,7 +90,6 @@ public class SkyWalkingAgent {
             .ignore(
                 nameStartsWith("net.bytebuddy.")
                     .or(nameStartsWith("org.slf4j."))
-                    .or(nameStartsWith("org.apache.logging."))
                     .or(nameStartsWith("org.groovy."))
                     .or(nameContains("javassist"))
                     .or(nameContains(".asm."))

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/Log4j2OutputAppenderActivation.java → apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/TraceIdConverterActivation.java

@@ -21,45 +21,37 @@ package org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x;
 
 import net.bytebuddy.description.method.MethodDescription;
 import net.bytebuddy.matcher.ElementMatcher;
-import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.ClassStaticMethodsEnhancePluginDefine;
-import org.apache.skywalking.apm.agent.core.plugin.match.NameMatch;
-import org.apache.skywalking.apm.agent.core.plugin.interceptor.StaticMethodsInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.ConstructorInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.InstanceMethodsInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.ClassInstanceMethodsEnhancePluginDefine;
 import org.apache.skywalking.apm.agent.core.plugin.match.ClassMatch;
 
 import static net.bytebuddy.matcher.ElementMatchers.named;
+import static org.apache.skywalking.apm.agent.core.plugin.match.NameMatch.byName;
+
 
 /**
- * Active the toolkit class "org.apache.skywalking.apm.toolkit.log.logback.v2.x.LogbackPatternConverter".
- * Should not dependency or import any class in "skywalking-toolkit-logback-2.x" module.
- * Activation's classloader is diff from "org.apache.skywalking.apm.toolkit.log.logback.v2.x.LogbackPatternConverter",
- * using direct will trigger classloader issue.
- *
- * @author wusheng
+ * @author xuhe
  */
-public class Log4j2OutputAppenderActivation extends ClassStaticMethodsEnhancePluginDefine {
 
-    public static final String ENHANCE_CLASS = "org.apache.skywalking.apm.toolkit.log.log4j.v2.x.Log4j2OutputAppender";
-    public static final String INTERCEPT_CLASS = "org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.PrintTraceIdInterceptor";
-    public static final String ENHANCE_METHOD = "append";
+public class TraceIdConverterActivation extends ClassInstanceMethodsEnhancePluginDefine {
+
+    private static final String INTERCEPT_CLASS = "org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.TraceIdConverterMethodInterceptor";
+    private static final String ENHANCE_CLASS = "org.apache.skywalking.apm.toolkit.log.log4j.v2.x.TraceIdConverter";
+    private static final String ENHANCE_METHOD = "format";
 
-    /**
-     * @return the target class, which needs active.
-     */
     @Override
-    protected ClassMatch enhanceClass() {
-        return NameMatch.byName(ENHANCE_CLASS);
+    public ConstructorInterceptPoint[] getConstructorsInterceptPoints() {
+        return new ConstructorInterceptPoint[0];
     }
 
-    /**
-     * @return the collection of {@link StaticMethodsInterceptPoint}, represent the intercepted methods and their
-     * interceptors.
-     */
     @Override
-    public StaticMethodsInterceptPoint[] getStaticMethodsInterceptPoints() {
-        return new StaticMethodsInterceptPoint[] {
-            new StaticMethodsInterceptPoint() {
+    public InstanceMethodsInterceptPoint[] getInstanceMethodsInterceptPoints() {
+        return new InstanceMethodsInterceptPoint[]{
+            new InstanceMethodsInterceptPoint() {
                 @Override
                 public ElementMatcher<MethodDescription> getMethodsMatcher() {
+
                     return named(ENHANCE_METHOD);
                 }
 
@@ -68,10 +60,17 @@ public class Log4j2OutputAppenderActivation extends ClassStaticMethodsEnhancePlu
                     return INTERCEPT_CLASS;
                 }
 
-                @Override public boolean isOverrideArgs() {
+                @Override
+                public boolean isOverrideArgs() {
                     return false;
                 }
             }
         };
     }
+
+    @Override
+    protected ClassMatch enhanceClass() {
+        return byName(ENHANCE_CLASS);
+    }
 }
+

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/TraceIdConverterMethodInterceptor.java

+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF 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 org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x;
+
+import org.apache.skywalking.apm.agent.core.context.ContextManager;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.EnhancedInstance;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstanceMethodsAroundInterceptor;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.MethodInterceptResult;
+
+import java.lang.reflect.Method;
+
+/**
+ * @author xuhe
+ */
+
+public class TraceIdConverterMethodInterceptor implements InstanceMethodsAroundInterceptor {
+
+
+    @Override
+    public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
+                             MethodInterceptResult result) throws Throwable {
+        String tid = "";
+
+        //Async Thread, where ContextManager is not active
+        if (!ContextManager.isActive() && allArguments[0] instanceof EnhancedInstance) {
+            tid = (String) ((EnhancedInstance) allArguments[0]).getSkyWalkingDynamicField();
+            if (tid == null) {
+                tid = "N/A";
+            }
+        } else {
+            tid = ContextManager.getGlobalTraceId();
+        }
+        ((StringBuilder) allArguments[1]).append("TID: ").append(tid);
+        result.defineReturnValue(null);
+    }
+
+    @Override
+    public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments,
+                              Class<?>[] argumentsTypes, Object ret) throws Throwable {
+        return ret;
+    }
+
+    @Override
+    public void handleMethodException(EnhancedInstance objInst, Method method, Object[] allArguments,
+                                      Class<?>[] argumentsTypes, Throwable t) {
+    }
+}

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/async/AsyncLoggerConfigInstrumentation.java

+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF 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 org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async;
+
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.ConstructorInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.InstanceMethodsInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.ClassInstanceMethodsEnhancePluginDefine;
+import org.apache.skywalking.apm.agent.core.plugin.match.ClassMatch;
+
+import static net.bytebuddy.matcher.ElementMatchers.named;
+import static org.apache.skywalking.apm.agent.core.plugin.match.NameMatch.byName;
+
+/**
+ * Instrument to intercept AsyncLoggerConfig of log4j2, .
+ * Finally I choose populateLazilyInitializedFields as the intercept point, which all versions of AsyncAppender will actually work with
+ * What's more, I choose callAppenders as the intercept point before, while it never works after log4j2 2.11.1+
+ *
+ * @author xuhe
+ */
+
+public class AsyncLoggerConfigInstrumentation extends ClassInstanceMethodsEnhancePluginDefine {
+
+    private static final String INTERCEPT_CLASS = "org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async.AsyncLoggerConfigMethodInterceptor";
+    private static final String ENHANCE_CLASS = "org.apache.logging.log4j.core.async.AsyncLoggerConfig";
+    private static final String ENHANCE_METHOD = "populateLazilyInitializedFields";
+
+    @Override
+    public ConstructorInterceptPoint[] getConstructorsInterceptPoints() {
+        return new ConstructorInterceptPoint[0];
+    }
+
+    @Override
+    public InstanceMethodsInterceptPoint[] getInstanceMethodsInterceptPoints() {
+        return new InstanceMethodsInterceptPoint[]{
+            new InstanceMethodsInterceptPoint() {
+                @Override
+                public ElementMatcher<MethodDescription> getMethodsMatcher() {
+                    return named(ENHANCE_METHOD);
+                }
+
+                @Override
+                public String getMethodsInterceptor() {
+                    return INTERCEPT_CLASS;
+                }
+
+                @Override
+                public boolean isOverrideArgs() {
+                    return false;
+                }
+            }
+        };
+    }
+
+    @Override
+    protected ClassMatch enhanceClass() {
+        return byName(ENHANCE_CLASS);
+    }
+}

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/PrintTraceIdInterceptor.java → apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/async/AsyncLoggerConfigMethodInterceptor.java

@@ -16,41 +16,41 @@
  *
  */
 
+package org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async;
 
-package org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x;
-
-import java.lang.reflect.Method;
 import org.apache.skywalking.apm.agent.core.context.ContextManager;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.EnhancedInstance;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstanceMethodsAroundInterceptor;
 import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.MethodInterceptResult;
-import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.StaticMethodsAroundInterceptor;
+
+import java.lang.reflect.Method;
 
 /**
- * Created by wusheng on 2016/12/7.
+ * <p>Pass the global trace Id into the _sw field of Lo4jLogEvent instance after enhancing</p>
+ *
+ * @author xuhe
  */
-public class PrintTraceIdInterceptor implements StaticMethodsAroundInterceptor {
-    /**
-     * Override org.apache.skywalking.apm.toolkit.log.log4j.v2.x.Log4j2OutputAppender.append(),
-     *
-     * @param method
-     * @param result change this result, to output the traceId. The origin append() method will not invoke.
-     */
-    @Override public void beforeMethod(Class clazz, Method method, Object[] allArguments, Class<?>[] parameterTypes,
-        MethodInterceptResult result) {
-        ((StringBuilder)allArguments[0]).append("TID:" + ContextManager.getGlobalTraceId());
-
-        //make sure origin method do not invoke.
-        result.defineReturnValue(null);
-    }
+
+public class AsyncLoggerConfigMethodInterceptor implements InstanceMethodsAroundInterceptor {
+
 
     @Override
-    public Object afterMethod(Class clazz, Method method, Object[] allArguments, Class<?>[] parameterTypes,
-        Object ret) {
-        return null;
+    public void beforeMethod(EnhancedInstance objInst, Method method, Object[] allArguments, Class<?>[] argumentsTypes,
+                             MethodInterceptResult result) throws Throwable {
+        if (allArguments[0] instanceof EnhancedInstance) {
+            EnhancedInstance instances = (EnhancedInstance) allArguments[0];
+            instances.setSkyWalkingDynamicField(ContextManager.getGlobalTraceId());
+        }
     }
 
     @Override
-    public void handleMethodException(Class clazz, Method method, Object[] allArguments, Class<?>[] parameterTypes,
-        Throwable t) {
+    public Object afterMethod(EnhancedInstance objInst, Method method, Object[] allArguments,
+                              Class<?>[] argumentsTypes, Object ret) throws Throwable {
+        return ret;
+    }
 
+    @Override
+    public void handleMethodException(EnhancedInstance objInst, Method method, Object[] allArguments,
+                                      Class<?>[] argumentsTypes, Throwable t) {
     }
 }

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/async/Log4jLogEventConstructorInterceptor.java

+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF 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 org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async;
+
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.EnhancedInstance;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstanceConstructorInterceptor;
+
+/**
+ * Log4jLogEvent implements LogEvent,
+ * which is a message in the Disruptor Array of the AsyncLoggerConfigDisruptor.class, appended by AsyncLoggerConfig.class.
+ * The Log4jLogEvent is enhanced to carry the tid in the synchronization thread using `dynamicField`.
+ *
+ * @author xuhe
+ */
+
+public class Log4jLogEventConstructorInterceptor implements InstanceConstructorInterceptor {
+
+    @Override
+    public void onConstruct(EnhancedInstance objInst, Object[] allArguments) {
+    }
+}

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v2/x/async/Log4jLogEventInstrumentation.java

+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements.  See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF 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 org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async;
+
+import net.bytebuddy.description.method.MethodDescription;
+import net.bytebuddy.matcher.ElementMatcher;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.ConstructorInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.InstanceMethodsInterceptPoint;
+import org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.ClassInstanceMethodsEnhancePluginDefine;
+import org.apache.skywalking.apm.agent.core.plugin.match.ClassMatch;
+
+import static net.bytebuddy.matcher.ElementMatchers.any;
+import static org.apache.skywalking.apm.agent.core.plugin.match.NameMatch.byName;
+
+
+/**
+ * Enhance all the Log4jLogEvent instance so that it can carries the trace id in _sw field
+ *
+ * @author xuhe
+ */
+
+
+public class Log4jLogEventInstrumentation extends ClassInstanceMethodsEnhancePluginDefine {
+    @Override
+    public ConstructorInterceptPoint[] getConstructorsInterceptPoints() {
+        return new ConstructorInterceptPoint[]{
+            new ConstructorInterceptPoint() {
+                @Override
+                public ElementMatcher<MethodDescription> getConstructorMatcher() {
+                    return any();
+                }
+
+                @Override
+                public String getConstructorInterceptor() {
+                    return "org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async.Log4jLogEventConstructorInterceptor";
+                }
+            }
+        };
+    }
+
+    @Override
+    public InstanceMethodsInterceptPoint[] getInstanceMethodsInterceptPoints() {
+        return new InstanceMethodsInterceptPoint[0];
+    }
+
+    @Override
+    protected ClassMatch enhanceClass() {
+        return byName("org.apache.logging.log4j.core.impl.Log4jLogEvent");
+    }
+}
+

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-2.x-activation/src/main/resources/skywalking-plugin.def

@@ -14,4 +14,6 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-toolkit-log4j2=org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.Log4j2OutputAppenderActivation
+toolkit-log4j2=org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.TraceIdConverterActivation
+toolkit-log4j2=org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async.AsyncLoggerConfigInstrumentation
+toolkit-log4j2=org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.async.Log4jLogEventInstrumentation

docs/en/setup/service-agent/java-agent/Application-toolkit-log4j-2.x.md

@@ -15,4 +15,21 @@
       </Console>
    </Appenders>
 ```
+
+* Support log4j2 AsyncRoot (AsyncAppender not supported for now), No additional configuration is required. Refer to the demo of log4j2.xml below. For details: [Log4j2 Async Loggers](https://logging.apache.org/log4j/2.x/manual/async.html)
+```xml
+    <Configuration>
+        <Appenders>
+            <Console name="Console" target="SYSTEM_OUT">
+                <PatternLayout pattern="%d [%traceId] %-5p %c{1}:%L - %m%n"/>
+            </Console>
+        </Appenders>
+        <Loggers>
+            <AsyncRoot level="INFO">
+                <AppenderRef ref="Console"/>
+            </AsyncRoot>
+        </Loggers>
+    </Configuration>
+```
+
 * When you use `-javaagent` to active the sky-walking tracer, log4j2 will output **traceId**, if it existed. If the tracer is inactive, the output will be `TID: N/A`.