diff --git a/inspectit-ocelot-agent/build.gradle b/inspectit-ocelot-agent/build.gradle index a2d316520b..36f0ab3581 100644 --- a/inspectit-ocelot-agent/build.gradle +++ b/inspectit-ocelot-agent/build.gradle @@ -184,7 +184,7 @@ task systemTest { doFirst { jvmArgs "-Dinspectit.config.file-based.path=$projectDir/src/system-test/resources/config" // make inspectIT scan the workdir for configs jvmArgs "-Dinspectit.publishOpenCensusToBootstrap=true" // make inspectIT push OC to the bootstrap - jvmArgs jacoco.asJvmArg + ",inclbootstrapclasses=true" // JaCoCo agent first + bootstrap instrumentaiton + jvmArgs jacoco.asJvmArg + ",inclbootstrapclasses=true" // JaCoCo agent first + bootstrap instrumentation jvmArgs "-javaagent:${agentJarPath}" // Our agent second. jacoco.enabled = false // Don't add the JaCoCo agent again. } diff --git a/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4J2TraceIdAutoInjectorTest.java b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4J2TraceIdAutoInjectorTest.java new file mode 100644 index 0000000000..42b650a587 --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4J2TraceIdAutoInjectorTest.java @@ -0,0 +1,111 @@ +package rocks.inspectit.ocelot.instrumentation.special.logging; + +import io.opencensus.common.Scope; +import io.opencensus.trace.Tracing; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; +import org.junit.jupiter.api.Test; +import rocks.inspectit.ocelot.instrumentation.InstrumentationSysTestBase; +import rocks.inspectit.ocelot.logging.Log4J2LoggingRecorder; + +import static org.assertj.core.api.Assertions.assertThat; + +public class Log4J2TraceIdAutoInjectorTest extends InstrumentationSysTestBase { + + private static final Logger LOGGER = LogManager.getLogger(Log4J2TraceIdAutoInjectorTest.class); + + @Test + public void logStringAndTraceExists() { + Log4J2LoggingRecorder.loggingEvents.clear(); + String message = "This is a traced String in {}."; + String traceId; + + try (Scope scope = Tracing.getTracer().spanBuilder("test").startScopedSpan()) { + traceId = Tracing.getTracer().getCurrentSpan().getContext().getTraceId().toLowerBase16(); + + LOGGER.info(message, "Log4J2"); + } + + assertThat(Log4J2LoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4J2LoggingRecorder.loggingEvents.get(0)) + .extracting(event -> event.getMessage().getFormattedMessage()) + .isEqualTo("[TraceID: " + traceId + "] This is a traced String in Log4J2."); + } + + @Test + public void logCharSequenceAndTraceExists() { + Log4J2LoggingRecorder.loggingEvents.clear(); + CharSequence message = "This is a traced CharSequence in Log4J2."; + String traceId; + + try (Scope scope = Tracing.getTracer().spanBuilder("test").startScopedSpan()) { + traceId = Tracing.getTracer().getCurrentSpan().getContext().getTraceId().toLowerBase16(); + + LOGGER.info(message); + } + + assertThat(Log4J2LoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4J2LoggingRecorder.loggingEvents.get(0)) + .extracting(event -> event.getMessage().getFormattedMessage()) + .isEqualTo("[TraceID: " + traceId + "] This is a traced CharSequence in Log4J2."); + } + + @Test + public void logObjectAndTraceExists() { + Log4J2LoggingRecorder.loggingEvents.clear(); + Object message = "This is a traced Object in Log4J2."; + String traceId; + + try (Scope scope = Tracing.getTracer().spanBuilder("test").startScopedSpan()) { + traceId = Tracing.getTracer().getCurrentSpan().getContext().getTraceId().toLowerBase16(); + + LOGGER.info(message); + } + + assertThat(Log4J2LoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4J2LoggingRecorder.loggingEvents.get(0)) + .extracting(event -> event.getMessage().getFormattedMessage()) + .isEqualTo("[TraceID: " + traceId + "] This is a traced Object in Log4J2."); + } + + @Test + public void logNullAndTraceExists() { + Log4J2LoggingRecorder.loggingEvents.clear(); + Object message = null; + String traceId; + + try (Scope scope = Tracing.getTracer().spanBuilder("test").startScopedSpan()) { + traceId = Tracing.getTracer().getCurrentSpan().getContext().getTraceId().toLowerBase16(); + + LOGGER.info(message); + } + + assertThat(Log4J2LoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4J2LoggingRecorder.loggingEvents.get(0)) + .extracting(event -> event.getMessage().getFormattedMessage()) + .isEqualTo("[TraceID: " + traceId + "] null"); + } + + @Test + public void traceNotExists() { + Log4J2LoggingRecorder.loggingEvents.clear(); + String message = "This is {}."; + + LOGGER.info(message, "Log4J2"); + + assertThat(Log4J2LoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4J2LoggingRecorder.loggingEvents.get(0)) + .extracting(event -> event.getMessage().getFormattedMessage()) + .isEqualTo("This is Log4J2."); + } +} diff --git a/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4JTraceIdAutoInjectorTest.java b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4JTraceIdAutoInjectorTest.java new file mode 100644 index 0000000000..3583976711 --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/instrumentation/special/logging/Log4JTraceIdAutoInjectorTest.java @@ -0,0 +1,51 @@ +package rocks.inspectit.ocelot.instrumentation.special.logging; + +import io.opencensus.common.Scope; +import io.opencensus.trace.Tracing; +import org.apache.log4j.Logger; +import org.apache.log4j.spi.LoggingEvent; +import org.junit.jupiter.api.Test; +import rocks.inspectit.ocelot.instrumentation.InstrumentationSysTestBase; +import rocks.inspectit.ocelot.logging.Log4JLoggingRecorder; + +import static org.assertj.core.api.Assertions.assertThat; + +public class Log4JTraceIdAutoInjectorTest extends InstrumentationSysTestBase { + + private static final Logger LOGGER = Logger.getLogger(Log4JTraceIdAutoInjectorTest.class.getName()); + + @Test + public void traceExists() { + Log4JLoggingRecorder.loggingEvents.clear(); + String message = "This is a test."; + String traceId; + + try (Scope scope = Tracing.getTracer().spanBuilder("test").startScopedSpan()) { + traceId = Tracing.getTracer().getCurrentSpan().getContext().getTraceId().toLowerBase16(); + + LOGGER.error(message); + } + + assertThat(Log4JLoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4JLoggingRecorder.loggingEvents.get(0)) + .extracting(LoggingEvent::getMessage) + .isEqualTo("[TraceID: " + traceId + "] " + message); + } + + @Test + public void traceNotExists() { + Log4JLoggingRecorder.loggingEvents.clear(); + String message = "This is a test."; + + LOGGER.error(message); + + assertThat(Log4JLoggingRecorder.loggingEvents) + .hasSize(1); + + assertThat(Log4JLoggingRecorder.loggingEvents.get(0)) + .extracting(LoggingEvent::getMessage) + .isEqualTo(message); + } +} diff --git a/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4J2LoggingRecorder.java b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4J2LoggingRecorder.java new file mode 100644 index 0000000000..56ef728d4d --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4J2LoggingRecorder.java @@ -0,0 +1,36 @@ +package rocks.inspectit.ocelot.logging; + +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.Core; +import org.apache.logging.log4j.core.Filter; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.appender.AbstractAppender; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.config.plugins.PluginAttribute; +import org.apache.logging.log4j.core.config.plugins.PluginElement; +import org.apache.logging.log4j.core.config.plugins.PluginFactory; + +import java.util.ArrayList; +import java.util.List; + +@Plugin(name = "Log4J2LoggingRecorder", + category = Core.CATEGORY_NAME, + elementType = Appender.ELEMENT_TYPE) +public class Log4J2LoggingRecorder extends AbstractAppender { + + public static final List loggingEvents = new ArrayList<>(); + + protected Log4J2LoggingRecorder(String name, Filter filter) { + super(name, filter, null); + } + + @Override + public void append(LogEvent event) { + loggingEvents.add(event); + } + + @PluginFactory + public static Log4J2LoggingRecorder createAppender(@PluginAttribute("name") String name, @PluginElement("Filter") Filter filter) { + return new Log4J2LoggingRecorder(name, filter); + } +} diff --git a/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4JLoggingRecorder.java b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4JLoggingRecorder.java new file mode 100644 index 0000000000..a9f4524095 --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/java/rocks/inspectit/ocelot/logging/Log4JLoggingRecorder.java @@ -0,0 +1,27 @@ +package rocks.inspectit.ocelot.logging; + +import org.apache.log4j.AppenderSkeleton; +import org.apache.log4j.spi.LoggingEvent; + +import java.util.ArrayList; +import java.util.List; + +public class Log4JLoggingRecorder extends AppenderSkeleton { + + public static final List loggingEvents = new ArrayList<>(); + + @Override + protected void append(LoggingEvent event) { + loggingEvents.add(event); + } + + @Override + public void close() { + + } + + @Override + public boolean requiresLayout() { + return false; + } +} diff --git a/inspectit-ocelot-agent/src/system-test/resources/config/LogCorrelationTest.yml b/inspectit-ocelot-agent/src/system-test/resources/config/LogCorrelationTest.yml index 87759fa6c6..624f523cec 100644 --- a/inspectit-ocelot-agent/src/system-test/resources/config/LogCorrelationTest.yml +++ b/inspectit-ocelot-agent/src/system-test/resources/config/LogCorrelationTest.yml @@ -1,8 +1,15 @@ inspectit: tracing: - log-correlation: + log-correlation: + trace-id-mdc-injection: enabled: true + + trace-id-auto-injection: + enabled: true + prefix: "[TraceID: " + suffix: "] " + instrumentation: scopes: LogCorrelationTest-methods: diff --git a/inspectit-ocelot-agent/src/system-test/resources/log4j.properties b/inspectit-ocelot-agent/src/system-test/resources/log4j.properties new file mode 100644 index 0000000000..b3ff16faf4 --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/resources/log4j.properties @@ -0,0 +1,8 @@ +log4j.rootLogger=DEBUG, recorder, stdout + +log4j.appender.recorder=rocks.inspectit.ocelot.logging.Log4JLoggingRecorder + +log4j.appender.stdout=org.apache.log4j.ConsoleAppender +log4j.appender.stdout.Target=System.out +log4j.appender.stdout.layout=org.apache.log4j.PatternLayout +log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1} - %m%n \ No newline at end of file diff --git a/inspectit-ocelot-agent/src/system-test/resources/log4j2.xml b/inspectit-ocelot-agent/src/system-test/resources/log4j2.xml new file mode 100644 index 0000000000..6bc5f0726a --- /dev/null +++ b/inspectit-ocelot-agent/src/system-test/resources/log4j2.xml @@ -0,0 +1,15 @@ + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/Instances.java b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/Instances.java index 49d709b925..67c645cb57 100644 --- a/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/Instances.java +++ b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/Instances.java @@ -3,7 +3,9 @@ import rocks.inspectit.ocelot.bootstrap.context.IContextManager; import rocks.inspectit.ocelot.bootstrap.context.noop.NoopContextManager; import rocks.inspectit.ocelot.bootstrap.correlation.LogTraceCorrelator; +import rocks.inspectit.ocelot.bootstrap.correlation.TraceIdInjector; import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopLogTraceCorrelator; +import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopTraceIdInjector; import rocks.inspectit.ocelot.bootstrap.exposed.ObjectAttachments; import rocks.inspectit.ocelot.bootstrap.instrumentation.IHookManager; import rocks.inspectit.ocelot.bootstrap.instrumentation.noop.NoopHookManager; @@ -37,4 +39,6 @@ public class Instances { public static ObjectAttachments attachments = NoopObjectAttachments.INSTANCE; public static LogTraceCorrelator logTraceCorrelator = NoopLogTraceCorrelator.INSTANCE; + + public static TraceIdInjector traceIdInjector = NoopTraceIdInjector.INSTANCE; } diff --git a/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/TraceIdInjector.java b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/TraceIdInjector.java new file mode 100644 index 0000000000..64c8c650bc --- /dev/null +++ b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/TraceIdInjector.java @@ -0,0 +1,16 @@ +package rocks.inspectit.ocelot.bootstrap.correlation; + +/** + * Implementations of this interface will inject the current trace id (if existing) into the given message. Normally, + * the message is a log format of a logging framework. + */ +public interface TraceIdInjector { + + /** + * Injects the trace id (if existing) into the given message and returns the result. + * + * @param message the message to use + * @return the resulting object of the injection + */ + Object injectTraceId(Object message); +} diff --git a/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/noop/NoopTraceIdInjector.java b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/noop/NoopTraceIdInjector.java new file mode 100644 index 0000000000..33b10ab458 --- /dev/null +++ b/inspectit-ocelot-bootstrap/src/main/java/rocks/inspectit/ocelot/bootstrap/correlation/noop/NoopTraceIdInjector.java @@ -0,0 +1,22 @@ +package rocks.inspectit.ocelot.bootstrap.correlation.noop; + +import rocks.inspectit.ocelot.bootstrap.correlation.TraceIdInjector; + +/** + * No-operation implementation of the {@link TraceIdInjector}. + */ +public class NoopTraceIdInjector implements TraceIdInjector { + + /** + * Singleton instance. + */ + public static final TraceIdInjector INSTANCE = new NoopTraceIdInjector(); + + private NoopTraceIdInjector() { + } + + @Override + public Object injectTraceId(Object message) { + return message; + } +} diff --git a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/LogCorrelationSettings.java b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/LogCorrelationSettings.java index d12d299df6..af55bd0963 100644 --- a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/LogCorrelationSettings.java +++ b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/LogCorrelationSettings.java @@ -3,21 +3,21 @@ import lombok.Data; import lombok.NoArgsConstructor; -import javax.validation.constraints.NotBlank; +import javax.validation.Valid; @Data @NoArgsConstructor public class LogCorrelationSettings { /** - * Specifies whether log correlation shall be performed or not. - * If enabled, the currently active traceID will be published to the MDC of all log libraries. + * Settings for the injection of trace ids into logging MDCs. */ - private boolean enabled; + @Valid + private TraceIdMDCInjectionSettings traceIdMdcInjection = new TraceIdMDCInjectionSettings(); /** - * The key under which the traceid is placed in the MDCs. + * Settings for the auto injection of trace ids into log messages. */ - @NotBlank - private String key; + @Valid + private TraceIdAutoInjectionSettings traceIdAutoInjection = new TraceIdAutoInjectionSettings(); } diff --git a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdAutoInjectionSettings.java b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdAutoInjectionSettings.java new file mode 100644 index 0000000000..7c46908e04 --- /dev/null +++ b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdAutoInjectionSettings.java @@ -0,0 +1,28 @@ +package rocks.inspectit.ocelot.config.model.tracing; + +import lombok.Data; +import lombok.NoArgsConstructor; + +/** + * Settings for the auto injection of trace ids into log messages. The trace id will be injected into a message in the + * following format: [PREFIX]_trace_id_[SUFFIX]_message_ + */ +@Data +@NoArgsConstructor +public class TraceIdAutoInjectionSettings { + + /** + * Whether the auto injection is enabled. + */ + private boolean enabled; + + /** + * The used prefix. + */ + private String prefix; + + /** + * The used suffix. + */ + private String suffix; +} diff --git a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdMDCInjectionSettings.java b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdMDCInjectionSettings.java new file mode 100644 index 0000000000..2e725ea4d9 --- /dev/null +++ b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TraceIdMDCInjectionSettings.java @@ -0,0 +1,23 @@ +package rocks.inspectit.ocelot.config.model.tracing; + +import lombok.Data; +import lombok.NoArgsConstructor; + +import javax.validation.constraints.NotBlank; + +@Data +@NoArgsConstructor +public class TraceIdMDCInjectionSettings { + + /** + * Specifies whether log correlation shall be performed or not. + * If enabled, the currently active traceID will be published to the MDC of all log libraries. + */ + private boolean enabled; + + /** + * The key under which the traceid is placed in the MDCs. + */ + @NotBlank + private String key; +} diff --git a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TracingSettings.java b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TracingSettings.java index eaf8bf7d7b..df777e34b8 100644 --- a/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TracingSettings.java +++ b/inspectit-ocelot-config/src/main/java/rocks/inspectit/ocelot/config/model/tracing/TracingSettings.java @@ -27,7 +27,9 @@ public class TracingSettings { @Min(0) private double sampleProbability; + /** + * Settings for log correlation. + */ @Valid - private LogCorrelationSettings logCorrelation; - + private LogCorrelationSettings logCorrelation = new LogCorrelationSettings(); } diff --git a/inspectit-ocelot-config/src/main/resources/rocks/inspectit/ocelot/config/default/basics.yml b/inspectit-ocelot-config/src/main/resources/rocks/inspectit/ocelot/config/default/basics.yml index d0b1efa249..4f8e0565f8 100644 --- a/inspectit-ocelot-config/src/main/resources/rocks/inspectit/ocelot/config/default/basics.yml +++ b/inspectit-ocelot-config/src/main/resources/rocks/inspectit/ocelot/config/default/basics.yml @@ -31,9 +31,22 @@ inspectit: # this value can be overridden by the tracing settings of individual instrumentation rules. sample-probability: 1.0 + # settings regarding log correlation log-correlation: - enabled: false - key: "traceid" + + trace-id-mdc-injection: + # whether existing trace ids should be injected into the logging framework's MDC + enabled: false + # the key which is used to store the trace id in the MDC + key: "traceid" + + trace-id-auto-injection: + # whether the trace id should automatically injected into log statements + enabled: false + # the prefix to use when injecting a trace id + prefix: "[TraceID: " + # the suffix to use when injecting a trace id + suffix: "]" # general settings regarding metrics capturing metrics: diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/config/spring/BootstrapInitializerConfiguration.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/config/spring/BootstrapInitializerConfiguration.java index 16bf512e15..e55f425057 100644 --- a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/config/spring/BootstrapInitializerConfiguration.java +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/config/spring/BootstrapInitializerConfiguration.java @@ -4,6 +4,9 @@ import org.springframework.context.annotation.Configuration; import rocks.inspectit.ocelot.bootstrap.Instances; import rocks.inspectit.ocelot.bootstrap.context.noop.NoopContextManager; +import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopLogTraceCorrelator; +import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopTraceIdInjector; +import rocks.inspectit.ocelot.bootstrap.instrumentation.noop.NoopHookManager; import rocks.inspectit.ocelot.bootstrap.instrumentation.noop.NoopObjectAttachments; import rocks.inspectit.ocelot.core.config.InspectitEnvironment; import rocks.inspectit.ocelot.core.instrumentation.config.InstrumentationConfigurationResolver; @@ -42,7 +45,7 @@ public ObjectAttachmentsImpl getObjectAttachments() { @Bean(LogTraceCorrelatorImpl.BEAN_NAME) public LogTraceCorrelatorImpl getLogTraceCorrelator(MDCAccess access, InspectitEnvironment env) { - String key = env.getCurrentConfig().getTracing().getLogCorrelation().getKey(); + String key = env.getCurrentConfig().getTracing().getLogCorrelation().getTraceIdMdcInjection().getKey(); LogTraceCorrelatorImpl correlator = new LogTraceCorrelatorImpl(access, key); return correlator; } @@ -51,5 +54,8 @@ public LogTraceCorrelatorImpl getLogTraceCorrelator(MDCAccess access, InspectitE void destroy() { Instances.contextManager = NoopContextManager.INSTANCE; Instances.attachments = NoopObjectAttachments.INSTANCE; + Instances.hookManager = NoopHookManager.INSTANCE; + Instances.logTraceCorrelator = NoopLogTraceCorrelator.INSTANCE; + Instances.traceIdInjector = NoopTraceIdInjector.INSTANCE; } } diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/InstrumentationConfigurationResolver.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/InstrumentationConfigurationResolver.java index 13be41b86b..e85186abcd 100644 --- a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/InstrumentationConfigurationResolver.java +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/InstrumentationConfigurationResolver.java @@ -198,12 +198,13 @@ private void inspectitConfigChanged(InspectitConfigChangedEvent ev) { } } - private InstrumentationConfiguration resolveConfiguration(InstrumentationSettings source, MetricsSettings metrics, TracingSettings tracing) { + private InstrumentationConfiguration resolveConfiguration(InstrumentationSettings source, MetricsSettings metricsSettings, TracingSettings tracingSettings) { val genericActions = genericActionConfigurationResolver.resolveActions(source); return InstrumentationConfiguration.builder() - .metricsEnabled(metrics.isEnabled()) - .tracingEnabled(tracing.isEnabled()) - .defaultTraceSampleProbability(tracing.getSampleProbability()) + .metricsEnabled(metricsSettings.isEnabled()) + .tracingEnabled(tracingSettings.isEnabled()) + .tracingSettings(tracingSettings) + .defaultTraceSampleProbability(tracingSettings.getSampleProbability()) .source(source) .rules(ruleResolver.resolve(source, genericActions)) .dataProperties(resolveDataProperties(source)) diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/model/InstrumentationConfiguration.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/model/InstrumentationConfiguration.java index e7e289c625..d1900fec13 100644 --- a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/model/InstrumentationConfiguration.java +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/config/model/InstrumentationConfiguration.java @@ -47,6 +47,8 @@ public class InstrumentationConfiguration { private DataProperties dataProperties; + private TracingSettings tracingSettings; + /** * The currently active instrumentation rules. */ diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/LogTraceCorrelationActivator.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/LogTraceCorrelationActivator.java index f180faea17..e7ffd27359 100644 --- a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/LogTraceCorrelationActivator.java +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/LogTraceCorrelationActivator.java @@ -6,7 +6,7 @@ import rocks.inspectit.ocelot.bootstrap.Instances; import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopLogTraceCorrelator; import rocks.inspectit.ocelot.config.model.InspectitConfig; -import rocks.inspectit.ocelot.config.model.tracing.LogCorrelationSettings; +import rocks.inspectit.ocelot.config.model.tracing.TraceIdMDCInjectionSettings; import rocks.inspectit.ocelot.core.config.InspectitConfigChangedEvent; import rocks.inspectit.ocelot.core.config.InspectitEnvironment; @@ -29,7 +29,7 @@ public class LogTraceCorrelationActivator { @EventListener(InspectitConfigChangedEvent.class) void update() { InspectitConfig config = environment.getCurrentConfig(); - LogCorrelationSettings logCorrelation = config.getTracing().getLogCorrelation(); + TraceIdMDCInjectionSettings logCorrelation = config.getTracing().getLogCorrelation().getTraceIdMdcInjection(); if (logCorrelation.isEnabled()) { correlatorImpl.setTraceIdKey(logCorrelation.getKey()); Instances.logTraceCorrelator = correlatorImpl; diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorActivator.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorActivator.java new file mode 100644 index 0000000000..8d2f51abba --- /dev/null +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorActivator.java @@ -0,0 +1,43 @@ +package rocks.inspectit.ocelot.core.instrumentation.correlation.log; + +import org.springframework.beans.factory.annotation.Autowired; +import org.springframework.context.event.EventListener; +import org.springframework.stereotype.Component; +import rocks.inspectit.ocelot.bootstrap.Instances; +import rocks.inspectit.ocelot.bootstrap.correlation.noop.NoopTraceIdInjector; +import rocks.inspectit.ocelot.config.model.tracing.TraceIdAutoInjectionSettings; +import rocks.inspectit.ocelot.config.model.tracing.TracingSettings; +import rocks.inspectit.ocelot.core.config.InspectitConfigChangedEvent; +import rocks.inspectit.ocelot.core.config.InspectitEnvironment; + +import javax.annotation.PostConstruct; + +/** + * This component handles the injection of the {@link rocks.inspectit.ocelot.bootstrap.correlation.TraceIdInjector} instance + * into the {@link Instances} class of the bootstrap classloader. + */ +@Component +public class TraceIdInjectorActivator { + + @Autowired + private InspectitEnvironment environment; + + /** + * Adds a new instance of the {@link rocks.inspectit.ocelot.bootstrap.correlation.TraceIdInjector} into {@link Instances} + * if auto injection is enabled. Otherwise it will use the noop instance. + */ + @PostConstruct + @EventListener(InspectitConfigChangedEvent.class) + public void activateInjector() { + TracingSettings tracingSettings = environment.getCurrentConfig().getTracing(); + TraceIdAutoInjectionSettings injectionSettings = tracingSettings.getLogCorrelation().getTraceIdAutoInjection(); + + if (injectionSettings.isEnabled()) { + String prefix = injectionSettings.getPrefix(); + String suffix = injectionSettings.getSuffix(); + Instances.traceIdInjector = new TraceIdInjectorImpl(prefix, suffix); + } else { + Instances.traceIdInjector = NoopTraceIdInjector.INSTANCE; + } + } +} diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorImpl.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorImpl.java new file mode 100644 index 0000000000..1614f29f8a --- /dev/null +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/correlation/log/TraceIdInjectorImpl.java @@ -0,0 +1,54 @@ +package rocks.inspectit.ocelot.core.instrumentation.correlation.log; + +import io.opencensus.trace.SpanContext; +import io.opencensus.trace.Tracing; +import rocks.inspectit.ocelot.bootstrap.correlation.TraceIdInjector; + +/** + * Implementation of {@link TraceIdInjector} for injecting trace ids into log messages. + * The resulting object will be in the following format if a trace id has been injected: + * [PREFIX]_trace_id_[SUFFIX]_message_ + */ +public class TraceIdInjectorImpl implements TraceIdInjector { + + /** + * The prefix to use. + */ + private String prefix; + + /** + * The suffix to use. + */ + private String suffix; + + /** + * Constructor. + */ + public TraceIdInjectorImpl(String prefix, String suffix) { + this.prefix = prefix; + this.suffix = suffix; + } + + @Override + public Object injectTraceId(Object message) { + String traceId = getTraceId(); + + if (traceId != null) { + return prefix + traceId + suffix + message; + } else { + return message; + } + } + + /** + * Returns the current trace id or `null` if non exists. + */ + private String getTraceId() { + SpanContext context = Tracing.getTracer().getCurrentSpan().getContext(); + if (context != null && context.isValid()) { + return context.getTraceId().toLowerBase16(); + } else { + return null; + } + } +} diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4J2TraceIdAutoInjector.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4J2TraceIdAutoInjector.java new file mode 100644 index 0000000000..7cf0c31a7f --- /dev/null +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4J2TraceIdAutoInjector.java @@ -0,0 +1,74 @@ +package rocks.inspectit.ocelot.core.instrumentation.special.traceinjector; + +import net.bytebuddy.asm.Advice; +import net.bytebuddy.asm.AsmVisitorWrapper; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.dynamic.DynamicType; +import net.bytebuddy.implementation.bytecode.assign.Assigner; +import net.bytebuddy.matcher.ElementMatcher; +import org.springframework.stereotype.Component; +import rocks.inspectit.ocelot.bootstrap.Instances; +import rocks.inspectit.ocelot.core.instrumentation.config.model.InstrumentationConfiguration; +import rocks.inspectit.ocelot.core.instrumentation.special.SpecialSensor; + +import static net.bytebuddy.matcher.ElementMatchers.*; + +/** + * Special sensor for automatically injecting the trace id into log messages done using the Log4J2 framework. + */ +@Component +public class Log4J2TraceIdAutoInjector implements SpecialSensor { + + /** + * Targeted classes to instrument. + */ + private static final ElementMatcher CLASSES_MATCHER = hasSuperType(named("org.apache.logging.log4j.message.MessageFactory")); + + @Override + public boolean shouldInstrument(Class clazz, InstrumentationConfiguration settings) { + TypeDescription type = TypeDescription.ForLoadedType.of(clazz); + return settings.getTracingSettings().getLogCorrelation().getTraceIdAutoInjection().isEnabled() && CLASSES_MATCHER.matches(type); + } + + @Override + public boolean requiresInstrumentationChange(Class clazz, InstrumentationConfiguration first, InstrumentationConfiguration second) { + return false; //if the sensor stays active it never requires changes + } + + @Override + public DynamicType.Builder instrument(Class clazz, InstrumentationConfiguration settings, DynamicType.Builder builder) { + return builder + .visit(NewMessageCharSequenceAdvice.TARGET) + .visit(NewMessageObjectAdvice.TARGET); + } + + /** + * On newMessage(java.lang.String) and newMessage(java.lang.CharSequence) of org.apache.logging.log4j.message.AbstractMessageFactory + * the current trace id will be injected into the log's message attribute. + */ + private static class NewMessageCharSequenceAdvice { + + static final AsmVisitorWrapper.ForDeclaredMethods TARGET = Advice.to(NewMessageCharSequenceAdvice.class) + .on(named("newMessage").and(takesArgument(0, String.class).or(takesArgument(0, CharSequence.class)))); + + @Advice.OnMethodEnter + public static void onMethodEnter(@Advice.Argument(value = 0, readOnly = false, typing = Assigner.Typing.DYNAMIC) CharSequence message) { + message = (String) Instances.traceIdInjector.injectTraceId(message); + } + } + + /** + * On org.apache.logging.log4j.message.AbstractMessageFactory#newMessage(java.lang.Object) + * the current trace id will be injected into the log's message attribute. + */ + private static class NewMessageObjectAdvice { + + static final AsmVisitorWrapper.ForDeclaredMethods TARGET = Advice.to(NewMessageObjectAdvice.class) + .on(named("newMessage").and(takesArgument(0, Object.class))); + + @Advice.OnMethodEnter + public static void onMethodEnter(@Advice.Argument(value = 0, readOnly = false) Object message) { + message = Instances.traceIdInjector.injectTraceId(message); + } + } +} diff --git a/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4JTraceIdAutoInjector.java b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4JTraceIdAutoInjector.java new file mode 100644 index 0000000000..fdd64ae3a3 --- /dev/null +++ b/inspectit-ocelot-core/src/main/java/rocks/inspectit/ocelot/core/instrumentation/special/traceinjector/Log4JTraceIdAutoInjector.java @@ -0,0 +1,56 @@ +package rocks.inspectit.ocelot.core.instrumentation.special.traceinjector; + +import net.bytebuddy.asm.Advice; +import net.bytebuddy.asm.AsmVisitorWrapper; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.dynamic.DynamicType; +import net.bytebuddy.matcher.ElementMatcher; +import org.springframework.stereotype.Component; +import rocks.inspectit.ocelot.bootstrap.Instances; +import rocks.inspectit.ocelot.core.instrumentation.config.model.InstrumentationConfiguration; +import rocks.inspectit.ocelot.core.instrumentation.special.SpecialSensor; + +import static net.bytebuddy.matcher.ElementMatchers.*; + +/** + * Special sensor for automatically injecting the trace id into log messages done using the Log4J framework. + */ +@Component +public class Log4JTraceIdAutoInjector implements SpecialSensor { + + /** + * Targeted classes to instrument. + */ + private static final ElementMatcher CLASSES_MATCHER = is(named("org.apache.log4j.Category")).or(hasSuperType(named("org.apache.log4j.Category"))); + + @Override + public boolean shouldInstrument(Class clazz, InstrumentationConfiguration settings) { + TypeDescription type = TypeDescription.ForLoadedType.of(clazz); + return settings.getTracingSettings().getLogCorrelation().getTraceIdAutoInjection().isEnabled() && CLASSES_MATCHER.matches(type); + } + + @Override + public boolean requiresInstrumentationChange(Class clazz, InstrumentationConfiguration first, InstrumentationConfiguration second) { + return false; //if the sensor stays active it never requires changes + } + + @Override + public DynamicType.Builder instrument(Class clazz, InstrumentationConfiguration settings, DynamicType.Builder builder) { + return builder + .visit(ForcedLogAdvice.TARGET); + } + + /** + * On org.apache.log4j.Category#forcedLog(java.lang.String, org.apache.log4j.Priority, java.lang.Object, java.lang.Throwable) + * the current trace id will be injected into the log's message attribute. + */ + private static class ForcedLogAdvice { + + static final AsmVisitorWrapper.ForDeclaredMethods TARGET = Advice.to(ForcedLogAdvice.class).on(named("forcedLog")); + + @Advice.OnMethodEnter + public static void onMethodEnter(@Advice.Argument(value = 2, readOnly = false) Object message) { + message = Instances.traceIdInjector.injectTraceId(message); + } + } +} diff --git a/inspectit-ocelot-documentation/docs/tracing/log-correlation.md b/inspectit-ocelot-documentation/docs/tracing/log-correlation.md index 04dbea1845..2c59ba356a 100644 --- a/inspectit-ocelot-documentation/docs/tracing/log-correlation.md +++ b/inspectit-ocelot-documentation/docs/tracing/log-correlation.md @@ -6,21 +6,24 @@ title: Log Correlation InspectIT Ocelot allows you to add trace information to your log statements in order to correlate them. This way, it is possible to identify the trace in which a log entry was created or to select all log statements given a specific trace id. +## Trace ID Injection Using MDC + The Ocelot agent does this by adding the current trace-id to the "Mapped Diagnostic Context" (MDC) of the used logging libraries. The MDC acts like a storage of environment variables which can be accessed by the logger and inject them into the log statements, according to the specified log pattern. Currently, the following logging APIs and Facades are supported: -* Log4J Version 1 -* Log4J Version 2 -* Logback -* SLF4J +* `Log4J Version 1` +* `Log4J Version 2` +* `Logback` +* `SLF4J` Log correlation is disabled by default. You can enable it using the following configuration snippet: ```yaml inspectit: tracing: log-correlation: - enabled: true + trace-id-mdc-injection: + enabled: true ``` When enabled, the trace-id is automatically added to all MDCs. @@ -36,10 +39,60 @@ For example for logback, the following pattern can be used: As a result, log messages, generated within an exported trace, will be prefixed with the corresponding trace-id: -``` +```text 09:39:53.014 [main] INFO test.TestMain TRACE[612772355048a0b21662ed3bc07a6326] - Hello logback! ``` -> Note that the trace-id is only available when the log statement is within a trace which is sampled, otherwise the trace-id is empty. +> Note that the trace ID is only available when the log statement is within a trace which is sampled, otherwise the trace-id is empty. + +You can change the key under which the trace-id is placed in the MDC using the property `inspectit.tracing.log-correlation.trace-id-mdc-injection.key`. + +## Automatical Trace ID Injection + +:::warning Experimental Feature +Please note that this is an experimental feature. +It is recommended to insert the trace IDs into the log messages via the MDC, which is described in section [Trace ID Injection Using MDC](#trace-id-injection-using-mdc). +::: + +The inspectIT Ocelot Java agent provides the ability to automatically inject trace IDs into log statements in order to correlate traces and logs. When this approach is used, there are the same limitations as when [injecting trace IDs using MDCs](#trace-id-injection-using-mdc), which means that a trace ID can only be injected into a log statement when it is within a sampled trace. + +Currently, the following logging APIs and Facades are supported: +* `Log4J Version 1` +* `Log4J Version 2` + +The automatical trace ID injection is disabled by default. You can enable it using the following configuration snippet: +```yaml +inspectit: + tracing: + log-correlation: + trace-id-auto-injection: + enabled: true +``` -You can change the key under which the trace-id is placed in the MDC using the property `inspectit.tracing.log-correlation.key`. \ No newline at end of file +In case a trace ID exists which is automatically injected, the agent will add the trace ID to the beginning of the log statement. Furthermore, the trace ID is wrapped into a prefix and suffix which results in the following format: `[PREFIX][TRACE_ID][SUFFIX][ORIGINAL_MESSAGE]` + +The used prefix and suffix can be configured using the following configuration snippet - the shown values are the default ones: + +```yaml +inspectit: + tracing: + log-correlation: + trace-id-auto-injection: + prefix: "[TraceID: " + suffix: "]" +``` + +The previous configuration would lead to the following log statement: + +```text +[TraceID: 612772355048a0b21662ed3bc07a6326]This is my log statement. +``` + +:::note +Please note that the trace ID will be injected at **the beginning of the log message and not at the beginning of the log pattern**. +The following output shows an example when the message is logged using a certain log pattern: + +```text +18:19:43.474 [main] INFO org.Example - [TraceID: e32ce6197f774d229460b2fd14448cf6]This is a test. +``` +::: \ No newline at end of file diff --git a/inspectit-ocelot-documentation/website/package.json b/inspectit-ocelot-documentation/website/package.json index e2dbb5afba..8369ba178f 100644 --- a/inspectit-ocelot-documentation/website/package.json +++ b/inspectit-ocelot-documentation/website/package.json @@ -10,5 +10,8 @@ }, "devDependencies": { "docusaurus": "^1.9.0" + }, + "dependencies": { + "remarkable-admonitions": "^0.2.1" } } diff --git a/inspectit-ocelot-documentation/website/pages/en/versions.js b/inspectit-ocelot-documentation/website/pages/en/versions.js index 8c4c3c8915..11e3903f9c 100644 --- a/inspectit-ocelot-documentation/website/pages/en/versions.js +++ b/inspectit-ocelot-documentation/website/pages/en/versions.js @@ -50,10 +50,6 @@ function Versions(props) { -

- This is the version that is configured automatically when you first - install this project. -

Pre-release versions

@@ -75,7 +71,6 @@ function Versions(props) {
-

Other text describing this section.

Past Versions

Here you can find previous versions of the documentation.

diff --git a/inspectit-ocelot-documentation/website/siteConfig.js b/inspectit-ocelot-documentation/website/siteConfig.js index d81ec17e94..43e47ec213 100644 --- a/inspectit-ocelot-documentation/website/siteConfig.js +++ b/inspectit-ocelot-documentation/website/siteConfig.js @@ -103,9 +103,14 @@ const siteConfig = { apiKey: 'ce332dcee733a92cefacc3195edd83dd', indexName: 'inspectit-ocelot', algoliaOptions: { - facetFilters: [ "version:VERSION" ] + facetFilters: ["version:VERSION"] } - } + }, + + markdownPlugins: [ + // Highlight admonitions. + require('remarkable-admonitions')({ icon: 'svg-inline' }) + ] }; module.exports = siteConfig; diff --git a/inspectit-ocelot-documentation/website/static/css/custom.css b/inspectit-ocelot-documentation/website/static/css/custom.css index b96aa6e296..3c982d68ea 100644 --- a/inspectit-ocelot-documentation/website/static/css/custom.css +++ b/inspectit-ocelot-documentation/website/static/css/custom.css @@ -17,4 +17,105 @@ td { vertical-align: top; -} \ No newline at end of file +} + +/** Docusaurus-like styling for `remarkable-admonitions` blocks */ + + .admonition { + margin-bottom: 1em; + padding: 15px 30px 15px 15px; + } + + .admonition h5 { + margin-top: 0; + margin-bottom: 8px; + text-transform: uppercase; + } + + .admonition-icon { + display: inline-block; + vertical-align: middle; + margin-right: 0.2em; + } + + .admonition-icon svg { + display: inline-block; + width: 22px; + height: 22px; + stroke-width: 0; + } + + .admonition-content > :last-child { + margin-bottom: 0; + } + + /** Customization */ + .admonition-warning { + background-color: rgba(230, 126, 34, 0.1); + border-left: 8px solid #e67e22; + } + + .admonition-warning h5 { + color: #e67e22; + } + + .admonition-warning .admonition-icon svg { + stroke: #e67e22; + fill: #e67e22; + } + + .admonition-tip { + background-color: rgba(46, 204, 113, 0.1); + border-left: 8px solid #2ecc71; + } + + .admonition-tip h5 { + color: #2ecc71; + } + + .admonition-tip .admonition-icon svg { + stroke: #2ecc71; + fill: #2ecc71; + } + + .admonition-caution { + background-color: rgba(231, 76, 60, 0.1); + border-left: 8px solid #e74c3c; + } + + .admonition-caution h5 { + color: #e74c3c; + } + + .admonition-caution .admonition-icon svg { + stroke: #e74c3c; + fill: #e74c3c; + } + + .admonition-important { + background-color: rgba(52, 152, 219, 0.1); + border-left: 8px solid #3498db; + } + + .admonition-important h5 { + color: #3498db; + } + + .admonition-important .admonition-icon svg { + stroke: #3498db; + fill: #3498db; + } + + .admonition-note { + background-color: rgba(241, 196, 15, 0.1); + border-left: 8px solid #f1c40f; + } + + .admonition-note h5 { + color: #f1c40f; + } + + .admonition-note .admonition-icon svg { + stroke: #f1c40f; + fill: #f1c40f; + }