Merge pull request #68 from gpolaert/fix-nanotime

Clock refactoring

dd-trace/dd-trace.gradle

@@ -16,6 +16,7 @@ whitelistedInstructionClasses += whitelistedBranchClasses += [
   'com.datadoghq.trace.writer.ListWriter',
   'com.datadoghq.trace.DDTags',
   'com.datadoghq.trace.DDTraceInfo',
+  'com.datadoghq.trace.util.Clock',
 ]
 
 dependencies {

dd-trace/src/main/java/com/datadoghq/trace/DDBaseSpan.java

@@ -1,5 +1,6 @@
 package com.datadoghq.trace;
 
+import com.datadoghq.trace.util.Clock;
 import com.fasterxml.jackson.annotation.JsonGetter;
 import com.fasterxml.jackson.annotation.JsonIgnore;
 import io.opentracing.BaseSpan;
@@ -13,14 +14,14 @@ import lombok.extern.slf4j.Slf4j;
 @Slf4j
 public abstract class DDBaseSpan<S extends BaseSpan> implements BaseSpan<S> {
 
+  /** The context attached to the span */
+  protected final DDSpanContext context;
   /** StartTime stores the creation time of the span in milliseconds */
   protected long startTimeMicro;
   /** StartTimeNano stores the only the nanoseconds for more accuracy */
   protected long startTimeNano;
   /** The duration in nanoseconds computed using the startTimeMicro and startTimeNano */
   protected long durationNano;
-  /** The context attached to the span */
-  protected final DDSpanContext context;
 
   /**
    * A simple constructor. Currently, users have
@@ -34,19 +35,18 @@ public abstract class DDBaseSpan<S extends BaseSpan> implements BaseSpan<S> {
 
     // record the start time in nano (current milli + nano delta)
     if (timestampMicro == 0L) {
-      this.startTimeMicro = TimeUnit.MILLISECONDS.toMicros(System.currentTimeMillis());
+      this.startTimeMicro = Clock.currentMicroTime();
     } else {
       this.startTimeMicro = timestampMicro;
     }
-    this.startTimeNano = System.nanoTime();
+    this.startTimeNano = Clock.currentNanoTicks();
 
     // track each span of the trace
     this.context.getTrace().add(this);
   }
 
   public final void finish() {
-    this.durationNano = System.nanoTime() - startTimeNano;
-    afterFinish();
+    finish(Clock.currentMicroTime() - startTimeMicro);
   }
 
   public final void finish(final long stoptimeMicros) {

dd-trace/src/main/java/com/datadoghq/trace/DDTracer.java

@@ -5,6 +5,7 @@ import com.datadoghq.trace.propagation.Codec;
 import com.datadoghq.trace.propagation.HTTPCodec;
 import com.datadoghq.trace.sampling.AllSampler;
 import com.datadoghq.trace.sampling.Sampler;
+import com.datadoghq.trace.util.Clock;
 import com.datadoghq.trace.writer.LoggingWriter;
 import com.datadoghq.trace.writer.Writer;
 import io.opentracing.ActiveSpan;
@@ -13,12 +14,7 @@ import io.opentracing.BaseSpan;
 import io.opentracing.SpanContext;
 import io.opentracing.propagation.Format;
 import io.opentracing.util.ThreadLocalActiveSpanSource;
-import java.util.ArrayList;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.List;
-import java.util.Map;
-import java.util.Queue;
+import java.util.*;
 import lombok.extern.slf4j.Slf4j;
 
 /** DDTracer makes it easy to send traces and span to DD using the OpenTracing integration. */
@@ -136,6 +132,24 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac
     writer.close();
   }
 
+  @Override
+  public String toString() {
+    return "DDTracer{" + "writer=" + writer + ", sampler=" + sampler + '}';
+  }
+
+  private static class CodecRegistry {
+
+    private final Map<Format<?>, Codec<?>> codecs = new HashMap<>();
+
+    <T> Codec<T> get(final Format<T> format) {
+      return (Codec<T>) codecs.get(format);
+    }
+
+    public <T> void register(final Format<T> format, final Codec<T> codec) {
+      codecs.put(format, codec);
+    }
+  }
+
   /** Spans are built using this builder */
   public class DDSpanBuilder implements SpanBuilder {
     private final ActiveSpanSource spanSource;
@@ -153,6 +167,11 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac
     private String spanType;
     private boolean ignoreActiveSpan = false;
 
+    public DDSpanBuilder(final String operationName, final ActiveSpanSource spanSource) {
+      this.operationName = operationName;
+      this.spanSource = spanSource;
+    }
+
     @Override
     public SpanBuilder ignoreActiveSpan() {
       this.ignoreActiveSpan = true;
@@ -206,11 +225,6 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac
       return withTag(tag, (Object) bool);
     }
 
-    public DDSpanBuilder(final String operationName, final ActiveSpanSource spanSource) {
-      this.operationName = operationName;
-      this.spanSource = spanSource;
-    }
-
     @Override
     public DDSpanBuilder withStartTimestamp(final long timestampMillis) {
       this.timestamp = timestampMillis;
@@ -271,7 +285,7 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac
     }
 
     private long generateNewId() {
-      return System.nanoTime();
+      return Clock.currentNanoTicks();
     }
 
     /**
@@ -344,22 +358,4 @@ public class DDTracer extends ThreadLocalActiveSpanSource implements io.opentrac
       return context;
     }
   }
-
-  private static class CodecRegistry {
-
-    private final Map<Format<?>, Codec<?>> codecs = new HashMap<>();
-
-    <T> Codec<T> get(final Format<T> format) {
-      return (Codec<T>) codecs.get(format);
-    }
-
-    public <T> void register(final Format<T> format, final Codec<T> codec) {
-      codecs.put(format, codec);
-    }
-  }
-
-  @Override
-  public String toString() {
-    return "DDTracer{" + "writer=" + writer + ", sampler=" + sampler + '}';
-  }
 }

dd-trace/src/main/java/com/datadoghq/trace/util/Clock.java

@@ -0,0 +1,37 @@
+package com.datadoghq.trace.util;
+
+import java.util.concurrent.TimeUnit;
+
+/**
+ * A simple wrapper for system clock that aims to provide the current time
+ *
+ * <p>
+ *
+ * <p>The JDK provides two clocks:
+ * <li>one in nanoseconds, for precision, but it can only use to measure durations
+ * <li>one in milliseconds, for accuracy, useful to provide epoch time
+ *     <p>
+ *     <p>At this time, we are using a millis precision (converted to micros) in order to guarantee
+ *     consistency between the span start times and the durations
+ */
+public class Clock {
+
+  /**
+   * Get the current nanos ticks, this method can't be use for date accuracy (only duration
+   * calculations)
+   *
+   * @return The current nanos ticks
+   */
+  public static synchronized long currentNanoTicks() {
+    return System.nanoTime();
+  }
+
+  /**
+   * Get the current time in micros. The actual precision is the millis
+   *
+   * @return the current epoch time in micros
+   */
+  public static synchronized long currentMicroTime() {
+    return TimeUnit.MILLISECONDS.toMicros(System.currentTimeMillis());
+  }
+}