diff --git a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/asserts/TagsAssert.groovy b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/asserts/TagsAssert.groovy index 96806880cd..c5cac37b1e 100644 --- a/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/asserts/TagsAssert.groovy +++ b/dd-java-agent/testing/src/main/groovy/datadog/trace/agent/test/asserts/TagsAssert.groovy @@ -12,7 +12,6 @@ class TagsAssert { private final BigInteger spanParentId private final Map tags private final Set assertedTags = new TreeSet<>() - private final Set ignoredTags = ["slow.stack"] // Don't error if this tag isn't checked. private TagsAssert(DDSpan span) { this.spanParentId = span.parentId @@ -103,7 +102,6 @@ class TagsAssert { void assertTagsAllVerified() { def set = new TreeMap<>(tags).keySet() set.removeAll(assertedTags) - set.removeAll(ignoredTags) // The primary goal is to ensure the set is empty. // tags and assertedTags are included via an "always true" comparison // so they provide better context in the error message. diff --git a/dd-trace-api/src/main/java/datadog/trace/api/Config.java b/dd-trace-api/src/main/java/datadog/trace/api/Config.java index 7d0ea7a49d..a53f58c2d0 100644 --- a/dd-trace-api/src/main/java/datadog/trace/api/Config.java +++ b/dd-trace-api/src/main/java/datadog/trace/api/Config.java @@ -23,7 +23,6 @@ import java.util.Properties; import java.util.Set; import java.util.SortedSet; import java.util.UUID; -import java.util.concurrent.TimeUnit; import java.util.regex.Pattern; import lombok.Getter; import lombok.ToString; @@ -86,8 +85,6 @@ public class Config { public static final String SPLIT_BY_TAGS = "trace.split-by-tags"; public static final String SCOPE_DEPTH_LIMIT = "trace.scope.depth.limit"; public static final String PARTIAL_FLUSH_MIN_SPANS = "trace.partial.flush.min.spans"; - public static final String SPAN_DURATION_ABOVE_AVERAGE_STACKTRACE_MILLIS = - "trace.span.duration-above-average.stacktrace.millis"; public static final String RUNTIME_CONTEXT_FIELD_INJECTION = "trace.runtime.context.field.injection"; public static final String PROPAGATION_STYLE_EXTRACT = "propagation.style.extract"; @@ -164,8 +161,6 @@ public class Config { private static final String DEFAULT_SPLIT_BY_TAGS = ""; private static final int DEFAULT_SCOPE_DEPTH_LIMIT = 100; private static final int DEFAULT_PARTIAL_FLUSH_MIN_SPANS = 1000; - private static final int DEFAULT_SPAN_DURATION_ABOVE_AVERAGE_STACKTRACE_MILLIS = - (int) TimeUnit.SECONDS.toMillis(1); private static final String DEFAULT_PROPAGATION_STYLE_EXTRACT = PropagationStyle.DATADOG.name(); private static final String DEFAULT_PROPAGATION_STYLE_INJECT = PropagationStyle.DATADOG.name(); private static final boolean DEFAULT_JMX_FETCH_ENABLED = true; @@ -238,7 +233,6 @@ public class Config { @Getter private final Set splitByTags; @Getter private final Integer scopeDepthLimit; @Getter private final Integer partialFlushMinSpans; - @Getter private final long spanDurationAboveAverageStacktraceNanos; @Getter private final boolean runtimeContextFieldInjection; @Getter private final Set propagationStylesToExtract; @Getter private final Set propagationStylesToInject; @@ -361,13 +355,6 @@ public class Config { partialFlushMinSpans = getIntegerSettingFromEnvironment(PARTIAL_FLUSH_MIN_SPANS, DEFAULT_PARTIAL_FLUSH_MIN_SPANS); - spanDurationAboveAverageStacktraceNanos = - TimeUnit.MILLISECONDS.toNanos( - getIntegerSettingFromEnvironment( - SPAN_DURATION_ABOVE_AVERAGE_STACKTRACE_MILLIS, - DEFAULT_SPAN_DURATION_ABOVE_AVERAGE_STACKTRACE_MILLIS) - .longValue()); - runtimeContextFieldInjection = getBooleanSettingFromEnvironment( RUNTIME_CONTEXT_FIELD_INJECTION, DEFAULT_RUNTIME_CONTEXT_FIELD_INJECTION); @@ -555,15 +542,6 @@ public class Config { partialFlushMinSpans = getPropertyIntegerValue(properties, PARTIAL_FLUSH_MIN_SPANS, parent.partialFlushMinSpans); - // do we care about the integer downcast here? - spanDurationAboveAverageStacktraceNanos = - TimeUnit.MILLISECONDS.toNanos( - getPropertyIntegerValue( - properties, - SPAN_DURATION_ABOVE_AVERAGE_STACKTRACE_MILLIS, - (int) - TimeUnit.NANOSECONDS.toMillis(parent.spanDurationAboveAverageStacktraceNanos))); - runtimeContextFieldInjection = getPropertyBooleanValue( properties, RUNTIME_CONTEXT_FIELD_INJECTION, parent.runtimeContextFieldInjection); diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java index c526d8caf5..1380b2753c 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpan.java @@ -1,6 +1,5 @@ package datadog.opentracing; -import datadog.trace.api.Config; import datadog.trace.api.DDTags; import datadog.trace.api.interceptor.MutableSpan; import datadog.trace.api.sampling.PrioritySampling; @@ -92,6 +91,16 @@ public class DDSpan implements Span, MutableSpan { return durationNano.get() != 0; } + private void finishAndAddToTrace(final long durationNano) { + // ensure a min duration of 1 + if (this.durationNano.compareAndSet(0, Math.max(1, durationNano))) { + log.debug("Finished: {}", this); + context.getTrace().addSpan(this); + } else { + log.debug("{} - already finished!", this); + } + } + @Override public final void finish() { if (startTimeNano > 0) { @@ -107,69 +116,6 @@ public class DDSpan implements Span, MutableSpan { finishAndAddToTrace(TimeUnit.MICROSECONDS.toNanos(stoptimeMicros - startTimeMicro)); } - private void finishAndAddToTrace(final long durationNano) { - // ensure a min duration of 1 - if (this.durationNano.compareAndSet(0, Math.max(1, durationNano))) { - log.debug("Finished: {}", this); - addStacktraceIfThresholdExceeded(); - context.getTrace().addSpan(this); - } else { - log.debug("{} - already finished!", this); - } - } - - // Track the average span duration per thread. - private static final ThreadLocal SPAN_COUNT = new ThreadLocal(); - private static final ThreadLocal AVG_DURATION = new ThreadLocal(); - private static final ThreadLocal AVG_REMAINDER = new ThreadLocal(); - - private long getOr0(final ThreadLocal threadLocal) { - final Long value = threadLocal.get(); - return value == null ? 0 : value; - } - - private void addStacktraceIfThresholdExceeded() { - final long spanDurationStacktraceNanos = - Config.get().getSpanDurationAboveAverageStacktraceNanos(); - if (spanDurationStacktraceNanos <= 0 - // If this span was finished async, then the stacktrace will be less meaningful. - || context.threadId != Thread.currentThread().getId()) { - return; - } - - final long duration = durationNano.get(); - final long count = getOr0(SPAN_COUNT) + 1; - long average = getOr0(AVG_DURATION); - long remainder = getOr0(AVG_REMAINDER); - - // http://www.onemanclapping.org/2012/03/calculating-long-running-averages.html - average += (duration + remainder) / count; - remainder = (duration + remainder) % count; - - SPAN_COUNT.set(count); - AVG_DURATION.set(average); - AVG_REMAINDER.set(remainder); - - if (isError() || duration <= average + spanDurationStacktraceNanos) { - return; - } - final StringBuilder stack = new StringBuilder(); - // TODO: use StackWalker api for java 9+ jvm's? - boolean skipNext = true; - for (final StackTraceElement element : Thread.currentThread().getStackTrace()) { - final boolean tracingClass = element.getClassName().startsWith("datadog.opentracing."); - if (skipNext || tracingClass) { - skipNext = tracingClass; - continue; - } - stack.append("\tat "); - stack.append(element); - stack.append("\n"); - } - // Prob not worth dealing with the trailing newline. - setTag("slow.stack", stack.toString()); - } - @Override public DDSpan setError(final boolean error) { context.setErrorFlag(error); diff --git a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpanContext.java b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpanContext.java index b76f8287d9..88e0974135 100644 --- a/dd-trace-ot/src/main/java/datadog/opentracing/DDSpanContext.java +++ b/dd-trace-ot/src/main/java/datadog/opentracing/DDSpanContext.java @@ -70,8 +70,7 @@ public class DDSpanContext implements io.opentracing.SpanContext { // Additional Metadata private final String threadName = Thread.currentThread().getName(); - // Visible for use in DDSpan - final long threadId = Thread.currentThread().getId(); + private final long threadId = Thread.currentThread().getId(); private final Map serviceNameMappings; diff --git a/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanTest.groovy b/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanTest.groovy index cf79ee5769..0cbc4c58c0 100644 --- a/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanTest.groovy +++ b/dd-trace-ot/src/test/groovy/datadog/opentracing/DDSpanTest.groovy @@ -1,14 +1,13 @@ package datadog.opentracing + import datadog.opentracing.propagation.ExtractedContext import datadog.opentracing.propagation.TagContext -import datadog.trace.api.Config import datadog.trace.api.sampling.PrioritySampling import datadog.trace.common.sampling.RateByServiceSampler import datadog.trace.common.writer.ListWriter import datadog.trace.util.test.DDSpecification import io.opentracing.SpanContext -import org.spockframework.util.ReflectionUtil import java.util.concurrent.TimeUnit @@ -170,28 +169,6 @@ class DDSpanTest extends DDSpecification { span.durationNano == 1 } - def "stacktrace captured when duration exceeds average + configured threshold"() { - setup: - // Get the part of the stack before this test is called. - def acceptRemaining = false - def originalStack = Thread.currentThread().stackTrace - def stackTraceElements = originalStack.dropWhile { - if (it.className == ReflectionUtil.name) { - acceptRemaining = true - } - return !acceptRemaining - } - def stack = "\tat " + stackTraceElements.join("\n\tat ") + "\n" - - def span = tracer.buildSpan("test").start() - span.finish(span.startTimeMicro + DDSpan.AVG_DURATION.get() + TimeUnit.NANOSECONDS.toMicros(Config.get().spanDurationAboveAverageStacktraceNanos) + 1) - def actual = span.tags["slow.stack"].toString() - - expect: - !stack.isEmpty() - actual.endsWith(stack) - } - def "priority sampling metric set only on root span"() { setup: def parent = tracer.buildSpan("testParent").start()