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 394ce657d2..31574f18ea 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 @@ -137,6 +137,7 @@ public class Span { 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; @@ -166,6 +167,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(); @@ -179,36 +181,61 @@ 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); } public static SpanBuilder builder() { @@ -358,7 +385,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.0.11 + */ + 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; @@ -413,8 +463,27 @@ public boolean isExportable() { return this.exportable; } + /** + * Returns the 16 or 32 character hex representation of the span's trace ID + * + * @since 1.0.11 + */ + 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]; @@ -449,21 +518,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.0.11 + */ + 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; @@ -471,7 +551,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 + "]"; } @@ -481,31 +561,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; @@ -541,6 +626,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; @@ -602,22 +692,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); - 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/MessagingSpanExtractor.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractor.java index b7cdc809fe..8b14098f63 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractor.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanExtractor.java @@ -76,12 +76,14 @@ private Span extractSpanFromNewHeaders(Message carrier, SpanBuilder spanBuild private Span extractSpanFromHeaders(Message carrier, SpanBuilder spanBuilder, String traceIdHeader, String spanIdHeader, String spanSampledHeader, String spanProcessIdHeader, String spanNameHeader, String spanParentIdHeader) { - long traceId = Span - .hexToId(getHeader(carrier, traceIdHeader)); + String traceId = getHeader(carrier, traceIdHeader); + spanBuilder.traceIdHigh(traceId.length() == 32 ? Span.hexToId(traceId, 0) : 0); + spanBuilder.traceId(Span.hexToId(traceId)); + long spanId = hasHeader(carrier, spanIdHeader) ? Span.hexToId(getHeader(carrier, spanIdHeader)) : this.random.nextLong(); - spanBuilder = spanBuilder.traceId(traceId).spanId(spanId); + spanBuilder = spanBuilder.spanId(spanId); spanBuilder.exportable( Span.SPAN_SAMPLED.equals(getHeader(carrier, spanSampledHeader))); String processId = getHeader(carrier, spanProcessIdHeader); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanInjector.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanInjector.java index 11098b447b..f867411acc 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanInjector.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/messaging/MessagingSpanInjector.java @@ -95,7 +95,7 @@ private void addHeaders(Span span, Message initialMessage, MessageHeaderAccessor accessor, Map headers, String traceIdHeader, String spanIdHeader, String parentIdHeader, String spanNameHeader, String processIdHeader, String spanSampledHeader, String spanHeader) { - addHeader(headers, traceIdHeader, Span.idToHex(span.getTraceId())); + addHeader(headers, traceIdHeader, span.traceIdString()); addHeader(headers, spanIdHeader, Span.idToHex(span.getSpanId())); if (span.isExportable()) { addAnnotations(this.traceKeys, initialMessage, span); diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractor.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractor.java index 2a682bfe6d..719fd96b93 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractor.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/HttpServletRequestExtractor.java @@ -58,32 +58,33 @@ public Span joinTrace(HttpServletRequest carrier) { String uri = this.urlPathHelper.getPathWithinApplication(carrier); boolean skip = this.skipPattern.matcher(uri).matches() || Span.SPAN_NOT_SAMPLED.equals(carrier.getHeader(Span.SAMPLED_NAME)); - long traceId = Span - .hexToId(carrier.getHeader(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(HttpServletRequest carrier, long traceId) { + private long spanId(HttpServletRequest carrier) { String spanId = carrier.getHeader(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.getHeader(Span.TRACE_ID_NAME)); } else { return Span.hexToId(spanId); } } - private Span buildParentSpan(HttpServletRequest carrier, String uri, boolean skip, - long traceId, long spanId) { - SpanBuilder span = Span.builder().traceId(traceId).spanId(spanId); + private Span buildParentSpan(HttpServletRequest carrier, String uri, boolean skip, long spanId) { + String traceId = carrier.getHeader(Span.TRACE_ID_NAME); + SpanBuilder span = Span.builder() + .traceIdHigh(traceId.length() == 32 ? Span.hexToId(traceId, 0) : 0) + .traceId(Span.hexToId(traceId)) + .spanId(spanId); String processId = carrier.getHeader(Span.PROCESS_ID_NAME); String parentName = carrier.getHeader(Span.SPAN_NAME_NAME); if (StringUtils.hasText(parentName)) { diff --git a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/HttpRequestInjector.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/HttpRequestInjector.java index 8f12f31502..b8185613b2 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/HttpRequestInjector.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/web/client/HttpRequestInjector.java @@ -32,7 +32,7 @@ class HttpRequestInjector implements SpanInjector { @Override public void inject(Span span, HttpRequest 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/RequestContextInjector.java b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/RequestContextInjector.java index 20b0c5d3af..341f036b64 100644 --- a/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/RequestContextInjector.java +++ b/spring-cloud-sleuth-core/src/main/java/org/springframework/cloud/sleuth/instrument/zuul/RequestContextInjector.java @@ -41,7 +41,7 @@ public void inject(Span span, RequestContext carrier) { return; } setHeader(requestHeaders, Span.SPAN_ID_NAME, span.getSpanId()); - setHeader(requestHeaders, Span.TRACE_ID_NAME, span.getTraceId()); + setHeader(requestHeaders, Span.TRACE_ID_NAME, span.traceIdString()); setHeader(requestHeaders, Span.SPAN_NAME_NAME, span.getName()); setHeader(requestHeaders, Span.SAMPLED_NAME, span.isExportable() ? Span.SPAN_SAMPLED : Span.SPAN_NOT_SAMPLED); 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 e39c07c8cc..3ab21ee9c3 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,7 @@ 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; import com.fasterxml.jackson.databind.ObjectMapper; @@ -33,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 { @@ -62,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); @@ -69,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); @@ -94,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(); @@ -108,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(); @@ -128,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()) @@ -145,4 +202,41 @@ public void should_throw_exception_when_converting_invalid_hex_value() { assertThat(deserialized.getAccumulatedMicros()) .isEqualTo(span.getAccumulatedMicros()); } + + // Duration of 0 is confusing to plot and can be misinterpreted as null + @Test public void getAccumulatedMicros_roundsUpToOneWhenRunning() throws IOException { + AtomicLong nanoTime = new AtomicLong(); + + // starts the span, recording its initial tick as zero + Span span = new Span(Span.builder().name("http:name").traceId(1L).spanId(2L)) { + @Override long nanoTime() { + return nanoTime.get(); + } + }; + + // When only 100 nanoseconds passed + nanoTime.set(100L); + + // We round so that we don't confuse "not started" with a short span. + assertThat(span.getAccumulatedMicros()).isEqualTo(1L); + } + + // Duration of 0 is confusing to plot and can be misinterpreted as null + @Test public void getAccumulatedMicros_roundsUpToOneWhenStopped() throws IOException { + final AtomicLong nanoTime = new AtomicLong(); + + // starts the span, recording its initial tick as zero + Span span = new Span(Span.builder().name("http:name").traceId(1L).spanId(2L)) { + @Override long nanoTime() { + return nanoTime.get(); + } + }; + + // When only 100 nanoseconds passed + nanoTime.set(100L); + span.stop(); + + // We round so that we don't confuse "not started" with a short span. + assertThat(span.getAccumulatedMicros()).isEqualTo(1L); + } } 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 1c8e3b283f..272230de77 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 @@ -81,7 +81,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()); @@ -97,7 +97,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()); @@ -116,7 +116,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()); @@ -135,7 +135,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()); @@ -273,7 +273,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(); } @@ -281,19 +281,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 acd2969518..1070d43f47 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,10 +19,10 @@ 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.Message; + import org.springframework.messaging.MessageHeaders; import org.springframework.messaging.support.MessageBuilder; import org.springframework.util.StringUtils; @@ -56,6 +56,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( + MessageBuilder.createMessage("", + headers(traceId128, randomId()))); + + then(span.traceIdString()).isEqualTo(traceId128); + } + @Test public void should_set_random_spanid_if_header_value_is_invalid() { Message message = MessageBuilder.createMessage("", 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 6cc85427fe..04dd26f955 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 @@ -79,7 +79,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"; @@ -90,6 +90,6 @@ public void should_downgrade_128bit_trace_id_by_dropping_high_bits() { Span span = this.extractor.joinTrace(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 1783bbfcef..a2f65aee18 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 @@ -119,7 +119,7 @@ static class CustomHttpServletResponseSpanInjector @Override public void inject(Span span, HttpServletResponse carrier) { - carrier.addHeader(Span.TRACE_ID_NAME, Span.idToHex(span.getTraceId())); + carrier.addHeader(Span.TRACE_ID_NAME, span.traceIdString()); carrier.addHeader(Span.SPAN_ID_NAME, 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);