rpc: add cpu_load to getpeerinfo

Add a new field `cpu_load` to the output of `getpeerinfo` RPC.

It represents the CPU time spent by the message handling thread for the
given peer, weighted for the duration of the connection. That is, for
example, if two peers are equally demanding and one is connected longer
than the other, then they will have the same `cpu_load` number.

Github-Pull: #31672
Rebased-From: 0f68c47e931de05200adeae639bcee50ea3c171d

configure.ac

@@ -841,6 +841,42 @@ 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

@@ -643,6 +643,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>
@@ -14,6 +16,16 @@
 #include <string>
 #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
@@ -72,3 +84,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 <string>
 
 using namespace std::chrono_literals;
@@ -116,4 +118,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

@@ -139,6 +139,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,
             {