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

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

This commit is contained in:
Mateusz Rzeszutek 2020-10-08 19:58:57 +02:00 committed by GitHub
parent 409530629f
commit ce4414e9dd
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
9 changed files with 49 additions and 56 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
docs/logger-mdc-instrumentation.md
View File

@ -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):

8
instrumentation/log4j/log4j-1.2/src/main/java/io/opentelemetry/instrumentation/auto/log4j/v1_2/Log4j1LoggingEventInstrumentation.java
View File

@ -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()));
}
}

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

@ -3,6 +3,10 @@
* 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"
}
}

1
instrumentation/log4j/log4j-2-testing/log4j-2-testing.gradle
View File

@ -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'
}

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

@ -3,6 +3,10 @@
* 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"
}
}

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

@ -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;
}
}

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

@ -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;
}

4
instrumentation/logback/logback-1.0.0/auto/src/main/java/io/opentelemetry/instrumentation/auto/logback/v1_0_0/LoggingEventInstrumentation.java
View File

@ -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;

4
instrumentation/logback/logback-1.0.0/library/src/main/java/io/opentelemetry/instrumentation/logback/v1_0_0/OpenTelemetryAppender.java
View File

@ -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;