From b2255f88057b75830e57f97308f38c9c0103cf10 Mon Sep 17 00:00:00 2001 From: Adrian Cole Date: Fri, 3 Apr 2020 08:50:08 +0800 Subject: [PATCH] Rewrites Slf4jScopeDecorator internally to re-use Brave's (#1595) --- .../cloud/sleuth/log/Slf4jScopeDecorator.java | 184 ++++-------------- .../cloud/sleuth/log/Slf4JSpanLoggerTest.java | 46 +++-- 2 files changed, 70 insertions(+), 160 deletions(-) diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jScopeDecorator.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jScopeDecorator.java index a0fe3caf0..c707d2fd4 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jScopeDecorator.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jScopeDecorator.java @@ -16,22 +16,20 @@ package org.springframework.cloud.sleuth.log; -import java.util.AbstractMap; -import java.util.List; -import java.util.stream.Collectors; -import java.util.stream.Stream; +import java.util.LinkedHashSet; +import java.util.Set; +import java.util.TreeSet; -import brave.internal.HexCodec; -import brave.internal.Nullable; -import brave.propagation.CurrentTraceContext; -import brave.propagation.ExtraFieldPropagation; +import brave.baggage.BaggageField; +import brave.baggage.BaggageFields; +import brave.baggage.CorrelationScopeDecorator; +import brave.context.slf4j.MDCScopeDecorator; +import brave.propagation.CurrentTraceContext.Scope; +import brave.propagation.CurrentTraceContext.ScopeDecorator; import brave.propagation.TraceContext; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import org.slf4j.MDC; import org.springframework.cloud.sleuth.autoconfig.SleuthProperties; -import org.springframework.util.StringUtils; /** * Adds {@linkplain MDC} properties "traceId", "parentId", "spanId" and "spanExportable" @@ -43,152 +41,46 @@ import org.springframework.util.StringUtils; * @author Marcin Grzejszczak * @since 2.1.0 */ -final class Slf4jScopeDecorator implements CurrentTraceContext.ScopeDecorator { +final class Slf4jScopeDecorator implements ScopeDecorator { // Backward compatibility for all logging patterns - private static final String LEGACY_EXPORTABLE_NAME = "X-Span-Export"; + private static final ScopeDecorator LEGACY_IDS = MDCScopeDecorator.newBuilder() + .clear().addField(BaggageFields.TRACE_ID, "X-B3-TraceId") + .addField(BaggageFields.PARENT_ID, "X-B3-ParentSpanId") + .addField(BaggageFields.SPAN_ID, "X-B3-SpanId") + .addField(BaggageFields.SAMPLED, "X-Span-Export").build(); - private static final String LEGACY_PARENT_ID_NAME = "X-B3-ParentSpanId"; - - private static final String LEGACY_TRACE_ID_NAME = "X-B3-TraceId"; - - private static final String LEGACY_SPAN_ID_NAME = "X-B3-SpanId"; - - private static final Logger log = LoggerFactory.getLogger(Slf4jScopeDecorator.class); - - private final SleuthProperties sleuthProperties; - - private final SleuthSlf4jProperties sleuthSlf4jProperties; + private final ScopeDecorator delegate; Slf4jScopeDecorator(SleuthProperties sleuthProperties, SleuthSlf4jProperties sleuthSlf4jProperties) { - this.sleuthProperties = sleuthProperties; - this.sleuthSlf4jProperties = sleuthSlf4jProperties; - } + CorrelationScopeDecorator.Builder builder = MDCScopeDecorator.newBuilder().clear() + .addField(BaggageFields.TRACE_ID).addField(BaggageFields.PARENT_ID) + .addField(BaggageFields.SPAN_ID) + .addField(BaggageFields.SAMPLED, "spanExportable"); - static void replace(String key, @Nullable String value) { - if (value != null) { - MDC.put(key, value); - } - else { - MDC.remove(key); + Set whitelist = new TreeSet<>(String.CASE_INSENSITIVE_ORDER); + whitelist.addAll(sleuthSlf4jProperties.getWhitelistedMdcKeys()); + + Set retained = new LinkedHashSet<>(); + retained.addAll(sleuthProperties.getBaggageKeys()); + retained.addAll(sleuthProperties.getPropagationKeys()); + + for (String name : retained) { + if (whitelist.contains(name)) { + // Until we move off ExtraFieldPropagation onto BaggagePropagation, + // manually create the fields... + builder.addField(BaggageField.create(name)); + builder.addDirtyName(name); + } } + + this.delegate = builder.build(); } @Override - public CurrentTraceContext.Scope decorateScope(TraceContext currentSpan, - CurrentTraceContext.Scope scope) { - final String previousTraceId = MDC.get("traceId"); - final String previousParentId = MDC.get("parentId"); - final String previousSpanId = MDC.get("spanId"); - final String spanExportable = MDC.get("spanExportable"); - final String legacyPreviousTraceId = MDC.get(LEGACY_TRACE_ID_NAME); - final String legacyPreviousParentId = MDC.get(LEGACY_PARENT_ID_NAME); - final String legacyPreviousSpanId = MDC.get(LEGACY_SPAN_ID_NAME); - final String legacySpanExportable = MDC.get(LEGACY_EXPORTABLE_NAME); - final List> previousMdc = Stream - .concat(whitelistedBaggageKeysWithValue(currentSpan), - whitelistedPropagationKeysWithValue(currentSpan)) - .map((s) -> new AbstractMap.SimpleEntry<>(s, MDC.get(s))) - .collect(Collectors.toList()); - - if (currentSpan != null) { - String traceIdString = currentSpan.traceIdString(); - MDC.put("traceId", traceIdString); - MDC.put(LEGACY_TRACE_ID_NAME, traceIdString); - String parentId = currentSpan.parentId() != null - ? HexCodec.toLowerHex(currentSpan.parentId()) : null; - replace("parentId", parentId); - replace(LEGACY_PARENT_ID_NAME, parentId); - String spanId = HexCodec.toLowerHex(currentSpan.spanId()); - MDC.put("spanId", spanId); - MDC.put(LEGACY_SPAN_ID_NAME, spanId); - String sampled = String.valueOf(currentSpan.sampled()); - MDC.put("spanExportable", sampled); - MDC.put(LEGACY_EXPORTABLE_NAME, sampled); - log("Starting scope for span: {}", currentSpan); - if (currentSpan.parentId() != null) { - if (log.isTraceEnabled()) { - log.trace("With parent: {}", currentSpan.parentId()); - } - } - whitelistedBaggageKeysWithValue(currentSpan).forEach( - (s) -> MDC.put(s, ExtraFieldPropagation.get(currentSpan, s))); - whitelistedPropagationKeysWithValue(currentSpan).forEach( - (s) -> MDC.put(s, ExtraFieldPropagation.get(currentSpan, s))); - } - else { - MDC.remove("traceId"); - MDC.remove("parentId"); - MDC.remove("spanId"); - MDC.remove("spanExportable"); - MDC.remove(LEGACY_TRACE_ID_NAME); - MDC.remove(LEGACY_PARENT_ID_NAME); - MDC.remove(LEGACY_SPAN_ID_NAME); - MDC.remove(LEGACY_EXPORTABLE_NAME); - whitelistedBaggageKeys().forEach(MDC::remove); - whitelistedPropagationKeys().forEach(MDC::remove); - } - - /** - * Thread context scope. - * - * @author Adrian Cole - */ - class ThreadContextCurrentTraceContextScope implements CurrentTraceContext.Scope { - - @Override - public void close() { - log("Closing scope for span: {}", currentSpan); - scope.close(); - replace("traceId", previousTraceId); - replace("parentId", previousParentId); - replace("spanId", previousSpanId); - replace("spanExportable", spanExportable); - replace(LEGACY_TRACE_ID_NAME, legacyPreviousTraceId); - replace(LEGACY_PARENT_ID_NAME, legacyPreviousParentId); - replace(LEGACY_SPAN_ID_NAME, legacyPreviousSpanId); - replace(LEGACY_EXPORTABLE_NAME, legacySpanExportable); - previousMdc.forEach((e) -> replace(e.getKey(), e.getValue())); - } - - } - return new ThreadContextCurrentTraceContextScope(); - } - - private Stream whitelistedBaggageKeys() { - return this.sleuthProperties.getBaggageKeys().stream().filter( - (s) -> this.sleuthSlf4jProperties.getWhitelistedMdcKeys().contains(s)); - } - - private Stream whitelistedBaggageKeysWithValue(TraceContext context) { - if (context == null) { - return Stream.empty(); - } - return whitelistedBaggageKeys().filter( - (s) -> StringUtils.hasText(ExtraFieldPropagation.get(context, s))); - } - - private Stream whitelistedPropagationKeys() { - return this.sleuthProperties.getPropagationKeys().stream().filter( - (s) -> this.sleuthSlf4jProperties.getWhitelistedMdcKeys().contains(s)); - } - - private Stream whitelistedPropagationKeysWithValue(TraceContext context) { - if (context == null) { - return Stream.empty(); - } - return whitelistedPropagationKeys().filter( - (s) -> StringUtils.hasText(ExtraFieldPropagation.get(context, s))); - } - - private void log(String text, TraceContext span) { - if (span == null) { - return; - } - if (log.isTraceEnabled()) { - log.trace(text, span); - } + public Scope decorateScope(TraceContext context, Scope scope) { + return LEGACY_IDS.decorateScope(context, delegate.decorateScope(context, scope)); } } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4JSpanLoggerTest.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4JSpanLoggerTest.java index 3a8c0ddb3..9cada2dc8 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4JSpanLoggerTest.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/log/Slf4JSpanLoggerTest.java @@ -32,6 +32,7 @@ import org.springframework.boot.autoconfigure.EnableAutoConfiguration; import org.springframework.boot.test.context.SpringBootTest; import org.springframework.test.context.junit4.SpringRunner; +import static brave.propagation.CurrentTraceContext.Scope.NOOP; import static org.assertj.core.api.Assertions.assertThat; /** @@ -66,13 +67,10 @@ public class Slf4JSpanLoggerTest { Scope scope = this.slf4jScopeDecorator.decorateScope(this.span.context(), () -> { }); - assertThat(MDC.get("X-B3-TraceId")) - .isEqualTo(this.span.context().traceIdString()); assertThat(MDC.get("traceId")).isEqualTo(this.span.context().traceIdString()); scope.close(); - assertThat(MDC.get("X-B3-TraceId")).isNullOrEmpty(); assertThat(MDC.get("traceId")).isNullOrEmpty(); } @@ -98,35 +96,55 @@ public class Slf4JSpanLoggerTest { ExtraFieldPropagation.set(this.span.context(), "my-baggage", "my-value"); ExtraFieldPropagation.set(this.span.context(), "my-propagation", "my-propagation-value"); - this.slf4jScopeDecorator.decorateScope(this.span.context(), () -> { - }); + + try (Scope scope1 = this.slf4jScopeDecorator.decorateScope(this.span.context(), + NOOP)) { + assertThat(MDC.get("my-baggage")).isEqualTo("my-value"); + assertThat(MDC.get("my-propagation")).isEqualTo("my-propagation-value"); + + try (Scope scope2 = this.slf4jScopeDecorator.decorateScope(null, NOOP)) { + assertThat(MDC.get("my-baggage")).isNullOrEmpty(); + assertThat(MDC.get("my-propagation")).isNullOrEmpty(); + } + } + } + + @Test + public void should_remove_entries_from_mdc_for_null_span_and_mdc_fields_set_directly() + throws Exception { + MDC.put("my-baggage", "my-value"); + MDC.put("my-propagation", "my-propagation-value"); + + // the span is holding no baggage so it clears the preceding values + try (Scope scope = this.slf4jScopeDecorator.decorateScope(this.span.context(), + NOOP)) { + assertThat(MDC.get("my-baggage")).isNullOrEmpty(); + assertThat(MDC.get("my-propagation")).isNullOrEmpty(); + } assertThat(MDC.get("my-baggage")).isEqualTo("my-value"); assertThat(MDC.get("my-propagation")).isEqualTo("my-propagation-value"); - Scope scope = this.slf4jScopeDecorator.decorateScope(null, () -> { - }); + try (Scope scope = this.slf4jScopeDecorator.decorateScope(null, NOOP)) { + assertThat(MDC.get("my-baggage")).isNullOrEmpty(); + assertThat(MDC.get("my-propagation")).isNullOrEmpty(); + } - scope.close(); - - assertThat(MDC.get("my-baggage")).isNullOrEmpty(); - assertThat(MDC.get("my-propagation")).isNullOrEmpty(); + assertThat(MDC.get("my-baggage")).isEqualTo("my-value"); + assertThat(MDC.get("my-propagation")).isEqualTo("my-propagation-value"); } @Test public void should_remove_entries_from_mdc_from_null_span() throws Exception { - MDC.put("X-B3-TraceId", "A"); MDC.put("traceId", "A"); Scope scope = this.slf4jScopeDecorator.decorateScope(null, () -> { }); - assertThat(MDC.get("X-B3-TraceId")).isNullOrEmpty(); assertThat(MDC.get("traceId")).isNullOrEmpty(); scope.close(); - assertThat(MDC.get("X-B3-TraceId")).isEqualTo("A"); assertThat(MDC.get("traceId")).isEqualTo("A"); }