Add Logging for non-increasing Clock#nanoTime calls.

We see negative duration values when calling CriticalPathComponent#getElapsedTime and these values are sometimes very large (from 7 days to 77 days). Add a logger when we get the finish time so we can compare the start and finish times at that moment.

RELNOTES: None.
PiperOrigin-RevId: 312732191

src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java

diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java
index 7e64fad..ed15f4c 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java
@@ -20,6 +20,8 @@
 import com.google.common.collect.Maps;
 import com.google.common.eventbus.AllowConcurrentEvents;
 import com.google.common.eventbus.Subscribe;
+import com.google.common.flogger.GoogleLogger;
+import com.google.common.flogger.StackSize;
 import com.google.devtools.build.lib.actions.Action;
 import com.google.devtools.build.lib.actions.ActionAnalysisMetadata;
 import com.google.devtools.build.lib.actions.ActionCompletionEvent;
@@ -35,6 +37,7 @@
 import com.google.devtools.build.lib.actions.SpawnMetrics;
 import com.google.devtools.build.lib.actions.SpawnResult;
 import com.google.devtools.build.lib.clock.Clock;
+import java.time.Duration;
 import java.util.Comparator;
 import java.util.List;
 import java.util.Map;
@@ -52,6 +55,8 @@
  */
 @ThreadSafe
 public class CriticalPathComputer {
+  private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
+
   /** Number of top actions to record. */
   static final int SLOWEST_COMPONENTS_SIZE = 30;
   private static final int LARGEST_MEMORY_COMPONENTS_SIZE = 20;
@@ -334,6 +339,12 @@
     for (Artifact input : action.getInputs().toList()) {
       addArtifactDependency(component, input, finishTimeNanos);
     }
+    if (Duration.ofNanos(finishTimeNanos - startTimeNanos).compareTo(Duration.ofMillis(-5)) < 0) {
+      // See note in {@link Clock#nanoTime} about non increasing subsequent #nanoTime calls.
+      logger.atWarning().withStackTrace(StackSize.MEDIUM).log(
+          "Negative duration time for [%s] %s with start: %s, finish: %s.",
+          action.getMnemonic(), action.getPrimaryOutput(), startTimeNanos, finishTimeNanos);
+    }
     component.finishActionExecution(startTimeNanos, finishTimeNanos);
     maxCriticalPath.accumulateAndGet(component, SELECT_LONGER_COMPONENT);
   }