open-telemetry
/
opentelemetry-java-instrumentation
mirror of https://github.com/open-telemetry/opentelemetry-java-instrumentation.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Add 'trace_flags' to logging MDC (#2312) 

* Add 'trace_flags' to logging MDC

* Remove 'sampled' flag
* Rename MDC keys to the current logging spec convention: trace_id instead of traceId

* Fix smoke tests
This commit is contained in:
Mateusz Rzeszutek 2021-02-18 08:47:26 +01:00 committed by GitHub
parent 8bba7ac364
commit f127a972dc
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
12 changed files with 83 additions and 74 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

25
instrumentation-api/src/main/java/io/opentelemetry/instrumentation/api/log/LoggingContextConstants.java
View File

@ -5,6 +5,8 @@
package io.opentelemetry.instrumentation.api.log;
import io.opentelemetry.api.trace.SpanContext;
/**
* This class contains several constants used in logging libraries' Mapped Diagnostic Context
* instrumentations.
@ -12,15 +14,24 @@ package io.opentelemetry.instrumentation.api.log;
* @see org.slf4j.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.
* Key under which the current trace id will be injected into the context data.
*
* @see SpanContext#getTraceId()
*/
public static final String SAMPLED = "sampled";
public static final String TRACE_ID = "trace_id";
/**
* Key under which the current span id will be injected into the context data.
*
* @see SpanContext#getSpanId()
*/
public static final String SPAN_ID = "span_id";
/**
* Key under which the current trace flags will be injected into the context data.
*
* @see SpanContext#getTraceFlags()
*/
public static final String TRACE_FLAGS = "trace_flags";
private LoggingContextConstants() {}
}

10
instrumentation/log4j/log4j-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/v1_2/LoggingEventInstrumentation.java
View File

@ -5,8 +5,8 @@
package io.opentelemetry.javaagent.instrumentation.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_FLAGS;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import static net.bytebuddy.matcher.ElementMatchers.isMethod;
import static net.bytebuddy.matcher.ElementMatchers.isPublic;
@ -59,7 +59,7 @@ public class LoggingEventInstrumentation implements TypeInstrumentation {
@Advice.This LoggingEvent event,
@Advice.Argument(0) String key,
@Advice.Return(readOnly = false) Object value) {
if (TRACE_ID.equals(key) || SPAN_ID.equals(key) || SAMPLED.equals(key)) {
if (TRACE_ID.equals(key) || SPAN_ID.equals(key) || TRACE_FLAGS.equals(key)) {
if (value != null) {
// Assume already instrumented event if traceId/spanId/sampled is present.
return;
@ -78,8 +78,8 @@ public class LoggingEventInstrumentation implements TypeInstrumentation {
case SPAN_ID:
value = spanContext.getSpanId();
break;
case SAMPLED:
value = Boolean.toString(spanContext.isSampled());
case TRACE_FLAGS:
value = spanContext.getTraceFlags().asHex();
break;
default:
// do nothing
@ -114,7 +114,7 @@ public class LoggingEventInstrumentation implements TypeInstrumentation {
SpanContext spanContext = span.getSpanContext();
mdc.put(TRACE_ID, spanContext.getTraceId());
mdc.put(SPAN_ID, spanContext.getSpanId());
mdc.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
mdc.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
}
}

30
instrumentation/log4j/log4j-1.2/javaagent/src/test/groovy/Log4j1MdcTest.groovy
View File

@ -26,14 +26,14 @@ class Log4j1MdcTest extends AgentInstrumentationSpecification {
events.size() == 2
events[0].message == "log message 1"
events[0].getMDC("traceId") == null
events[0].getMDC("spanId") == null
events[0].getMDC("sampled") == null
events[0].getMDC("trace_id") == null
events[0].getMDC("span_id") == null
events[0].getMDC("trace_flags") == null
events[1].message == "log message 2"
events[1].getMDC("traceId") == null
events[1].getMDC("spanId") == null
events[1].getMDC("sampled") == null
events[1].getMDC("trace_id") == null
events[1].getMDC("span_id") == null
events[1].getMDC("trace_flags") == null
}
def "ids when span"() {
@ -58,20 +58,20 @@ class Log4j1MdcTest extends AgentInstrumentationSpecification {
events.size() == 3
events[0].message == "log message 1"
events[0].getMDC("traceId") == span1.spanContext.traceId
events[0].getMDC("spanId") == span1.spanContext.spanId
events[0].getMDC("sampled") == "true"
events[0].getMDC("trace_id") == span1.spanContext.traceId
events[0].getMDC("span_id") == span1.spanContext.spanId
events[0].getMDC("trace_flags") == "01"
events[1].message == "log message 2"
events[1].getMDC("traceId") == null
events[1].getMDC("spanId") == null
events[1].getMDC("sampled") == null
events[1].getMDC("trace_id") == null
events[1].getMDC("span_id") == null
events[1].getMDC("trace_flags") == null
events[2].message == "log message 3"
// this explicit getMDCCopy() call here is to make sure that whole instrumentation is tested
events[2].getMDCCopy()
events[2].getMDC("traceId") == span2.spanContext.traceId
events[2].getMDC("spanId") == span2.spanContext.spanId
events[2].getMDC("sampled") == "true"
events[2].getMDC("trace_id") == span2.spanContext.traceId
events[2].getMDC("span_id") == span2.spanContext.spanId
events[2].getMDC("trace_flags") == "01"
}
}

30
instrumentation/log4j/log4j-2-testing/src/main/groovy/Log4j2Test.groovy
View File

@ -27,14 +27,14 @@ abstract class Log4j2Test extends InstrumentationSpecification {
then:
events.size() == 2
events[0].message.formattedMessage == "log message 1"
events[0].getContextData().getValue("traceId") == null
events[0].getContextData().getValue("spanId") == null
events[0].getContextData().getValue("sampled") == null
events[0].getContextData().getValue("trace_id") == null
events[0].getContextData().getValue("span_id") == null
events[0].getContextData().getValue("trace_flags") == null
events[1].message.formattedMessage == "log message 2"
events[1].getContextData().getValue("traceId") == null
events[1].getContextData().getValue("spanId") == null
events[1].getContextData().getValue("sampled") == null
events[1].getContextData().getValue("trace_id") == null
events[1].getContextData().getValue("span_id") == null
events[1].getContextData().getValue("trace_flags") == null
}
def "ids when span"() {
@ -59,18 +59,18 @@ abstract class Log4j2Test extends InstrumentationSpecification {
then:
events.size() == 3
events[0].message.formattedMessage == "log message 1"
events[0].getContextData().getValue("traceId") == span1.spanContext.traceId
events[0].getContextData().getValue("spanId") == span1.spanContext.spanId
events[0].getContextData().getValue("sampled") == "true"
events[0].getContextData().getValue("trace_id") == span1.spanContext.traceId
events[0].getContextData().getValue("span_id") == span1.spanContext.spanId
events[0].getContextData().getValue("trace_flags") == "01"
events[1].message.formattedMessage == "log message 2"
events[1].getContextData().getValue("traceId") == null
events[1].getContextData().getValue("spanId") == null
events[1].getContextData().getValue("sampled") == null
events[1].getContextData().getValue("trace_id") == null
events[1].getContextData().getValue("span_id") == null
events[1].getContextData().getValue("trace_flags") == null
events[2].message.formattedMessage == "log message 3"
events[2].getContextData().getValue("traceId") == span2.spanContext.traceId
events[2].getContextData().getValue("spanId") == span2.spanContext.spanId
events[2].getContextData().getValue("sampled") == "true"
events[2].getContextData().getValue("trace_id") == span2.spanContext.traceId
events[2].getContextData().getValue("span_id") == span2.spanContext.spanId
events[2].getContextData().getValue("trace_flags") == "01"
}
}

4
instrumentation/log4j/log4j-2.13.2/library/src/main/java/io/opentelemetry/instrumentation/log4j/v2_13_2/OpenTelemetryContextDataProvider.java
View File

@ -5,8 +5,8 @@
package io.opentelemetry.instrumentation.log4j.v2_13_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_FLAGS;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import io.opentelemetry.api.trace.Span;
@ -39,7 +39,7 @@ public class OpenTelemetryContextDataProvider implements ContextDataProvider {
SpanContext spanContext = currentSpan.getSpanContext();
contextData.put(TRACE_ID, spanContext.getTraceId());
contextData.put(SPAN_ID, spanContext.getSpanId());
contextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
contextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
return contextData;
}
}

4
instrumentation/log4j/log4j-2.7/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/v2_7/SpanDecoratingContextDataInjector.java
View File

@ -5,8 +5,8 @@
package io.opentelemetry.javaagent.instrumentation.log4j.v2_7;
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_FLAGS;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import io.opentelemetry.api.trace.SpanContext;
@ -42,7 +42,7 @@ public final class SpanDecoratingContextDataInjector implements ContextDataInjec
StringMap newContextData = new SortedArrayStringMap(contextData);
newContextData.putValue(TRACE_ID, currentContext.getTraceId());
newContextData.putValue(SPAN_ID, currentContext.getSpanId());
newContextData.putValue(SAMPLED, Boolean.toString(currentContext.isSampled()));
newContextData.putValue(TRACE_FLAGS, currentContext.getTraceFlags().asHex());
return newContextData;
}

4
instrumentation/logback/logback-1.0/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/logback/v1_0/LoggingEventInstrumentation.java
View File

@ -5,8 +5,8 @@
package io.opentelemetry.javaagent.instrumentation.logback.v1_0;
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_FLAGS;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import static io.opentelemetry.javaagent.tooling.bytebuddy.matcher.AgentElementMatchers.implementsInterface;
import static java.util.Collections.singletonMap;
@ -64,7 +64,7 @@ public class LoggingEventInstrumentation implements TypeInstrumentation {
SpanContext spanContext = currentSpan.getSpanContext();
spanContextData.put(TRACE_ID, spanContext.getTraceId());
spanContextData.put(SPAN_ID, spanContext.getSpanId());
spanContextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
spanContextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
if (contextData == null) {
contextData = spanContextData;

4
instrumentation/logback/logback-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0/OpenTelemetryAppender.java
View File

@ -5,8 +5,8 @@
package io.opentelemetry.instrumentation.logback.v1_0;
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_FLAGS;
import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID;
import ch.qos.logback.classic.spi.ILoggingEvent;
@ -42,7 +42,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
SpanContext spanContext = currentSpan.getSpanContext();
contextData.put(TRACE_ID, spanContext.getTraceId());
contextData.put(SPAN_ID, spanContext.getSpanId());
contextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
contextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
if (eventContext == null) {
eventContext = contextData;

40
instrumentation/logback/logback-1.0/testing/src/main/groovy/io/opentelemetry/instrumentation/logback/v1_0/AbstractLogbackTest.groovy
View File

@ -48,30 +48,28 @@ abstract class AbstractLogbackTest extends InstrumentationSpecification {
then:
events.size() == 2
events[0].message == "log message 1"
events[0].getMDCPropertyMap().get("traceId") == null
events[0].getMDCPropertyMap().get("spanId") == null
events[0].getMDCPropertyMap().get("traceFlags") == null
events[0].getMDCPropertyMap().get("trace_id") == null
events[0].getMDCPropertyMap().get("span_id") == null
events[0].getMDCPropertyMap().get("trace_flags") == null
events[1].message == "log message 2"
events[1].getMDCPropertyMap().get("traceId") == null
events[1].getMDCPropertyMap().get("spanId") == null
events[1].getMDCPropertyMap().get("traceFlags") == null
events[1].getMDCPropertyMap().get("trace_id") == null
events[1].getMDCPropertyMap().get("span_id") == null
events[1].getMDCPropertyMap().get("trace_flags") == null
}
def "ids when span"() {
when:
Span span1
TraceUtils.runUnderTrace("test") {
span1 = Span.current()
Span span1 = TraceUtils.runUnderTrace("test") {
logger.info("log message 1")
Span.current()
}
logger.info("log message 2")
Span span2
TraceUtils.runUnderTrace("test 2") {
span2 = Span.current()
Span span2 = TraceUtils.runUnderTrace("test 2") {
logger.info("log message 3")
Span.current()
}
def events = listAppender.list
@ -79,18 +77,18 @@ abstract class AbstractLogbackTest extends InstrumentationSpecification {
then:
events.size() == 3
events[0].message == "log message 1"
events[0].getMDCPropertyMap().get("traceId") == span1.spanContext.traceId
events[0].getMDCPropertyMap().get("spanId") == span1.spanContext.spanId
events[0].getMDCPropertyMap().get("sampled") == "true"
events[0].getMDCPropertyMap().get("trace_id") == span1.spanContext.traceId
events[0].getMDCPropertyMap().get("span_id") == span1.spanContext.spanId
events[0].getMDCPropertyMap().get("trace_flags") == "01"
events[1].message == "log message 2"
events[1].getMDCPropertyMap().get("traceId") == null
events[1].getMDCPropertyMap().get("spanId") == null
events[1].getMDCPropertyMap().get("sampled") == null
events[1].getMDCPropertyMap().get("trace_id") == null
events[1].getMDCPropertyMap().get("span_id") == null
events[1].getMDCPropertyMap().get("trace_flags") == null
events[2].message == "log message 3"
events[2].getMDCPropertyMap().get("traceId") == span2.spanContext.traceId
events[2].getMDCPropertyMap().get("spanId") == span2.spanContext.spanId
events[2].getMDCPropertyMap().get("sampled") == "true"
events[2].getMDCPropertyMap().get("trace_id") == span2.spanContext.traceId
events[2].getMDCPropertyMap().get("span_id") == span2.spanContext.spanId
events[2].getMDCPropertyMap().get("trace_flags") == "01"
}
}

2
smoke-tests/src/test/groovy/io/opentelemetry/smoketest/SmokeTest.groovy
View File

@ -31,7 +31,7 @@ import spock.lang.Shared
import spock.lang.Specification
abstract class SmokeTest extends Specification {
private static final Pattern TRACE_ID_PATTERN = Pattern.compile(".*traceId=(?<traceId>[a-zA-Z0-9]+).*")
private static final Pattern TRACE_ID_PATTERN = Pattern.compile(".*trace_id=(?<traceId>[a-zA-Z0-9]+).*")
private static final ObjectMapper OBJECT_MAPPER = new ObjectMapper()

2
smoke-tests/src/test/groovy/io/opentelemetry/smoketest/SpringBootSmokeTest.groovy
View File

@ -16,7 +16,7 @@ import spock.lang.Unroll
class SpringBootSmokeTest extends SmokeTest {
protected String getTargetImage(String jdk, String serverVersion) {
"ghcr.io/open-telemetry/java-test-containers:smoke-springboot-jdk$jdk-20210209.550405798"
"ghcr.io/open-telemetry/java-test-containers:smoke-springboot-jdk$jdk-20210218.576851845"
}
@Unroll

2
smoke-tests/src/test/groovy/io/opentelemetry/smoketest/SpringBootWithSamplingSmokeTest.groovy
View File

@ -15,7 +15,7 @@ class SpringBootWithSamplingSmokeTest extends SmokeTest {
static final int ALLOWED_DEVIATION = 0.1 * NUM_TRIES
protected String getTargetImage(String jdk, String serverVersion) {
"ghcr.io/open-telemetry/java-test-containers:smoke-springboot-jdk$jdk-20210209.550405798"
"ghcr.io/open-telemetry/java-test-containers:smoke-springboot-jdk$jdk-20210218.576851845"
}
@Override