diff --git a/src/ripple/rpc/impl/ServerHandlerImp.cpp b/src/ripple/rpc/impl/ServerHandlerImp.cpp index 6fccb89cc5..3aed453828 100644 --- a/src/ripple/rpc/impl/ServerHandlerImp.cpp +++ b/src/ripple/rpc/impl/ServerHandlerImp.cpp @@ -377,6 +377,25 @@ ServerHandlerImp::onStopped(Server&) //------------------------------------------------------------------------------ +template +void +logDuration( + Json::Value const& request, + T const& duration, + beast::Journal& journal) +{ + using namespace std::chrono_literals; + auto const level = (duration >= 10s) + ? journal.error() + : (duration >= 1s) ? journal.warn() : journal.debug(); + + JLOG(level) << "RPC request processing duration = " + << std::chrono::duration_cast( + duration) + .count() + << " microseconds. request = " << request; +} + Json::Value ServerHandlerImp::processSession( std::shared_ptr const& session, @@ -458,7 +477,10 @@ ServerHandlerImp::processSession( jv, {is->user(), is->forwarded_for()}}; + auto start = std::chrono::system_clock::now(); RPC::doCommand(context, jr[jss::result]); + auto end = std::chrono::system_clock::now(); + logDuration(jv, end - start, m_journal); } } catch (std::exception const& ex) @@ -851,7 +873,11 @@ ServerHandlerImp::processRequest( params, {user, forwardedFor}}; Json::Value result; + auto start = std::chrono::system_clock::now(); RPC::doCommand(context, result); + auto end = std::chrono::system_clock::now(); + logDuration(params, end - start, m_journal); + usage.charge(loadType); if (usage.warn()) result[jss::warning] = jss::load;