From cbca5194c20dc12a9069d293a90abc3d2a129831 Mon Sep 17 00:00:00 2001 From: Adrian Cole Date: Thu, 17 Nov 2016 13:23:25 +0800 Subject: [PATCH] Propagates logs and reports 128-bit trace IDs This supports 128-bit traces via a new field traceIdHigh, which matches other zipkin implementations. In encoded form, the trace ID is simply twice as long (32 hex characters). With this change in, a 128-bit trace propagated will not be downgraded to 64-bits when sending downstream, reporting to Zipkin or adding to the logging context. This will be followed by a change to support initiating 128-bit traces. See https://github.com/openzipkin/b3-propagation/issues/6 --- .../springframework/cloud/sleuth/Span.java | 176 +++++++++++++----- .../HeaderBasedMessagingExtractor.java | 12 +- .../HeaderBasedMessagingInjector.java | 2 +- .../web/ZipkinHttpSpanExtractor.java | 21 ++- .../web/ZipkinHttpSpanInjector.java | 2 +- .../SpanInjectingRibbonRequestCustomizer.java | 2 +- .../cloud/sleuth/log/Slf4jSpanLogger.java | 4 +- .../cloud/sleuth/SpanTests.java | 90 +++++++-- .../async/issues/issue410/Issue410Tests.java | 16 +- .../MessagingSpanExtractorTests.java | 14 +- .../web/HttpServletRequestExtractorTests.java | 4 +- ...raceCustomFilterResponseInjectorTests.java | 2 +- .../web/TraceFilterCustomExtractorTests.java | 2 +- .../cloud/sleuth/log/Slf4JSpanLoggerTest.java | 39 ++++ .../stream/ConvertToZipkinSpanList.java | 1 + .../stream/ConvertToZipkinSpanListTests.java | 17 +- .../sleuth/zipkin/ZipkinSpanListener.java | 1 + .../zipkin/ZipkinSpanListenerTests.java | 10 + 18 files changed, 311 insertions(+), 104 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 6ab7d80438..49e9269fb5 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 @@ -138,6 +138,7 @@ public class Span implements SpanContext { private final long begin; private long end = 0; private final String name; + private final long traceIdHigh; private final long traceId; private List parents = new ArrayList<>(); private final long spanId; @@ -169,6 +170,7 @@ public Span(Span current, Span savedSpan) { this.begin = current.getBegin(); this.end = current.getEnd(); this.name = current.getName(); + this.traceIdHigh = current.getTraceIdHigh(); this.traceId = current.getTraceId(); this.parents = current.getParents(); this.spanId = current.getSpanId(); @@ -183,37 +185,63 @@ public Span(Span current, Span savedSpan) { this.savedSpan = savedSpan; } + /** + * @deprecated please use {@link SpanBuilder} + */ + @Deprecated public Span(long begin, long end, String name, long traceId, List parents, long spanId, boolean remote, boolean exportable, String processId) { this(begin, end, name, traceId, parents, spanId, remote, exportable, processId, null); } + /** + * @deprecated please use {@link SpanBuilder} + */ + @Deprecated public Span(long begin, long end, String name, long traceId, List parents, long spanId, boolean remote, boolean exportable, String processId, Span savedSpan) { - if (begin > 0) { // conventionally, 0 indicates unset + this(new SpanBuilder() + .begin(begin) + .end(end) + .name(name) + .traceId(traceId) + .parents(parents) + .spanId(spanId) + .remote(remote) + .exportable(exportable) + .processId(processId) + .savedSpan(savedSpan)); + } + + Span(SpanBuilder builder) { + if (builder.begin > 0) { // conventionally, 0 indicates unset this.startNanos = null; // don't know the start tick - this.begin = begin; + this.begin = builder.begin; } else { this.startNanos = nanoTime(); this.begin = System.currentTimeMillis(); } - if (end > 0) { - this.end = end; - this.durationMicros = (end - begin) * 1000; + if (builder.end > 0) { + this.end = builder.end; + this.durationMicros = (this.end - this.begin) * 1000; } - this.name = name != null ? name : ""; - this.traceId = traceId; - this.parents = parents; - this.spanId = spanId; - this.remote = remote; - this.exportable = exportable; - this.processId = processId; - this.savedSpan = savedSpan; + this.name = builder.name != null ? builder.name : ""; + this.traceIdHigh = builder.traceIdHigh; + this.traceId = builder.traceId; + this.parents.addAll(builder.parents); + this.spanId = builder.spanId; + this.remote = builder.remote; + this.exportable = builder.exportable; + this.processId = builder.processId; + this.savedSpan = builder.savedSpan; this.tags = new ConcurrentHashMap<>(); + this.tags.putAll(builder.tags); this.logs = new ConcurrentLinkedQueue<>(); + this.logs.addAll(builder.logs); this.baggage = new ConcurrentHashMap<>(); + this.baggage.putAll(builder.baggage); } public static SpanBuilder builder() { @@ -397,7 +425,30 @@ public long getSpanId() { } /** - * A pseudo-unique (random) number assigned to the trace associated with this span + * When non-zero, the trace containing this span uses 128-bit trace identifiers. + * + *

{@code traceIdHigh} corresponds to the high bits in big-endian format and + * {@link #getTraceId()} corresponds to the low bits. + * + *

Ex. to convert the two fields to a 128bit opaque id array, you'd use code like below. + * 

{@code
+	 * ByteBuffer traceId128 = ByteBuffer.allocate(16);
+	 * traceId128.putLong(span.getTraceIdHigh());
+	 * traceId128.putLong(span.getTraceId());
+	 * traceBytes = traceId128.array();
+	 * }
+ * + * @see #traceIdString() + * @since 1.2.0 + */ + public long getTraceIdHigh() { + return this.traceIdHigh; + } + + /** + * Unique 8-byte identifier for a trace, set on all spans within it. + * + * @see #getTraceIdHigh() for notes about 128-bit trace identifiers */ public long getTraceId() { return this.traceId; @@ -452,8 +503,27 @@ public boolean isExportable() { return this.exportable; } + /** + * Returns the 16 or 32 character hex representation of the span's trace ID + * + * @since 1.2.0 + */ + public String traceIdString() { + if (this.traceIdHigh != 0) { + char[] result = new char[32]; + writeHexLong(result, 0, this.traceIdHigh); + writeHexLong(result, 16, this.traceId); + return new String(result); + } + char[] result = new char[16]; + writeHexLong(result, 0, this.traceId); + return new String(result); + } + /** * Represents given long id as 16-character lower-hex string + * + * @see #traceIdString() */ public static String idToHex(long id) { char[] data = new char[16]; @@ -488,21 +558,32 @@ static void writeHexByte(char[] data, int pos, byte b) { public static long hexToId(String hexString) { Assert.hasText(hexString, "Can't convert empty hex string to long"); int length = hexString.length(); - if (length < 1 || length > 32) throw new IllegalArgumentException("Malformed id"); + if (length < 1 || length > 32) throw new IllegalArgumentException("Malformed id: " + hexString); // trim off any high bits - int i = length > 16 ? length - 16 : 0; + int beginIndex = length > 16 ? length - 16 : 0; + + return hexToId(hexString, beginIndex); + } + /** + * Parses a 16 character lower-hex string with no prefix into an unsigned long, starting at the + * specified index. + * + * @since 1.2.0 + */ + public static long hexToId(String lowerHex, int index) { + Assert.hasText(lowerHex, "Can't convert empty hex string to long"); long result = 0; - for (; i < length; i++) { - char c = hexString.charAt(i); + for (int endIndex = Math.min(index + 16, lowerHex.length()); index < endIndex; index++) { + char c = lowerHex.charAt(index); result <<= 4; if (c >= '0' && c <= '9') { result |= c - '0'; } else if (c >= 'a' && c <= 'f') { result |= c - 'a' + 10; } else { - throw new IllegalArgumentException("Malformed id"); + throw new IllegalArgumentException("Malformed id: " + lowerHex); } } return result; @@ -510,7 +591,7 @@ public static long hexToId(String hexString) { @Override public String toString() { - return "[Trace: " + idToHex(this.traceId) + ", Span: " + idToHex(this.spanId) + return "[Trace: " + traceIdString() + ", Span: " + idToHex(this.spanId) + ", Parent: " + getParentIdIfPresent() + ", exportable:" + this.exportable + "]"; } @@ -520,31 +601,36 @@ private String getParentIdIfPresent() { @Override public int hashCode() { - final int prime = 31; - int result = 1; - result = prime * result + (int) (this.spanId ^ (this.spanId >>> 32)); - result = prime * result + (int) (this.traceId ^ (this.traceId >>> 32)); - return result; + int h = 1; + h *= 1000003; + h ^= (this.traceIdHigh >>> 32) ^ this.traceIdHigh; + h *= 1000003; + h ^= (this.traceId >>> 32) ^ this.traceId; + h *= 1000003; + h ^= (this.spanId >>> 32) ^ this.spanId; + h *= 1000003; + return h; } @Override - public boolean equals(Object obj) { - if (this == obj) + public boolean equals(Object o) { + if (o == this) { return true; - if (obj == null) - return false; - if (getClass() != obj.getClass()) - return false; - Span other = (Span) obj; - if (this.spanId != other.spanId) - return false; - return this.traceId == other.traceId; + } + if (o instanceof Span) { + Span that = (Span) o; + return (this.traceIdHigh == that.traceIdHigh) + && (this.traceId == that.traceId) + && (this.spanId == that.spanId); + } + return false; } public static class SpanBuilder { private long begin; private long end; private String name; + private long traceIdHigh; private long traceId; private ArrayList parents = new ArrayList<>(); private long spanId; @@ -581,6 +667,11 @@ public Span.SpanBuilder name(String name) { return this; } + public Span.SpanBuilder traceIdHigh(long traceIdHigh) { + this.traceIdHigh = traceIdHigh; + return this; + } + public Span.SpanBuilder traceId(long traceId) { this.traceId = traceId; return this; @@ -652,23 +743,12 @@ public Span.SpanBuilder savedSpan(Span savedSpan) { } public Span build() { - Span span = new Span(this.begin, this.end, this.name, this.traceId, - this.parents, this.spanId, this.remote, this.exportable, - this.processId, this.savedSpan); - span.logs.addAll(this.logs); - span.tags.putAll(this.tags); - span.baggage.putAll(this.baggage); - return span; + return new Span(this); } @Override public String toString() { - return "SpanBuilder{" + "begin=" + this.begin + ", end=" + this.end - + ", name=" + this.name + ", traceId=" + this.traceId + ", parents=" - + this.parents + ", spanId=" + this.spanId + ", remote=" + this.remote - + ", exportable=" + this.exportable + ", processId='" + this.processId - + '\'' + ", savedSpan=" + this.savedSpan + ", logs=" + this.logs - + ", tags=" + this.tags + '}'; + return new Span(this).toString(); } } } diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingExtractor.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingExtractor.java index a2c0d14c05..f143c1126e 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingExtractor.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingExtractor.java @@ -25,12 +25,12 @@ public Span joinTrace(SpanTextMap textMap) { return extractSpanFromHeaders(carrier, Span.builder()); } - private Span extractSpanFromHeaders(Map carrier, Span.SpanBuilder builder) { - Span.SpanBuilder spanBuilder = builder; - long traceId = Span - .hexToId(carrier.get(TraceMessageHeaders.TRACE_ID_NAME)); - long spanId = Span.hexToId(carrier.get(TraceMessageHeaders.SPAN_ID_NAME)); - spanBuilder = spanBuilder.traceId(traceId).spanId(spanId); + private Span extractSpanFromHeaders(Map carrier, Span.SpanBuilder spanBuilder) { + String traceId = carrier.get(TraceMessageHeaders.TRACE_ID_NAME); + spanBuilder = spanBuilder + .traceIdHigh(traceId.length() == 32 ? Span.hexToId(traceId, 0) : 0) + .traceId(Span.hexToId(traceId)) + .spanId(Span.hexToId(carrier.get(TraceMessageHeaders.SPAN_ID_NAME))); spanBuilder.exportable( Span.SPAN_SAMPLED.equals(carrier.get(TraceMessageHeaders.SAMPLED_NAME))); String processId = carrier.get(TraceMessageHeaders.PROCESS_ID_NAME); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingInjector.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingInjector.java index b74a8e4b2a..7a6856c0a0 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingInjector.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/HeaderBasedMessagingInjector.java @@ -41,7 +41,7 @@ private boolean isSampled(Map initialMessage, String sampledHead } private void addHeaders(Span span, SpanTextMap textMap) { - addHeader(textMap, TraceMessageHeaders.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + addHeader(textMap, TraceMessageHeaders.TRACE_ID_NAME, span.traceIdString()); addHeader(textMap, TraceMessageHeaders.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); if (span.isExportable()) { addAnnotations(this.traceKeys, textMap, span); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanExtractor.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanExtractor.java index 5f8aceffef..a7879f78a1 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanExtractor.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanExtractor.java @@ -41,32 +41,33 @@ public Span joinTrace(SpanTextMap textMap) { String uri = carrier.get(URI_HEADER); boolean skip = this.skipPattern.matcher(uri).matches() || Span.SPAN_NOT_SAMPLED.equals(carrier.get(Span.SAMPLED_NAME)); - long traceId = Span - .hexToId(carrier.get(Span.TRACE_ID_NAME)); - long spanId = spanId(carrier, traceId); - return buildParentSpan(carrier, uri, skip, traceId, spanId); + long spanId = spanId(carrier); + return buildParentSpan(carrier, uri, skip, spanId); } catch (Exception e) { log.error("Exception occurred while trying to extract span from carrier", e); return null; } } - private long spanId(Map carrier, long traceId) { + private long spanId(Map carrier) { String spanId = carrier.get(Span.SPAN_ID_NAME); if (spanId == null) { if (log.isDebugEnabled()) { log.debug("Request is missing a span id but it has a trace id. We'll assume that this is " - + "a root span with span id equal to trace id"); + + "a root span with span id equal to the lower 64-bits of the trace id"); } - return traceId; + return Span.hexToId(carrier.get(Span.TRACE_ID_NAME)); } else { return Span.hexToId(spanId); } } - private Span buildParentSpan(Map carrier, String uri, boolean skip, - long traceId, long spanId) { - Span.SpanBuilder span = Span.builder().traceId(traceId).spanId(spanId); + private Span buildParentSpan(Map carrier, String uri, boolean skip, long spanId) { + String traceId = carrier.get(Span.TRACE_ID_NAME); + Span.SpanBuilder span = Span.builder() + .traceIdHigh(traceId.length() == 32 ? Span.hexToId(traceId, 0) : 0) + .traceId(Span.hexToId(traceId)) + .spanId(spanId); String processId = carrier.get(Span.PROCESS_ID_NAME); String parentName = carrier.get(Span.SPAN_NAME_NAME); if (StringUtils.hasText(parentName)) { diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanInjector.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanInjector.java index 9b05ca17d7..8788ff2de2 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanInjector.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/ZipkinHttpSpanInjector.java @@ -18,7 +18,7 @@ public class ZipkinHttpSpanInjector implements HttpSpanInjector { @Override public void inject(Span span, SpanTextMap carrier) { - setIdHeader(carrier, Span.TRACE_ID_NAME, span.getTraceId()); + setHeader(carrier, Span.TRACE_ID_NAME, span.traceIdString()); setIdHeader(carrier, Span.SPAN_ID_NAME, span.getSpanId()); setHeader(carrier, Span.SAMPLED_NAME, span.isExportable() ? Span.SPAN_SAMPLED : Span.SPAN_NOT_SAMPLED); setHeader(carrier, Span.SPAN_NAME_NAME, span.getName()); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/SpanInjectingRibbonRequestCustomizer.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/SpanInjectingRibbonRequestCustomizer.java index 90575c1c23..c0b9181626 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/SpanInjectingRibbonRequestCustomizer.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/SpanInjectingRibbonRequestCustomizer.java @@ -68,7 +68,7 @@ public void inject(Span span, SpanTextMap carrier) { } carrier.put(Span.SAMPLED_NAME, span.isExportable() ? Span.SPAN_SAMPLED : Span.SPAN_NOT_SAMPLED); - carrier.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + carrier.put(Span.TRACE_ID_NAME, span.traceIdString()); carrier.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); carrier.put(Span.SPAN_NAME_NAME, span.getName()); if (getParentId(span) != null) { diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanLogger.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanLogger.java index 3df9f1b036..db1dbe31cb 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanLogger.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/log/Slf4jSpanLogger.java @@ -49,7 +49,7 @@ public Slf4jSpanLogger(String nameSkipPattern) { public void logStartedSpan(Span parent, Span span) { MDC.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); MDC.put(Span.SPAN_EXPORT_NAME, String.valueOf(span.isExportable())); - MDC.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + MDC.put(Span.TRACE_ID_NAME, span.traceIdString()); log("Starting span: {}", span); if (parent != null) { log("With parent: {}", parent); @@ -59,7 +59,7 @@ public void logStartedSpan(Span parent, Span span) { @Override public void logContinuedSpan(Span span) { MDC.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); - MDC.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + MDC.put(Span.TRACE_ID_NAME, span.traceIdString()); MDC.put(Span.SPAN_EXPORT_NAME, String.valueOf(span.isExportable())); log("Continued span: {}", span); } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/SpanTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/SpanTests.java index 907b9d6dc8..2f51e189ff 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/SpanTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/SpanTests.java @@ -17,7 +17,6 @@ package org.springframework.cloud.sleuth; import java.io.IOException; -import java.util.Collections; import java.util.concurrent.atomic.AtomicLong; import com.fasterxml.jackson.core.JsonProcessingException; @@ -34,6 +33,45 @@ * @author Spencer Gibb */ public class SpanTests { + Span span = Span.builder().begin(1).end(2).name("http:name").traceId(1L).spanId(2L) + .remote(true).exportable(true).processId("process").build(); + + @Test + public void should_consider_trace_and_span_id_on_equals_and_hashCode() throws Exception { + Span span = Span.builder().traceId(1L).spanId(2L).build(); + Span differentSpan = Span.builder().traceId(1L).spanId(3L).build(); + Span withParent =Span.builder().traceId(1L).spanId(2L).parent(3L).build(); + + then(span).isEqualTo(withParent); + then(span).isNotEqualTo(differentSpan); + then(span.hashCode()).isNotEqualTo(differentSpan.hashCode()); + } + + @Test + public void should_have_toString_with_identifiers_and_export() throws Exception { + span = Span.builder().traceId(1L).spanId(2L).parent(3L).name("foo").build(); + + then(span).hasToString( + "[Trace: 0000000000000001, Span: 0000000000000002, Parent: 0000000000000003, exportable:true]"); + } + + @Test + public void should_have_toString_with_128bit_trace_id() throws Exception { + span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).parent(4L).build(); + + then(span.toString()).startsWith("[Trace: 00000000000000010000000000000002,"); + } + + @Test + public void should_consider_128bit_trace_and_span_id_on_equals_and_hashCode() throws Exception { + Span span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).build(); + Span differentSpan = Span.builder().traceIdHigh(2L).traceId(2L).spanId(3L).build(); + Span withParent = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).parent(4L).build(); + + then(span).isEqualTo(withParent); + then(span).isNotEqualTo(differentSpan); + then(span.hashCode()).isNotEqualTo(differentSpan.hashCode()); + } @Test public void should_convert_long_to_16_character_hex_string() throws Exception { @@ -63,6 +101,36 @@ public void should_convert_lower_64bits_of_hex_string_to_long() throws Exception then(someLong).isEqualTo(Span.hexToId(lower64Bits)); } + @Test + public void should_convert_offset_64bits_of_hex_string_to_long() throws Exception { + String hex128Bits = "463ac35c9f6413ad48485a3953bb6124"; + String high64Bits = "463ac35c9f6413ad"; + + long someLong = Span.hexToId(hex128Bits, 0); + + then(someLong).isEqualTo(Span.hexToId(high64Bits)); + } + + @Test + public void should_writeFixedLength64BitTraceId() throws Exception { + String traceId = span.traceIdString(); + + then(traceId).isEqualTo("0000000000000001"); + } + + @Test + public void should_writeFixedLength128BitTraceId() throws Exception { + String high128Bits = "463ac35c9f6413ad"; + String low64Bits = "48485a3953bb6124"; + + span = Span.builder().traceIdHigh(Span.hexToId(high128Bits)).traceId(Span.hexToId(low64Bits)) + .spanId(1L).name("foo").build(); + + String traceId = span.traceIdString(); + + then(traceId).isEqualTo(high128Bits + low64Bits); + } + @Test(expected = IllegalArgumentException.class) public void should_throw_exception_when_null_string_is_to_be_converted_to_long() throws Exception { Span.hexToId(null); @@ -70,23 +138,15 @@ public void should_throw_exception_when_null_string_is_to_be_converted_to_long() @Test(expected = UnsupportedOperationException.class) public void getAnnotationsReadOnly() { - Span span = new Span(1, 2, "http:name", 1L, Collections.emptyList(), 2L, true, - true, "process"); - span.tags().put("a", "b"); } @Test(expected = UnsupportedOperationException.class) public void getTimelineAnnotationsReadOnly() { - Span span = new Span(1, 2, "http:name", 1L, Collections.emptyList(), 2L, true, - true, "process"); - span.logs().add(new Log(1, "1")); } @Test public void should_properly_serialize_object() throws JsonProcessingException { - Span span = new Span(1, 2, "http:name", 1L, - Collections.emptyList(), 2L, true, true, "process"); ObjectMapper objectMapper = new ObjectMapper(); String serializedName = objectMapper.writeValueAsString(span); @@ -95,8 +155,6 @@ public void getTimelineAnnotationsReadOnly() { } @Test public void should_properly_serialize_logs() throws IOException { - Span span = new Span(1, 2, "http:name", 1L, - Collections.emptyList(), 2L, true, true, "process"); span.logEvent("cs"); ObjectMapper objectMapper = new ObjectMapper(); @@ -109,8 +167,6 @@ public void getTimelineAnnotationsReadOnly() { } @Test public void should_properly_serialize_tags() throws IOException { - Span span = new Span(1, 2, "http:name", 1L, - Collections.emptyList(), 2L, true, true, "process"); span.tag("calculatedTax", "100"); ObjectMapper objectMapper = new ObjectMapper(); @@ -129,7 +185,7 @@ public void should_throw_exception_when_converting_invalid_hex_value() { /** When going over a transport like spring-cloud-stream, we must retain the precise duration. */ @Test public void shouldSerializeDurationMicros() throws IOException { - Span span = Span.builder().traceId(1L).name("http:parent").remote(true).build(); + Span span = Span.builder().traceId(1L).name("http:parent").build(); span.stop(); assertThat(span.getAccumulatedMicros()) @@ -152,8 +208,7 @@ public void should_throw_exception_when_converting_invalid_hex_value() { AtomicLong nanoTime = new AtomicLong(); // starts the span, recording its initial tick as zero - Span span = new Span(0, 0, "http:name", 1L, Collections.emptyList(), 2L, true, - true, "process", null) { + Span span = new Span(Span.builder().name("http:name").traceId(1L).spanId(2L)) { @Override long nanoTime() { return nanoTime.get(); } @@ -171,8 +226,7 @@ public void should_throw_exception_when_converting_invalid_hex_value() { AtomicLong nanoTime = new AtomicLong(); // starts the span, recording its initial tick as zero - Span span = new Span(0, 0, "http:name", 1L, Collections.emptyList(), 2L, true, - true, "process", null) { + Span span = new Span(Span.builder().name("http:name").traceId(1L).spanId(2L)) { @Override long nanoTime() { return nanoTime.get(); } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/async/issues/issue410/Issue410Tests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/async/issues/issue410/Issue410Tests.java index 2e88b31bbc..2668ca25cc 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/async/issues/issue410/Issue410Tests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/async/issues/issue410/Issue410Tests.java @@ -85,7 +85,7 @@ public void should_pass_tracing_info_for_tasks_running_without_a_pool() { try { String response = this.restTemplate.getForObject("http://localhost:" + port() + "/without_pool", String.class); - then(response).isEqualTo(Span.idToHex(span.getTraceId())); + then(response).isEqualTo(span.traceIdString()); Awaitility.await().until(() -> { then(this.asyncTask.getSpan().get()).isNotNull(); then(this.asyncTask.getSpan().get().getTraceId()).isEqualTo(span.getTraceId()); @@ -102,7 +102,7 @@ public void should_pass_tracing_info_for_tasks_running_with_a_pool() { try { String response = this.restTemplate.getForObject("http://localhost:" + port() + "/with_pool", String.class); - then(response).isEqualTo(Span.idToHex(span.getTraceId())); + then(response).isEqualTo(span.traceIdString()); Awaitility.await().until(() -> { then(this.asyncTask.getSpan().get()).isNotNull(); then(this.asyncTask.getSpan().get().getTraceId()).isEqualTo(span.getTraceId()); @@ -122,7 +122,7 @@ public void should_pass_tracing_info_for_completable_futures_with_executor() { try { String response = this.restTemplate.getForObject("http://localhost:" + port() + "/completable", String.class); - then(response).isEqualTo(Span.idToHex(span.getTraceId())); + then(response).isEqualTo(span.traceIdString()); Awaitility.await().until(() -> { then(this.asyncTask.getSpan().get()).isNotNull(); then(this.asyncTask.getSpan().get().getTraceId()).isEqualTo(span.getTraceId()); @@ -142,7 +142,7 @@ public void should_pass_tracing_info_for_completable_futures_with_task_scheduler try { String response = this.restTemplate.getForObject("http://localhost:" + port() + "/taskScheduler", String.class); - then(response).isEqualTo(Span.idToHex(span.getTraceId())); + then(response).isEqualTo(span.traceIdString()); Awaitility.await().until(() -> { then(this.asyncTask.getSpan().get()).isNotNull(); then(this.asyncTask.getSpan().get().getTraceId()).isEqualTo(span.getTraceId()); @@ -280,7 +280,7 @@ class Application { public String withPool() { log.info("Executing with pool."); this.asyncTask.runWithPool(); - return Span.idToHex(this.tracer.getCurrentSpan().getTraceId()); + return this.tracer.getCurrentSpan().traceIdString(); } @@ -288,19 +288,19 @@ public String withPool() { public String withoutPool() { log.info("Executing without pool."); this.asyncTask.runWithoutPool(); - return Span.idToHex(this.tracer.getCurrentSpan().getTraceId()); + return this.tracer.getCurrentSpan().traceIdString(); } @RequestMapping("/completable") public String completable() throws ExecutionException, InterruptedException { log.info("Executing completable"); - return Span.idToHex(this.asyncTask.completableFutures().getTraceId()); + return this.asyncTask.completableFutures().traceIdString(); } @RequestMapping("/taskScheduler") public String taskScheduler() throws ExecutionException, InterruptedException { log.info("Executing completable via task scheduler"); - return Span.idToHex(this.asyncTask.taskScheduler().getTraceId()); + return this.asyncTask.taskScheduler().traceIdString(); } /** diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractorTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractorTests.java index 1122e96b83..fa90eeed45 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractorTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractorTests.java @@ -19,8 +19,9 @@ import java.util.HashMap; import java.util.Map; import java.util.Random; - import org.junit.Test; + +import org.springframework.cloud.sleuth.Span; import org.springframework.messaging.MessageHeaders; import org.springframework.messaging.support.MessageBuilder; import org.springframework.util.StringUtils; @@ -53,6 +54,17 @@ public void should_set_random_traceid_if_header_value_is_invalid() { } } + @Test + public void should_parse_128bit_trace_id() { + String traceId128 = "463ac35c9f6413ad48485a3953bb6124"; + + Span span = this.extractor.joinTrace( + new MessagingTextMap(MessageBuilder.withPayload("") + .copyHeaders(headers(traceId128, randomId())))); + + then(span.traceIdString()).isEqualTo(traceId128); + } + @Test public void should_set_random_spanid_if_header_value_is_invalid() { try { diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractorTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractorTests.java index 66e118e1f5..c628ab25e0 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractorTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractorTests.java @@ -81,7 +81,7 @@ public void should_not_throw_exception_if_parent_id_is_invalid() { } @Test - public void should_downgrade_128bit_trace_id_by_dropping_high_bits() { + public void should_accept_128bit_trace_id() { String hex128Bits = "463ac35c9f6413ad48485a3953bb6124"; String lower64Bits = "48485a3953bb6124"; @@ -94,6 +94,6 @@ public void should_downgrade_128bit_trace_id_by_dropping_high_bits() { Span span = this.extractor.joinTrace(new HttpServletRequestTextMap(this.request)); - then(span.getTraceId()).isEqualTo(Span.hexToId(lower64Bits)); + then(span.traceIdString()).isEqualTo(hex128Bits); } } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceCustomFilterResponseInjectorTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceCustomFilterResponseInjectorTests.java index 7e7c1d492c..df1af48a3b 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceCustomFilterResponseInjectorTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceCustomFilterResponseInjectorTests.java @@ -118,7 +118,7 @@ static class CustomHttpServletResponseSpanInjector extends ZipkinHttpSpanInjecto @Override public void inject(Span span, SpanTextMap carrier) { super.inject(span, carrier); - carrier.put(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + carrier.put(Span.TRACE_ID_NAME, span.traceIdString()); carrier.put(Span.SPAN_ID_NAME, Span.idToHex(span.getSpanId())); } } diff --git a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterCustomExtractorTests.java b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterCustomExtractorTests.java index 12df869f94..cc7c934164 100644 --- a/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterCustomExtractorTests.java +++ b/spring-cloud-sleuth-core/src/test/java/org/springframework/cloud/sleuth/instrument/web/TraceFilterCustomExtractorTests.java @@ -154,7 +154,7 @@ static class CustomHttpSpanInjector implements HttpSpanInjector { @Override public void inject(Span span, SpanTextMap carrier) { - carrier.put("correlationId", Span.idToHex(span.getTraceId())); + carrier.put("correlationId", span.traceIdString()); carrier.put("mySpanId", Span.idToHex(span.getSpanId())); } } 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 29b3afea63..649ea1a9da 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 @@ -20,8 +20,10 @@ import org.junit.Test; import org.mockito.Mockito; import org.slf4j.Logger; +import org.slf4j.MDC; import org.springframework.cloud.sleuth.Span; +import static org.assertj.core.api.Assertions.assertThat; import static org.mockito.BDDMockito.given; import static org.mockito.BDDMockito.then; import static org.mockito.Matchers.anyList; @@ -42,9 +44,46 @@ public class Slf4JSpanLoggerTest { @Before public void setup() { + MDC.clear(); given(log.isTraceEnabled()).willReturn(true); } + @Test + public void when_start_event_arrived_should_add_64bit_trace_id_to_MDC() throws Exception { + Span span = Span.builder().traceId(1L).spanId(2L).build(); + + this.slf4JSpanLogger.logStartedSpan(this.spanWithNameNotToBeExcluded, span); + + assertThat(MDC.get("X-B3-TraceId")).isEqualTo("0000000000000001"); + } + + @Test + public void when_start_event_arrived_should_add_128bit_trace_id_to_MDC() throws Exception { + Span span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).build(); + + this.slf4JSpanLogger.logStartedSpan(this.spanWithNameNotToBeExcluded, span); + + assertThat(MDC.get("X-B3-TraceId")).isEqualTo("00000000000000010000000000000002"); + } + + @Test + public void when_continued_event_arrived_should_add_64bit_trace_id_to_MDC() throws Exception { + Span span = Span.builder().traceId(1L).spanId(2L).build(); + + this.slf4JSpanLogger.logContinuedSpan(span); + + assertThat(MDC.get("X-B3-TraceId")).isEqualTo("0000000000000001"); + } + + @Test + public void when_continued_event_arrived_should_add_128bit_trace_id_to_MDC() throws Exception { + Span span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).build(); + + this.slf4JSpanLogger.logContinuedSpan(span); + + assertThat(MDC.get("X-B3-TraceId")).isEqualTo("00000000000000010000000000000002"); + } + @Test public void should_log_when_start_event_arrived_and_pattern_doesnt_match_span_name() throws Exception { this.slf4JSpanLogger.logStartedSpan(this.spanWithNameNotToBeExcluded, diff --git a/spring-cloud-sleuth-zipkin-stream/src/main/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanList.java b/spring-cloud-sleuth-zipkin-stream/src/main/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanList.java index 7a1e2bd473..7bd83c15bc 100644 --- a/spring-cloud-sleuth-zipkin-stream/src/main/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanList.java +++ b/spring-cloud-sleuth-zipkin-stream/src/main/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanList.java @@ -99,6 +99,7 @@ static zipkin.Span convert(Span span, Host host) { zipkinSpan.duration(calculateDurationInMicros(span)); } } + zipkinSpan.traceIdHigh(span.getTraceIdHigh()); zipkinSpan.traceId(span.getTraceId()); if (span.getParents().size() > 0) { if (span.getParents().size() > 1) { diff --git a/spring-cloud-sleuth-zipkin-stream/src/test/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanListTests.java b/spring-cloud-sleuth-zipkin-stream/src/test/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanListTests.java index 4aa3cac913..26161e080f 100644 --- a/spring-cloud-sleuth-zipkin-stream/src/test/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanListTests.java +++ b/spring-cloud-sleuth-zipkin-stream/src/test/java/org/springframework/cloud/sleuth/zipkin/stream/ConvertToZipkinSpanListTests.java @@ -19,12 +19,10 @@ import java.util.Collections; import java.util.List; import java.util.Random; - import org.junit.Test; import org.springframework.cloud.sleuth.Span; import org.springframework.cloud.sleuth.stream.Host; import org.springframework.cloud.sleuth.stream.Spans; - import zipkin.Constants; import static org.assertj.core.api.Assertions.assertThat; @@ -183,13 +181,24 @@ public void doesntSetTimestampOrDurationWhenRemote() { .isNull(); } + @Test + public void converts128BitTraceId() { + Span span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).name("foo").build(); + + Spans spans = new Spans(this.host, Collections.singletonList(span)); + zipkin.Span result = ConvertToZipkinSpanList.convert(spans).get(0); + + assertThat(result.traceIdHigh).isEqualTo(span.getTraceIdHigh()); + assertThat(result.traceId).isEqualTo(span.getTraceId()); + } + Span span(String name) { return span(name, false); } Span span(String name, boolean remote) { Long id = new Random().nextLong(); - return new Span(1, 3, "message:" + name, id, Collections.emptyList(), id, remote, true, - "process"); + return Span.builder().begin(1).end(3).name("message:" + name).traceId(id).spanId(id) + .remote(remote).processId("process").build(); } } diff --git a/spring-cloud-sleuth-zipkin/src/main/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListener.java b/spring-cloud-sleuth-zipkin/src/main/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListener.java index 116a876e41..46a34f5b52 100644 --- a/spring-cloud-sleuth-zipkin/src/main/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListener.java +++ b/spring-cloud-sleuth-zipkin/src/main/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListener.java @@ -95,6 +95,7 @@ zipkin.Span convert(Span span) { zipkinSpan.duration(calculateDurationInMicros(span)); } } + zipkinSpan.traceIdHigh(span.getTraceIdHigh()); zipkinSpan.traceId(span.getTraceId()); if (span.getParents().size() > 0) { if (span.getParents().size() > 1) { diff --git a/spring-cloud-sleuth-zipkin/src/test/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListenerTests.java b/spring-cloud-sleuth-zipkin/src/test/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListenerTests.java index a99e4d2672..239754a49e 100644 --- a/spring-cloud-sleuth-zipkin/src/test/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListenerTests.java +++ b/spring-cloud-sleuth-zipkin/src/test/java/org/springframework/cloud/sleuth/zipkin/ZipkinSpanListenerTests.java @@ -215,6 +215,16 @@ public void appendsServerAddressTagIfClientLogIsPresent() { .isNotEmpty(); } + @Test + public void converts128BitTraceId() { + Span span = Span.builder().traceIdHigh(1L).traceId(2L).spanId(3L).name("foo").build(); + + zipkin.Span result = this.spanReporter.convert(span); + + assertThat(result.traceIdHigh).isEqualTo(span.getTraceIdHigh()); + assertThat(result.traceId).isEqualTo(span.getTraceId()); + } + @Test public void shouldReuseServerAddressTag() { this.parent.logEvent(Constants.CLIENT_SEND);