diff --git a/cmake/bitcoin-build-config.h.in b/cmake/bitcoin-build-config.h.in index 19d815db0ee..8d5abaf7498 100644 --- a/cmake/bitcoin-build-config.h.in +++ b/cmake/bitcoin-build-config.h.in @@ -105,6 +105,12 @@ /* Define this symbol if the BSD sysctl(KERN_ARND) is available */ #cmakedefine HAVE_SYSCTL_ARND 1 +/* Define this symbol if you have clock_gettime() */ +#cmakedefine HAVE_CLOCK_GETTIME 1 + +/* Define this symbol if you have GetThreadTimes() */ +#cmakedefine HAVE_GETTHREADTIMES 1 + /* Define to 1 if std::system or ::wsystem is available. */ #cmakedefine HAVE_SYSTEM 1 diff --git a/cmake/introspection.cmake b/cmake/introspection.cmake index d4ed4866b9c..24178e4a8f2 100644 --- a/cmake/introspection.cmake +++ b/cmake/introspection.cmake @@ -159,6 +159,40 @@ check_cxx_source_compiles(" " HAVE_SYSCTL_ARND ) +# Check for clock_gettime() (POSIX.1b). +check_cxx_source_compiles(" + #include + + int main(int, char**) + { + timespec now; + clock_gettime(CLOCK_THREAD_CPUTIME_ID, &now); + (void)now.tv_sec; + (void)now.tv_nsec; + return 0; + } + " HAVE_CLOCK_GETTIME +) + +# Check for GetThreadTimes() (Windows). +check_cxx_source_compiles(" + #include + #include + + #include + + int main(int, char**) + { + FILETIME creation; + FILETIME exit; + FILETIME kernel; + FILETIME user; + (void)GetThreadTimes(GetCurrentThread(), &creation, &exit, &kernel, &user); + return 0; + } + " HAVE_GETTHREADTIMES +) + if(NOT MSVC) include(CheckSourceCompilesWithFlags) diff --git a/doc/release-notes-31672.md b/doc/release-notes-31672.md new file mode 100644 index 00000000000..44e176bc035 --- /dev/null +++ b/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) diff --git a/src/net.cpp b/src/net.cpp index 735985a8414..be7408aa675 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -660,6 +660,8 @@ void CNode::CopyStats(CNodeStats& stats) stats.addrLocal = addrLocalUnlocked.IsValid() ? addrLocalUnlocked.ToStringAddrPort() : ""; X(m_conn_type); + + X(m_cpu_time); } #undef X @@ -3047,6 +3049,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); diff --git a/src/net.h b/src/net.h index e64d9a67f46..2d65b5ba91c 100644 --- a/src/net.h +++ b/src/net.h @@ -31,6 +31,7 @@ #include #include #include +#include #include #include @@ -220,6 +221,8 @@ public: TransportProtocolType m_transport_type; /** BIP324 session id string in hex, if any. */ std::string m_session_id; + /** CPU time spent processing messages from this node and crafting messages for it. */ + std::chrono::nanoseconds m_cpu_time; }; @@ -969,6 +972,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 m_cpu_time; + private: const NodeId id; const uint64_t nLocalHostNonce; diff --git a/src/rpc/net.cpp b/src/rpc/net.cpp index bda07365e0e..224df8f7904 100644 --- a/src/rpc/net.cpp +++ b/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"}, @@ -205,6 +210,8 @@ static RPCHelpMan getpeerinfo() UniValue ret(UniValue::VARR); + const auto now{GetTime()}; + for (const CNodeStats& stats : vstats) { UniValue obj(UniValue::VOBJ); CNodeStateStats statestats; @@ -239,6 +246,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(statestats.time_offset)); if (stats.m_last_ping_time > 0us) { diff --git a/src/util/time.cpp b/src/util/time.cpp index cafc27e0d05..ab6f4e436c6 100644 --- a/src/util/time.cpp +++ b/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 // IWYU pragma: keep + #include #include @@ -17,6 +19,16 @@ #include #include +#ifdef HAVE_CLOCK_GETTIME +#include +#elif defined(HAVE_GETTHREADTIMES) +#include +#include + +#include +#endif + + void UninterruptibleSleep(const std::chrono::microseconds& n) { std::this_thread::sleep_for(n); } static std::atomic g_mock_time{}; //!< For testing @@ -128,3 +140,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& 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; +} diff --git a/src/util/time.h b/src/util/time.h index c43b306ff24..219db13b562 100644 --- a/src/util/time.h +++ b/src/util/time.h @@ -6,8 +6,10 @@ #ifndef BITCOIN_UTIL_TIME_H #define BITCOIN_UTIL_TIME_H +#include #include // IWYU pragma: export #include +#include #include #include #include @@ -144,4 +146,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; + + /** + * 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& a, std::chrono::nanoseconds b); + #endif // BITCOIN_UTIL_TIME_H diff --git a/test/functional/rpc_net.py b/test/functional/rpc_net.py index 41ecbbed22d..a450ae381db 100755 --- a/test/functional/rpc_net.py +++ b/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, {