diff --git a/.gitignore b/.gitignore index 9be4cac7d..0ce6227af 100644 --- a/.gitignore +++ b/.gitignore @@ -19,6 +19,7 @@ bin/ .idea/ out/ generated_src/ +generated_testSrc/ # Codegen .generated diff --git a/tracing-benchmarks/src/jmh/java/com/palantir/tracing/TracingBenchmark.java b/tracing-benchmarks/src/jmh/java/com/palantir/tracing/TracingBenchmark.java index 31bcc19f9..ec3576339 100644 --- a/tracing-benchmarks/src/jmh/java/com/palantir/tracing/TracingBenchmark.java +++ b/tracing-benchmarks/src/jmh/java/com/palantir/tracing/TracingBenchmark.java @@ -16,6 +16,7 @@ package com.palantir.tracing; +import com.google.common.util.concurrent.Runnables; import java.util.concurrent.TimeUnit; import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; @@ -47,13 +48,13 @@ @SuppressWarnings({"checkstyle:hideutilityclassconstructor", "checkstyle:VisibilityModifier"}) public class TracingBenchmark { - private static final Runnable nestedSpans = createnestedSpan(100); + private static final Runnable nestedSpans = createNestedSpan(100); @SuppressWarnings("ImmutableEnumChecker") public enum BenchmarkObservability { SAMPLE(AlwaysSampler.INSTANCE), DO_NOT_SAMPLE(() -> false), - UNDECIDED(new RandomSampler(0.1f)); + UNDECIDED(new RandomSampler(0.01f)); private final TraceSampler traceSampler; @@ -87,20 +88,19 @@ public static void nestedSpans() { nestedSpans.run(); } - private static Runnable createnestedSpan(int depth) { - if (depth == 0) { - return () -> { - }; + private static Runnable createNestedSpan(int depth) { + if (depth <= 0) { + return Runnables.doNothing(); } else { - return wrapWithSpan(createnestedSpan(depth - 1)); + return wrapWithSpan("benchmark-span-" + depth, createNestedSpan(depth - 1)); } } - private static Runnable wrapWithSpan(Runnable toBenNested) { + private static Runnable wrapWithSpan(String operation, Runnable next) { return () -> { + Tracer.fastStartSpan(operation); try { - Tracer.startSpan("span"); - toBenNested.run(); + next.run(); } finally { Tracer.fastCompleteSpan(); } diff --git a/tracing-jaxrs/src/test/java/com/palantir/tracing/jaxrs/JaxRsTracersTest.java b/tracing-jaxrs/src/test/java/com/palantir/tracing/jaxrs/JaxRsTracersTest.java index 081625f1a..a08200a9b 100644 --- a/tracing-jaxrs/src/test/java/com/palantir/tracing/jaxrs/JaxRsTracersTest.java +++ b/tracing-jaxrs/src/test/java/com/palantir/tracing/jaxrs/JaxRsTracersTest.java @@ -18,6 +18,7 @@ import static org.assertj.core.api.Assertions.assertThat; +import com.palantir.tracing.AlwaysSampler; import com.palantir.tracing.Tracer; import java.io.ByteArrayOutputStream; import javax.ws.rs.core.StreamingOutput; @@ -26,22 +27,58 @@ public final class JaxRsTracersTest { @Test - public void testWrappingStreamingOutput_streamingOutputTraceIsIsolated() throws Exception { - Tracer.startSpan("outside"); + public void testWrappingStreamingOutput_streamingOutputTraceIsIsolated_sampled() throws Exception { + Tracer.setSampler(AlwaysSampler.INSTANCE); + Tracer.getAndClearTrace(); + + Tracer.fastStartSpan("outside"); StreamingOutput streamingOutput = JaxRsTracers.wrap(os -> { - Tracer.startSpan("inside"); // never completed + Tracer.fastStartSpan("inside"); // never completed }); streamingOutput.write(new ByteArrayOutputStream()); assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("outside"); } @Test - public void testWrappingStreamingOutput_traceStateIsCapturedAtConstructionTime() throws Exception { - Tracer.startSpan("before-construction"); + public void testWrappingStreamingOutput_streamingOutputTraceIsIsolated_unsampled() throws Exception { + Tracer.setSampler(() -> false); + Tracer.getAndClearTrace(); + + Tracer.fastStartSpan("outside"); + StreamingOutput streamingOutput = JaxRsTracers.wrap(os -> { + Tracer.fastStartSpan("inside"); // never completed + }); + streamingOutput.write(new ByteArrayOutputStream()); + assertThat(Tracer.hasTraceId()).isTrue(); + Tracer.fastCompleteSpan(); + assertThat(Tracer.hasTraceId()).isFalse(); + } + + @Test + public void testWrappingStreamingOutput_traceStateIsCapturedAtConstructionTime_sampled() throws Exception { + Tracer.setSampler(AlwaysSampler.INSTANCE); + Tracer.getAndClearTrace(); + + Tracer.fastStartSpan("before-construction"); StreamingOutput streamingOutput = JaxRsTracers.wrap(os -> { assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("streaming-output"); }); - Tracer.startSpan("after-construction"); + Tracer.fastStartSpan("after-construction"); + streamingOutput.write(new ByteArrayOutputStream()); + } + + @Test + public void testWrappingStreamingOutput_traceStateIsCapturedAtConstructionTime_unsampled() throws Exception { + Tracer.setSampler(() -> false); + Tracer.getAndClearTrace(); + + Tracer.fastStartSpan("before-construction"); + StreamingOutput streamingOutput = JaxRsTracers.wrap(os -> { + assertThat(Tracer.hasTraceId()).isTrue(); + Tracer.fastCompleteSpan(); + assertThat(Tracer.hasTraceId()).isFalse(); + }); + Tracer.fastStartSpan("after-construction"); streamingOutput.write(new ByteArrayOutputStream()); } } diff --git a/tracing-jersey/src/main/java/com/palantir/tracing/jersey/TraceEnrichingFilter.java b/tracing-jersey/src/main/java/com/palantir/tracing/jersey/TraceEnrichingFilter.java index fb0a6029f..8a6db3599 100644 --- a/tracing-jersey/src/main/java/com/palantir/tracing/jersey/TraceEnrichingFilter.java +++ b/tracing-jersey/src/main/java/com/palantir/tracing/jersey/TraceEnrichingFilter.java @@ -68,14 +68,14 @@ public void filter(ContainerRequestContext requestContext) throws IOException { if (Strings.isNullOrEmpty(traceId)) { // HTTP request did not indicate a trace; initialize trace state and create a span. Tracer.initTrace(getObservabilityFromHeader(requestContext), Tracers.randomId()); - Tracer.startSpan(operation, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, SpanType.SERVER_INCOMING); } else { Tracer.initTrace(getObservabilityFromHeader(requestContext), traceId); if (spanId == null) { - Tracer.startSpan(operation, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, SpanType.SERVER_INCOMING); } else { // caller's span is this span's parent. - Tracer.startSpan(operation, spanId, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, spanId, SpanType.SERVER_INCOMING); } } diff --git a/tracing-servlet/src/test/java/com/palantir/tracing/servlet/LeakedTraceFilterTest.java b/tracing-servlet/src/test/java/com/palantir/tracing/servlet/LeakedTraceFilterTest.java index b71617c5a..183a8a558 100644 --- a/tracing-servlet/src/test/java/com/palantir/tracing/servlet/LeakedTraceFilterTest.java +++ b/tracing-servlet/src/test/java/com/palantir/tracing/servlet/LeakedTraceFilterTest.java @@ -103,7 +103,7 @@ public void doFilter(ServletRequest request, ServletResponse response, FilterCha throws IOException, ServletException { // Open a span to simulate a thread from another request // leaving bad data without the leaked trace filter applied. - Tracer.startSpan("previous request leaked"); + Tracer.fastStartSpan("previous request leaked"); chain.doFilter(request, response); } @@ -140,7 +140,7 @@ public void destroy() {} env.servlets().addServlet("alwaysLeaks", new HttpServlet() { @Override protected void service(HttpServletRequest req, HttpServletResponse resp) { - Tracer.startSpan("leaky"); + Tracer.fastStartSpan("leaky"); resp.addHeader("Leaky-Invoked", "true"); } }).addMapping("/leaky"); diff --git a/tracing-undertow/src/main/java/com/palantir/tracing/undertow/TracedOperationHandler.java b/tracing-undertow/src/main/java/com/palantir/tracing/undertow/TracedOperationHandler.java index da0e558b0..d255369f4 100644 --- a/tracing-undertow/src/main/java/com/palantir/tracing/undertow/TracedOperationHandler.java +++ b/tracing-undertow/src/main/java/com/palantir/tracing/undertow/TracedOperationHandler.java @@ -103,10 +103,10 @@ private void initializeTraceFromExisting(HeaderMap headers, String traceId) { Tracer.initTrace(getObservabilityFromHeader(headers), traceId); String spanId = headers.getFirst(SPAN_ID); // nullable if (spanId == null) { - Tracer.startSpan(operation, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, SpanType.SERVER_INCOMING); } else { // caller's span is this span's parent. - Tracer.startSpan(operation, spanId, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, spanId, SpanType.SERVER_INCOMING); } } @@ -115,7 +115,7 @@ private String initializeNewTrace(HeaderMap headers) { // HTTP request did not indicate a trace; initialize trace state and create a span. String newTraceId = Tracers.randomId(); Tracer.initTrace(getObservabilityFromHeader(headers), newTraceId); - Tracer.startSpan(operation, SpanType.SERVER_INCOMING); + Tracer.fastStartSpan(operation, SpanType.SERVER_INCOMING); return newTraceId; } diff --git a/tracing/src/main/java/com/palantir/tracing/AsyncTracer.java b/tracing/src/main/java/com/palantir/tracing/AsyncTracer.java index 266328851..e18ca3f88 100644 --- a/tracing/src/main/java/com/palantir/tracing/AsyncTracer.java +++ b/tracing/src/main/java/com/palantir/tracing/AsyncTracer.java @@ -62,7 +62,7 @@ public AsyncTracer(String operation) { */ public AsyncTracer(Optional operation) { this.operation = operation.orElse(DEFAULT_OPERATION); - Tracer.startSpan(this.operation + "-enqueue"); + Tracer.fastStartSpan(this.operation + "-enqueue"); deferredTrace = Tracer.copyTrace().get(); Tracer.fastDiscardSpan(); // span will completed in the deferred execution } @@ -76,7 +76,7 @@ public T withTrace(Tracers.ThrowingCallable inner Tracer.setTrace(deferredTrace); // Finish the enqueue span Tracer.fastCompleteSpan(); - Tracer.startSpan(operation + "-run"); + Tracer.fastStartSpan(operation + "-run"); try { return inner.call(); } finally { diff --git a/tracing/src/main/java/com/palantir/tracing/CloseableTracer.java b/tracing/src/main/java/com/palantir/tracing/CloseableTracer.java index edd490829..c32cd3710 100644 --- a/tracing/src/main/java/com/palantir/tracing/CloseableTracer.java +++ b/tracing/src/main/java/com/palantir/tracing/CloseableTracer.java @@ -44,7 +44,7 @@ public static CloseableTracer startSpan(String operation) { * labeled with the provided operation. */ public static CloseableTracer startSpan(String operation, SpanType spanType) { - Tracer.startSpan(operation, spanType); + Tracer.fastStartSpan(operation, spanType); return INSTANCE; } diff --git a/tracing/src/main/java/com/palantir/tracing/DeferredTracer.java b/tracing/src/main/java/com/palantir/tracing/DeferredTracer.java index 5f81369a1..607c81e9d 100644 --- a/tracing/src/main/java/com/palantir/tracing/DeferredTracer.java +++ b/tracing/src/main/java/com/palantir/tracing/DeferredTracer.java @@ -104,11 +104,11 @@ public T withTrace(Tracers.ThrowingCallable inner Optional originalTrace = Tracer.copyTrace(); - Tracer.setTrace(new Trace(isObservable, traceId)); + Tracer.setTrace(Trace.of(isObservable, traceId)); if (parentSpanId != null) { - Tracer.startSpan(operation, parentSpanId, SpanType.LOCAL); + Tracer.fastStartSpan(operation, parentSpanId, SpanType.LOCAL); } else { - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); } try { diff --git a/tracing/src/main/java/com/palantir/tracing/Trace.java b/tracing/src/main/java/com/palantir/tracing/Trace.java index dbc8db4e3..c22d9d48a 100644 --- a/tracing/src/main/java/com/palantir/tracing/Trace.java +++ b/tracing/src/main/java/com/palantir/tracing/Trace.java @@ -17,9 +17,15 @@ package com.palantir.tracing; import static com.palantir.logsafe.Preconditions.checkArgument; +import static com.palantir.logsafe.Preconditions.checkState; +import com.google.common.base.Strings; +import com.google.errorprone.annotations.CheckReturnValue; +import com.palantir.logsafe.SafeArg; +import com.palantir.logsafe.exceptions.SafeIllegalStateException; import com.palantir.tracing.api.OpenSpan; import com.palantir.tracing.api.SpanObserver; +import com.palantir.tracing.api.SpanType; import java.util.ArrayDeque; import java.util.Deque; import java.util.Optional; @@ -27,63 +33,228 @@ /** * Represents a trace as an ordered list of non-completed spans. Supports adding and removing of spans. This class is * not thread-safe and is intended to be used in a thread-local context. + * + * There are two implementations of {@link Trace}: {@link Sampled} and {@link Unsampled}. + * A {@link Sampled sampled trace} records each span in order to record tracing data, however in most scenarios + * most traces will be {@link Unsampled}, which avoids creation of span objects, random span ID generation, + * clock reads, etc. Instead, the {@link Unsampled unsampled} implementation tracks the number of 'active' spans + * on the current thread so it can provide correct {@link Trace#isEmpty()} values allowing the {@link Tracer} + * utility to reset thread state after the emulated root span has been completed. */ -public final class Trace { +public abstract class Trace { - private final Deque stack; - private final boolean isObservable; private final String traceId; - private Trace(ArrayDeque stack, boolean isObservable, String traceId) { - checkArgument(!traceId.isEmpty(), "traceId must be non-empty"); - - this.stack = stack; - this.isObservable = isObservable; + private Trace(String traceId) { + checkArgument(!Strings.isNullOrEmpty(traceId), "traceId must be non-empty"); this.traceId = traceId; } - Trace(boolean isObservable, String traceId) { - this(new ArrayDeque<>(), isObservable, traceId); + /** + * Opens a new span for this thread's call trace, labeled with the provided operation and parent span. Only allowed + * when the current trace is empty. + * If the return value is not used, prefer {@link #fastStartSpan(String, String, SpanType)}}. + */ + @CheckReturnValue + final OpenSpan startSpan(String operation, String parentSpanId, SpanType type) { + checkState(isEmpty(), "Cannot start a span with explicit parent if the current thread's trace is non-empty"); + checkArgument(!Strings.isNullOrEmpty(parentSpanId), "parentSpanId must be non-empty"); + OpenSpan span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.of(parentSpanId)); + push(span); + return span; } - void push(OpenSpan span) { - stack.push(span); - } + /** + * Opens a new span for this thread's call trace, labeled with the provided operation. + * If the return value is not used, prefer {@link #fastStartSpan(String, SpanType)}}. + */ + @CheckReturnValue + final OpenSpan startSpan(String operation, SpanType type) { + Optional prevState = top(); + final OpenSpan span; + // Avoid lambda allocation in hot paths + if (prevState.isPresent()) { + span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.of(prevState.get().getSpanId())); + } else { + span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.empty()); + } - Optional top() { - return stack.isEmpty() ? Optional.empty() : Optional.of(stack.peekFirst()); + push(span); + return span; } - Optional pop() { - return stack.isEmpty() ? Optional.empty() : Optional.of(stack.pop()); - } + /** + * Like {@link #startSpan(String, String, SpanType)}, but does not return an {@link OpenSpan}. + */ + abstract void fastStartSpan(String operation, String parentSpanId, SpanType type); - boolean isEmpty() { - return stack.isEmpty(); - } + /** + * Like {@link #startSpan(String, SpanType)}, but does not return an {@link OpenSpan}. + */ + abstract void fastStartSpan(String operation, SpanType type); + + protected abstract void push(OpenSpan span); + + abstract Optional top(); + + abstract Optional pop(); + + abstract boolean isEmpty(); /** * True iff the spans of this trace are to be observed by {@link SpanObserver span obververs} upon {@link * Tracer#completeSpan span completion}. */ - boolean isObservable() { - return isObservable; - } + abstract boolean isObservable(); /** * The globally unique non-empty identifier for this call trace. */ - String getTraceId() { + final String getTraceId() { return traceId; } /** Returns a copy of this Trace which can be independently mutated. */ - Trace deepCopy() { - return new Trace(new ArrayDeque<>(stack), isObservable, traceId); + abstract Trace deepCopy(); + + static Trace of(boolean isObservable, String traceId) { + return isObservable ? new Sampled(traceId) : new Unsampled(traceId); } - @Override - public String toString() { - return "Trace{stack=" + stack + ", isObservable=" + isObservable + ", traceId='" + traceId + "'}"; + private static final class Sampled extends Trace { + + private final Deque stack; + + private Sampled(ArrayDeque stack, String traceId) { + super(traceId); + this.stack = stack; + } + + private Sampled(String traceId) { + this(new ArrayDeque<>(), traceId); + } + + @Override + @SuppressWarnings("ResultOfMethodCallIgnored") // Sampled traces cannot optimize this path + void fastStartSpan(String operation, String parentSpanId, SpanType type) { + startSpan(operation, parentSpanId, type); + } + + @Override + @SuppressWarnings("ResultOfMethodCallIgnored") // Sampled traces cannot optimize this path + void fastStartSpan(String operation, SpanType type) { + startSpan(operation, type); + } + + @Override + protected void push(OpenSpan span) { + stack.push(span); + } + + @Override + Optional top() { + return stack.isEmpty() ? Optional.empty() : Optional.of(stack.peekFirst()); + } + + @Override + Optional pop() { + return stack.isEmpty() ? Optional.empty() : Optional.of(stack.pop()); + } + + @Override + boolean isEmpty() { + return stack.isEmpty(); + } + + @Override + boolean isObservable() { + return true; + } + + @Override + Trace deepCopy() { + return new Sampled(new ArrayDeque<>(stack), getTraceId()); + } + + @Override + public String toString() { + return "Trace{stack=" + stack + ", isObservable=true, traceId='" + getTraceId() + "'}"; + } + } + + private static final class Unsampled extends Trace { + /** + * Tracks the size that a {@link Sampled} trace {@link Sampled#stack} would have if this was sampled. + * This allows thread trace state to be cleared when all "started" spans have been "removed". + */ + private int numberOfSpans; + + private Unsampled(int numberOfSpans, String traceId) { + super(traceId); + this.numberOfSpans = numberOfSpans; + validateNumberOfSpans(); + } + + private Unsampled(String traceId) { + this(0, traceId); + } + + @Override + void fastStartSpan(String operation, String parentSpanId, SpanType type) { + fastStartSpan(operation, type); + } + + @Override + void fastStartSpan(String operation, SpanType type) { + numberOfSpans++; + } + + @Override + protected void push(OpenSpan span) { + numberOfSpans++; + } + + @Override + Optional top() { + return Optional.empty(); + } + + @Override + Optional pop() { + validateNumberOfSpans(); + if (numberOfSpans > 0) { + numberOfSpans--; + } + return Optional.empty(); + } + + @Override + boolean isEmpty() { + validateNumberOfSpans(); + return numberOfSpans <= 0; + } + + @Override + boolean isObservable() { + return false; + } + + @Override + Trace deepCopy() { + return new Unsampled(numberOfSpans, getTraceId()); + } + + /** Internal validation, this should never fail because {@link #pop()} only decrements positive values. */ + private void validateNumberOfSpans() { + if (numberOfSpans < 0) { + throw new SafeIllegalStateException("Unexpected negative numberOfSpans", + SafeArg.of("numberOfSpans", numberOfSpans)); + } + } + + @Override + public String toString() { + return "Trace{numberOfSpans=" + numberOfSpans + ", isObservable=false, traceId='" + getTraceId() + "'}"; + } } } diff --git a/tracing/src/main/java/com/palantir/tracing/Tracer.java b/tracing/src/main/java/com/palantir/tracing/Tracer.java index c3d217d89..08830338f 100644 --- a/tracing/src/main/java/com/palantir/tracing/Tracer.java +++ b/tracing/src/main/java/com/palantir/tracing/Tracer.java @@ -68,7 +68,7 @@ private Tracer() {} private static Trace createTrace(Observability observability, String traceId) { checkArgument(!Strings.isNullOrEmpty(traceId), "traceId must be non-empty"); boolean observable = shouldObserve(observability); - return new Trace(observable, traceId); + return Trace.of(observable, traceId); } private static boolean shouldObserve(Observability observability) { @@ -108,51 +108,58 @@ public static void initTrace(Observability observability, String traceId) { /** * Opens a new span for this thread's call trace, labeled with the provided operation and parent span. Only allowed * when the current trace is empty. + * If the return value is not used, prefer {@link Tracer#fastStartSpan(String, String, SpanType)}}. */ + @CheckReturnValue public static OpenSpan startSpan(String operation, String parentSpanId, SpanType type) { - Trace current = getOrCreateCurrentTrace(); - checkState(current.isEmpty(), - "Cannot start a span with explicit parent if the current thread's trace is non-empty"); - checkArgument(!Strings.isNullOrEmpty(parentSpanId), "parentSpanId must be non-empty"); - OpenSpan span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.of(parentSpanId)); - current.push(span); - return span; + return getOrCreateCurrentTrace().startSpan(operation, parentSpanId, type); } /** * Like {@link #startSpan(String)}, but opens a span of the explicitly given {@link SpanType span type}. + * If the return value is not used, prefer {@link Tracer#fastStartSpan(String, SpanType)}}. */ + @CheckReturnValue public static OpenSpan startSpan(String operation, SpanType type) { - return startSpanInternal(operation, type); + return getOrCreateCurrentTrace().startSpan(operation, type); } /** * Opens a new {@link SpanType#LOCAL LOCAL} span for this thread's call trace, labeled with the provided operation. + * If the return value is not used, prefer {@link Tracer#fastStartSpan(String)}}. */ + @CheckReturnValue public static OpenSpan startSpan(String operation) { - return startSpanInternal(operation, SpanType.LOCAL); + return startSpan(operation, SpanType.LOCAL); } - private static OpenSpan startSpanInternal(String operation, SpanType type) { - Trace trace = getOrCreateCurrentTrace(); - Optional prevState = trace.top(); - final OpenSpan span; - // Avoid lambda allocation in hot paths - if (prevState.isPresent()) { - span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.of(prevState.get().getSpanId())); - } else { - span = OpenSpan.of(operation, Tracers.randomId(), type, Optional.empty()); - } + /** + * Like {@link #startSpan(String, String, SpanType)}, but does not return an {@link OpenSpan}. + */ + public static void fastStartSpan(String operation, String parentSpanId, SpanType type) { + getOrCreateCurrentTrace().fastStartSpan(operation, parentSpanId, type); + } - trace.push(span); - return span; + /** + * Like {@link #startSpan(String, SpanType)}, but does not return an {@link OpenSpan}. + */ + public static void fastStartSpan(String operation, SpanType type) { + getOrCreateCurrentTrace().fastStartSpan(operation, type); + } + + /** + * Like {@link #startSpan(String)}, but does not return an {@link OpenSpan}. + */ + public static void fastStartSpan(String operation) { + fastStartSpan(operation, SpanType.LOCAL); } /** Discards the current span without emitting it. */ static void fastDiscardSpan() { Trace trace = currentTrace.get(); checkNotNull(trace, "Expected current trace to exist"); - checkState(popCurrentSpan().isPresent(), "Expected span to exist before discarding"); + checkState(!trace.isEmpty(), "Expected span to exist before discarding"); + popCurrentSpan(trace); } /** @@ -171,14 +178,20 @@ public static void fastCompleteSpan() { public static void fastCompleteSpan(Map metadata) { Trace trace = currentTrace.get(); if (trace != null) { - Optional span = popCurrentSpan(); + Optional span = popCurrentSpan(trace); if (trace.isObservable()) { - span.map(openSpan -> toSpan(openSpan, metadata, trace.getTraceId())) - .ifPresent(Tracer::notifyObservers); + completeSpanAndNotifyObservers(span, metadata, trace.getTraceId()); } } } + private static void completeSpanAndNotifyObservers( + Optional openSpan, Map metadata, String traceId) { + if (openSpan.isPresent()) { + Tracer.notifyObservers(toSpan(openSpan.get(), metadata, traceId)); + } + } + /** * Completes and returns the current span (if it exists) and notifies all {@link #observers subscribers} about the * completed span. @@ -199,7 +212,7 @@ public static Optional completeSpan(Map metadata) { if (trace == null) { return Optional.empty(); } - Optional maybeSpan = popCurrentSpan() + Optional maybeSpan = popCurrentSpan(trace) .map(openSpan -> toSpan(openSpan, metadata, trace.getTraceId())); // Notify subscribers iff trace is observable @@ -215,16 +228,12 @@ private static void notifyObservers(Span span) { compositeObserver.accept(span); } - private static Optional popCurrentSpan() { - Trace trace = currentTrace.get(); - if (trace != null) { - Optional span = trace.pop(); - if (trace.isEmpty()) { - clearCurrentTrace(); - } - return span; + private static Optional popCurrentSpan(Trace trace) { + Optional span = trace.pop(); + if (trace.isEmpty()) { + clearCurrentTrace(); } - return Optional.empty(); + return span; } private static Span toSpan(OpenSpan openSpan, Map metadata, String traceId) { diff --git a/tracing/src/main/java/com/palantir/tracing/Tracers.java b/tracing/src/main/java/com/palantir/tracing/Tracers.java index 47dee7d7e..377da2ba0 100644 --- a/tracing/src/main/java/com/palantir/tracing/Tracers.java +++ b/tracing/src/main/java/com/palantir/tracing/Tracers.java @@ -235,7 +235,7 @@ public static Callable wrapWithNewTrace(String operation, Observability o try { Tracer.initTrace(observability, Tracers.randomId()); - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); return delegate.call(); } finally { Tracer.fastCompleteSpan(); @@ -271,7 +271,7 @@ public static Runnable wrapWithNewTrace(String operation, Observability observab try { Tracer.initTrace(observability, Tracers.randomId()); - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); delegate.run(); } finally { Tracer.fastCompleteSpan(); @@ -309,7 +309,7 @@ public static Runnable wrapWithAlternateTraceId(String traceId, String operation try { Tracer.initTrace(observability, traceId); - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); delegate.run(); } finally { Tracer.fastCompleteSpan(); diff --git a/tracing/src/test/java/com/palantir/tracing/AsyncSlf4jSpanObserverTest.java b/tracing/src/test/java/com/palantir/tracing/AsyncSlf4jSpanObserverTest.java index 5659653db..52195328f 100644 --- a/tracing/src/test/java/com/palantir/tracing/AsyncSlf4jSpanObserverTest.java +++ b/tracing/src/test/java/com/palantir/tracing/AsyncSlf4jSpanObserverTest.java @@ -78,6 +78,8 @@ public final class AsyncSlf4jSpanObserverTest { public void before() { MockitoAnnotations.initMocks(this); + Tracer.setSampler(AlwaysSampler.INSTANCE); + when(appender.getName()).thenReturn("MOCK"); logger = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger(AsyncSlf4jSpanObserver.class); logger.addAppender(appender); @@ -99,7 +101,7 @@ public void testJsonFormatToLog() throws Exception { Tracer.subscribe(TEST_OBSERVER, AsyncSlf4jSpanObserver.of( "serviceName", Inet4Address.getLoopbackAddress(), logger, executor)); Tracer.initTrace(Observability.SAMPLE, Tracers.randomId()); - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); Span span = Tracer.completeSpan().get(); verify(appender, never()).doAppend(any(ILoggingEvent.class)); // async logger only fires when executor runs @@ -120,7 +122,7 @@ public void testDefaultConstructorDeterminesIpAddress() throws Exception { DeterministicScheduler executor = new DeterministicScheduler(); Tracer.subscribe(TEST_OBSERVER, AsyncSlf4jSpanObserver.of("serviceName", executor)); Tracer.initTrace(Observability.SAMPLE, Tracers.randomId()); - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); Span span = Tracer.completeSpan().get(); executor.runNextPendingCommand(); @@ -252,7 +254,7 @@ public void testFastCompleteSpanAfterExecutorShutdown() { .extracting("spanId", "operation") .contains(span1.getSpanId(), span1.getOperation()); - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); executor.shutdown(); Tracer.fastCompleteSpan(); } diff --git a/tracing/src/test/java/com/palantir/tracing/AsyncTracerTest.java b/tracing/src/test/java/com/palantir/tracing/AsyncTracerTest.java index 3eb6be1b9..092ae92af 100644 --- a/tracing/src/test/java/com/palantir/tracing/AsyncTracerTest.java +++ b/tracing/src/test/java/com/palantir/tracing/AsyncTracerTest.java @@ -20,9 +20,16 @@ import com.google.common.collect.Lists; import java.util.List; +import org.junit.Before; import org.junit.Test; public class AsyncTracerTest { + + @Before + public void before() { + Tracer.setSampler(AlwaysSampler.INSTANCE); + } + @Test public void doesNotLeakEnqueueSpan() { Tracer.initTrace(Observability.UNDECIDED, "defaultTraceId"); @@ -42,7 +49,7 @@ public void doesNotLeakEnqueueSpan() { @Test public void completesBothDeferredSpans() { Tracer.initTrace(Observability.SAMPLE, "defaultTraceId"); - Tracer.startSpan("defaultSpan"); + Tracer.fastStartSpan("defaultSpan"); AsyncTracer asyncTracer = new AsyncTracer(); List observedSpans = Lists.newArrayList(); Tracer.subscribe( @@ -57,9 +64,9 @@ public void completesBothDeferredSpans() { @Test public void preservesState() { Tracer.initTrace(Observability.UNDECIDED, "defaultTraceId"); - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); Trace originalTrace = getTrace(); AsyncTracer asyncTracer = new AsyncTracer(); diff --git a/tracing/src/test/java/com/palantir/tracing/CloseableTracerTest.java b/tracing/src/test/java/com/palantir/tracing/CloseableTracerTest.java index 6a31cf72c..d8c71d499 100644 --- a/tracing/src/test/java/com/palantir/tracing/CloseableTracerTest.java +++ b/tracing/src/test/java/com/palantir/tracing/CloseableTracerTest.java @@ -29,6 +29,7 @@ public final class CloseableTracerTest { @Before public void before() { + Tracer.setSampler(AlwaysSampler.INSTANCE); Tracer.getAndClearTrace(); } diff --git a/tracing/src/test/java/com/palantir/tracing/TraceTest.java b/tracing/src/test/java/com/palantir/tracing/TraceTest.java index e2fa8c2f5..0c1158ddc 100644 --- a/tracing/src/test/java/com/palantir/tracing/TraceTest.java +++ b/tracing/src/test/java/com/palantir/tracing/TraceTest.java @@ -27,21 +27,17 @@ public final class TraceTest { @Test public void constructTrace_emptyTraceId() { - assertThatThrownBy(() -> new Trace(false, "")) + assertThatThrownBy(() -> Trace.of(false, "")) .isInstanceOf(IllegalArgumentException.class); } @Test public void testToString() { - Trace trace = new Trace(true, "traceId"); - trace.push(OpenSpan.builder() - .type(SpanType.LOCAL) - .spanId("spanId") - .operation("operation") - .startClockNanoSeconds(0L) - .startTimeMicroSeconds(0L) - .build()); - assertThat(trace.toString()).isEqualTo("Trace{stack=[OpenSpan{operation=operation, startTimeMicroSeconds=0, " - + "startClockNanoSeconds=0, spanId=spanId, type=LOCAL}], isObservable=true, traceId='traceId'}"); + Trace trace = Trace.of(true, "traceId"); + OpenSpan span = trace.startSpan("operation", SpanType.LOCAL); + assertThat(trace.toString()) + .isEqualTo("Trace{stack=[" + span + "], isObservable=true, traceId='traceId'}") + .contains(span.getOperation()) + .contains(span.getSpanId()); } } diff --git a/tracing/src/test/java/com/palantir/tracing/TracerTest.java b/tracing/src/test/java/com/palantir/tracing/TracerTest.java index d9d63e473..330e73c41 100644 --- a/tracing/src/test/java/com/palantir/tracing/TracerTest.java +++ b/tracing/src/test/java/com/palantir/tracing/TracerTest.java @@ -19,13 +19,11 @@ import static com.palantir.logsafe.testing.Assertions.assertThatLoggableExceptionThrownBy; import static org.assertj.core.api.Assertions.assertThat; import static org.junit.Assert.assertTrue; -import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.verifyNoMoreInteractions; import static org.mockito.Mockito.when; import com.google.common.collect.ImmutableMap; -import com.palantir.tracing.api.OpenSpan; import com.palantir.tracing.api.Span; import com.palantir.tracing.api.SpanObserver; import com.palantir.tracing.api.SpanType; @@ -70,6 +68,7 @@ public void after() { } @Test + @SuppressWarnings("ResultOfMethodCallIgnored") // testing that exceptions are thrown public void testIdsMustBeNonNullAndNotEmpty() throws Exception { assertThatLoggableExceptionThrownBy(() -> Tracer.initTrace(Observability.UNDECIDED, null)) .hasLogMessage("traceId must be non-empty") @@ -86,6 +85,14 @@ public void testIdsMustBeNonNullAndNotEmpty() throws Exception { assertThatLoggableExceptionThrownBy(() -> Tracer.startSpan("op", "", null)) .hasLogMessage("parentSpanId must be non-empty") .hasArgs(); + + assertThatLoggableExceptionThrownBy(() -> Tracer.fastStartSpan("op", null, null)) + .hasLogMessage("parentSpanId must be non-empty") + .hasArgs(); + + assertThatLoggableExceptionThrownBy(() -> Tracer.fastStartSpan("op", "", null)) + .hasLogMessage("parentSpanId must be non-empty") + .hasArgs(); } @Test @@ -138,17 +145,33 @@ public void testObserversAreInvokedOnObservableTracesOnly() throws Exception { verifyNoMoreInteractions(observer1); Tracer.initTrace(Observability.DO_NOT_SAMPLE, Tracers.randomId()); - startAndCompleteSpan(); // not sampled, see above + startAndFastCompleteSpan(); // not sampled, see above verifyNoMoreInteractions(observer1); } @Test - public void testDerivesNewSpansWhenTraceIsNotObservable() throws Exception { - Tracer.initTrace(Observability.DO_NOT_SAMPLE, Tracers.randomId()); - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("bar"); - assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("foo"); + public void testCountsSpansWhenTraceIsNotObservable() throws Exception { + String traceId = Tracers.randomId(); + assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isNull(); + assertThat(Tracer.hasTraceId()).isFalse(); + Tracer.initTrace(Observability.DO_NOT_SAMPLE, traceId); + // Unsampled trace should still apply thread state + assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isEqualTo(traceId); + assertThat(Tracer.hasTraceId()).isTrue(); + assertThat(Tracer.getTraceId()).isEqualTo(traceId); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + + Tracer.fastCompleteSpan(); + // Unsampled trace should still apply thread state + assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isEqualTo(traceId); + assertThat(Tracer.hasTraceId()).isTrue(); + assertThat(Tracer.getTraceId()).isEqualTo(traceId); + + // Complete the root span, which should clear thread state + Tracer.fastCompleteSpan(); + assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isNull(); + assertThat(Tracer.hasTraceId()).isFalse(); } @Test @@ -163,17 +186,17 @@ public void testInitTraceCallsSampler() throws Exception { verifyNoMoreInteractions(observer1, sampler); Mockito.reset(observer1, sampler); - startAndCompleteSpan(); // not sampled, see above + startAndFastCompleteSpan(); // not sampled, see above verify(sampler).sample(); verifyNoMoreInteractions(observer1, sampler); } @Test public void testTraceCopyIsIndependent() throws Exception { - Tracer.startSpan("span"); + Tracer.fastStartSpan("span"); try { Trace trace = Tracer.copyTrace().get(); - trace.push(mock(OpenSpan.class)); + trace.fastStartSpan("fop", SpanType.LOCAL); } finally { Tracer.fastCompleteSpan(); } @@ -182,8 +205,8 @@ public void testTraceCopyIsIndependent() throws Exception { @Test public void testSetTraceSetsCurrentTraceAndMdcTraceIdKey() throws Exception { - Tracer.startSpan("operation"); - Tracer.setTrace(new Trace(true, "newTraceId")); + Tracer.fastStartSpan("operation"); + Tracer.setTrace(Trace.of(true, "newTraceId")); assertThat(Tracer.getTraceId()).isEqualTo("newTraceId"); assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isEqualTo("newTraceId"); assertThat(Tracer.completeSpan()).isEmpty(); @@ -192,7 +215,7 @@ public void testSetTraceSetsCurrentTraceAndMdcTraceIdKey() throws Exception { @Test public void testSetTraceSetsMdcTraceSampledKeyWhenObserved() { - Tracer.setTrace(new Trace(true, "observedTraceId")); + Tracer.setTrace(Trace.of(true, "observedTraceId")); assertThat(MDC.get(Tracers.TRACE_SAMPLED_KEY)).isEqualTo("1"); assertThat(Tracer.completeSpan()).isEmpty(); assertThat(MDC.get(Tracers.TRACE_SAMPLED_KEY)).isNull(); @@ -200,7 +223,7 @@ public void testSetTraceSetsMdcTraceSampledKeyWhenObserved() { @Test public void testSetTraceMissingMdcTraceSampledKeyWhenNotObserved() { - Tracer.setTrace(new Trace(false, "notObservedTraceId")); + Tracer.setTrace(Trace.of(false, "notObservedTraceId")); assertThat(MDC.get(Tracers.TRACE_SAMPLED_KEY)).isNull(); assertThat(Tracer.completeSpan()).isEmpty(); assertThat(MDC.get(Tracers.TRACE_SAMPLED_KEY)).isNull(); @@ -209,12 +232,12 @@ public void testSetTraceMissingMdcTraceSampledKeyWhenNotObserved() { @Test public void testCompletedSpanHasCorrectSpanType() throws Exception { for (SpanType type : SpanType.values()) { - Tracer.startSpan("1", type); + Tracer.fastStartSpan("1", type); assertThat(Tracer.completeSpan().get().type()).isEqualTo(type); } // Default is LOCAL - Tracer.startSpan("1"); + Tracer.fastStartSpan("1"); assertThat(Tracer.completeSpan().get().type()).isEqualTo(SpanType.LOCAL); } @@ -223,7 +246,7 @@ public void testCompleteSpanWithMetadataIncludesMetadata() { Map metadata = ImmutableMap.of( "key1", "value1", "key2", "value2"); - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); Optional maybeSpan = Tracer.completeSpan(metadata); assertTrue(maybeSpan.isPresent()); assertThat(maybeSpan.get().getMetadata()).isEqualTo(metadata); @@ -238,7 +261,7 @@ public void testCompleteSpanWithoutMetadataHasNoMetadata() { public void testFastCompleteSpan() { Tracer.subscribe("1", observer1); String operation = "operation"; - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); Tracer.fastCompleteSpan(); verify(observer1).consume(spanCaptor.capture()); assertThat(spanCaptor.getValue().getOperation()).isEqualTo(operation); @@ -249,7 +272,7 @@ public void testFastCompleteSpanWithMetadata() { Tracer.subscribe("1", observer1); Map metadata = ImmutableMap.of("key", "value"); String operation = "operation"; - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); Tracer.fastCompleteSpan(metadata); verify(observer1).consume(spanCaptor.capture()); assertThat(spanCaptor.getValue().getOperation()).isEqualTo(operation); @@ -266,7 +289,7 @@ public void testObserversThrow() { throw new IllegalStateException("2"); }); String operation = "operation"; - Tracer.startSpan(operation); + Tracer.fastStartSpan(operation); Tracer.fastCompleteSpan(); verify(observer1).consume(spanCaptor.capture()); assertThat(spanCaptor.getValue().getOperation()).isEqualTo(operation); @@ -275,7 +298,7 @@ public void testObserversThrow() { @Test public void testGetAndClearTraceIfPresent() { - Trace trace = new Trace(true, "newTraceId"); + Trace trace = Trace.of(true, "newTraceId"); Tracer.setTrace(trace); Optional nonEmptyTrace = Tracer.getAndClearTraceIfPresent(); @@ -288,7 +311,7 @@ public void testGetAndClearTraceIfPresent() { @Test public void testClearAndGetTraceClearsMdc() { - Tracer.startSpan("test"); + Tracer.fastStartSpan("test"); try { String startTrace = Tracer.getTraceId(); assertThat(MDC.get(Tracers.TRACE_ID_KEY)).isEqualTo(startTrace); @@ -320,7 +343,7 @@ public void testCompleteRootSpanCompletesTrace() { @Test public void testHasTraceId() { assertThat(Tracer.hasTraceId()).isEqualTo(false); - Tracer.startSpan("testSpan"); + Tracer.fastStartSpan("testSpan"); try { assertThat(Tracer.hasTraceId()).isEqualTo(true); } finally { @@ -329,8 +352,13 @@ public void testHasTraceId() { assertThat(Tracer.hasTraceId()).isEqualTo(false); } + private static void startAndFastCompleteSpan() { + Tracer.fastStartSpan("operation"); + Tracer.fastCompleteSpan(); + } + private static Span startAndCompleteSpan() { - Tracer.startSpan("operation"); + Tracer.fastStartSpan("operation"); return Tracer.completeSpan().get(); } } diff --git a/tracing/src/test/java/com/palantir/tracing/TracersTest.java b/tracing/src/test/java/com/palantir/tracing/TracersTest.java index b46a5aed3..94c33991c 100644 --- a/tracing/src/test/java/com/palantir/tracing/TracersTest.java +++ b/tracing/src/test/java/com/palantir/tracing/TracersTest.java @@ -45,6 +45,7 @@ public void before() { MockitoAnnotations.initMocks(this); MDC.clear(); + Tracer.setSampler(AlwaysSampler.INSTANCE); // Initialize a new trace for each test Tracer.initTrace(Observability.UNDECIDED, "defaultTraceId"); } @@ -65,9 +66,9 @@ public void testWrapExecutorService() throws Exception { wrappedService.submit(traceExpectingCallableWithSingleSpan("DeferredTracer(unnamed operation)")).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.submit(traceExpectingCallableWithSingleSpan("DeferredTracer(unnamed operation)")).get(); wrappedService.submit(traceExpectingCallableWithSingleSpan("DeferredTracer(unnamed operation)")).get(); Tracer.fastCompleteSpan(); @@ -85,9 +86,9 @@ public void testWrapExecutorService_withSpan() throws Exception { wrappedService.submit(traceExpectingRunnableWithSingleSpan("operation")).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.submit(traceExpectingCallableWithSingleSpan("operation")).get(); wrappedService.submit(traceExpectingRunnableWithSingleSpan("operation")).get(); Tracer.fastCompleteSpan(); @@ -107,9 +108,9 @@ public void testWrapScheduledExecutorService() throws Exception { traceExpectingRunnableWithSingleSpan("DeferredTracer(unnamed operation)"), 0, TimeUnit.SECONDS).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.schedule( traceExpectingCallableWithSingleSpan("DeferredTracer(unnamed operation)"), 0, TimeUnit.SECONDS).get(); wrappedService.schedule( @@ -129,9 +130,9 @@ public void testWrapScheduledExecutorService_withSpan() throws Exception { wrappedService.schedule(traceExpectingRunnableWithSingleSpan("operation"), 0, TimeUnit.SECONDS).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.schedule(traceExpectingCallableWithSingleSpan("operation"), 0, TimeUnit.SECONDS).get(); wrappedService.schedule(traceExpectingRunnableWithSingleSpan("operation"), 0, TimeUnit.SECONDS).get(); Tracer.fastCompleteSpan(); @@ -155,9 +156,9 @@ public void testWrapExecutorServiceWithNewTrace() throws Exception { wrappedService.submit(runnable).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.submit(callable).get(); wrappedService.submit(runnable).get(); Tracer.fastCompleteSpan(); @@ -181,9 +182,9 @@ public void testWrapScheduledExecutorServiceWithNewTrace() throws Exception { wrappedService.schedule(runnable, 0, TimeUnit.SECONDS).get(); // Non-empty trace - Tracer.startSpan("foo"); - Tracer.startSpan("bar"); - Tracer.startSpan("baz"); + Tracer.fastStartSpan("foo"); + Tracer.fastStartSpan("bar"); + Tracer.fastStartSpan("baz"); wrappedService.schedule(callable, 0, TimeUnit.SECONDS).get(); wrappedService.schedule(runnable, 0, TimeUnit.SECONDS).get(); Tracer.fastCompleteSpan(); @@ -193,9 +194,9 @@ public void testWrapScheduledExecutorServiceWithNewTrace() throws Exception { @Test public void testWrapCallable_callableTraceIsIsolated() throws Exception { - Tracer.startSpan("outside"); + Tracer.fastStartSpan("outside"); Callable callable = Tracers.wrap(() -> { - Tracer.startSpan("inside"); // never completed + Tracer.fastStartSpan("inside"); // never completed return null; }); callable.call(); @@ -204,18 +205,18 @@ public void testWrapCallable_callableTraceIsIsolated() throws Exception { @Test public void testWrapCallable_traceStateIsCapturedAtConstructionTime() throws Exception { - Tracer.startSpan("before-construction"); + Tracer.fastStartSpan("before-construction"); Callable callable = Tracers.wrap(() -> { assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("DeferredTracer(unnamed operation)"); return null; }); - Tracer.startSpan("after-construction"); + Tracer.fastStartSpan("after-construction"); callable.call(); } @Test public void testWrapCallable_withSpan() throws Exception { - Tracer.startSpan("outside"); + Tracer.fastStartSpan("outside"); Runnable runnable = Tracers.wrap("operation", () -> { assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("operation"); }); @@ -225,9 +226,9 @@ public void testWrapCallable_withSpan() throws Exception { @Test public void testWrapRunnable_runnableTraceIsIsolated() throws Exception { - Tracer.startSpan("outside"); + Tracer.fastStartSpan("outside"); Runnable runnable = Tracers.wrap(() -> { - Tracer.startSpan("inside"); // never completed + Tracer.fastStartSpan("inside"); // never completed }); runnable.run(); assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("outside"); @@ -235,17 +236,17 @@ public void testWrapRunnable_runnableTraceIsIsolated() throws Exception { @Test public void testWrapRunnable_traceStateIsCapturedAtConstructionTime() throws Exception { - Tracer.startSpan("before-construction"); + Tracer.fastStartSpan("before-construction"); Runnable runnable = Tracers.wrap(() -> { assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("DeferredTracer(unnamed operation)"); }); - Tracer.startSpan("after-construction"); + Tracer.fastStartSpan("after-construction"); runnable.run(); } @Test public void testWrapRunnable_startsNewSpan() throws Exception { - Tracer.startSpan("outside"); + Tracer.fastStartSpan("outside"); Runnable runnable = Tracers.wrap("operation", () -> { assertThat(Tracer.completeSpan().get().getOperation()).isEqualTo("operation"); });