Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log request and duration for every RPC call #4036

Closed
wants to merge 1 commit into from
Closed
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 26 additions & 0 deletions src/ripple/rpc/impl/ServerHandlerImp.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -377,6 +377,25 @@ ServerHandlerImp::onStopped(Server&)

//------------------------------------------------------------------------------

template <class T>
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<std::chrono::microseconds>(
duration)
.count()
<< " microseconds. request = " << request;
}

Json::Value
ServerHandlerImp::processSession(
std::shared_ptr<WSSession> const& session,
Expand Down Expand Up @@ -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);
Comment on lines +480 to +483
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If this pattern is used in more places, it might be worth investing in a helper class that uses RAII in the style of scope_guard.

}
}
catch (std::exception const& ex)
Expand Down Expand Up @@ -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;
Expand Down