Benchmark message reading/waiting/processing time per endpoint

This commit is contained in:
Alexander A. Klimov 2024-12-10 15:59:10 +01:00 committed by Alvar Penning
parent 3c201fa605
commit 9f783baeb1
No known key found for this signature in database
2 changed files with 32 additions and 0 deletions

View File

@ -5,6 +5,7 @@
#include "remote/i2-remote.hpp" #include "remote/i2-remote.hpp"
#include "remote/endpoint-ti.hpp" #include "remote/endpoint-ti.hpp"
#include "base/benchmark.hpp"
#include "base/ringbuffer.hpp" #include "base/ringbuffer.hpp"
#include <set> #include <set>
@ -43,6 +44,14 @@ public:
void AddMessageSent(int bytes); void AddMessageSent(int bytes);
void AddMessageReceived(int bytes); void AddMessageReceived(int bytes);
template<class R, class S, class P>
void AddInputTimes(const R& readTime, const S& semaphoreTime, const P& processTime)
{
m_InputReadTime += readTime;
m_InputSemaphoreTime += semaphoreTime;
m_InputProcessTime += processTime;
}
double GetMessagesSentPerSecond() const override; double GetMessagesSentPerSecond() const override;
double GetMessagesReceivedPerSecond() const override; double GetMessagesReceivedPerSecond() const override;
@ -61,6 +70,10 @@ private:
mutable RingBuffer m_MessagesReceived{60}; mutable RingBuffer m_MessagesReceived{60};
mutable RingBuffer m_BytesSent{60}; mutable RingBuffer m_BytesSent{60};
mutable RingBuffer m_BytesReceived{60}; mutable RingBuffer m_BytesReceived{60};
Benchmark m_InputReadTime;
Benchmark m_InputSemaphoreTime;
Benchmark m_InputProcessTime;
}; };
} }

View File

@ -3,6 +3,7 @@
#include "remote/jsonrpcconnection.hpp" #include "remote/jsonrpcconnection.hpp"
#include "remote/apilistener.hpp" #include "remote/apilistener.hpp"
#include "remote/apifunction.hpp" #include "remote/apifunction.hpp"
#include "base/benchmark.hpp"
#include "remote/jsonrpc.hpp" #include "remote/jsonrpc.hpp"
#include "base/defer.hpp" #include "base/defer.hpp"
#include "base/configtype.hpp" #include "base/configtype.hpp"
@ -66,11 +67,17 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
return ch::duration_cast<ch::milliseconds>(d).count(); return ch::duration_cast<ch::milliseconds>(d).count();
}); });
Benchmark::Clock::time_point readStarted, readFinished, processingStarted;
m_Stream->next_layer().SetSeen(&m_Seen); m_Stream->next_layer().SetSeen(&m_Seen);
while (!m_ShuttingDown) { while (!m_ShuttingDown) {
String jsonString; String jsonString;
if (m_Endpoint) {
readStarted = Benchmark::Clock::now();
}
try { try {
jsonString = JsonRpc::ReadMessage(m_Stream, yc, m_Endpoint ? -1 : 1024 * 1024); jsonString = JsonRpc::ReadMessage(m_Stream, yc, m_Endpoint ? -1 : 1024 * 1024);
} catch (const std::exception& ex) { } catch (const std::exception& ex) {
@ -81,6 +88,10 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
break; break;
} }
if (m_Endpoint) {
readFinished = Benchmark::Clock::now();
}
m_Seen = Utility::GetTime(); m_Seen = Utility::GetTime();
if (m_Endpoint) { if (m_Endpoint) {
m_Endpoint->AddMessageReceived(jsonString.GetLength()); m_Endpoint->AddMessageReceived(jsonString.GetLength());
@ -96,6 +107,10 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
// Cache the elapsed time to acquire a CPU semaphore used to detect extremely heavy workloads. // Cache the elapsed time to acquire a CPU semaphore used to detect extremely heavy workloads.
cpuBoundDuration = ch::steady_clock::now() - start; cpuBoundDuration = ch::steady_clock::now() - start;
if (m_Endpoint) {
processingStarted = Benchmark::Clock::now();
}
Dictionary::Ptr message = JsonRpc::DecodeMessage(jsonString); Dictionary::Ptr message = JsonRpc::DecodeMessage(jsonString);
if (String method = message->Get("method"); !method.IsEmpty()) { if (String method = message->Get("method"); !method.IsEmpty()) {
rpcMethod = std::move(method); rpcMethod = std::move(method);
@ -103,6 +118,10 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
MessageHandler(message); MessageHandler(message);
if (m_Endpoint) {
m_Endpoint->AddInputTimes(readFinished - readStarted, cpuBoundDuration, processingStarted);
}
l_TaskStats.InsertValue(Utility::GetTime(), 1); l_TaskStats.InsertValue(Utility::GetTime(), 1);
auto total = ch::steady_clock::now() - start; auto total = ch::steady_clock::now() - start;