*: Fix time step backward for Stopwatch::elapsedFromLastTime (#8338)

dbms/src/Common/Stopwatch.h

@@ -14,6 +14,7 @@
 
 #pragma once
 
+#include <common/defines.h>
 #include <common/types.h>
 #include <time.h>
 
@@ -23,21 +24,28 @@
 #include <common/apple_rt.h>
 #endif
 
-
-namespace StopWatchDetail
-{
-inline UInt64 nanoseconds(clockid_t clock_type)
+inline UInt64 clock_gettime_ns(clockid_t clock_type = CLOCK_MONOTONIC)
 {
-    struct timespec ts;
+    struct timespec ts
+    {
+    };
     clock_gettime(clock_type, &ts);
-    return ts.tv_sec * 1000000000ULL + ts.tv_nsec;
+    return static_cast<UInt64>(ts.tv_sec * 1000000000ULL + ts.tv_nsec);
 }
-inline UInt64 seconds(clockid_t clock_type)
+
+/// Sometimes monotonic clock may not be monotonic (due to bug in kernel?).
+/// It may cause some operations to fail with "Timeout exceeded: elapsed 18446744073.709553 seconds".
+/// Takes previously returned value and returns it again if time stepped back for some reason.
+inline UInt64 clock_gettime_ns_adjusted(UInt64 prev_time, clockid_t clock_type = CLOCK_MONOTONIC)
 {
-    return nanoseconds(clock_type) / 1000000000ULL;
-}
-} // namespace StopWatchDetail
+    UInt64 current_time = clock_gettime_ns(clock_type);
+    if (likely(prev_time <= current_time))
+        return current_time;
 
+    /// Something probably went completely wrong if time stepped back for more than 1 second.
+    assert(prev_time - current_time <= 1000000000ULL);
+    return prev_time;
+}
 
 /** Differs from Poco::Stopwatch only by using 'clock_gettime' instead of 'gettimeofday',
   *  returns nanoseconds instead of microseconds, and also by other minor differencies.
@@ -56,14 +64,14 @@ class Stopwatch
 
     void start()
     {
-        start_ns = nanoseconds();
+        start_ns = nanosecondsWithBound(start_ns);
         last_ns = start_ns;
         is_running = true;
     }
 
     void stop()
     {
-        stop_ns = nanoseconds();
+        stop_ns = nanosecondsWithBound(start_ns);
         is_running = false;
     }
 
@@ -74,14 +82,16 @@ class Stopwatch
         last_ns = 0;
         is_running = false;
     }
+
     void restart() { start(); }
-    UInt64 elapsed() const { return is_running ? nanoseconds() - start_ns : stop_ns - start_ns; }
+
+    UInt64 elapsed() const { return is_running ? nanosecondsWithBound(start_ns) - start_ns : stop_ns - start_ns; }
     UInt64 elapsedMilliseconds() const { return elapsed() / 1000000UL; }
     double elapsedSeconds() const { return static_cast<double>(elapsed()) / 1000000000ULL; }
 
     UInt64 elapsedFromLastTime()
     {
-        const auto now_ns = nanoseconds();
+        const auto now_ns = nanosecondsWithBound(last_ns);
         if (is_running)
         {
             auto rc = now_ns - last_ns;
@@ -92,7 +102,7 @@ class Stopwatch
         {
             return stop_ns - last_ns;
         }
-    };
+    }
 
     UInt64 elapsedMillisecondsFromLastTime() { return elapsedFromLastTime() / 1000000UL; }
     UInt64 elapsedSecondsFromLastTime() { return elapsedFromLastTime() / 1000000UL; }
@@ -104,21 +114,28 @@ class Stopwatch
     clockid_t clock_type;
     bool is_running = false;
 
-    UInt64 nanoseconds() const { return StopWatchDetail::nanoseconds(clock_type); }
+    // Get current nano seconds, ensuring the return value is not
+    // less than `lower_bound`.
+    UInt64 nanosecondsWithBound(UInt64 lower_bound) const { return clock_gettime_ns_adjusted(lower_bound, clock_type); }
 };
 
 
 class AtomicStopwatch
 {
 public:
     explicit AtomicStopwatch(clockid_t clock_type_ = CLOCK_MONOTONIC)
-        : clock_type(clock_type_)
+        : start_ns(0)
+        , clock_type(clock_type_)
     {
         restart();
     }
 
-    void restart() { start_ns = nanoseconds(); }
-    UInt64 elapsed() const { return nanoseconds() - start_ns; }
+    void restart() { start_ns = nanoseconds(0); }
+    UInt64 elapsed() const
+    {
+        UInt64 current_start_ns = start_ns;
+        return nanoseconds(current_start_ns) - start_ns;
+    }
     UInt64 elapsedMilliseconds() const { return elapsed() / 1000000UL; }
     double elapsedSeconds() const { return static_cast<double>(elapsed()) / 1000000000ULL; }
 
@@ -129,8 +146,8 @@ class AtomicStopwatch
     bool compareAndRestart(double seconds)
     {
         UInt64 threshold = seconds * 1000000000ULL;
-        UInt64 current_ns = nanoseconds();
         UInt64 current_start_ns = start_ns;
+        UInt64 current_ns = nanoseconds(current_start_ns);
 
         while (true)
         {
@@ -175,8 +192,8 @@ class AtomicStopwatch
     Lock compareAndRestartDeferred(double seconds)
     {
         UInt64 threshold = seconds * 1000000000ULL;
-        UInt64 current_ns = nanoseconds();
         UInt64 current_start_ns = start_ns;
+        UInt64 current_ns = nanoseconds(current_start_ns);
 
         while (true)
         {
@@ -197,5 +214,5 @@ class AtomicStopwatch
     clockid_t clock_type;
 
     /// Most significant bit is a lock. When it is set, compareAndRestartDeferred method will return false.
-    UInt64 nanoseconds() const { return StopWatchDetail::nanoseconds(clock_type) & 0x7FFFFFFFFFFFFFFFULL; }
+    UInt64 nanoseconds(UInt64 prev_time) const { return clock_gettime_ns_adjusted(prev_time, clock_type) & 0x7FFFFFFFFFFFFFFFULL; }
 };

dbms/src/Common/ThreadMetricUtil.cpp

@@ -17,14 +17,16 @@
 #include <Common/TiFlashMetrics.h>
 #include <common/types.h>
 
+#include <ctime>
+
 std::atomic<UInt64> last_max_thds_metric_reset_ts{0};
 const UInt64 max_thds_metric_reset_interval = 60; //60s
 
 namespace DB
 {
 bool tryToResetMaxThreadsMetrics()
 {
-    UInt64 now_ts = StopWatchDetail::seconds(CLOCK_MONOTONIC);
+    UInt64 now_ts = clock_gettime_ns(CLOCK_MONOTONIC) / 1000000000ULL;
     if (now_ts > last_max_thds_metric_reset_ts + max_thds_metric_reset_interval)
     {
         last_max_thds_metric_reset_ts = now_ts;
@@ -37,4 +39,4 @@ bool tryToResetMaxThreadsMetrics()
     }
     return false;
 }
-} // namespace DB
+} // namespace DB

dbms/src/Storages/DeltaMerge/tests/stress/DMStressProxy.cpp

@@ -26,7 +26,7 @@ namespace tests
 {
 IDGenerator<Int64> pk{0};
 
-IDGenerator<UInt64> tso{StopWatchDetail::nanoseconds(CLOCK_MONOTONIC)};
+IDGenerator<UInt64> tso{clock_gettime_ns(CLOCK_MONOTONIC)};
 
 template <typename T>
 void insertColumn(Block & block, const DataTypePtr & type, const String & name, Int64 col_id, const std::vector<T> & values)

dbms/src/Storages/DeltaMerge/tools/workload/TimestampGenerator.h

@@ -24,7 +24,7 @@ class TimestampGenerator
 {
 public:
     TimestampGenerator()
-        : t(StopWatchDetail::nanoseconds(CLOCK_MONOTONIC))
+        : t(clock_gettime_ns(CLOCK_MONOTONIC))
     {}
 
     std::vector<uint64_t> get(int count)
@@ -43,4 +43,4 @@ class TimestampGenerator
 private:
     std::atomic<uint64_t> t;
 };
-} // namespace DB::DM::tests
+} // namespace DB::DM::tests