From 9f783baeb1d04515c6ef5d9543c4e9905538b5b3 Mon Sep 17 00:00:00 2001
From: "Alexander A. Klimov" <alexander.klimov@icinga.com>
Date: Tue, 10 Dec 2024 15:59:10 +0100
Subject: [PATCH] Benchmark message reading/waiting/processing time per
 endpoint

---
 lib/remote/endpoint.hpp          | 13 +++++++++++++
 lib/remote/jsonrpcconnection.cpp | 19 +++++++++++++++++++
 2 files changed, 32 insertions(+)

diff --git a/lib/remote/endpoint.hpp b/lib/remote/endpoint.hpp
index d641c2c6b..737a8d626 100644
--- a/lib/remote/endpoint.hpp
+++ b/lib/remote/endpoint.hpp
@@ -5,6 +5,7 @@
 
 #include "remote/i2-remote.hpp"
 #include "remote/endpoint-ti.hpp"
+#include "base/benchmark.hpp"
 #include "base/ringbuffer.hpp"
 #include <set>
 
@@ -43,6 +44,14 @@ public:
 	void AddMessageSent(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 GetMessagesReceivedPerSecond() const override;
 
@@ -61,6 +70,10 @@ private:
 	mutable RingBuffer m_MessagesReceived{60};
 	mutable RingBuffer m_BytesSent{60};
 	mutable RingBuffer m_BytesReceived{60};
+
+	Benchmark m_InputReadTime;
+	Benchmark m_InputSemaphoreTime;
+	Benchmark m_InputProcessTime;
 };
 
 }
diff --git a/lib/remote/jsonrpcconnection.cpp b/lib/remote/jsonrpcconnection.cpp
index b8ae22aaa..1acc8b714 100644
--- a/lib/remote/jsonrpcconnection.cpp
+++ b/lib/remote/jsonrpcconnection.cpp
@@ -3,6 +3,7 @@
 #include "remote/jsonrpcconnection.hpp"
 #include "remote/apilistener.hpp"
 #include "remote/apifunction.hpp"
+#include "base/benchmark.hpp"
 #include "remote/jsonrpc.hpp"
 #include "base/defer.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();
 	});
 
+	Benchmark::Clock::time_point readStarted, readFinished, processingStarted;
+
 	m_Stream->next_layer().SetSeen(&m_Seen);
 
 	while (!m_ShuttingDown) {
 		String jsonString;
 
+		if (m_Endpoint) {
+			readStarted = Benchmark::Clock::now();
+		}
+
 		try {
 			jsonString = JsonRpc::ReadMessage(m_Stream, yc, m_Endpoint ? -1 : 1024 * 1024);
 		} catch (const std::exception& ex) {
@@ -81,6 +88,10 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
 			break;
 		}
 
+		if (m_Endpoint) {
+			readFinished = Benchmark::Clock::now();
+		}
+
 		m_Seen = Utility::GetTime();
 		if (m_Endpoint) {
 			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.
 			cpuBoundDuration = ch::steady_clock::now() - start;
 
+			if (m_Endpoint) {
+				processingStarted = Benchmark::Clock::now();
+			}
+
 			Dictionary::Ptr message = JsonRpc::DecodeMessage(jsonString);
 			if (String method = message->Get("method"); !method.IsEmpty()) {
 				rpcMethod = std::move(method);
@@ -103,6 +118,10 @@ void JsonRpcConnection::HandleIncomingMessages(boost::asio::yield_context yc)
 
 			MessageHandler(message);
 
+			if (m_Endpoint) {
+				m_Endpoint->AddInputTimes(readFinished - readStarted, cpuBoundDuration, processingStarted);
+			}
+
 			l_TaskStats.InsertValue(Utility::GetTime(), 1);
 
 			auto total = ch::steady_clock::now() - start;