Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add Baggage to logback MDC controlled by flag #7892

Merged
merged 13 commits into from
Mar 9, 2023
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
plugins {
id("otel.javaagent-instrumentation")
id("org.unbroken-dome.test-sets")
}

muzzle {
Expand All @@ -10,6 +11,10 @@ muzzle {
}
}

testSets {
create("addBaggageTest")
}

dependencies {
implementation(project(":instrumentation:logback:logback-mdc-1.0:library"))

Expand Down Expand Up @@ -42,3 +47,17 @@ dependencies {

testImplementation(project(":instrumentation:logback:logback-mdc-1.0:testing"))
}

tasks {
val addBaggageTest by existing(Test::class) {
jvmArgs("-Dotel.instrumentation.logback.mdc.add-baggage=true")
}

test {
jvmArgs("-Dotel.instrumentation.logback.mdc.add-baggage=false")
}

named("check") {
dependsOn(addBaggageTest)
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.v1_0

import io.opentelemetry.instrumentation.logback.mdc.v1_0.AbstractLogbackWithBaggageTest
import io.opentelemetry.instrumentation.test.AgentTestTrait

class LogbackWithBaggageTest extends AbstractLogbackWithBaggageTest implements AgentTestTrait {
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="LIST" class="ch.qos.logback.core.read.ListAppender" />

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%coloredLevel %logger{15} - %message%n%xException{10}</pattern>
</encoder>
</appender>

<logger name="test">
<level value="info" />
<appender-ref ref="LIST" />
</logger>

<root level="debug">
<appender-ref ref="STDOUT" />
</root>
</configuration>
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.javaagent.instrumentation.logback.mdc.v1_0;

import io.opentelemetry.instrumentation.api.internal.ConfigPropertiesUtil;

public final class LogbackSingletons {
private static final boolean ADD_BAGGAGE =
ConfigPropertiesUtil.getBoolean("otel.instrumentation.logback.mdc.add-baggage", false);
adamleantech marked this conversation as resolved.
Show resolved Hide resolved

public static boolean addBaggage() {
return ADD_BAGGAGE;
}

private LogbackSingletons() {}
}
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@
import static net.bytebuddy.matcher.ElementMatchers.takesArguments;

import ch.qos.logback.classic.spi.ILoggingEvent;
import io.opentelemetry.api.baggage.Baggage;
import io.opentelemetry.api.baggage.BaggageEntry;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.util.VirtualField;
Expand Down Expand Up @@ -54,11 +56,11 @@ public void transform(TypeTransformer transformer) {

@SuppressWarnings("unused")
public static class GetMdcAdvice {

@Advice.OnMethodExit(suppress = Throwable.class)
public static void onExit(
@Advice.This ILoggingEvent event,
@Advice.Return(typing = Typing.DYNAMIC, readOnly = false) Map<String, String> contextData) {

if (contextData != null && contextData.containsKey(TRACE_ID)) {
// Assume already instrumented event if traceId is present.
return;
Expand All @@ -69,15 +71,25 @@ public static void onExit(
return;
}

Map<String, String> spanContextData = new HashMap<>();

SpanContext spanContext = Java8BytecodeBridge.spanFromContext(context).getSpanContext();
if (!spanContext.isValid()) {
return;

if (spanContext.isValid()) {
spanContextData.put(TRACE_ID, spanContext.getTraceId());
spanContextData.put(SPAN_ID, spanContext.getSpanId());
spanContextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
}

Map<String, String> spanContextData = new HashMap<>();
spanContextData.put(TRACE_ID, spanContext.getTraceId());
spanContextData.put(SPAN_ID, spanContext.getSpanId());
spanContextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
if (LogbackSingletons.addBaggage()) {
Baggage baggage = Java8BytecodeBridge.baggageFromContext(context);
adamleantech marked this conversation as resolved.
Show resolved Hide resolved

// using a lambda here does not play nicely with instrumentation bytecode process
// (Java 6 related errors are observed) so relying on for loop instead
for (Map.Entry<String, BaggageEntry> entry : baggage.asMap().entrySet()) {
spanContextData.put(entry.getKey(), entry.getValue().getValue());
}
}

if (contextData == null) {
contextData = spanContextData;
Expand Down
Original file line number Diff line number Diff line change
@@ -1,5 +1,10 @@
plugins {
id("otel.library-instrumentation")
id("org.unbroken-dome.test-sets")
}

testSets {
create("addBaggageTest")
}

dependencies {
Expand Down Expand Up @@ -32,3 +37,11 @@ dependencies {

testImplementation(project(":instrumentation:logback:logback-mdc-1.0:testing"))
}

tasks {
val addBaggageTest by existing

named("check") {
dependsOn(addBaggageTest)
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.logback.mdc.v1_0


import io.opentelemetry.instrumentation.test.LibraryTestTrait

class LogbackWithBaggageTest extends AbstractLogbackWithBaggageTest implements LibraryTestTrait {
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,31 @@
<?xml version="1.0" encoding="UTF-8"?>
<!--
~ 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.
-->

<configuration>
<appender name="LIST" class="ch.qos.logback.core.read.ListAppender"/>

<appender name="OTEL"
class="io.opentelemetry.instrumentation.logback.mdc.v1_0.OpenTelemetryAppender">
<addBaggage>true</addBaggage>
<appender-ref ref="LIST"/>
</appender>

<logger name="test">
<level value="info"/>
<appender-ref ref="OTEL"/>
</logger>
</configuration>
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
import ch.qos.logback.core.UnsynchronizedAppenderBase;
import ch.qos.logback.core.spi.AppenderAttachable;
import ch.qos.logback.core.spi.AppenderAttachableImpl;
import io.opentelemetry.api.baggage.Baggage;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.instrumentation.logback.mdc.v1_0.internal.UnionMap;
Expand All @@ -23,26 +24,35 @@

public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEvent>
implements AppenderAttachable<ILoggingEvent> {
private volatile boolean addBaggage;
adamleantech marked this conversation as resolved.
Show resolved Hide resolved

private final AppenderAttachableImpl<ILoggingEvent> aai = new AppenderAttachableImpl<>();

public static ILoggingEvent wrapEvent(ILoggingEvent event) {
Span currentSpan = Span.current();
if (!currentSpan.getSpanContext().isValid()) {
return event;
}
public void setAddBaggage(boolean addBaggage) {
adamleantech marked this conversation as resolved.
Show resolved Hide resolved
this.addBaggage = addBaggage;
}

public ILoggingEvent wrapEvent(ILoggingEvent event) {
Map<String, String> eventContext = event.getMDCPropertyMap();
if (eventContext != null && eventContext.containsKey(TRACE_ID)) {
// Assume already instrumented event if traceId is present.
return event;
}

Map<String, String> contextData = new HashMap<>();
SpanContext spanContext = currentSpan.getSpanContext();
contextData.put(TRACE_ID, spanContext.getTraceId());
contextData.put(SPAN_ID, spanContext.getSpanId());
contextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
Span currentSpan = Span.current();
adamleantech marked this conversation as resolved.
Show resolved Hide resolved

if (currentSpan.getSpanContext().isValid()) {
SpanContext spanContext = currentSpan.getSpanContext();
contextData.put(TRACE_ID, spanContext.getTraceId());
contextData.put(SPAN_ID, spanContext.getSpanId());
contextData.put(TRACE_FLAGS, spanContext.getTraceFlags().asHex());
}

if (addBaggage) {
Baggage baggage = Baggage.current();
baggage.forEach((key, value) -> contextData.put(key, value.getValue()));
adamleantech marked this conversation as resolved.
Show resolved Hide resolved
}

if (eventContext == null) {
eventContext = contextData;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ package io.opentelemetry.instrumentation.logback.mdc.v1_0

import ch.qos.logback.classic.spi.ILoggingEvent
import ch.qos.logback.core.read.ListAppender
import io.opentelemetry.api.baggage.Baggage
import io.opentelemetry.api.trace.Span
import io.opentelemetry.instrumentation.test.InstrumentationSpecification
import org.slf4j.Logger
Expand Down Expand Up @@ -39,8 +40,12 @@ abstract class AbstractLogbackTest extends InstrumentationSpecification {

def "no ids when no span"() {
when:
logger.info("log message 1")
logger.info("log message 2")
Baggage baggage = Baggage.empty().toBuilder().put("baggage_key", "baggage_value").build()

runWithBaggage(baggage) {
AbstractLogbackTest.logger.info("log message 1")
AbstractLogbackTest.logger.info("log message 2")
}

def events = listAppender.list

Expand All @@ -50,25 +55,27 @@ abstract class AbstractLogbackTest extends InstrumentationSpecification {
events[0].getMDCPropertyMap().get("trace_id") == null
events[0].getMDCPropertyMap().get("span_id") == null
events[0].getMDCPropertyMap().get("trace_flags") == null
events[0].getMDCPropertyMap().get("baggage_key") == (expectBaggage() ? "baggage_value" : null)

events[1].message == "log message 2"
events[1].getMDCPropertyMap().get("trace_id") == null
events[1].getMDCPropertyMap().get("span_id") == null
events[1].getMDCPropertyMap().get("trace_flags") == null
events[1].getMDCPropertyMap().get("baggage_key") == (expectBaggage() ? "baggage_value" : null)
}

def "ids when span"() {
when:
Span span1 = runWithSpan("test") {
Baggage baggage = Baggage.empty().toBuilder().put("baggage_key", "baggage_value").build()

Span span1 = runWithSpanAndBaggage("test", baggage) {
AbstractLogbackTest.logger.info("log message 1")
Span.current()
}

logger.info("log message 2")

Span span2 = runWithSpan("test 2") {
Span span2 = runWithSpanAndBaggage("test 2", baggage) {
AbstractLogbackTest.logger.info("log message 3")
Span.current()
}

def events = listAppender.list
Expand All @@ -79,15 +86,35 @@ abstract class AbstractLogbackTest extends InstrumentationSpecification {
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[0].getMDCPropertyMap().get("baggage_key") == (expectBaggage() ? "baggage_value" : null)

events[1].message == "log message 2"
events[1].getMDCPropertyMap().get("trace_id") == null
events[1].getMDCPropertyMap().get("span_id") == null
events[1].getMDCPropertyMap().get("trace_flags") == null
events[1].getMDCPropertyMap().get("baggage_key") == null

events[2].message == "log message 3"
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"
events[2].getMDCPropertyMap().get("baggage_key") == (expectBaggage() ? "baggage_value" : null)
}

Span runWithSpanAndBaggage(String spanName, Baggage baggage, Closure callback) {
return runWithSpan(spanName) {
runWithBaggage(baggage, callback)
Span.current()
}
}

void runWithBaggage(Baggage baggage, Closure callback) {
try (var unusedScope = baggage.makeCurrent()) {
callback.call()
}
}

boolean expectBaggage() {
return false
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.logback.mdc.v1_0

abstract class AbstractLogbackWithBaggageTest extends AbstractLogbackTest {
@Override
boolean expectBaggage() {
return true
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@

package io.opentelemetry.javaagent.bootstrap;

import io.opentelemetry.api.baggage.Baggage;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.context.Context;

Expand Down Expand Up @@ -37,5 +38,9 @@ public static Span spanFromContext(Context context) {
return Span.fromContext(context);
}

public static Baggage baggageFromContext(Context context) {
return Baggage.fromContext(context);
}

private Java8BytecodeBridge() {}
}