diff --git a/dd-trace/dd-trace.gradle b/dd-trace/dd-trace.gradle index 6094b11d8d..272535fa88 100644 --- a/dd-trace/dd-trace.gradle +++ b/dd-trace/dd-trace.gradle @@ -1,6 +1,7 @@ plugins { id 'groovy' id "com.github.johnrengelman.shadow" version "2.0.1" + id "me.champeau.gradle.jmh" version "0.4.4" } description = 'dd-trace' @@ -32,6 +33,7 @@ dependencies { testCompile group: 'org.spockframework', name: 'spock-core', version: '1.0-groovy-2.4' testCompile group: 'org.codehaus.groovy', name: 'groovy-all', version: '2.4.4' testCompile group: 'io.ratpack', name: 'ratpack-groovy-test', version: '1.4.6' + jmh 'commons-io:commons-io:2.4' } shadowJar { @@ -46,3 +48,29 @@ shadowJar { relocate 'org.reflections', 'dd.deps.org.reflections' relocate 'org.yaml', 'dd.deps.org.yaml' } + +jmh { + timeUnit = 'us' // Output time unit. Available time units are: [m, s, ms, us, ns]. + benchmarkMode = ['thrpt', 'avgt'] + timeOnIteration = '1s' + iterations = 1 // Number of measurement iterations to do. +// fork = 2 // How many times to forks a single benchmark. Use 0 to disable forking altogether + jvmArgs = [] + failOnError = true // Should JMH fail immediately if any benchmark had experienced the unrecoverable error? + warmup = '2s' // Time to spend at each warmup iteration. + warmupIterations = 1 // Number of warmup iterations to do. +// warmupForks = 0 // How many warmup forks to make for a single benchmark. 0 to disable warmup forks. + +// profilers = ['stack'] + // Use profilers to collect additional data. Supported profilers: [cl, comp, gc, stack, perf, perfnorm, perfasm, xperf, xperfasm, hs_cl, hs_comp, hs_gc, hs_rt, hs_thr] + +// humanOutputFile = project.file("${project.buildDir}/reports/jmh/human.txt") // human-readable output file +// operationsPerInvocation = 10 // Operations per invocation. +// synchronizeIterations = false // Synchronize iterations? +// timeout = '1s' // Timeout for benchmark iteration. +// includeTests = true + // Allows to include test sources into generate JMH jar, i.e. use it when benchmarks depend on the test classes. + + duplicateClassesStrategy = 'fail' + jmhVersion = '1.19' // Specifies JMH version +} diff --git a/dd-trace/src/jmh/java/com/datadoghq/trace/DDTraceBenchmark.java b/dd-trace/src/jmh/java/com/datadoghq/trace/DDTraceBenchmark.java new file mode 100644 index 0000000000..398edc4026 --- /dev/null +++ b/dd-trace/src/jmh/java/com/datadoghq/trace/DDTraceBenchmark.java @@ -0,0 +1,59 @@ +package com.datadoghq.trace; + +import com.datadoghq.trace.writer.ListWriter; +import io.opentracing.ActiveSpan; +import io.opentracing.Span; +import io.opentracing.Tracer; +import org.openjdk.jmh.annotations.Benchmark; +import org.openjdk.jmh.annotations.Scope; +import org.openjdk.jmh.annotations.State; + +public class DDTraceBenchmark { + public static String SPAN_NAME = "span-benchmark"; + + @State(Scope.Thread) + public static class TraceState { + public ListWriter traceCollector = new ListWriter(); + public Tracer tracer = new DDTracer(traceCollector); + public ActiveSpan activeSpan = tracer.buildSpan(SPAN_NAME).startActive(); + } + + @Benchmark + public Object testBuildSpan(final TraceState state) { + return state.tracer.buildSpan(SPAN_NAME); + } + + @Benchmark + public Object testBuildStartSpan(final TraceState state) { + return state.tracer.buildSpan(SPAN_NAME).startManual(); + } + + @Benchmark + public Object testFullSpan(final TraceState state) { + final Span span = state.tracer.buildSpan(SPAN_NAME).startManual(); + span.finish(); + return span; + } + + @Benchmark + public Object testBuildStartSpanActive(final TraceState state) { + return state.tracer.buildSpan(SPAN_NAME).startActive(); + } + + @Benchmark + public Object testFullActiveSpan(final TraceState state) { + final ActiveSpan activeSpan = state.tracer.buildSpan(SPAN_NAME).startActive(); + activeSpan.deactivate(); + return activeSpan; + } + + @Benchmark + public Object testContinuationCapture(final TraceState state) { + return state.activeSpan.capture(); + } + + @Benchmark + public Object testContinuationActivate(final TraceState state) { + return state.activeSpan.capture().activate(); + } +} diff --git a/dd-trace/src/jmh/reports/2017-07-18.using-array-copy.txt b/dd-trace/src/jmh/reports/2017-07-18.using-array-copy.txt new file mode 100644 index 0000000000..70a1020e03 --- /dev/null +++ b/dd-trace/src/jmh/reports/2017-07-18.using-array-copy.txt @@ -0,0 +1,15 @@ +Benchmark Mode Cnt Score Error Units +DDTraceBenchmark.testBuildSpan thrpt 10 124.480 ± 6.190 ops/us +DDTraceBenchmark.testBuildStartSpan thrpt 10 0.542 ± 0.210 ops/us +DDTraceBenchmark.testBuildStartSpanActive thrpt 10 0.433 ± 0.136 ops/us +DDTraceBenchmark.testContinuationActivate thrpt 10 1.408 ± 0.701 ops/us +DDTraceBenchmark.testContinuationCapture thrpt 10 77.598 ± 16.400 ops/us +DDTraceBenchmark.testFullActiveSpan thrpt 10 1.348 ± 0.935 ops/us +DDTraceBenchmark.testFullSpan thrpt 10 0.976 ± 1.515 ops/us +DDTraceBenchmark.testBuildSpan avgt 10 0.009 ± 0.003 us/op +DDTraceBenchmark.testBuildStartSpan avgt 10 2.287 ± 0.937 us/op +DDTraceBenchmark.testBuildStartSpanActive avgt 10 2.548 ± 1.400 us/op +DDTraceBenchmark.testContinuationActivate avgt 10 0.744 ± 0.192 us/op +DDTraceBenchmark.testContinuationCapture avgt 10 0.013 ± 0.003 us/op +DDTraceBenchmark.testFullActiveSpan avgt 10 1.039 ± 0.564 us/op +DDTraceBenchmark.testFullSpan avgt 10 1.789 ± 1.174 us/op diff --git a/dd-trace/src/jmh/reports/2017-07-18.using-linked-queue.txt b/dd-trace/src/jmh/reports/2017-07-18.using-linked-queue.txt new file mode 100644 index 0000000000..a472cd7a05 --- /dev/null +++ b/dd-trace/src/jmh/reports/2017-07-18.using-linked-queue.txt @@ -0,0 +1,15 @@ +Benchmark Mode Cnt Score Error Units +DDTraceBenchmark.testBuildSpan thrpt 10 124.865 ± 3.206 ops/us +DDTraceBenchmark.testBuildStartSpan thrpt 10 0.595 ± 0.250 ops/us +DDTraceBenchmark.testBuildStartSpanActive thrpt 10 0.390 ± 0.142 ops/us +DDTraceBenchmark.testContinuationActivate thrpt 10 1.478 ± 0.575 ops/us +DDTraceBenchmark.testContinuationCapture thrpt 10 81.097 ± 13.030 ops/us +DDTraceBenchmark.testFullActiveSpan thrpt 10 1.365 ± 1.032 ops/us +DDTraceBenchmark.testFullSpan thrpt 10 0.484 ± 0.246 ops/us +DDTraceBenchmark.testBuildSpan avgt 10 0.008 ± 0.001 us/op +DDTraceBenchmark.testBuildStartSpan avgt 10 2.406 ± 0.950 us/op +DDTraceBenchmark.testBuildStartSpanActive avgt 10 2.943 ± 1.512 us/op +DDTraceBenchmark.testContinuationActivate avgt 10 0.620 ± 0.223 us/op +DDTraceBenchmark.testContinuationCapture avgt 10 0.012 ± 0.001 us/op +DDTraceBenchmark.testFullActiveSpan avgt 10 1.496 ± 1.948 us/op +DDTraceBenchmark.testFullSpan avgt 10 2.112 ± 1.857 us/op diff --git a/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java b/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java index 74e18238de..cce50cffc2 100644 --- a/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java +++ b/dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java @@ -4,9 +4,9 @@ import com.fasterxml.jackson.annotation.JsonGetter; import com.fasterxml.jackson.annotation.JsonIgnore; import io.opentracing.BaseSpan; import java.util.HashMap; -import java.util.List; import java.util.Map; import java.util.Map.Entry; +import java.util.Queue; import java.util.concurrent.TimeUnit; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -65,10 +65,10 @@ public abstract class DDBaseSpan implements BaseSpan { // warn if one of the parent's children is not finished if (this.isRootSpan()) { - final List> spans = this.context().getTrace(); + final Queue> spans = this.context().getTrace(); for (final DDBaseSpan span : spans) { - if (((DDBaseSpan) span).getDurationNano() == 0L) { + if (span.getDurationNano() == 0L) { logger.warn( "{} - The parent span is marked as finished but this span isn't. You have to close each children.", this); @@ -90,7 +90,7 @@ public abstract class DDBaseSpan implements BaseSpan { return false; } // First item of the array AND tracer set - final DDBaseSpan first = context().getTrace().get(0); + final DDBaseSpan first = context().getTrace().peek(); return first.context().getSpanId() == this.context().getSpanId() && this.context.getTracer() != null; } diff --git a/dd-trace/src/main/java/com/datadoghq/trace/DDSpanContext.java b/dd-trace/src/main/java/com/datadoghq/trace/DDSpanContext.java index 9307eae98a..1bb63c2b1e 100644 --- a/dd-trace/src/main/java/com/datadoghq/trace/DDSpanContext.java +++ b/dd-trace/src/main/java/com/datadoghq/trace/DDSpanContext.java @@ -8,7 +8,8 @@ import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; -import java.util.concurrent.CopyOnWriteArrayList; +import java.util.Queue; +import java.util.concurrent.ConcurrentLinkedQueue; /** * SpanContext represents Span state that must propagate to descendant Spans and across process @@ -40,7 +41,7 @@ public class DDSpanContext implements io.opentracing.SpanContext { /** The type of the span. If null, the Datadog Agent will report as a custom */ private String spanType; /** The collection of all span related to this one */ - private final List> trace; + private final Queue> trace; /** Each span have an operation name describing the current span */ private String operationName; @@ -61,7 +62,7 @@ public class DDSpanContext implements io.opentracing.SpanContext { final boolean errorFlag, final String spanType, final Map tags, - final List> trace, + final Queue> trace, final DDTracer tracer) { this.traceId = traceId; @@ -84,7 +85,7 @@ public class DDSpanContext implements io.opentracing.SpanContext { if (trace == null) { // TODO: figure out better concurrency model. - this.trace = new CopyOnWriteArrayList<>(); // must be thread safe! + this.trace = new ConcurrentLinkedQueue<>(); } else { this.trace = trace; } @@ -150,7 +151,7 @@ public class DDSpanContext implements io.opentracing.SpanContext { } @JsonIgnore - public List> getTrace() { + public Queue> getTrace() { return this.trace; } diff --git a/dd-trace/src/main/java/com/datadoghq/trace/DDTracer.java b/dd-trace/src/main/java/com/datadoghq/trace/DDTracer.java index f419c9522f..db9ef404a2 100644 --- a/dd-trace/src/main/java/com/datadoghq/trace/DDTracer.java +++ b/dd-trace/src/main/java/com/datadoghq/trace/DDTracer.java @@ -18,6 +18,7 @@ import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.Queue; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -32,6 +33,12 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac CURRENT_VERSION = version != null ? version : "unknown"; } + public static final String UNASSIGNED_DEFAULT_SERVICE_NAME = "unnamed-java-app"; + public static final Writer UNASSIGNED_WRITER = new LoggingWriter(); + public static final Sampler UNASSIGNED_SAMPLER = new AllSampler(); + + private static final Logger logger = LoggerFactory.getLogger(DDTracer.class); + /** Writer is an charge of reporting traces and spans to the desired endpoint */ private final Writer writer; /** Sampler defines the sampling policy in order to reduce the number of traces for instance */ @@ -43,13 +50,8 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac /** Span context decorators */ private final Map> spanContextDecorators = new HashMap<>(); - private static final Logger logger = LoggerFactory.getLogger(DDTracer.class); private final CodecRegistry registry; - public static final String UNASSIGNED_DEFAULT_SERVICE_NAME = "unnamed-java-app"; - public static final Writer UNASSIGNED_WRITER = new LoggingWriter(); - public static final Sampler UNASSIGNED_SAMPLER = new AllSampler(); - /** Default constructor, trace/spans are logged, no trace/span dropped */ public DDTracer() { this(UNASSIGNED_WRITER); @@ -131,12 +133,12 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac * * @param trace a list of the spans related to the same trace */ - public void write(final List> trace) { + public void write(final Queue> trace) { if (trace.isEmpty()) { return; } - if (this.sampler.sample(trace.get(0))) { - this.writer.write(trace); + if (this.sampler.sample(trace.peek())) { + this.writer.write(new ArrayList<>(trace)); } } @@ -293,7 +295,7 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac final long spanId = generateNewId(); final long parentSpanId; final Map baggage; - final List> parentTrace; + final Queue> parentTrace; final DDSpanContext context; SpanContext parentContext = this.parent; diff --git a/dd-trace/src/test/java/com/datadoghq/trace/DDTracerTest.java b/dd-trace/src/test/java/com/datadoghq/trace/DDTracerTest.java index 208d9b0ff4..c52574404c 100644 --- a/dd-trace/src/test/java/com/datadoghq/trace/DDTracerTest.java +++ b/dd-trace/src/test/java/com/datadoghq/trace/DDTracerTest.java @@ -9,7 +9,8 @@ import static org.mockito.Mockito.when; import com.datadoghq.trace.sampling.RateSampler; import com.datadoghq.trace.writer.Writer; import java.util.ArrayList; -import java.util.List; +import java.util.LinkedList; +import java.util.Queue; import org.junit.Test; public class DDTracerTest { @@ -24,7 +25,7 @@ public class DDTracerTest { // Rate 0.5 when(sampler.sample(any(DDSpan.class))).thenReturn(true).thenReturn(false); - final List> spans = new ArrayList<>(); + final Queue> spans = new LinkedList<>(); spans.add(span); spans.add(span); spans.add(span); @@ -35,6 +36,6 @@ public class DDTracerTest { tracer.write(spans); verify(sampler, times(2)).sample(span); - verify(writer, times(1)).write(spans); + verify(writer, times(1)).write(new ArrayList<>(spans)); } } diff --git a/dd-trace/src/test/java/com/datadoghq/trace/writer/impl/DDAgentWriterTest.java b/dd-trace/src/test/java/com/datadoghq/trace/writer/impl/DDAgentWriterTest.java index 92dc86d160..80abb64868 100644 --- a/dd-trace/src/test/java/com/datadoghq/trace/writer/impl/DDAgentWriterTest.java +++ b/dd-trace/src/test/java/com/datadoghq/trace/writer/impl/DDAgentWriterTest.java @@ -40,7 +40,7 @@ public class DDAgentWriterTest { parent.finish(); //Create DDWriter - traces.add(parent.context().getTrace()); + traces.add(new ArrayList<>(parent.context().getTrace())); mockedAPI = mock(DDApi.class); when(mockedAPI.sendTraces(traces)).thenReturn(true); ddAgentWriter = new DDAgentWriter(mockedAPI); @@ -49,7 +49,7 @@ public class DDAgentWriterTest { @Test public void testWrite() throws Exception { - ddAgentWriter.write(parent.context().getTrace()); + ddAgentWriter.write(new ArrayList<>(parent.context().getTrace())); Thread.sleep(500); verify(mockedAPI).sendTraces(traces); } @@ -58,7 +58,7 @@ public class DDAgentWriterTest { public void testClose() throws Exception { ddAgentWriter.close(); - ddAgentWriter.write(parent.context().getTrace()); + ddAgentWriter.write(new ArrayList<>(parent.context().getTrace())); Thread.sleep(500); verifyNoMoreInteractions(mockedAPI); }