[close #404] use System.nanoTime() to calculate duration, cause System.currentTimeMillis() is not monotonic

src/main/java/org/tikv/common/log/SlowLogImpl.java

@@ -38,13 +38,19 @@ public class SlowLogImpl implements SlowLog {
   private Throwable error = null;
 
   private final long startMS;
+  /**
+   * use System.nanoTime() to calculate duration, cause System.currentTimeMillis() is not monotonic
+   */
+  private final long startNS;
+
   private final long slowThresholdMS;
 
   /** Key-Value pairs which will be logged, e.g. function name, key, region, etc. */
   private final Map<String, String> properties;
 
   public SlowLogImpl(long slowThresholdMS, Map<String, String> properties) {
     this.startMS = System.currentTimeMillis();
+    this.startNS = System.nanoTime();
     this.slowThresholdMS = slowThresholdMS;
     this.properties = new HashMap<>(properties);
   }
@@ -56,7 +62,7 @@ public void addProperty(String key, String value) {
 
   @Override
   public synchronized SlowLogSpan start(String name) {
-    SlowLogSpan slowLogSpan = new SlowLogSpanImpl(name);
+    SlowLogSpan slowLogSpan = new SlowLogSpanImpl(name, startMS, startNS);
     if (slowLogSpans.size() < MAX_SPAN_SIZE) {
       slowLogSpans.add(slowLogSpan);
     }
@@ -71,7 +77,8 @@ public void setError(Throwable err) {
 
   @Override
   public void log() {
-    long currentMS = System.currentTimeMillis();
+    long currentNS = System.nanoTime();
+    long currentMS = startMS + (currentNS - startNS) / 1_000_000;
     if (error != null || (slowThresholdMS >= 0 && currentMS - startMS > slowThresholdMS)) {
       logger.warn("SlowLog:" + getSlowLogString(currentMS));
     }

src/main/java/org/tikv/common/log/SlowLogSpanImpl.java

@@ -24,23 +24,38 @@
 
 public class SlowLogSpanImpl implements SlowLogSpan {
   private final String name;
+  private final long requestStartNS;
+  private final long requestStartMS;
+
   private long startMS;
   private long endMS;
+  /**
+   * use System.nanoTime() to calculate duration, cause System.currentTimeMillis() is not monotonic
+   */
+  private long startNS;
+
+  private long endNS;
 
-  public SlowLogSpanImpl(String name) {
+  public SlowLogSpanImpl(String name, long requestStartMS, long requestStartNS) {
     this.name = name;
+    this.requestStartMS = requestStartMS;
+    this.requestStartNS = requestStartNS;
     this.startMS = 0;
+    this.startNS = 0;
     this.endMS = 0;
+    this.endNS = 0;
   }
 
   @Override
   public void start() {
-    this.startMS = System.currentTimeMillis();
+    startNS = System.nanoTime();
+    startMS = requestStartMS + (startNS - requestStartNS) / 1_000_000;
   }
 
   @Override
   public void end() {
-    this.endMS = System.currentTimeMillis();
+    endNS = System.nanoTime();
+    endMS = startMS + (endNS - startNS) / 1_000_000;
   }
 
   @Override