Ability to send log template + arguments instead of pre-formatted message (#6286)

CHANGES.md

@@ -40,6 +40,7 @@ Release Notes.
 * Support config `agent.ignore_suffix` can be changed in the runtime.
 * Support DNS periodic resolving mechanism to update backend service.
 * Support config `agent.trace.ignore_path` can be changed in the runtime.
+* Added support for transmitting logback 1.x and log4j 2.x formatted & un-formatted messages via gPRC
 
 #### OAP-Backend
 * Make meter receiver support MAL.

apm-sniffer/apm-toolkit-activation/apm-toolkit-log4j-1.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/log4j/v1/x/log/GRPCLogAppenderActivation.java

@@ -21,6 +21,8 @@ package org.apache.skywalking.apm.toolkit.activation.log.log4j.v1.x.log;
 import static net.bytebuddy.matcher.ElementMatchers.named;
 import static org.apache.skywalking.apm.agent.core.plugin.match.NameMatch.byName;
 
+import org.apache.skywalking.apm.agent.core.logging.api.ILog;
+import org.apache.skywalking.apm.agent.core.logging.api.LogManager;
 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;
@@ -28,6 +30,7 @@ import org.apache.skywalking.apm.agent.core.plugin.match.ClassMatch;
 
 import net.bytebuddy.description.method.MethodDescription;
 import net.bytebuddy.matcher.ElementMatcher;
+import org.apache.skywalking.apm.toolkit.logging.common.log.ToolkitConfig;
 
 /**
  * enhance the method append of the grpc log send log4j class "org.apache.skywalking.apm.toolkit.log.log4j.v1.x.log
@@ -35,6 +38,8 @@ import net.bytebuddy.matcher.ElementMatcher;
  */
 public class GRPCLogAppenderActivation extends ClassInstanceMethodsEnhancePluginDefine {
 
+    private static final ILog LOGGER = LogManager.getLogger(GRPCLogAppenderActivation.class);
+
     public static final String INTERCEPT_CLASS =
             "org.apache.skywalking.apm.toolkit.activation.log.log4j.v1.x.log.GRPCLogAppenderInterceptor";
     public static final String ENHANCE_CLASS =
@@ -53,6 +58,10 @@ public class GRPCLogAppenderActivation extends ClassInstanceMethodsEnhancePlugin
 
     @Override
     public InstanceMethodsInterceptPoint[] getInstanceMethodsInterceptPoints() {
+        if (!ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+            LOGGER.warn("Log4j 1.x does not support transmitting un-formatted messages");
+        }
+
         return new InstanceMethodsInterceptPoint[] {
                 new InstanceMethodsInterceptPoint() {
                     @Override

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

@@ -20,6 +20,7 @@ package org.apache.skywalking.apm.toolkit.activation.log.log4j.v2.x.log;
 
 import java.lang.reflect.Method;
 import java.util.Objects;
+import java.util.Optional;
 
 import org.apache.logging.log4j.core.LogEvent;
 import org.apache.skywalking.apm.agent.core.boot.ServiceManager;
@@ -36,6 +37,7 @@ import org.apache.skywalking.apm.network.logging.v3.LogDataBody;
 import org.apache.skywalking.apm.network.logging.v3.LogTags;
 import org.apache.skywalking.apm.network.logging.v3.TextLog;
 import org.apache.skywalking.apm.network.logging.v3.TraceContext;
+import org.apache.skywalking.apm.toolkit.logging.common.log.ToolkitConfig;
 
 public class GRPCLogAppenderInterceptor implements InstanceMethodsAroundInterceptor {
 
@@ -75,30 +77,48 @@ public class GRPCLogAppenderInterceptor implements InstanceMethodsAroundIntercep
      * @return {@link LogData} with filtered trace context in order to reduce the cost on the network
      */
     private LogData transform(LogEvent event) {
+        LogTags.Builder logTags = LogTags.newBuilder()
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("level").setValue(event.getLevel().toString()).build())
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("logger").setValue(event.getLoggerName()).build())
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("thread").setValue(event.getThreadName()).build());
+        if (!ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+            if (event.getMessage().getParameters() != null) {
+                for (int i = 0; i < event.getMessage().getParameters().length; i++) {
+                    String value = Optional.ofNullable(event.getMessage().getParameters()[i]).orElse("null").toString();
+                    logTags.addData(KeyStringValuePair.newBuilder()
+                            .setKey("argument." + i).setValue(value).build());
+                }
+            }
+
+            if (event.getThrown() != null) {
+                logTags.addData(KeyStringValuePair.newBuilder()
+                        .setKey("exception").setValue(ThrowableTransformer.INSTANCE.convert2String(event.getThrown(), 2048)).build());
+            }
+        }
+
         LogData.Builder builder = LogData.newBuilder()
                 .setTimestamp(event.getTimeMillis())
                 .setService(Config.Agent.SERVICE_NAME)
                 .setServiceInstance(Config.Agent.INSTANCE_NAME)
-                .setTags(LogTags.newBuilder()
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("level").setValue(event.getLevel().toString()).build())
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("logger").setValue(event.getLoggerName()).build())
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("thread").setValue(event.getThreadName()).build())
-                        .build())
+                .setTags(logTags.build())
                 .setBody(LogDataBody.newBuilder().setType(LogDataBody.ContentCase.TEXT.name())
-                        .setText(TextLog.newBuilder().setText(transformLogText(event)).build())
-                        .build());
+                        .setText(TextLog.newBuilder().setText(transformLogText(event)).build()).build());
         return -1 == ContextManager.getSpanId() ? builder.build()
                 : builder.setTraceContext(TraceContext.newBuilder()
-                        .setTraceId(ContextManager.getGlobalTraceId())
-                        .setSpanId(ContextManager.getSpanId())
-                        .setTraceSegmentId(ContextManager.getSegmentId())
-                        .build()).build();
+                .setTraceId(ContextManager.getGlobalTraceId())
+                .setSpanId(ContextManager.getSpanId())
+                .setTraceSegmentId(ContextManager.getSegmentId())
+                .build()).build();
     }
 
     private String transformLogText(final LogEvent event) {
-        return event.getMessage().getFormattedMessage() + "\n" + ThrowableTransformer.INSTANCE.convert2String(event.getThrown(), 2048);
+        if (ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+            return event.getMessage().getFormattedMessage() + "\n" + ThrowableTransformer.INSTANCE.convert2String(event.getThrown(), 2048);
+        } else {
+            return event.getMessage().getFormat();
+        }
     }
 }

apm-sniffer/apm-toolkit-activation/apm-toolkit-logback-1.x-activation/src/main/java/org/apache/skywalking/apm/toolkit/activation/log/logback/v1/x/log/GRPCLogAppenderInterceptor.java

@@ -22,6 +22,7 @@ import ch.qos.logback.classic.spi.IThrowableProxy;
 import ch.qos.logback.classic.spi.ThrowableProxy;
 import java.lang.reflect.Method;
 import java.util.Objects;
+import java.util.Optional;
 
 import org.apache.skywalking.apm.agent.core.boot.ServiceManager;
 import org.apache.skywalking.apm.agent.core.conf.Config;
@@ -39,6 +40,7 @@ import org.apache.skywalking.apm.network.logging.v3.TextLog;
 import org.apache.skywalking.apm.network.logging.v3.TraceContext;
 
 import ch.qos.logback.classic.spi.ILoggingEvent;
+import org.apache.skywalking.apm.toolkit.logging.common.log.ToolkitConfig;
 
 public class GRPCLogAppenderInterceptor implements InstanceMethodsAroundInterceptor {
 
@@ -78,18 +80,35 @@ public class GRPCLogAppenderInterceptor implements InstanceMethodsAroundIntercep
      * @return {@link LogData} with filtered trace context in order to reduce the cost on the network
      */
     private LogData transform(ILoggingEvent event) {
+        LogTags.Builder logTags = LogTags.newBuilder()
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("level").setValue(event.getLevel().toString()).build())
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("logger").setValue(event.getLoggerName()).build())
+                .addData(KeyStringValuePair.newBuilder()
+                        .setKey("thread").setValue(event.getThreadName()).build());
+        if (!ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+            if (event.getArgumentArray() != null) {
+                for (int i = 0; i < event.getArgumentArray().length; i++) {
+                    String value = Optional.ofNullable(event.getArgumentArray()[i]).orElse("null").toString();
+                    logTags.addData(KeyStringValuePair.newBuilder()
+                            .setKey("argument." + i).setValue(value).build());
+                }
+            }
+
+            final IThrowableProxy throwableProxy = event.getThrowableProxy();
+            if (throwableProxy instanceof ThrowableProxy) {
+                Throwable throwable = ((ThrowableProxy) throwableProxy).getThrowable();
+                logTags.addData(KeyStringValuePair.newBuilder()
+                        .setKey("exception").setValue(ThrowableTransformer.INSTANCE.convert2String(throwable, 2048)).build());
+            }
+        }
+
         LogData.Builder builder = LogData.newBuilder()
                 .setTimestamp(event.getTimeStamp())
                 .setService(Config.Agent.SERVICE_NAME)
                 .setServiceInstance(Config.Agent.INSTANCE_NAME)
-                .setTags(LogTags.newBuilder()
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("level").setValue(event.getLevel().toString()).build())
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("logger").setValue(event.getLoggerName()).build())
-                        .addData(KeyStringValuePair.newBuilder()
-                                .setKey("thread").setValue(event.getThreadName()).build())
-                        .build())
+                .setTags(logTags.build())
                 .setBody(LogDataBody.newBuilder().setType(LogDataBody.ContentCase.TEXT.name())
                                     .setText(TextLog.newBuilder().setText(transformLogText(event)).build()).build());
         return -1 == ContextManager.getSpanId() ? builder.build()
@@ -103,9 +122,17 @@ public class GRPCLogAppenderInterceptor implements InstanceMethodsAroundIntercep
     private String transformLogText(final ILoggingEvent event) {
         final IThrowableProxy throwableProxy = event.getThrowableProxy();
         if (!(throwableProxy instanceof ThrowableProxy)) {
-            return event.getFormattedMessage();
+            if (ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+                return event.getFormattedMessage();
+            } else {
+                return event.getMessage();
+            }
+        }
+        if (ToolkitConfig.Plugin.Toolkit.Log.TRANSMIT_FORMATTED) {
+            final Throwable throwable = ((ThrowableProxy) throwableProxy).getThrowable();
+            return event.getFormattedMessage() + "\n" + ThrowableTransformer.INSTANCE.convert2String(throwable, 2048);
+        } else {
+            return event.getMessage();
         }
-        final Throwable throwable = ((ThrowableProxy) throwableProxy).getThrowable();
-        return event.getFormattedMessage() + "\n" + ThrowableTransformer.INSTANCE.convert2String(throwable, 2048);
     }
 }

apm-sniffer/apm-toolkit-activation/apm-toolkit-logging-common/src/main/java/org/apache/skywalking/apm/toolkit/logging/common/log/ToolkitConfig.java

@@ -24,7 +24,13 @@ public class ToolkitConfig {
 
     public static class Plugin {
         public static class Toolkit {
+            @PluginConfig(root = ToolkitConfig.class)
             public static class Log {
+                /**
+                 * Whether or not to transmit logged data as formatted or un-formatted.
+                 */
+                public static boolean TRANSMIT_FORMATTED = true;
+
                 public static class GRPC {
                     @PluginConfig(root = ToolkitConfig.class)
                     public static class Reporter {

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

@@ -121,4 +121,41 @@ plugin.toolkit.log.grpc.reporter.server_host=${SW_GRPC_LOG_SERVER_HOST:127.0.0.1
 plugin.toolkit.log.grpc.reporter.server_port=${SW_GRPC_LOG_SERVER_PORT:11800}
 plugin.toolkit.log.grpc.reporter.max_message_size=${SW_GRPC_LOG_MAX_MESSAGE_SIZE:10485760}
 plugin.toolkit.log.grpc.reporter.upstream_timeout=${SW_GRPC_LOG_GRPC_UPSTREAM_TIMEOUT:30}
-```
\ No newline at end of file
+```
+
+
+## Transmitting un-formatted messages
+
+The log4j 2.x gRPC reporter supports transmitting logs as formatted or un-formatted. Transmitting formatted data is the default but can be disabled by adding the following to the agent config:
+
+```
+plugin.toolkit.log.transmit_formatted=false
+```
+
+The above will result in the `content` field being used for the log pattern with additional log tags of `argument.0`, `argument.1`, and so on representing each logged argument as well as an additional `exception` tag which is only present if a throwable is also logged.
+
+For example, the following code:
+```java
+log.info("{} {} {}", 1, 2, 3);
+```
+
+Will result in:
+```json
+{
+  "content": "{} {} {}",
+  "tags": [
+    {
+      "key": "argument.0",
+      "value": "1"
+    },
+    {
+      "key": "argument.1",
+      "value": "2"
+    },
+    {
+      "key": "argument.2",
+      "value": "3"
+    }
+  ]
+}
+```

docs/en/setup/service-agent/java-agent/Application-toolkit-logback-1.x.md

@@ -113,7 +113,7 @@
 
 # gRPC reporter
 
-The gRPC report could forward the collected logs to SkyWalking OAP server, or [SkyWalking Satellite sidecar](https://github.com/apache/skywalking-satellite). Trace id, segment id, and span id will attach to logs automatically. You don't need to change the layout.
+The gRPC reporter could forward the collected logs to SkyWalking OAP server, or [SkyWalking Satellite sidecar](https://github.com/apache/skywalking-satellite). Trace id, segment id, and span id will attach to logs automatically. There is no need to modify existing layouts.
 
 * Add `GRPCLogClientAppender` in logback.xml
 
@@ -128,4 +128,40 @@ plugin.toolkit.log.grpc.reporter.server_host=${SW_GRPC_LOG_SERVER_HOST:127.0.0.1
 plugin.toolkit.log.grpc.reporter.server_port=${SW_GRPC_LOG_SERVER_PORT:11800}
 plugin.toolkit.log.grpc.reporter.max_message_size=${SW_GRPC_LOG_MAX_MESSAGE_SIZE:10485760}
 plugin.toolkit.log.grpc.reporter.upstream_timeout=${SW_GRPC_LOG_GRPC_UPSTREAM_TIMEOUT:30}
-```
\ No newline at end of file
+```
+
+## Transmitting un-formatted messages
+
+The logback 1.x gRPC reporter supports transmitting logs as formatted or un-formatted. Transmitting formatted data is the default but can be disabled by adding the following to the agent config:
+
+```
+plugin.toolkit.log.transmit_formatted=false
+```
+
+The above will result in the `content` field being used for the log pattern with additional log tags of `argument.0`, `argument.1`, and so on representing each logged argument as well as an additional `exception` tag which is only present if a throwable is also logged.
+
+For example, the following code:
+```java
+log.info("{} {} {}", 1, 2, 3);
+```
+
+Will result in:
+```json
+{
+  "content": "{} {} {}",
+  "tags": [
+    {
+      "key": "argument.0",
+      "value": "1"
+    },
+    {
+      "key": "argument.1",
+      "value": "2"
+    },
+    {
+      "key": "argument.2",
+      "value": "3"
+    }
+  ]
+}
+```

docs/en/setup/service-agent/java-agent/README.md

@@ -161,6 +161,7 @@ property key | Description | Default |
 `plugin.kafka.topic_profilings` | Specify which Kafka topic name for Thread Profiling snapshot to report to. | `skywalking_profilings` |
 `plugin.kafka.topic_management` | Specify which Kafka topic name for the register or heartbeat data of Service Instance to report to. | `skywalking_managements` |
 `plugin.springannotation.classname_match_regex` |  Match spring beans with regular expression for the class name. Multiple expressions could be separated by a comma. This only works when `Spring annotation plugin` has been activated. | `All the spring beans tagged with @Bean,@Service,@Dao, or @Repository.` |
+`plugin.toolkit.log.transmit_formatted` | Whether or not to transmit logged data as formatted or un-formatted. | `true` |
 `plugin.toolkit.log.grpc.reporter.server_host` | Specify which grpc server's host for log data to report to. | `127.0.0.1` |
 `plugin.toolkit.log.grpc.reporter.server_port` | Specify which grpc server's port for log data to report to. | `11800` |
 `plugin.toolkit.log.grpc.reporter.max_message_size` | Specify the maximum size of log data for grpc client to report to. | `10485760` |