Logging instrumentation: always log sampled flag value
MODIFY
docs/logger-mdc-instrumentation.md
docs/logger-mdc-instrumentation.md
@@ -17,8 +17,6 @@ event's MDC copy:
(same as `TracingContextUtils.getCurrentSpan().getContext().getSpanIdAsHexString()`);
- `sampled` - a boolean flag marking whether the current span is sampled or not
(same as `TracingContextUtils.getCurrentSpan().getContext().isSampled()`).
- This flag is only added when `sampled` is `true`, for non-sampled spans MDC does not contain it at
- all.
Those three pieces of information can be included in log statements produced by the logging library
by specifying them in the pattern/format. Example for Spring Boot configuration (which uses logback):

MODIFY
instrumentation/log4j/log4j-1.2/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v1_2/Log4j1LoggingEventInstrumentation.java
instrumentation/log4j/log4j-1.2/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v1_2/Log4j1LoggingEventInstrumentation.java
@@ -91,9 +91,7 @@ public class Log4j1LoggingEventInstrumentation extends Instrumenter.Default {
value = spanContext.getSpanIdAsHexString();
break;
case SAMPLED:
- if (spanContext.isSampled()) {
- value = "true";
- }
+ value = Boolean.toString(spanContext.isSampled());
break;
}
}
@@ -126,9 +124,7 @@ public class Log4j1LoggingEventInstrumentation extends Instrumenter.Default {
SpanContext spanContext = span.getContext();
mdc.put(TRACE_ID, spanContext.getTraceIdAsHexString());
mdc.put(SPAN_ID, spanContext.getSpanIdAsHexString());
- if (spanContext.isSampled()) {
- mdc.put(SAMPLED, "true");
- }
+ mdc.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
}
}

MODIFY
instrumentation/log4j/log4j-1.2/src/test/groovy/Log4j1MdcTest.groovy
instrumentation/log4j/log4j-1.2/src/test/groovy/Log4j1MdcTest.groovy
* SPDX-License-Identifier: Apache-2.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_ID
+
import io.opentelemetry.auto.test.AgentTestRunner
import io.opentelemetry.auto.test.utils.TraceUtils
import io.opentelemetry.trace.TracingContextUtils
@@ -26,14 +30,14 @@ class Log4j1MdcTest extends AgentTestRunner {
events.size() == 2
events[0].message == "log message 1"
- events[0].getMDC("traceId") == null
- events[0].getMDC("spanId") == null
- events[0].getMDC("traceFlags") == null
+ events[0].getMDC(TRACE_ID) == null
+ events[0].getMDC(SPAN_ID) == null
+ events[0].getMDC(SAMPLED) == null
events[1].message == "log message 2"
- events[1].getMDC("traceId") == null
- events[1].getMDC("spanId") == null
- events[1].getMDC("traceFlags") == null
+ events[1].getMDC(TRACE_ID) == null
+ events[1].getMDC(SPAN_ID) == null
+ events[1].getMDC(SAMPLED) == null
}
def "ids when span"() {
@@ -58,20 +62,20 @@ class Log4j1MdcTest extends AgentTestRunner {
events.size() == 3
events[0].message == "log message 1"
- events[0].getMDC("traceId") == span1.context.traceIdAsHexString
- events[0].getMDC("spanId") == span1.context.spanIdAsHexString
- events[0].getMDC("sampled") == "true"
+ events[0].getMDC(TRACE_ID) == span1.context.traceIdAsHexString
+ events[0].getMDC(SPAN_ID) == span1.context.spanIdAsHexString
+ events[0].getMDC(SAMPLED) == "true"
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(SAMPLED) == 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.context.traceIdAsHexString
- events[2].getMDC("spanId") == span2.context.spanIdAsHexString
- events[2].getMDC("sampled") == "true"
+ events[2].getMDC(TRACE_ID) == span2.context.traceIdAsHexString
+ events[2].getMDC(SPAN_ID) == span2.context.spanIdAsHexString
+ events[2].getMDC(SAMPLED) == "true"
}
}

MODIFY
instrumentation/log4j/log4j-2-testing/log4j-2-testing.gradle
instrumentation/log4j/log4j-2-testing/log4j-2-testing.gradle
@@ -10,6 +10,7 @@ dependencies {
implementation deps.groovy
implementation deps.opentelemetryApi
implementation deps.spock
+ implementation project(':instrumentation-api')
annotationProcessor group: 'org.apache.logging.log4j', name: 'log4j-core', version: '2.7'
}

MODIFY
instrumentation/log4j/log4j-2-testing/src/main/groovy/Log4j2Test.groovy
instrumentation/log4j/log4j-2-testing/src/main/groovy/Log4j2Test.groovy
* SPDX-License-Identifier: Apache-2.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_ID
+
import io.opentelemetry.auto.test.InstrumentationSpecification
import io.opentelemetry.auto.test.utils.TraceUtils
import io.opentelemetry.instrumentation.log4j.v2_13_2.ListAppender
@@ -28,14 +32,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("traceFlags") == null
+ events[0].getContextData().getValue(TRACE_ID) == null
+ events[0].getContextData().getValue(SPAN_ID) == null
+ events[0].getContextData().getValue(SAMPLED) == null
events[1].message.formattedMessage == "log message 2"
- events[1].getContextData().getValue("traceId") == null
- events[1].getContextData().getValue("spanId") == null
- events[1].getContextData().getValue("traceFlags") == null
+ events[1].getContextData().getValue(TRACE_ID) == null
+ events[1].getContextData().getValue(SPAN_ID) == null
+ events[1].getContextData().getValue(SAMPLED) == null
}
def "ids when span"() {
@@ -43,18 +47,16 @@ abstract class Log4j2Test extends InstrumentationSpecification {
def logger = LogManager.getLogger("TestLogger")
when:
- Span span1
- TraceUtils.runUnderTrace("test") {
- span1 = TracingContextUtils.currentSpan
+ Span span1 = TraceUtils.runUnderTrace("test") {
logger.info("log message 1")
+ TracingContextUtils.currentSpan
}
logger.info("log message 2")
- Span span2
- TraceUtils.runUnderTrace("test 2") {
- span2 = TracingContextUtils.currentSpan
+ Span span2 = TraceUtils.runUnderTrace("test 2") {
logger.info("log message 3")
+ TracingContextUtils.currentSpan
}
def events = ListAppender.get().getEvents()
@@ -62,18 +64,18 @@ abstract class Log4j2Test extends InstrumentationSpecification {
then:
events.size() == 3
events[0].message.formattedMessage == "log message 1"
- events[0].getContextData().getValue("traceId") == span1.context.traceIdAsHexString
- events[0].getContextData().getValue("spanId") == span1.context.spanIdAsHexString
- events[0].getContextData().getValue("sampled") == "true"
+ events[0].getContextData().getValue(TRACE_ID) == span1.context.traceIdAsHexString
+ events[0].getContextData().getValue(SPAN_ID) == span1.context.spanIdAsHexString
+ events[0].getContextData().getValue(SAMPLED) == "true"
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(SAMPLED) == null
events[2].message.formattedMessage == "log message 3"
- events[2].getContextData().getValue("traceId") == span2.context.traceIdAsHexString
- events[2].getContextData().getValue("spanId") == span2.context.spanIdAsHexString
- events[2].getContextData().getValue("sampled") == "true"
+ events[2].getContextData().getValue(TRACE_ID) == span2.context.traceIdAsHexString
+ events[2].getContextData().getValue(SPAN_ID) == span2.context.spanIdAsHexString
+ events[2].getContextData().getValue(SAMPLED) == "true"
}
}

MODIFY
instrumentation/log4j/log4j-2.13.2/library/src/main/java/io/opentelemetry/instrumentation/log4j/v2_13_2/OpenTelemetryContextDataProvider.java
instrumentation/log4j/log4j-2.13.2/library/src/main/java/io/opentelemetry/instrumentation/log4j/v2_13_2/OpenTelemetryContextDataProvider.java
@@ -40,9 +40,7 @@ public class OpenTelemetryContextDataProvider implements ContextDataProvider {
SpanContext spanContext = currentSpan.getContext();
contextData.put(TRACE_ID, spanContext.getTraceIdAsHexString());
contextData.put(SPAN_ID, spanContext.getSpanIdAsHexString());
- if (spanContext.isSampled()) {
- contextData.put(SAMPLED, "true");
- }
+ contextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
return contextData;
}
}

MODIFY
instrumentation/log4j/log4j-2.7/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v2_7/SpanDecoratingContextDataInjector.java
instrumentation/log4j/log4j-2.7/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v2_7/SpanDecoratingContextDataInjector.java
@@ -42,9 +42,7 @@ public final class SpanDecoratingContextDataInjector implements ContextDataInjec
StringMap newContextData = new SortedArrayStringMap(contextData);
newContextData.putValue(TRACE_ID, currentContext.getTraceIdAsHexString());
newContextData.putValue(SPAN_ID, currentContext.getSpanIdAsHexString());
- if (currentContext.isSampled()) {
- newContextData.putValue(SAMPLED, "true");
- }
+ newContextData.putValue(SAMPLED, Boolean.toString(currentContext.isSampled()));
return newContextData;
}

MODIFY
instrumentation/logback/logback-1.0.0/auto/src/main/java/io/opentelemetry/instrumentation/auto/logback/v1_0_0/LoggingEventInstrumentation.java
instrumentation/logback/logback-1.0.0/auto/src/main/java/io/opentelemetry/instrumentation/auto/logback/v1_0_0/LoggingEventInstrumentation.java
@@ -84,9 +84,7 @@ public class LoggingEventInstrumentation extends Instrumenter.Default {
SpanContext spanContext = currentSpan.getContext();
spanContextData.put(TRACE_ID, spanContext.getTraceIdAsHexString());
spanContextData.put(SPAN_ID, spanContext.getSpanIdAsHexString());
- if (spanContext.isSampled()) {
- spanContextData.put(SAMPLED, "true");
- }
+ spanContextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
if (contextData == null) {
contextData = spanContextData;

MODIFY
instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/OpenTelemetryAppender.java
instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/OpenTelemetryAppender.java
@@ -43,9 +43,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
SpanContext spanContext = currentSpan.getContext();
contextData.put(TRACE_ID, spanContext.getTraceIdAsHexString());
contextData.put(SPAN_ID, spanContext.getSpanIdAsHexString());
- if (spanContext.isSampled()) {
- contextData.put(SAMPLED, "true");
- }
+ contextData.put(SAMPLED, Boolean.toString(spanContext.isSampled()));
if (eventContext == null) {
eventContext = contextData;

Logging instrumentation: always log sampled flag value (#1347)