From 785dab0908c6466b6934b33067b046d2dfa5220c Mon Sep 17 00:00:00 2001 From: Marcin Grzejszczak Date: Thu, 18 Feb 2016 13:56:41 +0100 Subject: [PATCH] [#161] Fixed the way collections are passed between spans When a span is continued a new one is created from the previous one. We've been copying span collections thus the changes in the continued instance were not reflected in the parent. Fixes #161 --- .../org/springframework/cloud/sleuth/Span.java | 16 ++++++++++++---- .../instrument/messaging/SpanMessageHeaders.java | 2 +- .../TraceFeignClientAutoConfiguration.java | 2 +- .../instrument/zuul/TracePreZuulFilter.java | 2 +- .../TraceRestClientRibbonCommandFactory.java | 2 +- .../cloud/sleuth/trace/DefaultTracer.java | 4 ++-- .../cloud/sleuth/assertions/SpanAssert.java | 12 ++++++++++++ .../sleuth/instrument/web/TraceFilterTests.java | 4 ++-- .../cloud/sleuth/trace/DefaultTracerTests.java | 16 ++++++++++++++++ 9 files changed, 48 insertions(+), 12 deletions(-) diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/Span.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/Span.java index fb46f25f4..f8466f41a 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/Span.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/Span.java @@ -63,11 +63,17 @@ public class Span { private final long spanId; private boolean remote = false; private boolean exportable = true; - private final Map tags = new LinkedHashMap<>(); + private final Map tags; private final String processId; - private final List logs = new ArrayList<>(); + private final List logs; private final Span savedSpan; + /** + * Creates a new span that still tracks tags and logs of the + * current span. This is crucial when continuing spans + * since the changes in those collections done in the continued span + * need to be reflected until the span gets closed. + */ public Span(Span current, Span savedSpan) { this.begin = current.getBegin(); this.end = current.getEnd(); @@ -78,8 +84,8 @@ public class Span { this.remote = current.isRemote(); this.exportable = current.isExportable(); this.processId = current.getProcessId(); - this.tags.putAll(current.tags()); - this.logs.addAll(current.logs()); + this.tags = current.tags; + this.logs = current.logs; this.savedSpan = savedSpan; } @@ -102,6 +108,8 @@ public class Span { this.exportable = exportable; this.processId = processId; this.savedSpan = savedSpan; + this.tags = new LinkedHashMap<>(); + this.logs = new ArrayList<>(); } public static SpanBuilder builder() { diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/SpanMessageHeaders.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/SpanMessageHeaders.java index 3f240bd40..5924a4f5b 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/SpanMessageHeaders.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/SpanMessageHeaders.java @@ -73,7 +73,7 @@ public class SpanMessageHeaders { if (parentId != null) { addHeader(headers, Span.PARENT_ID_NAME, Span.toHex(parentId)); } - addHeader(headers, Span.SPAN_NAME_NAME, span.getName().toString()); + addHeader(headers, Span.SPAN_NAME_NAME, span.getName()); addHeader(headers, Span.PROCESS_ID_NAME, span.getProcessId()); } else { diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/TraceFeignClientAutoConfiguration.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/TraceFeignClientAutoConfiguration.java index 511a60c02..3a7f55613 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/TraceFeignClientAutoConfiguration.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/TraceFeignClientAutoConfiguration.java @@ -127,7 +127,7 @@ public class TraceFeignClientAutoConfiguration { return; } template.header(Span.TRACE_ID_NAME, Span.toHex(span.getTraceId())); - setHeader(template, Span.SPAN_NAME_NAME, span.getName().toString()); + setHeader(template, Span.SPAN_NAME_NAME, span.getName()); setHeader(template, Span.SPAN_ID_NAME, Span.toHex(span.getSpanId())); if (!span.isExportable()) { setHeader(template, Span.NOT_SAMPLED_NAME, "true"); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TracePreZuulFilter.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TracePreZuulFilter.java index 167d2f77a..188af5fb8 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TracePreZuulFilter.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TracePreZuulFilter.java @@ -69,7 +69,7 @@ public class TracePreZuulFilter extends ZuulFilter try { setHeader(response, Span.SPAN_ID_NAME, span.getSpanId()); setHeader(response, Span.TRACE_ID_NAME, span.getTraceId()); - setHeader(response, Span.SPAN_NAME_NAME, span.getName().toString()); + setHeader(response, Span.SPAN_NAME_NAME, span.getName()); if (!span.isExportable()) { setHeader(response, Span.NOT_SAMPLED_NAME, "true"); } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TraceRestClientRibbonCommandFactory.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TraceRestClientRibbonCommandFactory.java index d6023ae37..a87bf453b 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TraceRestClientRibbonCommandFactory.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/TraceRestClientRibbonCommandFactory.java @@ -103,7 +103,7 @@ public class TraceRestClientRibbonCommandFactory extends RestClientRibbonCommand } setHeader(requestBuilder, Span.TRACE_ID_NAME, Span.toHex(span.getTraceId())); setHeader(requestBuilder, Span.SPAN_ID_NAME, Span.toHex(span.getSpanId())); - setHeader(requestBuilder, Span.SPAN_NAME_NAME, span.getName().toString()); + setHeader(requestBuilder, Span.SPAN_NAME_NAME, span.getName()); setHeader(requestBuilder, Span.PARENT_ID_NAME, Span.toHex(getParentId(span))); setHeader(requestBuilder, Span.PROCESS_ID_NAME, diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java index aad7dc401..7d2706b6f 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/trace/DefaultTracer.java @@ -164,12 +164,12 @@ public class DefaultTracer implements Tracer { } else { return null; } - Span newSpan = createSpan(span, SpanContextHolder.getCurrentSpan()); + Span newSpan = createContinuedSpan(span, SpanContextHolder.getCurrentSpan()); SpanContextHolder.setCurrentSpan(newSpan); return newSpan; } - protected Span createSpan(Span span, Span saved) { + private Span createContinuedSpan(Span span, Span saved) { if (saved == null && span.getSavedSpan() != null) { saved = span.getSavedSpan(); } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java index e5e9a773e..5ec96aca2 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/assertions/SpanAssert.java @@ -103,4 +103,16 @@ public class SpanAssert extends AbstractAssert { } return this; } + + public SpanAssert hasLoggedAnEvent(String event) { + isNotNull(); + if (!this.actual.logs().stream().map(org.springframework.cloud.sleuth.Log::getEvent) + .filter(s -> s.equals(event)).findAny().isPresent()) { + String message = String.format("Expected span to have the event with event value <%s>. " + + "Found logs are <%s>", event, this.actual.logs()); + log.error(message); + failWithMessage(message); + } + return this; + } } \ No newline at end of file diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterTests.java index dfe8c688d..3a94b2ebb 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterTests.java @@ -71,8 +71,8 @@ public class TraceFilterTests { this.tracer = new DefaultTracer(new DelegateSampler(), new Random(), this.publisher, new DefaultSpanNamer()) { @Override - protected Span createSpan(Span span, Span saved) { - TraceFilterTests.this.span = super.createSpan(span, saved); + public Span continueSpan(Span span) { + TraceFilterTests.this.span = super.continueSpan(span); return TraceFilterTests.this.span; } }; diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/trace/DefaultTracerTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/trace/DefaultTracerTests.java index d7b82e267..e88fea93b 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/trace/DefaultTracerTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/trace/DefaultTracerTests.java @@ -43,6 +43,7 @@ import static org.mockito.Mockito.atLeast; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; +import static org.springframework.cloud.sleuth.assertions.SleuthAssertions.then; /** * @author Spencer Gibb @@ -168,6 +169,21 @@ public class DefaultTracerTests { assertThat(tracer.getCurrentSpan(), is(equalTo(grandParent))); } + @Test + public void shouldUpdateLogsInSpanWhenItGetsContinued() { + DefaultTracer tracer = new DefaultTracer(new AlwaysSampler(), new Random(), + this.publisher, this.spanNamer); + Span span = Span.builder().name(IMPORTANT_WORK_1).traceId(1L).spanId(1L) + .build(); + Span continuedSpan = tracer.continueSpan(span); + + tracer.addTag("key", "value"); + continuedSpan.logEvent("event"); + + then(span).hasATag("key", "value").hasLoggedAnEvent("event"); + then(continuedSpan).hasATag("key", "value").hasLoggedAnEvent("event"); + } + private Span assertSpan(List spans, Long parentId, String name) { List found = findSpans(spans, parentId); assertThat("more than one span with parentId " + parentId, found.size(), is(1));