Print logs when Latency is negative (#474)

* Print logs when Latency is negative * spotless
thulab · Jan 6, 2025 · ecef404 · ecef404
1 parent d0f84d7
commit ecef404
Show file tree

Hide file tree

Showing 2 changed files with 22 additions and 1 deletion.
diff --git a/core/src/main/java/cn/edu/tsinghua/iot/benchmark/measurement/Measurement.java b/core/src/main/java/cn/edu/tsinghua/iot/benchmark/measurement/Measurement.java
@@ -141,6 +141,8 @@ public void calculateMetrics(List<Operation> operations) {
                 return operationLatencyDigest.get(operation).centroids().iterator().next().mean();
               }
             };
+        // log negative latency details
+        logNegativeLatencyDetails(operations);
         Metric.MIN_LATENCY.getTypeValueMap().put(operation, quantileOrItself.apply(0.0));
         Metric.MAX_LATENCY.getTypeValueMap().put(operation, quantileOrItself.apply(1.0));
         Metric.P10_LATENCY.getTypeValueMap().put(operation, quantileOrItself.apply(0.1));
@@ -155,6 +157,21 @@ public void calculateMetrics(List<Operation> operations) {
     }
   }
 
+  private void logNegativeLatencyDetails(List<Operation> operations) {
+    for (Operation operation : operations) {
+      TDigest tDigest = operationLatencyDigest.get(operation);
+      // Output all centers of mass less than 0 in TDigest.
+      tDigest
+          .centroids()
+          .forEach(
+              centroid -> {
+                if (centroid != null && centroid.mean() < 0) {
+                  LOGGER.error("{}: Centroid mean: {}", operation, centroid.mean());
+                }
+              });
+    }
+  }
+
   /** Show measurements and record according to TEST_DATA_PERSISTENCE */
   public String getMeasurementsString(List<Operation> operations) {
     PersistenceFactory persistenceFactory = new PersistenceFactory();

diff --git a/core/src/main/java/cn/edu/tsinghua/iot/benchmark/mode/BaseMode.java b/core/src/main/java/cn/edu/tsinghua/iot/benchmark/mode/BaseMode.java
@@ -251,7 +251,11 @@ private static void measure(
       List<Operation> operations,
       String prefix,
       boolean needPrintConf) {
-    measurement.setElapseTime((System.nanoTime() - startTime) / NANO_TO_SECOND);
+    double elapseTime = (System.nanoTime() - startTime) / NANO_TO_SECOND;
+    if (elapseTime < 0) {
+      LOGGER.error("elapseTime is negative: {}", elapseTime);
+    }
+    measurement.setElapseTime(elapseTime);
     // sum up all the measurements and calculate statistics
     measurement.resetMeasurementMaps();
     allClientsMeasurement.forEach(measurement::mergeMeasurement);