From f59251681b994a3e232f7348cd3f5591d94d081e Mon Sep 17 00:00:00 2001 From: Brandon Fergerson Date: Sun, 31 Jan 2021 23:57:37 -0500 Subject: [PATCH] Ability to send log template + arguments instead of pre-formatted message (#6286) --- CHANGES.md | 1 + .../v1/x/log/GRPCLogAppenderActivation.java | 9 ++++ .../v2/x/log/GRPCLogAppenderInterceptor.java | 50 +++++++++++++------ .../v1/x/log/GRPCLogAppenderInterceptor.java | 49 ++++++++++++++---- .../logging/common/log/ToolkitConfig.java | 6 +++ .../Application-toolkit-log4j-2.x.md | 39 ++++++++++++++- .../Application-toolkit-logback-1.x.md | 40 ++++++++++++++- .../setup/service-agent/java-agent/README.md | 1 + 8 files changed, 166 insertions(+), 29 deletions(-) diff --git a/CHANGES.md b/CHANGES.md index 1696a4e0fa..15708cf44d 100644 --- a/CHANGES.md +++ b/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. diff --git a/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 b/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 index 0c17d80c37..702a194312 100644 --- a/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 +++ b/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 diff --git a/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 b/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 index bb5868ef91..f9df92c5ac 100644 --- a/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 +++ b/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(); + } } } diff --git a/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 b/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 index 9335ff4a44..9823b41753 100644 --- a/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 +++ b/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); } } diff --git a/apm-sniffer/apm-toolkit-activation/apm-toolkit-logging-common/src/main/java/org/apache/skywalking/apm/toolkit/logging/common/log/ToolkitConfig.java b/apm-sniffer/apm-toolkit-activation/apm-toolkit-logging-common/src/main/java/org/apache/skywalking/apm/toolkit/logging/common/log/ToolkitConfig.java index 6cc51184a7..ee6d001bcc 100644 --- a/apm-sniffer/apm-toolkit-activation/apm-toolkit-logging-common/src/main/java/org/apache/skywalking/apm/toolkit/logging/common/log/ToolkitConfig.java +++ b/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 { diff --git a/docs/en/setup/service-agent/java-agent/Application-toolkit-log4j-2.x.md b/docs/en/setup/service-agent/java-agent/Application-toolkit-log4j-2.x.md index 00f4ed1d38..30f16b17f4 100644 --- a/docs/en/setup/service-agent/java-agent/Application-toolkit-log4j-2.x.md +++ b/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" + } + ] +} +``` diff --git a/docs/en/setup/service-agent/java-agent/Application-toolkit-logback-1.x.md b/docs/en/setup/service-agent/java-agent/Application-toolkit-logback-1.x.md index 0c44478b26..3e35113bfc 100644 --- a/docs/en/setup/service-agent/java-agent/Application-toolkit-logback-1.x.md +++ b/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" + } + ] +} +``` diff --git a/docs/en/setup/service-agent/java-agent/README.md b/docs/en/setup/service-agent/java-agent/README.md index 2e78cce2a2..c20d40e15c 100755 --- a/docs/en/setup/service-agent/java-agent/README.md +++ b/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` | -- GitLab