Add more debug build logging to IDO MySQL

refs #4603
This commit is contained in:
Michael Friedrich 2017-02-22 16:32:17 +01:00
parent b3e727e1e7
commit 6f1efff46c
1 changed files with 74 additions and 0 deletions

View File

@ -107,6 +107,11 @@ void IdoMysqlConnection::Pause(void)
DbConnection::Pause(); DbConnection::Pause();
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Rescheduling disconnect task.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::Disconnect, this), PriorityHigh); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::Disconnect, this), PriorityHigh);
m_QueryQueue.Join(); m_QueryQueue.Join();
} }
@ -150,6 +155,11 @@ void IdoMysqlConnection::TxTimerHandler(void)
void IdoMysqlConnection::NewTransaction(void) void IdoMysqlConnection::NewTransaction(void)
{ {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling new transaction and finishing async queries.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalNewTransaction, this), PriorityHigh); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalNewTransaction, this), PriorityHigh);
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::FinishAsyncQueries, this), PriorityHigh); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::FinishAsyncQueries, this), PriorityHigh);
} }
@ -167,6 +177,11 @@ void IdoMysqlConnection::InternalNewTransaction(void)
void IdoMysqlConnection::ReconnectTimerHandler(void) void IdoMysqlConnection::ReconnectTimerHandler(void)
{ {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling reconnect task.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::Reconnect, this), PriorityLow); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::Reconnect, this), PriorityLow);
} }
@ -420,6 +435,11 @@ void IdoMysqlConnection::Reconnect(void)
UpdateAllObjects(); UpdateAllObjects();
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling session table clear and finish connect task.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::ClearTablesBySession, this), PriorityLow); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::ClearTablesBySession, this), PriorityLow);
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::FinishConnect, this, startTime), PriorityLow); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::FinishConnect, this, startTime), PriorityLow);
@ -683,6 +703,11 @@ void IdoMysqlConnection::DiscardRows(const IdoMysqlResult& result)
void IdoMysqlConnection::ActivateObject(const DbObject::Ptr& dbobj) void IdoMysqlConnection::ActivateObject(const DbObject::Ptr& dbobj)
{ {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling object activation task for '" << dbobj->GetName1() << "!" << dbobj->GetName2() << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalActivateObject, this, dbobj), PriorityLow); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalActivateObject, this, dbobj), PriorityLow);
} }
@ -717,6 +742,11 @@ void IdoMysqlConnection::InternalActivateObject(const DbObject::Ptr& dbobj)
void IdoMysqlConnection::DeactivateObject(const DbObject::Ptr& dbobj) void IdoMysqlConnection::DeactivateObject(const DbObject::Ptr& dbobj)
{ {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling object deactivation task for '" << dbobj->GetName1() << "!" << dbobj->GetName2() << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalDeactivateObject, this, dbobj), PriorityLow); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalDeactivateObject, this, dbobj), PriorityLow);
} }
@ -817,6 +847,11 @@ void IdoMysqlConnection::ExecuteQuery(const DbQuery& query)
{ {
ASSERT(query.Category != DbCatInvalid); ASSERT(query.Category != DbCatInvalid);
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling execute query task, type " << query.Type << ", table '" << query.Table << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority, true); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority, true);
} }
@ -825,6 +860,11 @@ void IdoMysqlConnection::ExecuteMultipleQueries(const std::vector<DbQuery>& quer
if (queries.empty()) if (queries.empty())
return; return;
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling multiple execute query task, type " << queries[0].Type << ", table '" << queries[0].Table << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteMultipleQueries, this, queries), queries[0].Priority, true); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteMultipleQueries, this, queries), queries[0].Priority, true);
} }
@ -871,6 +911,13 @@ void IdoMysqlConnection::InternalExecuteMultipleQueries(const std::vector<DbQuer
ASSERT(query.Type == DbQueryNewTransaction || query.Category != DbCatInvalid); ASSERT(query.Type == DbQueryNewTransaction || query.Category != DbCatInvalid);
if (!CanExecuteQuery(query)) { if (!CanExecuteQuery(query)) {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling multiple execute query task again: Cannot execute query now. Type '"
<< query.Type << "', table '" << query.Table << "', queue size: '" << GetPendingQueryCount() << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteMultipleQueries, this, queries), query.Priority); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteMultipleQueries, this, queries), query.Priority);
return; return;
} }
@ -902,6 +949,13 @@ void IdoMysqlConnection::InternalExecuteQuery(const DbQuery& query, int typeOver
/* check if there are missing object/insert ids and re-enqueue the query */ /* check if there are missing object/insert ids and re-enqueue the query */
if (!CanExecuteQuery(query)) { if (!CanExecuteQuery(query)) {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling execute query task again: Cannot execute query now. Type '"
<< typeOverride << "', table '" << query.Table << "', queue size: '" << GetPendingQueryCount() << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, typeOverride), query.Priority); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, typeOverride), query.Priority);
return; return;
} }
@ -918,6 +972,13 @@ void IdoMysqlConnection::InternalExecuteQuery(const DbQuery& query, int typeOver
for (const Dictionary::Pair& kv : query.WhereCriteria) { for (const Dictionary::Pair& kv : query.WhereCriteria) {
if (!FieldToEscapedString(kv.first, kv.second, &value)) { if (!FieldToEscapedString(kv.first, kv.second, &value)) {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling execute query task again: Cannot execute query now. Type '"
<< typeOverride << "', table '" << query.Table << "', queue size: '" << GetPendingQueryCount() << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority);
return; return;
} }
@ -990,6 +1051,13 @@ void IdoMysqlConnection::InternalExecuteQuery(const DbQuery& query, int typeOver
continue; continue;
if (!FieldToEscapedString(kv.first, kv.second, &value)) { if (!FieldToEscapedString(kv.first, kv.second, &value)) {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Scheduling execute query task again: Cannot extract required INSERT/UPDATE fields, key '"
<< kv.first << "', val '" << kv.second << "', type " << typeOverride << ", table '" << query.Table << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalExecuteQuery, this, query, -1), query.Priority);
return; return;
} }
@ -1045,6 +1113,12 @@ void IdoMysqlConnection::FinishExecuteQuery(const DbQuery& query, int type, bool
void IdoMysqlConnection::CleanUpExecuteQuery(const String& table, const String& time_column, double max_age) void IdoMysqlConnection::CleanUpExecuteQuery(const String& table, const String& time_column, double max_age)
{ {
#ifdef I2_DEBUG /* I2_DEBUG */
Log(LogDebug, "IdoMysqlConnection")
<< "Rescheduling cleanup query for table '" << table << "' and column '"
<< time_column << "'. max_age is set to '" << max_age << "'.";
#endif /* I2_DEBUG */
m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalCleanUpExecuteQuery, this, table, time_column, max_age), PriorityLow, true); m_QueryQueue.Enqueue(boost::bind(&IdoMysqlConnection::InternalCleanUpExecuteQuery, this, table, time_column, max_age), PriorityLow, true);
} }