diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java b/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java index e3a43fc2a8..06da705005 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DDTracer.java @@ -297,12 +297,17 @@ public class DDTracer implements io.opentracing.Tracer, Closeable { } } } - traceCount.incrementAndGet(); + incrementTraceCount(); if (!writtenTrace.isEmpty() && sampler.sample(writtenTrace.get(0))) { writer.write(writtenTrace); } } + /** Increment the reported trace count, but do not write a trace. */ + void incrementTraceCount() { + traceCount.incrementAndGet(); + } + @Override public void close() { PendingTrace.close(); diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/PendingTrace.java b/dd-trace-ot/src/main/java/datadog/opentracing/PendingTrace.java index f4c56319ad..9656dfb78e 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/PendingTrace.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/PendingTrace.java @@ -214,11 +214,20 @@ public class PendingTrace extends ConcurrentLinkedDeque { int count = 0; while ((ref = referenceQueue.poll()) != null) { weakReferences.remove(ref); + if (isWritten.compareAndSet(false, true)) { + SPAN_CLEANER.pendingTraces.remove(this); + // preserve throughput count. + // Don't report the trace because the data comes from buggy uses of the api and is suspect. + tracer.incrementTraceCount(); + } count++; expireReference(); } if (count > 0) { - log.debug("{} unfinished spans garbage collected!", count); + log.debug( + "trace {} : {} unfinished spans garbage collected. Trace will not report.", + traceId, + count); } return count > 0; } diff --git a/dd-trace-ot/src/test/groovy/datadog/opentracing/PendingTraceTest.groovy b/dd-trace-ot/src/test/groovy/datadog/opentracing/PendingTraceTest.groovy index 9104ab8335..8327221913 100644 --- a/dd-trace-ot/src/test/groovy/datadog/opentracing/PendingTraceTest.groovy +++ b/dd-trace-ot/src/test/groovy/datadog/opentracing/PendingTraceTest.groovy @@ -4,6 +4,7 @@ import datadog.trace.agent.test.TestUtils import datadog.trace.common.writer.ListWriter import spock.lang.Specification import spock.lang.Subject +import spock.lang.Timeout import java.lang.ref.WeakReference import java.util.concurrent.TimeUnit @@ -94,7 +95,8 @@ class PendingTraceTest extends Specification { traceCount.get() == 1 } - def "trace reported when unfinished child discarded"() { + @Timeout(value = 60, unit = TimeUnit.SECONDS) + def "trace does not report when unfinished child discarded"() { when: def child = tracer.buildSpan("child").asChildOf(rootSpan).start() rootSpan.finish() @@ -109,15 +111,17 @@ class PendingTraceTest extends Specification { def childRef = new WeakReference<>(child) child = null TestUtils.awaitGC(childRef) - while (trace.clean()) { + while (trace.pendingReferenceCount.get() > 0) { + trace.clean() } then: trace.pendingReferenceCount.get() == 0 trace.weakReferences.size() == 0 trace.asList() == [rootSpan] - writer == [[rootSpan]] + writer == [] traceCount.get() == 1 + !PendingTrace.SPAN_CLEANER.pendingTraces.contains(trace) } def "add unfinished span to trace fails"() { diff --git a/dd-trace-ot/src/test/groovy/datadog/opentracing/scopemanager/ScopeManagerTest.groovy b/dd-trace-ot/src/test/groovy/datadog/opentracing/scopemanager/ScopeManagerTest.groovy index 09b7f7a8e3..602e459fbb 100644 --- a/dd-trace-ot/src/test/groovy/datadog/opentracing/scopemanager/ScopeManagerTest.groovy +++ b/dd-trace-ot/src/test/groovy/datadog/opentracing/scopemanager/ScopeManagerTest.groovy @@ -10,8 +10,10 @@ import io.opentracing.Span import io.opentracing.noop.NoopSpan import spock.lang.Specification import spock.lang.Subject +import spock.lang.Timeout import java.lang.ref.WeakReference +import java.util.concurrent.TimeUnit import java.util.concurrent.atomic.AtomicBoolean import java.util.concurrent.atomic.AtomicReference @@ -179,11 +181,13 @@ class ScopeManagerTest extends Specification { false | true } + @Timeout(value = 60, unit = TimeUnit.SECONDS) def "hard reference on continuation prevents trace from reporting"() { setup: def builder = tracer.buildSpan("test") def scope = (ContinuableScope) builder.startActive(false) def span = scope.span() + def traceCount = ((DDSpan) span).context().tracer.traceCount scope.setAsyncPropagation(true) def continuation = scope.capture() scope.close() @@ -199,7 +203,9 @@ class ScopeManagerTest extends Specification { def continuationRef = new WeakReference<>(continuation) continuation = null // Continuation references also hold up traces. TestUtils.awaitGC(continuationRef) - writer.waitForTraces(1) + while (traceCount.get() == 0) { + // wait until trace count increments or timeout expires + } } if (autoClose) { if (continuation != null) { @@ -208,7 +214,8 @@ class ScopeManagerTest extends Specification { } then: - writer == [[span]] + forceGC ? true : writer == [[span]] + traceCount.get() == 1 where: autoClose | forceGC