Merge pull request #4529 from LandSandBoat/sql_slow_query_logging

[core] Add options for logging slow SQL queries
LandSandBoat · Sep 20, 2023 · 792df51 · 792df51
2 parents ee4997f + 55eacf8
commit 792df51
Show file tree

Hide file tree

Showing 3 changed files with 22 additions and 8 deletions.
diff --git a/settings/default/logging.lua b/settings/default/logging.lua
@@ -54,4 +54,8 @@ xi.settings.logging =
     DEBUG_MODULES        = false, -- Calls in C++: DebugModules(...)
     DEBUG_PACKET_BACKLOG = false, -- Special logic in map.cpp::send_parse
     DEBUG_DELIVERY_BOX   = false, -- Special logic in packet_system.cpp::SmallPacket0x04D
+
+    SQL_SLOW_QUERY_LOG_ENABLE   = true, -- true/false. If true, slow SQL queries will generate warning or error logs if they exceed the durations listed below.
+    SQL_SLOW_QUERY_WARNING_TIME = 100,  -- uint (milliseconds).
+    SQL_SLOW_QUERY_ERROR_TIME   = 250,  -- uint (milliseconds).
 }
diff --git a/src/common/sql.cpp b/src/common/sql.cpp
@@ -34,19 +34,24 @@
 #include <string>
 #include <thread>
 
+// TODO: Since kernel.cpp isn't used by the processes which now use Application, we can't
+//     : store this global flag there. So we're storing it here until all processes are
+//     : refactored to use Application. Once that's done this should be moved out of static
+//     : storage in this unit to a member of Application.
+std::atomic<bool> gProcessLoaded = false;
+
 SqlConnection::SqlConnection()
 : SqlConnection(settings::get<std::string>("network.SQL_LOGIN").c_str(),
                 settings::get<std::string>("network.SQL_PASSWORD").c_str(),
                 settings::get<std::string>("network.SQL_HOST").c_str(),
                 settings::get<uint16>("network.SQL_PORT"),
                 settings::get<std::string>("network.SQL_DATABASE").c_str())
 {
-    // Just forwarding the default credentials to the next contrictor
+    // Just forwarding the default credentials to the next constructor
 }
 
 SqlConnection::SqlConnection(const char* user, const char* passwd, const char* host, uint16 port, const char* db)
-: m_LatencyWarning(false)
-, m_ThreadId(std::this_thread::get_id())
+: m_ThreadId(std::this_thread::get_id())
 {
     TracyZoneScoped;
 
@@ -335,15 +340,16 @@ int32 SqlConnection::QueryStr(const char* query)
 
     auto endTime = hires_clock::now();
     auto dTime   = std::chrono::duration_cast<std::chrono::milliseconds>(endTime - startTime);
-    if (m_LatencyWarning)
+
+    if (gProcessLoaded && settings::get<bool>("logging.SQL_SLOW_QUERY_LOG_ENABLE"))
     {
-        if (dTime > 250ms)
+        if (dTime > std::chrono::milliseconds(settings::get<uint32>("logging.SQL_SLOW_QUERY_ERROR_TIME")))
         {
-            ShowError(fmt::format("Query took {}ms: {}", dTime.count(), self->buf));
+            ShowError(fmt::format("SQL query took {}ms: {}", dTime.count(), self->buf));
         }
-        else if (dTime > 100ms)
+        else if (dTime > std::chrono::milliseconds(settings::get<uint32>("logging.SQL_SLOW_QUERY_WARNING_TIME")))
         {
-            ShowWarning(fmt::format("Query took {}ms: {}", dTime.count(), self->buf));
+            ShowWarning(fmt::format("SQL query took {}ms: {}", dTime.count(), self->buf));
         }
     }
 

diff --git a/src/map/map.cpp b/src/map/map.cpp
@@ -99,6 +99,8 @@ bool gLoadAllLua = false;
 
 std::unordered_map<uint32, std::unordered_map<uint16, std::vector<std::pair<uint16, uint8>>>> PacketMods;
 
+extern std::atomic<bool> gProcessLoaded;
+
 namespace
 {
     uint32 MAX_BUFFER_SIZE             = 2500U;
@@ -369,6 +371,8 @@ int32 do_init(int32 argc, char** argv)
     });
     // clang-format on
 
+    gProcessLoaded = true;
+
     return 0;
 }