Backport RPCStats to master

src/Makefile.am

@@ -217,6 +217,7 @@ DEFI_CORE_H = \
   rpc/request.h \
   rpc/server.h \
   rpc/util.h \
+  rpc/stats.h \
   scheduler.h \
   script/descriptor.h \
   script/keyorigin.h \
@@ -603,6 +604,7 @@ libdefi_common_a_SOURCES = \
   psbt.cpp \
   rpc/rawtransaction_util.cpp \
   rpc/util.cpp \
+  rpc/stats.cpp \
   scheduler.cpp \
   script/descriptor.cpp \
   script/sign.cpp \

src/httprpc.cpp

@@ -9,6 +9,7 @@
 #include <httpserver.h>
 #include <rpc/protocol.h>
 #include <rpc/server.h>
+#include <rpc/stats.h>
 #include <sync.h>
 #include <ui_interface.h>
 #include <util/strencodings.h>
@@ -148,7 +149,7 @@ static bool RPCAuthorized(const std::string& strAuth, std::string& strAuthUserna
 
 static bool CorsHandler(HTTPRequest *req) {
     auto host = corsOriginHost;
-    // If if it's empty assume cors is disallowed. Do nothing and proceed, 
+    // If if it's empty assume cors is disallowed. Do nothing and proceed,
     // with request as usual.
     if (host.empty())
         return false;
@@ -157,7 +158,7 @@ static bool CorsHandler(HTTPRequest *req) {
     req->WriteHeader("Access-Control-Allow-Credentials", "true");
     req->WriteHeader("Access-Control-Allow-Methods", "POST, GET, OPTIONS");
     req->WriteHeader("Access-Control-Allow-Headers", "Content-Type, Authorization");
-    
+
     // If it's a Cors preflight request, short-circuit and return. We have
     // set what's needed already.
     if (req->GetRequestMethod() == HTTPRequest::OPTIONS) {
@@ -171,8 +172,9 @@ static bool CorsHandler(HTTPRequest *req) {
 
 static bool HTTPReq_JSONRPC(HTTPRequest* req, const std::string &)
 {
+    int64_t time = GetTimeMillis();
     // Handle CORS
-    if (CorsHandler(req)) 
+    if (CorsHandler(req))
         return true;
 
     // JSONRPC handles only POST
@@ -230,6 +232,8 @@ static bool HTTPReq_JSONRPC(HTTPRequest* req, const std::string &)
 
         req->WriteHeader("Content-Type", "application/json");
         req->WriteReply(HTTP_OK, strReply);
+
+        if (statsRPC.isActive()) statsRPC.add(jreq.strMethod, GetTimeMillis() - time, strReply.length());
     } catch (const UniValue& objError) {
         JSONErrorReply(req, objError, jreq.id);
         return false;
@@ -279,6 +283,7 @@ bool StartHTTPRPC()
     assert(eventBase);
     httpRPCTimerInterface = MakeUnique<HTTPRPCTimerInterface>(eventBase);
     RPCSetTimerInterface(httpRPCTimerInterface.get());
+    if (statsRPC.isActive()) statsRPC.load();
     return true;
 }
 
@@ -298,4 +303,8 @@ void StopHTTPRPC()
         RPCUnsetTimerInterface(httpRPCTimerInterface.get());
         httpRPCTimerInterface.reset();
     }
+
+    if (statsRPC.isActive()) statsRPC.save();
 }
+
+CRPCStats statsRPC;

src/init.cpp

@@ -40,6 +40,7 @@
 #include <policy/settings.h>
 #include <rpc/blockchain.h>
 #include <rpc/register.h>
+#include <rpc/stats.h>
 #include <rpc/server.h>
 #include <rpc/util.h>
 #include <scheduler.h>
@@ -591,6 +592,7 @@ void SetupServerArgs()
     gArgs.AddArg("-rpcworkqueue=<n>", strprintf("Set the depth of the work queue to service RPC calls (default: %d)", DEFAULT_HTTP_WORKQUEUE), ArgsManager::ALLOW_ANY | ArgsManager::DEBUG_ONLY, OptionsCategory::RPC);
     gArgs.AddArg("-server", "Accept command line and JSON-RPC commands", ArgsManager::ALLOW_ANY, OptionsCategory::RPC);
     gArgs.AddArg("-rpcallowcors=<host>", "Allow CORS requests from the given host origin. Include scheme and port (eg: -rpcallowcors=http://127.0.0.1:5000)", ArgsManager::ALLOW_ANY, OptionsCategory::RPC);
+    gArgs.AddArg("-rpcstats", strprintf("Log RPC stats. (default: %u)", DEFAULT_RPC_STATS), ArgsManager::ALLOW_ANY, OptionsCategory::RPC);
 
 #if HAVE_DECL_DAEMON
     gArgs.AddArg("-daemon", "Run in the background as a daemon and accept commands", ArgsManager::ALLOW_ANY, OptionsCategory::OPTIONS);
@@ -2066,5 +2068,7 @@ bool AppInitMain(InitInterfaces& interfaces)
         ));
     }
 
+    if (!gArgs.GetBoolArg("-rpcstats", DEFAULT_RPC_STATS)) statsRPC.setActive(false);
+
     return true;
 }

src/rpc/register.h

@@ -13,6 +13,8 @@ class CRPCTable;
 void RegisterBlockchainRPCCommands(CRPCTable &tableRPC);
 /** Register P2P networking RPC commands */
 void RegisterNetRPCCommands(CRPCTable &tableRPC);
+/** Register stats RPC commands */
+void RegisterStatsRPCCommands(CRPCTable &tableRPC);
 /** Register miscellaneous RPC commands */
 void RegisterMiscRPCCommands(CRPCTable &tableRPC);
 /** Register mining RPC commands */
@@ -45,6 +47,7 @@ static inline void RegisterAllCoreRPCCommands(CRPCTable &t)
 {
     RegisterBlockchainRPCCommands(t);
     RegisterNetRPCCommands(t);
+    RegisterStatsRPCCommands(t);
     RegisterMiscRPCCommands(t);
     RegisterMiningRPCCommands(t);
     RegisterRawTransactionRPCCommands(t);

src/rpc/stats.cpp

@@ -0,0 +1,203 @@
+#include <rpc/stats.h>
+
+#include <rpc/server.h>
+#include <rpc/util.h>
+
+UniValue RPCStats::toJSON() {
+    UniValue stats(UniValue::VOBJ),
+             latencyObj(UniValue::VOBJ),
+             payloadObj(UniValue::VOBJ),
+             historyArr(UniValue::VARR);
+
+    latencyObj.pushKV("min", latency.min);
+    latencyObj.pushKV("avg", latency.avg);
+    latencyObj.pushKV("max", latency.max);
+
+    payloadObj.pushKV("min", payload.min);
+    payloadObj.pushKV("avg", payload.avg);
+    payloadObj.pushKV("max", payload.max);
+
+    for (auto const &entry : history) {
+        UniValue historyObj(UniValue::VOBJ);
+        historyObj.pushKV("timestamp", entry.timestamp);
+        historyObj.pushKV("latency", entry.latency);
+        historyObj.pushKV("payload", entry.payload);
+        historyArr.push_back(historyObj);
+    }
+
+    stats.pushKV("name", name);
+    stats.pushKV("count", count);
+    stats.pushKV("lastUsedTime", lastUsedTime);
+    stats.pushKV("latency", latencyObj);
+    stats.pushKV("payload", payloadObj);
+    stats.pushKV("history", historyArr);
+    return stats;
+}
+
+RPCStats RPCStats::fromJSON(UniValue json) {
+    RPCStats stats;
+
+    stats.name = json["name"].get_str();
+    stats.lastUsedTime = json["lastUsedTime"].get_int64();
+    stats.count = json["count"].get_int64();
+    if (!json["latency"].isNull()) {
+        auto latencyObj  = json["latency"].get_obj();
+        stats.latency = {
+            latencyObj["min"].get_int64(),
+            latencyObj["avg"].get_int64(),
+            latencyObj["max"].get_int64()
+        };
+    }
+
+    if (!json["payload"].isNull()) {
+        auto payloadObj  = json["payload"].get_obj();
+        stats.payload = {
+            payloadObj["min"].get_int64(),
+            payloadObj["avg"].get_int64(),
+            payloadObj["max"].get_int64()
+        };
+    }
+
+    if (!json["history"].isNull()) {
+        auto historyArr = json["history"].get_array();
+        for (const auto &entry : historyArr.getValues()) {
+            auto historyObj = entry.get_obj();
+            StatHistoryEntry historyEntry {
+                historyObj["timestamp"].get_int64(),
+                historyObj["latency"].get_int64(),
+                historyObj["payload"].get_int64()
+            };
+            stats.history.push_back(historyEntry);
+        }
+    }
+    return stats;
+}
+
+void CRPCStats::add(const std::string& name, const int64_t latency, const int64_t payload)
+{
+    auto stats = CRPCStats::get(name);
+    if (stats) {
+        stats->count++;
+        stats->lastUsedTime = GetSystemTimeInSeconds();
+        stats->latency = {
+            std::min(latency, stats->latency.min),
+            stats->latency.avg + (latency - stats->latency.avg) / stats->count,
+            std::max(latency, stats->latency.max)
+        };
+        stats->payload = {
+            std::min(payload, stats->payload.min),
+            stats->payload.avg + (payload - stats->payload.avg) / stats->count,
+            std::max(payload, stats->payload.max)
+        };
+    } else {
+        stats = { name, latency, payload };
+    }
+    stats->history.push_back({ stats->lastUsedTime, latency, payload });
+
+    CLockFreeGuard lock(lock_stats);
+    map[name] = *stats;
+}
+
+UniValue CRPCStats::toJSON() {
+    auto map = CRPCStats::getMap();
+
+    UniValue ret(UniValue::VARR);
+    for (auto &[_, stats] : map) {
+        ret.push_back(stats.toJSON());
+    }
+    return ret;
+}
+
+static UniValue getrpcstats(const JSONRPCRequest& request)
+{
+    RPCHelpMan{"getrpcstats",
+        "\nGet RPC stats for selected command.\n",
+        {
+            {"command", RPCArg::Type::STR, RPCArg::Optional::NO, "The command to get stats for."}
+        },
+        RPCResult{
+            " {\n"
+            "  \"name\":               (string) The RPC command name.\n"
+            "  \"latency\":            (json object) Min, max and average latency.\n"
+            "  \"payload\":            (json object) Min, max and average payload size in bytes.\n"
+            "  \"count\":              (numeric) The number of times this command as been used.\n"
+            "  \"lastUsedTime\":       (numeric) Last used time as timestamp.\n"
+            "  \"history\":            (json array) History of last 5 RPC calls.\n"
+            "  [\n"
+            "       {\n"
+            "           \"timestamp\": (numeric)\n"
+            "           \"latency\":   (numeric)\n"
+            "           \"payload\":   (numeric)\n"
+            "       }\n"
+            "  ]\n"
+            "}"
+        },
+        RPCExamples{
+            HelpExampleCli("getrpcstats", "getblockcount") +
+            HelpExampleRpc("getrpcstats", "\"getblockcount\"")
+        },
+    }.Check(request);
+
+    if (!statsRPC.isActive()) {
+        throw JSONRPCError(RPC_INVALID_REQUEST, "Rpcstats is desactivated.");
+    }
+
+    auto command = request.params[0].get_str();
+    auto stats = statsRPC.get(command);
+    if (!stats) {
+        throw JSONRPCError(RPC_INVALID_PARAMS, "No stats for this command.");
+    }
+    return stats->toJSON();
+}
+
+static UniValue listrpcstats(const JSONRPCRequest& request)
+{
+    RPCHelpMan{"listrpcstats",
+        "\nList used RPC commands.\n",
+        {},
+        RPCResult{
+            "[\n"
+            " {\n"
+            "  \"name\":               (string) The RPC command name.\n"
+            "  \"latency\":            (json object) Min, max and average latency.\n"
+            "  \"payload\":            (json object) Min, max and average payload size in bytes.\n"
+            "  \"count\":              (numeric) The number of times this command as been used.\n"
+            "  \"lastUsedTime\":       (numeric) Last used time as timestamp.\n"
+            "  \"history\":            (json array) History of last 5 RPC calls.\n"
+            "  [\n"
+            "       {\n"
+            "           \"timestamp\": (numeric)\n"
+            "           \"latency\":   (numeric)\n"
+            "           \"payload\":   (numeric)\n"
+            "       }\n"
+            "  ]\n"
+            " }\n"
+            "]"
+        },
+        RPCExamples{
+            HelpExampleCli("listrpcstats", "") +
+            HelpExampleRpc("listrpcstats", "")
+        },
+    }.Check(request);
+
+    if (!statsRPC.isActive()) {
+        throw JSONRPCError(RPC_INVALID_REQUEST, "Rpcstats is desactivated.");
+    }
+
+    return statsRPC.toJSON();
+}
+
+// clang-format off
+static const CRPCCommand commands[] =
+{ //  category              name                      actor (function)         argNames
+  //  --------------------- ------------------------  -----------------------  ----------
+    { "stats",              "getrpcstats",            &getrpcstats,            {"command"} },
+    { "stats",              "listrpcstats",           &listrpcstats,           {} },
+};
+// clang-format on
+
+void RegisterStatsRPCCommands(CRPCTable &t)
+{
+    for (unsigned int vcidx = 0; vcidx < ARRAYLEN(commands); vcidx++)
+        t.appendCommand(commands[vcidx].name, &commands[vcidx]);
+}