From 82c3827b66a762d9ba8e41184f10808ba25468b2 Mon Sep 17 00:00:00 2001 From: "Alexander A. Klimov" Date: Wed, 10 Feb 2021 16:54:07 +0100 Subject: [PATCH] RedisConnection: log actual query performance --- lib/icingadb/redisconnection.cpp | 61 +++++++++++++++++++++++++++++++- lib/icingadb/redisconnection.hpp | 12 +++++++ 2 files changed, 72 insertions(+), 1 deletion(-) diff --git a/lib/icingadb/redisconnection.cpp b/lib/icingadb/redisconnection.cpp index a605e7967..3536abadc 100644 --- a/lib/icingadb/redisconnection.cpp +++ b/lib/icingadb/redisconnection.cpp @@ -9,6 +9,7 @@ #include "base/objectlock.hpp" #include "base/string.hpp" #include "base/tcpsocket.hpp" +#include "base/utility.hpp" #include #include #include @@ -30,7 +31,8 @@ RedisConnection::RedisConnection(const String& host, const int port, const Strin RedisConnection::RedisConnection(boost::asio::io_context& io, String host, int port, String path, String password, int db) : m_Host(std::move(host)), m_Port(port), m_Path(std::move(path)), m_Password(std::move(password)), m_DbIndex(db), - m_Connecting(false), m_Connected(false), m_Started(false), m_Strand(io), m_QueuedWrites(io), m_QueuedReads(io) + m_Connecting(false), m_Connected(false), m_Started(false), m_Strand(io), + m_QueuedWrites(io), m_QueuedReads(io), m_LogStatsTimer(io) { } @@ -41,6 +43,7 @@ void RedisConnection::Start() IoEngine::SpawnCoroutine(m_Strand, [this, keepAlive](asio::yield_context yc) { ReadLoop(yc); }); IoEngine::SpawnCoroutine(m_Strand, [this, keepAlive](asio::yield_context yc) { WriteLoop(yc); }); + IoEngine::SpawnCoroutine(m_Strand, [this, keepAlive](asio::yield_context yc) { LogStats(yc); }); } if (!m_Connecting.exchange(true)) { @@ -97,6 +100,7 @@ void RedisConnection::FireAndForgetQuery(RedisConnection::Query query, RedisConn asio::post(m_Strand, [this, item, priority]() { m_Queues.Writes[priority].emplace(WriteQueueItem{item, nullptr, nullptr, nullptr}); m_QueuedWrites.Set(); + IncreasePendingQueries(1); }); } @@ -118,6 +122,7 @@ void RedisConnection::FireAndForgetQueries(RedisConnection::Queries queries, Red asio::post(m_Strand, [this, item, priority]() { m_Queues.Writes[priority].emplace(WriteQueueItem{nullptr, item, nullptr, nullptr}); m_QueuedWrites.Set(); + IncreasePendingQueries(item->size()); }); } @@ -143,6 +148,7 @@ RedisConnection::Reply RedisConnection::GetResultOfQuery(RedisConnection::Query asio::post(m_Strand, [this, item, priority]() { m_Queues.Writes[priority].emplace(WriteQueueItem{nullptr, nullptr, item, nullptr}); m_QueuedWrites.Set(); + IncreasePendingQueries(1); }); item = nullptr; @@ -172,6 +178,7 @@ RedisConnection::Replies RedisConnection::GetResultsOfQueries(RedisConnection::Q asio::post(m_Strand, [this, item, priority]() { m_Queues.Writes[priority].emplace(WriteQueueItem{nullptr, nullptr, nullptr, item}); m_QueuedWrites.Set(); + IncreasePendingQueries(item->first.size()); }); item = nullptr; @@ -379,6 +386,41 @@ void RedisConnection::WriteLoop(asio::yield_context& yc) } } +/** + * Periodically log current query performance + */ +void RedisConnection::LogStats(asio::yield_context& yc) +{ + double lastMessage = 0; + + m_LogStatsTimer.expires_from_now(boost::posix_time::seconds(10)); + + for (;;) { + m_LogStatsTimer.async_wait(yc); + m_LogStatsTimer.expires_from_now(boost::posix_time::seconds(10)); + + if (!IsConnected()) + continue; + + auto now (Utility::GetTime()); + bool timeoutReached = now - lastMessage >= 5 * 60; + + if (m_PendingQueries < 1 && !timeoutReached) + continue; + + auto output (round(m_OutputQueries.CalculateRate(now, 10))); + + if (m_PendingQueries < output * 5 && !timeoutReached) + continue; + + Log(LogInformation, "IcingaDB") + << "Pending queries: " << m_PendingQueries << " (Input: " + << round(m_InputQueries.CalculateRate(now, 10)) << "/s; Output: " << output << "/s)"; + + lastMessage = now; + } +} + /** * Send next and schedule receiving the response * @@ -388,6 +430,7 @@ void RedisConnection::WriteItem(boost::asio::yield_context& yc, RedisConnection: { if (next.FireAndForgetQuery) { auto& item (*next.FireAndForgetQuery); + DecreasePendingQueries(1); try { WriteOne(item, yc); @@ -420,6 +463,8 @@ void RedisConnection::WriteItem(boost::asio::yield_context& yc, RedisConnection: auto& item (*next.FireAndForgetQueries); size_t i = 0; + DecreasePendingQueries(item.size()); + try { for (auto& query : item) { WriteOne(query, yc); @@ -452,6 +497,7 @@ void RedisConnection::WriteItem(boost::asio::yield_context& yc, RedisConnection: if (next.GetResultOfQuery) { auto& item (*next.GetResultOfQuery); + DecreasePendingQueries(1); try { WriteOne(item.first, yc); @@ -476,6 +522,7 @@ void RedisConnection::WriteItem(boost::asio::yield_context& yc, RedisConnection: if (next.GetResultsOfQueries) { auto& item (*next.GetResultsOfQueries); + DecreasePendingQueries(item.first.size()); try { for (auto& query : item.first) { @@ -538,3 +585,15 @@ void RedisConnection::WriteOne(RedisConnection::Query& query, asio::yield_contex void RedisConnection::SetConnectedCallback(std::function callback) { m_ConnectedCallback = std::move(callback); } + +void RedisConnection::IncreasePendingQueries(int count) +{ + m_PendingQueries += count; + m_InputQueries.InsertValue(Utility::GetTime(), count); +} + +void RedisConnection::DecreasePendingQueries(int count) +{ + m_PendingQueries -= count; + m_OutputQueries.InsertValue(Utility::GetTime(), count); +} diff --git a/lib/icingadb/redisconnection.hpp b/lib/icingadb/redisconnection.hpp index bf580405b..cea198ad9 100644 --- a/lib/icingadb/redisconnection.hpp +++ b/lib/icingadb/redisconnection.hpp @@ -7,11 +7,13 @@ #include "base/atomic.hpp" #include "base/io-engine.hpp" #include "base/object.hpp" +#include "base/ringbuffer.hpp" #include "base/shared.hpp" #include "base/string.hpp" #include "base/value.hpp" #include #include +#include #include #include #include @@ -146,6 +148,7 @@ namespace icinga void Connect(boost::asio::yield_context& yc); void ReadLoop(boost::asio::yield_context& yc); void WriteLoop(boost::asio::yield_context& yc); + void LogStats(boost::asio::yield_context& yc); void WriteItem(boost::asio::yield_context& yc, WriteQueueItem item); Reply ReadOne(boost::asio::yield_context& yc); void WriteOne(Query& query, boost::asio::yield_context& yc); @@ -156,6 +159,9 @@ namespace icinga template void WriteOne(StreamPtr& stream, Query& query, boost::asio::yield_context& yc); + void IncreasePendingQueries(int count); + void DecreasePendingQueries(int count); + String m_Path; String m_Host; int m_Port; @@ -185,6 +191,12 @@ namespace icinga AsioConditionVariable m_QueuedWrites, m_QueuedReads; std::function m_ConnectedCallback; + + // Stats + RingBuffer m_InputQueries{10}; + RingBuffer m_OutputQueries{10}; + int m_PendingQueries{0}; + boost::asio::deadline_timer m_LogStatsTimer; }; /**