Skip to content

Commit

Permalink
Implement MDC auto-instrumentation for log4j2 (#1200)
Browse files Browse the repository at this point in the history
* Implement MDC auto-instrumentation for log4j2

* Implement MDC auto-instrumentation for log4j2 2.7

* Implement MDC auto-instrumentation for log4j2

* Implement MDC auto-instrumentation for log4j2

* Implement MDC auto-instrumentation for log4j2

* Implement MDC auto-instrumentation for log4j1

* Implement MDC auto-instrumentation for log4j2
  • Loading branch information
Mateusz Rzeszutek authored Sep 18, 2020
1 parent beb1901 commit d89ce81
Show file tree
Hide file tree
Showing 22 changed files with 414 additions and 39 deletions.
1 change: 1 addition & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -204,6 +204,7 @@ provide the path to a JAR file including an SPI implementation using the system
| [khttp](https://khttp.readthedocs.io) | 0.1+ |
| [Kubernetes Client](https://github.com/kubernetes-client/java) | 7.0+ |
| [Lettuce](https://github.com/lettuce-io/lettuce-core) | 4.0+ |
| [Log4j 2](https://logging.apache.org/log4j/2.x/) | 2.7+ |
| [Logback](http://logback.qos.ch/) | 1.0+ |
| [MongoDB Drivers](https://mongodb.github.io/mongo-java-driver/) | 3.3+ |
| [Netty](https://github.com/netty/netty) | 3.8+ |
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed 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 io.opentelemetry.instrumentation.api.log;

/**
* This class contains several constants used in logging libraries' Mapped Diagnostic Context
* instrumentations.
*
* @see org.slf4j.MDC
* @see org.apache.logging.log4j.ThreadContext
* @see org.apache.log4j.MDC
*/
public final class LoggingContextConstants {
/** Key under which the current trace id will be injected into the context data. */
public static final String TRACE_ID = "traceId";
/** Key under which the current span id will be injected into the context data. */
public static final String SPAN_ID = "spanId";
/**
* Key under which a boolean indicating whether current span is sampled will be injected into the
* context data.
*/
public static final String SAMPLED = "sampled";

private LoggingContextConstants() {}
}
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,9 @@

package io.opentelemetry.instrumentation.auto.log4j.v1_2;

import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.SAMPLED;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.SPAN_ID;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import static java.util.Collections.singletonMap;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
Expand Down Expand Up @@ -79,7 +82,7 @@ public static void onExit(
@Advice.This LoggingEvent event,
@Advice.Argument(0) String key,
@Advice.Return(readOnly = false) Object value) {
if ("traceId".equals(key) || "spanId".equals(key) || "sampled".equals(key)) {
if (TRACE_ID.equals(key) || SPAN_ID.equals(key) || SAMPLED.equals(key)) {
if (value != null) {
// Assume already instrumented event if traceId/spanId/sampled is present.
return;
Expand All @@ -92,13 +95,13 @@ public static void onExit(

SpanContext spanContext = span.getContext();
switch (key) {
case "traceId":
case TRACE_ID:
value = spanContext.getTraceIdAsHexString();
break;
case "spanId":
case SPAN_ID:
value = spanContext.getSpanIdAsHexString();
break;
case "sampled":
case SAMPLED:
if (spanContext.isSampled()) {
value = "true";
}
Expand Down Expand Up @@ -128,14 +131,14 @@ public static void onEnter(
}

// Assume already instrumented event if traceId is present.
if (!mdc.contains("traceId")) {
if (!mdc.contains(TRACE_ID)) {
Span span = InstrumentationContext.get(LoggingEvent.class, Span.class).get(event);
if (span != null && span.getContext().isValid()) {
SpanContext spanContext = span.getContext();
mdc.put("traceId", spanContext.getTraceIdAsHexString());
mdc.put("spanId", spanContext.getSpanIdAsHexString());
mdc.put(TRACE_ID, spanContext.getTraceIdAsHexString());
mdc.put(SPAN_ID, spanContext.getSpanIdAsHexString());
if (spanContext.isSampled()) {
mdc.put("sampled", "true");
mdc.put(SAMPLED, "true");
}
}
}
Expand Down
15 changes: 15 additions & 0 deletions instrumentation/log4j/log4j-2-testing/log4j-2-testing.gradle
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
apply from: "$rootDir/gradle/java.gradle"

dependencies {
api project(':testing-common')

api group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.7'

implementation deps.guava

implementation deps.groovy
implementation deps.opentelemetryApi
implementation deps.spock

annotationProcessor group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.7'
}
Original file line number Diff line number Diff line change
Expand Up @@ -14,24 +14,22 @@
* limitations under the License.
*/

package io.opentelemetry.instrumentation.log4j.v2_13_2

import io.opentelemetry.auto.test.InstrumentationSpecification
import io.opentelemetry.auto.test.utils.TraceUtils
import io.opentelemetry.instrumentation.log4j.v2_13_2.ListAppender
import io.opentelemetry.trace.Span
import io.opentelemetry.trace.TracingContextUtils
import org.apache.logging.log4j.LogManager
import org.apache.logging.log4j.Logger
import spock.lang.Specification

class Log4j2Test extends Specification {

private static final Logger logger = LogManager.getLogger("TestLogger")

abstract class Log4j2Test extends InstrumentationSpecification {
def cleanup() {
ListAppender.get().clearEvents()
}

def "no ids when no span"() {
given:
def logger = LogManager.getLogger("TestLogger")

when:
logger.info("log message 1")
logger.info("log message 2")
Expand All @@ -52,6 +50,9 @@ class Log4j2Test extends Specification {
}

def "ids when span"() {
given:
def logger = LogManager.getLogger("TestLogger")

when:
Span span1
TraceUtils.runUnderTrace("test") {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,17 +20,15 @@
import java.util.Collections;
import java.util.List;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Core;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractAppender;
import org.apache.logging.log4j.core.config.Property;
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.PluginFactory;

@Plugin(
name = "ListAppender",
category = Core.CATEGORY_NAME,
category = "Core",
elementType = Appender.ELEMENT_TYPE,
printObject = true)
public class ListAppender extends AbstractAppender {
Expand All @@ -41,10 +39,10 @@ public static ListAppender get() {

private static final ListAppender INSTANCE = new ListAppender();

private final List<LogEvent> events = Collections.synchronizedList(new ArrayList<>());
private final List<LogEvent> events = Collections.synchronizedList(new ArrayList<LogEvent>());

public ListAppender() {
super("ListAppender", null, null, true, Property.EMPTY_ARRAY);
super("ListAppender", null, null, true);
}

public List<LogEvent> getEvents() {
Expand Down
18 changes: 18 additions & 0 deletions instrumentation/log4j/log4j-2.13.2/auto/log4j-2.13.2-auto.gradle
Original file line number Diff line number Diff line change
@@ -0,0 +1,18 @@
apply from: "$rootDir/gradle/instrumentation.gradle"

muzzle {
pass {
group = "org.apache.logging.log4j"
module = "log4j-core"
versions = "[2.13.2,)"
assertInverse = true
}
}

dependencies {
library group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.13.2'

implementation project(':instrumentation:log4j:log4j-2.13.2:library')

testImplementation project(':instrumentation:log4j:log4j-2-testing')
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,69 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed 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 io.opentelemetry.instrumentation.auto.log4j.v2_13_2;

import static io.opentelemetry.javaagent.tooling.ClassLoaderMatcher.hasClassesNamed;
import static net.bytebuddy.matcher.ElementMatchers.named;

import com.google.auto.service.AutoService;
import io.opentelemetry.javaagent.tooling.Instrumenter;
import java.util.Collections;
import java.util.Map;
import net.bytebuddy.description.method.MethodDescription;
import net.bytebuddy.description.type.TypeDescription;
import net.bytebuddy.matcher.ElementMatcher;

@AutoService(Instrumenter.class)
public final class Log4j2MdcInstrumentation extends Instrumenter.Default {
public Log4j2MdcInstrumentation() {
super("log4j2", "log4j", "log4j-2.13.2");
}

@Override
public ElementMatcher<ClassLoader> classLoaderMatcher() {
return hasClassesNamed("org.apache.logging.log4j.core.util.ContextDataProvider");
}

@Override
public ElementMatcher<? super TypeDescription> typeMatcher() {
// we cannot use ContextDataProvider here because one of the classes that we inject implements
// this interface, causing the interface to be loaded while it's being transformed, which leads
// to duplicate class definition error after the interface is transformed and the triggering
// class loader tries to load it.
return named("org.apache.logging.log4j.core.impl.ThreadContextDataInjector");
}

@Override
public String[] helperResourceNames() {
return new String[] {
"META-INF/services/org.apache.logging.log4j.core.util.ContextDataProvider",
};
}

@Override
public String[] helperClassNames() {
return new String[] {
"io.opentelemetry.instrumentation.log4j.v2_13_2.OpenTelemetryContextDataProvider"
};
}

@Override
public Map<? extends ElementMatcher<? super MethodDescription>, String> transformers() {
// Nothing to instrument, injecting helper resource & class is enough
return Collections.emptyMap();
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed 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.
*/

import io.opentelemetry.auto.test.AgentTestTrait

class AutoLog4j2Test extends Log4j2Test implements AgentTestTrait {
}
2 changes: 1 addition & 1 deletion instrumentation/log4j/log4j-2.13.2/library/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ a log statement is made when a span is active.

- `traceId`
- `spanId`
- `traceFlags`
- `sampled`

You can use these keys when defining an appender in your `log4j.xml` configuration, for example

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,8 +7,5 @@ apply from: "$rootDir/gradle/instrumentation-library.gradle"
dependencies {
library group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.13.2'

annotationProcessor deps.autoservice
compileOnly deps.autoservice

testAnnotationProcessor group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.13.2'
testImplementation project(':instrumentation:log4j:log4j-2-testing')
}
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,10 @@

package io.opentelemetry.instrumentation.log4j.v2_13_2;

import com.google.auto.service.AutoService;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.SAMPLED;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.SPAN_ID;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;

import io.opentelemetry.trace.Span;
import io.opentelemetry.trace.SpanContext;
import io.opentelemetry.trace.TracingContextUtils;
Expand All @@ -29,7 +32,6 @@
* Implementation of Log4j 2's {@link ContextDataProvider} which is loaded via SPI. {@link
* #supplyContextData()} is called when a log entry is created.
*/
@AutoService(ContextDataProvider.class)
public class OpenTelemetryContextDataProvider implements ContextDataProvider {

/**
Expand All @@ -47,10 +49,10 @@ public Map<String, String> supplyContextData() {

Map<String, String> contextData = new HashMap<>();
SpanContext spanContext = currentSpan.getContext();
contextData.put("traceId", spanContext.getTraceIdAsHexString());
contextData.put("spanId", spanContext.getSpanIdAsHexString());
contextData.put(TRACE_ID, spanContext.getTraceIdAsHexString());
contextData.put(SPAN_ID, spanContext.getSpanIdAsHexString());
if (spanContext.isSampled()) {
contextData.put("sampled", "true");
contextData.put(SAMPLED, "true");
}
return contextData;
}
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
io.opentelemetry.instrumentation.log4j.v2_13_2.OpenTelemetryContextDataProvider
Original file line number Diff line number Diff line change
@@ -0,0 +1,20 @@
/*
* Copyright The OpenTelemetry Authors
*
* Licensed 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.
*/

import io.opentelemetry.auto.test.InstrumentationTestTrait

class LibraryLog4j2Test extends Log4j2Test implements InstrumentationTestTrait {
}
15 changes: 15 additions & 0 deletions instrumentation/log4j/log4j-2.7/log4j-2.7.gradle
Original file line number Diff line number Diff line change
@@ -0,0 +1,15 @@
apply from: "$rootDir/gradle/instrumentation.gradle"

muzzle {
pass {
group = "org.apache.logging.log4j"
module = "log4j-core"
versions = "[2.7,2.13.2)"
}
}

dependencies {
library group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.7'

testImplementation project(':instrumentation:log4j:log4j-2-testing')
}
Loading

0 comments on commit d89ce81

Please sign in to comment.