Rewrites Slf4jScopeDecorator internally to re-use Brave's (#1595)

This commit is contained in:
Adrian Cole
2020-04-03 08:50:08 +08:00
committed by Adrian Cole
parent 6fe46bf062
commit b2255f8805
2 changed files with 70 additions and 160 deletions

View File

@@ -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<String> whitelist = new TreeSet<>(String.CASE_INSENSITIVE_ORDER);
whitelist.addAll(sleuthSlf4jProperties.getWhitelistedMdcKeys());
Set<String> 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<AbstractMap.SimpleEntry<String, String>> 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<String> whitelistedBaggageKeys() {
return this.sleuthProperties.getBaggageKeys().stream().filter(
(s) -> this.sleuthSlf4jProperties.getWhitelistedMdcKeys().contains(s));
}
private Stream<String> whitelistedBaggageKeysWithValue(TraceContext context) {
if (context == null) {
return Stream.empty();
}
return whitelistedBaggageKeys().filter(
(s) -> StringUtils.hasText(ExtraFieldPropagation.get(context, s)));
}
private Stream<String> whitelistedPropagationKeys() {
return this.sleuthProperties.getPropagationKeys().stream().filter(
(s) -> this.sleuthSlf4jProperties.getWhitelistedMdcKeys().contains(s));
}
private Stream<String> 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));
}
}

View File

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