Merge 31672 via peer_cpu_load-28+knots

configure.ac

@@ -857,6 +857,44 @@ if test "$ac_cv_sys_large_files" != "" &&
   CORE_CPPFLAGS="$CORE_CPPFLAGS -D_LARGE_FILES=$ac_cv_sys_large_files"
 fi
 
+AC_SEARCH_LIBS([clock_gettime],[rt])
+
+AC_MSG_CHECKING([for clock_gettime w/ CLOCK_THREAD_CPUTIME_ID])
+AC_COMPILE_IFELSE([AC_LANG_PROGRAM([[
+    #include <time.h>
+  ]],[[
+    timespec now;
+    clock_gettime(CLOCK_THREAD_CPUTIME_ID, &now);
+    (void)now.tv_sec;
+    (void)now.tv_nsec;
+  ]])
+],[
+  AC_MSG_RESULT([yes])
+  AC_DEFINE([HAVE_CLOCK_GETTIME], [1], [Define this symbol if you have clock_gettime])
+],[
+  AC_MSG_RESULT([no])
+])
+
+AC_MSG_CHECKING([for GetThreadTimes])
+AC_COMPILE_IFELSE([AC_LANG_PROGRAM([[
+    #include <windows.h>
+    #include <winnt.h>
+
+    #include <processthreadsapi.h>
+  ]],[[
+    FILETIME creation;
+    FILETIME exit;
+    FILETIME kernel;
+    FILETIME user;
+    (void)GetThreadTimes(GetCurrentThread(), &creation, &exit, &kernel, &user);
+  ]])
+],[
+  AC_MSG_RESULT([yes])
+  AC_DEFINE([HAVE_GETTHREADTIMES], [1], [Define this symbol if you have GetThreadTimes])
+],[
+  AC_MSG_RESULT([no])
+])
+
 if test "$TARGET_OS" != "windows"; then
   dnl All windows code is PIC, forcing it on just adds useless compile warnings
   AX_CHECK_COMPILE_FLAG([-fPIC], [PIC_FLAGS="-fPIC"])

doc/release-notes-31672.md

@@ -0,0 +1,8 @@
+RPC
+---
+
+A new field `cpu_load` has been added to the `getpeerinfo` RPC output.
+It shows the CPU time (user + system) spent processing messages from the
+given peer and crafting messages for it expressed in per milles (‰) of
+the duration of the connection. The field is optional and will be omitted
+on platforms that do not support this or if still not measured. (#31672)

src/net.cpp

@@ -642,6 +642,8 @@ void CNode::CopyStats(CNodeStats& stats)
     stats.addrLocal = addrLocalUnlocked.IsValid() ? addrLocalUnlocked.ToStringAddrPort() : "";
 
     X(m_conn_type);
+
+    X(m_cpu_time);
 }
 #undef X
 
@@ -2958,6 +2960,8 @@ void CConnman::ThreadMessageHandler()
                 if (pnode->fDisconnect)
                     continue;
 
+                CpuTimer timer{[&pnode](std::chrono::nanoseconds elapsed) { pnode->m_cpu_time += elapsed; }};
+
                 // Receive messages
                 bool fMoreNodeWork = m_msgproc->ProcessMessages(pnode, flagInterruptMsgProc);
                 fMoreWork |= (fMoreNodeWork && !pnode->fPauseSend);

src/net.h

@@ -31,6 +31,7 @@
 #include <util/check.h>
 #include <util/sock.h>
 #include <util/threadinterrupt.h>
+#include <util/time.h>
 
 #include <atomic>
 #include <condition_variable>
@@ -222,6 +223,8 @@ public:
     std::string m_session_id;
     /** whether this peer forced its connection by evicting another */
     bool m_forced_inbound;
+    /** CPU time spent processing messages from this node and crafting messages for it. */
+    std::chrono::nanoseconds m_cpu_time;
 };
 
 
@@ -955,6 +958,9 @@ public:
         m_min_ping_time = std::min(m_min_ping_time.load(), ping_time);
     }
 
+    /** CPU time spent processing messages from this node and crafting messages for it. */
+    std::atomic<std::chrono::nanoseconds> m_cpu_time;
+
 private:
     const NodeId id;
     const uint64_t nLocalHostNonce;

src/rpc/net.cpp

@@ -143,6 +143,11 @@ static RPCHelpMan getpeerinfo()
                     {RPCResult::Type::NUM_TIME, "last_block", "The " + UNIX_EPOCH_TIME + " of the last block received from this peer"},
                     {RPCResult::Type::NUM, "bytessent", "The total bytes sent"},
                     {RPCResult::Type::NUM, "bytesrecv", "The total bytes received"},
+                    {RPCResult::Type::NUM, "cpu_load", /*optional=*/true,
+                        "The CPU time (user + system) spent processing messages from this peer "
+                        "and crafting messages for it expressed in per milles (‰) of the "
+                        "duration of the connection. Will be omitted on platforms that do not "
+                        "support this or if still not measured."},
                     {RPCResult::Type::NUM_TIME, "conntime", "The " + UNIX_EPOCH_TIME + " of the connection"},
                     {RPCResult::Type::NUM, "timeoffset", "The time offset in seconds"},
                     {RPCResult::Type::NUM, "pingtime", /*optional=*/true, "The last ping time in milliseconds (ms), if any"},
@@ -206,6 +211,8 @@ static RPCHelpMan getpeerinfo()
 
     UniValue ret(UniValue::VARR);
 
+    const auto now{GetTime<std::chrono::seconds>()};
+
     for (const CNodeStats& stats : vstats) {
         UniValue obj(UniValue::VOBJ);
         CNodeStateStats statestats;
@@ -240,6 +247,9 @@ static RPCHelpMan getpeerinfo()
         obj.pushKV("last_block", count_seconds(stats.m_last_block_time));
         obj.pushKV("bytessent", stats.nSendBytes);
         obj.pushKV("bytesrecv", stats.nRecvBytes);
+        if (stats.m_cpu_time > 0s && now > stats.m_connected) {
+            obj.pushKV("cpu_load", /* ‰ */1000.0 * stats.m_cpu_time / (now - stats.m_connected));
+        }
         obj.pushKV("conntime", count_seconds(stats.m_connected));
         obj.pushKV("timeoffset", Ticks<std::chrono::seconds>(statestats.time_offset));
         if (stats.m_last_ping_time > 0us) {

src/util/time.cpp

@@ -3,6 +3,8 @@
 // Distributed under the MIT software license, see the accompanying
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
+#include <config/bitcoin-config.h> // IWYU pragma: keep
+
 #include <util/time.h>
 
 #include <compat/compat.h>
@@ -17,6 +19,16 @@
 #include <string_view>
 #include <thread>
 
+#ifdef HAVE_CLOCK_GETTIME
+#include <time.h>
+#elif defined(HAVE_GETTHREADTIMES)
+#include <windows.h>
+#include <winnt.h>
+
+#include <processthreadsapi.h>
+#endif
+
+
 void UninterruptibleSleep(const std::chrono::microseconds& n) { std::this_thread::sleep_for(n); }
 
 static std::atomic<std::chrono::seconds> g_mock_time{}; //!< For testing
@@ -107,3 +119,62 @@ struct timeval MillisToTimeval(std::chrono::milliseconds ms)
 {
     return MillisToTimeval(count_milliseconds(ms));
 }
+
+std::chrono::nanoseconds ThreadCpuTime()
+{
+#ifdef HAVE_CLOCK_GETTIME
+    // An alternative to clock_gettime() is getrusage().
+
+    timespec t;
+    if (clock_gettime(CLOCK_THREAD_CPUTIME_ID, &t) == -1) {
+        return std::chrono::nanoseconds{0};
+    }
+    return std::chrono::seconds{t.tv_sec} + std::chrono::nanoseconds{t.tv_nsec};
+#elif defined(HAVE_GETTHREADTIMES)
+    // An alternative to GetThreadTimes() is QueryThreadCycleTime() but it
+    // counts CPU cycles.
+
+    FILETIME creation;
+    FILETIME exit;
+    FILETIME kernel;
+    FILETIME user;
+    // GetThreadTimes():
+    // https://learn.microsoft.com/en-us/windows/win32/api/processthreadsapi/nf-processthreadsapi-getthreadtimes
+    if (GetThreadTimes(GetCurrentThread(), &creation, &exit, &kernel, &user) == 0) {
+        return std::chrono::nanoseconds{0};
+    }
+
+    // https://learn.microsoft.com/en-us/windows/win32/api/minwinbase/ns-minwinbase-filetime
+    // "... you should copy the low- and high-order parts of the file time to a
+    // ULARGE_INTEGER structure, perform 64-bit arithmetic on the QuadPart
+    // member ..."
+
+    ULARGE_INTEGER kernel_;
+    kernel_.LowPart = kernel.dwLowDateTime;
+    kernel_.HighPart = kernel.dwHighDateTime;
+
+    ULARGE_INTEGER user_;
+    user_.LowPart = user.dwLowDateTime;
+    user_.HighPart = user.dwHighDateTime;
+
+    // https://learn.microsoft.com/en-us/windows/win32/api/processthreadsapi/nf-processthreadsapi-getthreadtimes
+    // "Thread kernel mode and user mode times are amounts of time. For example,
+    // if a thread has spent one second in kernel mode, this function will fill
+    // the FILETIME structure specified by lpKernelTime with a 64-bit value of
+    // ten million. That is the number of 100-nanosecond units in one second."
+    return std::chrono::nanoseconds{(kernel_.QuadPart + user_.QuadPart) * 100};
+#else
+    return std::chrono::nanoseconds{0};
+#endif
+}
+
+std::chrono::nanoseconds operator+=(std::atomic<std::chrono::nanoseconds>& a, std::chrono::nanoseconds b)
+{
+    std::chrono::nanoseconds expected;
+    std::chrono::nanoseconds desired;
+    do {
+        expected = a.load();
+        desired = expected + b;
+    } while (!a.compare_exchange_weak(expected, desired));
+    return desired;
+}

src/util/time.h

@@ -6,8 +6,10 @@
 #ifndef BITCOIN_UTIL_TIME_H
 #define BITCOIN_UTIL_TIME_H
 
+#include <atomic>
 #include <chrono> // IWYU pragma: export
 #include <cstdint>
+#include <functional>
 #include <optional>
 #include <string>
 #include <string_view>
@@ -120,4 +122,46 @@ struct timeval MillisToTimeval(int64_t nTimeout);
  */
 struct timeval MillisToTimeval(std::chrono::milliseconds ms);
 
+/**
+ * Retrieve the CPU time (user + system) spent by the current thread.
+ */
+std::chrono::nanoseconds ThreadCpuTime();
+
+/**
+ * Measure CPU time spent by the current thread.
+ * A clock is started when a CpuTimer is created. When the object is destroyed
+ * the elapsed CPU time is calculated and a callback function is invoked,
+ * providing it the elapsed CPU time.
+ */
+class CpuTimer
+{
+public:
+    using FinishedCB = std::function<void(std::chrono::nanoseconds)>;
+
+    /**
+     * Construct a timer.
+     * @param[in] finished_cb A callback to invoke when this object is destroyed.
+     */
+    CpuTimer(const FinishedCB& finished_cb)
+        : m_start{ThreadCpuTime()},
+          m_finished_cb{finished_cb}
+    {
+    }
+
+    ~CpuTimer()
+    {
+        m_finished_cb(ThreadCpuTime() - m_start);
+    }
+
+private:
+    const std::chrono::nanoseconds m_start;
+    FinishedCB m_finished_cb;
+};
+
+/**
+ * Add `b` nanoseconds to a nanoseconds atomic.
+ * @return The value of `a` immediately after the operation.
+ */
+std::chrono::nanoseconds operator+=(std::atomic<std::chrono::nanoseconds>& a, std::chrono::nanoseconds b);
+
 #endif // BITCOIN_UTIL_TIME_H

test/functional/rpc_net.py

@@ -142,6 +142,7 @@ class NetTest(BitcoinTestFramework):
         # The next two fields will vary for v2 connections because we send a rng-based number of decoy messages
         peer_info.pop("bytesrecv")
         peer_info.pop("bytessent")
+        peer_info.pop("cpu_load", None)
         assert_equal(
             peer_info,
             {