From 30c445a5ee678d5a785785ea37b76ea0f5fabc1b Mon Sep 17 00:00:00 2001 From: Gunnar Beutner Date: Wed, 16 Dec 2015 08:49:47 +0100 Subject: [PATCH] Implement additional query statistics for DB IDO fixes #10860 --- lib/db_ido/dbconnection.cpp | 35 ++++++++++++++++++++++++- lib/db_ido/dbconnection.hpp | 5 ++++ lib/db_ido_mysql/idomysqlconnection.cpp | 12 +++++++++ lib/db_ido_mysql/idomysqlconnection.hpp | 2 ++ lib/db_ido_pgsql/idopgsqlconnection.cpp | 10 +++++++ lib/db_ido_pgsql/idopgsqlconnection.hpp | 4 +++ 6 files changed, 67 insertions(+), 1 deletion(-) diff --git a/lib/db_ido/dbconnection.cpp b/lib/db_ido/dbconnection.cpp index 81fb681ed..919ef3959 100644 --- a/lib/db_ido/dbconnection.cpp +++ b/lib/db_ido/dbconnection.cpp @@ -39,7 +39,7 @@ Timer::Ptr DbConnection::m_ProgramStatusTimer; boost::once_flag DbConnection::m_OnceFlag = BOOST_ONCE_INIT; DbConnection::DbConnection(void) - : m_QueryStats(15 * 60) + : m_QueryStats(15 * 60), m_PendingQueries(0), m_PendingQueriesTimestamp(0) { } void DbConnection::OnConfigLoaded(void) @@ -65,6 +65,34 @@ void DbConnection::Start(bool runtimeCreated) ConfigObject::OnActiveChanged.connect(boost::bind(&DbConnection::UpdateObject, this, _1)); } +void DbConnection::StatsLoggerTimerHandler(void) +{ + int pending = GetPendingQueryCount(); + + double now = Utility::GetTime(); + double gradient = (pending - m_PendingQueries) / (now - m_PendingQueriesTimestamp); + double timeToZero = -pending / gradient; + + String timeInfo; + + if (pending > GetQueryCount(5)) { + timeInfo = " empty in "; + if (timeToZero < 0) + timeInfo += "infinite time, your database isn't able to keep up"; + else + timeInfo += Utility::FormatDuration(timeToZero); + } + + m_PendingQueries = pending; + m_PendingQueriesTimestamp = now; + + Log(LogInformation, GetReflectionType()->GetName()) + << "Query queue items: " << pending + << ", query rate: " << std::setw(2) << GetQueryCount(60) / 60.0 << "/s" + << " (" << GetQueryCount(60) << "/min " << GetQueryCount(5 * 60) << "/5min " << GetQueryCount(15 * 60) << "/15min);" + << timeInfo; +} + void DbConnection::Resume(void) { ConfigObject::Resume(); @@ -76,6 +104,11 @@ void DbConnection::Resume(void) m_CleanUpTimer->SetInterval(60); m_CleanUpTimer->OnTimerExpired.connect(boost::bind(&DbConnection::CleanUpHandler, this)); m_CleanUpTimer->Start(); + + m_StatsLoggerTimer = new Timer(); + m_StatsLoggerTimer->SetInterval(15); + m_StatsLoggerTimer->OnTimerExpired.connect(boost::bind(&DbConnection::StatsLoggerTimerHandler, this)); + m_StatsLoggerTimer->Start(); } void DbConnection::Pause(void) diff --git a/lib/db_ido/dbconnection.hpp b/lib/db_ido/dbconnection.hpp index e93c6b297..63c12489c 100644 --- a/lib/db_ido/dbconnection.hpp +++ b/lib/db_ido/dbconnection.hpp @@ -114,11 +114,16 @@ private: static Timer::Ptr m_ProgramStatusTimer; static boost::once_flag m_OnceFlag; + Timer::Ptr m_StatsLoggerTimer; + void StatsLoggerTimerHandler(void); + static void InsertRuntimeVariable(const String& key, const Value& value); static void ProgramStatusHandler(void); mutable boost::mutex m_StatsMutex; RingBuffer m_QueryStats; + int m_PendingQueries; + double m_PendingQueriesTimestamp; }; struct database_error : virtual std::exception, virtual boost::exception { }; diff --git a/lib/db_ido_mysql/idomysqlconnection.cpp b/lib/db_ido_mysql/idomysqlconnection.cpp index 5b1bfd057..a7ec5459e 100644 --- a/lib/db_ido_mysql/idomysqlconnection.cpp +++ b/lib/db_ido_mysql/idomysqlconnection.cpp @@ -387,6 +387,18 @@ void IdoMysqlConnection::Reconnect(void) ClearCustomVarTable("customvariables"); ClearCustomVarTable("customvariablestatus"); + m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::FinishConnect, this, startTime), PriorityLow); +} + +void IdoMysqlConnection::FinishConnect(double startTime) +{ + AssertOnWorkQueue(); + + if (!GetConnected()) + return; + + FinishAsyncQueries(); + Log(LogInformation, "IdoMysqlConnection") << "Finished reconnecting to MySQL IDO database in " << std::setw(2) << Utility::GetTime() - startTime << " second(s)."; diff --git a/lib/db_ido_mysql/idomysqlconnection.hpp b/lib/db_ido_mysql/idomysqlconnection.hpp index 71fbc4a6e..5823e33e3 100644 --- a/lib/db_ido_mysql/idomysqlconnection.hpp +++ b/lib/db_ido_mysql/idomysqlconnection.hpp @@ -118,6 +118,8 @@ private: void ClearCustomVarTable(const String& table); void ExceptionHandler(boost::exception_ptr exp); + + void FinishConnect(double startTime); }; } diff --git a/lib/db_ido_pgsql/idopgsqlconnection.cpp b/lib/db_ido_pgsql/idopgsqlconnection.cpp index eb5bce15f..581a20a70 100644 --- a/lib/db_ido_pgsql/idopgsqlconnection.cpp +++ b/lib/db_ido_pgsql/idopgsqlconnection.cpp @@ -377,6 +377,16 @@ void IdoPgsqlConnection::Reconnect(void) ClearCustomVarTable("customvariables"); ClearCustomVarTable("customvariablestatus"); + m_QueryQueue.Enqueue(boost::bind(&IdoPgsqlConnection::FinishConnect, this, startTime), PriorityLow); +} + +void IdoPgsqlConnection::FinishConnect(double startTime) +{ + AssertOnWorkQueue(); + + if (!GetConnected()) + return; + Log(LogInformation, "IdoPgsqlConnection") << "Finished reconnecting to PostgreSQL IDO database in " << std::setw(2) << Utility::GetTime() - startTime << " second(s)."; diff --git a/lib/db_ido_pgsql/idopgsqlconnection.hpp b/lib/db_ido_pgsql/idopgsqlconnection.hpp index d0e2e5673..cdf789ff7 100644 --- a/lib/db_ido_pgsql/idopgsqlconnection.hpp +++ b/lib/db_ido_pgsql/idopgsqlconnection.hpp @@ -91,6 +91,8 @@ private: void TxTimerHandler(void); void ReconnectTimerHandler(void); + void StatsLoggerTimerHandler(void); + bool CanExecuteQuery(const DbQuery& query); void InternalExecuteQuery(const DbQuery& query, DbQueryType *typeOverride = NULL); @@ -101,6 +103,8 @@ private: void ClearCustomVarTable(const String& table); void ExceptionHandler(boost::exception_ptr exp); + + void FinishConnect(double startTime); }; } -- 2.40.0