Fix unexpected max latency in output of stat

src/Service/ConnectionHandler.cpp

@@ -1,9 +1,9 @@
-#include "ConnectionHandler.h"
+#include <algorithm>
 
 #include <Poco/Net/NetException.h>
-
 #include <Common/Stopwatch.h>
 
+#include <Service/ConnectionHandler.h>
 #include <Service/FourLetterCommand.h>
 #include <Service/formatHex.h>
 #include <ZooKeeper/ZooKeeperCommon.h>
@@ -687,20 +687,25 @@ void ConnectionHandler::updateStats(const Coordination::ZooKeeperResponsePtr & r
     if (response->xid != Coordination::WATCH_XID && response->getOpNum() != Coordination::OpNum::Heartbeat
         && response->getOpNum() != Coordination::OpNum::SetWatches && response->getOpNum() != Coordination::OpNum::Close)
     {
-        Int64 elapsed = Poco::Timestamp().epochMicroseconds() / 1000 - response->request_created_time_ms;
-        {
-            conn_stats.updateLatency(elapsed);
-            if (unlikely(elapsed > 10000))
-                LOG_WARNING(
-                    log,
-                    "Slow request detected #{}#{}#{}, time costs {}ms, please take care.",
-                    toHexString(session_id.load()),
-                    response->xid,
-                    Coordination::toString(response->getOpNum()),
-                    elapsed);
-        }
+        const auto current_time = getCurrentTimeMilliseconds();
+        // Use std::chrono::steady_clock to calculate elapsed time.
+        // If current_time is earlier than create_time, assume current_time is incorrect and set elapsed to zero.
+        // Otherwise, calculate the elapsed time.
+        Int64 elapsed = current_time < response->request_created_time_ms ? 0 : current_time - response->request_created_time_ms;
+
+        conn_stats.updateLatency(elapsed);
+        if (unlikely(elapsed > 10000))
+            LOG_WARNING(
+                log,
+                "Slow request detected #{}#{}#{}, time costs {}ms, please take care.",
+                toHexString(session_id.load()),
+                response->xid,
+                Coordination::toString(response->getOpNum()),
+                elapsed);
+
         keeper_dispatcher->updateKeeperStatLatency(elapsed);
 
+
         last_op.set(std::make_unique<LastOp>(LastOp{
             .name = Coordination::toString(response->getOpNum()),
             .last_cxid = response->xid,

src/Service/KeeperDispatcher.cpp

@@ -170,7 +170,7 @@ bool KeeperDispatcher::pushSessionRequest(const Coordination::ZooKeeperRequestPt
     request_info.session_id = internal_id;
 
     using namespace std::chrono;
-    request_info.create_time = duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
+    request_info.create_time = getCurrentTimeMilliseconds();
 
     LOG_TRACE(
         log,
@@ -198,7 +198,7 @@ bool KeeperDispatcher::pushRequest(const Coordination::ZooKeeperRequestPtr & req
     request_info.session_id = session_id;
 
     using namespace std::chrono;
-    request_info.create_time = duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
+    request_info.create_time = getCurrentTimeMilliseconds();
 
     LOG_TRACE(log, "Push user request #{}#{}#{}", toHexString(session_id), request->xid, Coordination::toString(request->getOpNum()));
     /// Put close requests without timeouts
@@ -220,7 +220,7 @@ bool KeeperDispatcher::pushForwardRequest(size_t server_id, size_t client_id, Fo
     RequestForSession && request_info = request->requestForSession();
 
     using namespace std::chrono;
-    request_info.create_time = duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
+    request_info.create_time = getCurrentTimeMilliseconds();
 
     request_info.server_id = server_id;
     request_info.client_id = client_id;
@@ -460,7 +460,7 @@ void KeeperDispatcher::deadSessionCleanThread()
                     request_info.session_id = dead_session;
                     // request_info.is_internal = true;
                     using namespace std::chrono;
-                    request_info.create_time = duration_cast<milliseconds>(system_clock::now().time_since_epoch()).count();
+                    request_info.create_time = getCurrentTimeMilliseconds();
                     {
                         std::lock_guard lock(push_request_mutex);
                         if (!requests_queue->push(std::move(request_info)))

src/Service/Metrics.h

@@ -15,7 +15,7 @@ namespace RK
 
 inline UInt64 getCurrentTimeMilliseconds()
 {
-    return duration_cast<std::chrono::milliseconds>(std::chrono::system_clock::now().time_since_epoch()).count();
+    return duration_cast<std::chrono::milliseconds>(std::chrono::steady_clock::now().time_since_epoch()).count();
 };
 
 

src/Service/NuRaftStateMachine.cpp

@@ -147,7 +147,7 @@ ptr<RequestForSession> NuRaftStateMachine::createRequestSession(ptr<log_entry> &
     request_for_session->request->readImpl(buffer);
 
     if (buffer.eof())
-        request_for_session->create_time = std::chrono::system_clock::now().time_since_epoch() / std::chrono::milliseconds(1);
+        request_for_session->create_time = getCurrentTimeMilliseconds();
     else
         Coordination::read(request_for_session->create_time, buffer);