feat: OTS Statistics

cmake/modules/CanaryLib.cmake

@@ -57,6 +57,14 @@ if(SPEED_UP_BUILD_UNITY)
     log_option_enabled("Build unity for speed up compilation")
 endif()
 
+# === OTS Statistics ===
+if(NOT DEFINED DISABLE_STATS OR NOT DISABLE_STATS)
+    message(STATUS "OTS stats enabled. Run 'cmake -DDISABLE_STATS=1 ..' to disable")
+    add_definitions(-DSTATS_ENABLED)
+else()
+    message(STATUS "OTS stats disabled. Run 'cmake -DDISABLE_STATS=0 ..' to enable")
+endif()
+
 # *****************************************************************************
 # Target include directories - to allow #include
 # *****************************************************************************

config.lua.dist

@@ -468,3 +468,9 @@ vipFamiliarTimeCooldownReduction = 0
 -- NOTE set rewardChestMaxCollectItems max items per collect action
 rewardChestCollectEnabled = true
 rewardChestMaxCollectItems = 200
+
+-- OTS Statistics (Get more info in: https://github.com/opentibiabr/canary/pull/1692)
+-- NOTE: time in seconds: 30 = 30 seconds, 0 = disabled
+statsDumpInterval = 30
+statsSlowLogTime = 10
+statsVerySlowLogTime = 50

src/canary_server.cpp

@@ -28,6 +28,7 @@
 #include "server/network/webhook/webhook.hpp"
 #include "io/ioprey.hpp"
 #include "io/io_bosstiary.hpp"
+#include "utils\stats.hpp"
 
 #include "core.hpp"
 
@@ -65,6 +66,10 @@ int CanaryServer::run() {
 				setWorldType();
 				loadMaps();
 
+#ifdef STATS_ENABLED
+				g_stats.start();
+#endif
+
 				logger.info("Initializing gamestate...");
 				g_game().setGameState(GAME_STATE_INIT);
 
@@ -111,6 +116,9 @@ int CanaryServer::run() {
 
 	if (loadFailed || !serviceManager.is_running()) {
 		logger.error("No services running. The server is NOT online!");
+#ifdef STATS_ENABLED
+		g_stats.shutdown();
+#endif
 		shutdown();
 		return EXIT_FAILURE;
 	}
@@ -119,6 +127,10 @@ int CanaryServer::run() {
 
 	serviceManager.run();
 
+#ifdef STATS_ENABLED
+	g_stats.join();
+#endif
+
 	shutdown();
 	return EXIT_SUCCESS;
 }

src/config/config_definitions.hpp

@@ -259,6 +259,10 @@ enum integerConfig_t {
 	REWARD_CHEST_MAX_COLLECT_ITEMS,
 	DISCORD_WEBHOOK_DELAY_MS,
 
+	STATS_DUMP_INTERVAL,
+	STATS_SLOW_LOG_TIME,
+	STATS_VERY_SLOW_LOG_TIME,
+
 	LAST_INTEGER_CONFIG
 };
 

src/config/configmanager.cpp

@@ -394,6 +394,10 @@ bool ConfigManager::load() {
 
 	boolean[TOGGLE_RECEIVE_REWARD] = getGlobalBoolean(L, "toggleReceiveReward", false);
 
+	integer[STATS_DUMP_INTERVAL] = getGlobalNumber(L, "statsDumpInterval", 30000);
+	integer[STATS_SLOW_LOG_TIME] = getGlobalNumber(L, "statsSlowLogTime", 10);
+	integer[STATS_VERY_SLOW_LOG_TIME] = getGlobalNumber(L, "statsVerySlowLogTime", 50);
+
 	loaded = true;
 	lua_close(L);
 	return true;

src/database/database.cpp

@@ -12,6 +12,7 @@
 #include "config/configmanager.hpp"
 #include "database/database.hpp"
 #include "lib/di/container.hpp"
+#include "utils\stats.hpp"
 
 Database::~Database() {
 	if (handle != nullptr) {
@@ -123,8 +124,17 @@ bool Database::executeQuery(const std::string_view &query) {
 
 	std::scoped_lock lock { databaseLock };
 
+#ifdef STATS_ENABLED
+	std::chrono::high_resolution_clock::time_point time_point = std::chrono::high_resolution_clock::now();
+#endif
+
 	bool success = retryQuery(query, 10);
 
+#ifdef STATS_ENABLED
+	uint64_t ns = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::high_resolution_clock::now() - time_point).count();
+	g_stats.addSqlStats(new Stat(ns, query.substr(0, 100), query.substr(0, 256)));
+#endif
+
 	mysql_free_result(mysql_store_result(handle));
 	return success;
 }
@@ -138,6 +148,10 @@ DBResult_ptr Database::storeQuery(const std::string_view &query) {
 
 	std::scoped_lock lock { databaseLock };
 
+#ifdef STATS_ENABLED
+	std::chrono::high_resolution_clock::time_point time_point = std::chrono::high_resolution_clock::now();
+#endif
+
 retry:
 	if (mysql_query(handle, query.data()) != 0) {
 		g_logger().error("Query: {}", query);
@@ -149,6 +163,11 @@ DBResult_ptr Database::storeQuery(const std::string_view &query) {
 		goto retry;
 	}
 
+#ifdef STATS_ENABLED
+	uint64_t ns = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::high_resolution_clock::now() - time_point).count();
+	g_stats.addSqlStats(new Stat(ns, query.substr(0, 100), query.substr(0, 256)));
+#endif
+
 	// Retrieving results of query
 	MYSQL_RES* res = mysql_store_result(handle);
 	if (res != nullptr) {

src/game/game.cpp

@@ -365,6 +365,10 @@ void Game::setGameState(GameState_t newState) {
 
 			g_dispatcher().addTask(std::bind(&Game::shutdown, this), "Game::shutdown");
 
+#ifdef STATS_ENABLED
+			g_stats.stop();
+#endif
+
 			break;
 		}
 
@@ -5701,6 +5705,9 @@ void Game::checkCreatures(size_t index) {
 		}
 	}
 	cleanup();
+#ifdef STATS_ENABLED
+	g_stats.playersOnline = getPlayersOnline();
+#endif
 }
 
 void Game::changeSpeed(std::shared_ptr<Creature> creature, int32_t varSpeedDelta) {
@@ -7287,7 +7294,9 @@ void Game::shutdown() {
 	map.spawnsMonster.clear();
 	map.spawnsNpc.clear();
 	raids.clear();
-
+#ifdef STATS_ENABLED
+	g_stats.shutdown();
+#endif
 	cleanup();
 
 	if (serviceManager) {

src/lua/scripts/luascript.cpp

@@ -165,6 +165,15 @@ const std::string &LuaScriptInterface::getFileById(int32_t scriptId) {
 	return it->second;
 }
 
+const std::string &LuaScriptInterface::getFileByIdForStats(int32_t scriptId) {
+	auto it = cacheFiles.find(scriptId);
+	if (it == cacheFiles.end()) {
+		static const std::string &unk = "(Unknown scriptfile)";
+		return unk;
+	}
+	return it->second;
+}
+
 std::string LuaScriptInterface::getStackTrace(const std::string &error_desc) {
 	lua_getglobal(luaState, "debug");
 	if (!isTable(luaState, -1)) {
@@ -227,6 +236,15 @@ bool LuaScriptInterface::closeState() {
 }
 
 bool LuaScriptInterface::callFunction(int params) {
+#ifdef STATS_ENABLED
+	int32_t scriptId;
+	int32_t callbackId;
+	bool timerEvent;
+	LuaScriptInterface* scriptInterface;
+	getScriptEnv()->getEventInfo(scriptId, scriptInterface, callbackId, timerEvent);
+	std::chrono::high_resolution_clock::time_point time_point = std::chrono::high_resolution_clock::now();
+#endif
+
 	bool result = false;
 	int size = lua_gettop(luaState);
 	if (protectedCall(luaState, params, 1) != 0) {
@@ -240,6 +258,11 @@ bool LuaScriptInterface::callFunction(int params) {
 		LuaScriptInterface::reportError(nullptr, "Stack size changed!");
 	}
 
+#ifdef STATS_ENABLED
+	uint64_t ns = std::chrono::duration_cast<std::chrono::nanoseconds>(std::chrono::high_resolution_clock::now() - time_point).count();
+	g_stats.addLuaStats(new Stat(ns, getFileByIdForStats(scriptId), ""));
+#endif
+
 	resetScriptEnv();
 	return result;
 }

src/lua/scripts/luascript.hpp

@@ -28,6 +28,7 @@ class LuaScriptInterface : public LuaFunctionsLoader {
 	int32_t loadFile(const std::string &file, const std::string &scriptName);
 
 	const std::string &getFileById(int32_t scriptId);
+	const std::string &getFileByIdForStats(int32_t scriptId);
 	int32_t getEvent(const std::string &eventName);
 	int32_t getEvent();
 	int32_t getMetaEvent(const std::string &globalName, const std::string &eventName);

src/server/network/protocol/protocolgame.cpp

@@ -240,13 +240,13 @@ ProtocolGame::ProtocolGame(Connection_ptr initConnection) :
 }
 
 template <typename Callable, typename... Args>
-void ProtocolGame::addGameTask(Callable function, Args &&... args) {
-	g_dispatcher().addTask(std::bind(function, &g_game(), std::forward<Args>(args)...), "ProtocolGame::addGameTask");
+void ProtocolGame::addGameTaskWithStats(Callable function, const std::string &function_str, const std::string &extra_info, Args &&... args) {
+	g_dispatcher().addTaskWithStats(std::bind(function, &g_game(), std::forward<Args>(args)...), "ProtocolGame::addGameTaskWithStats", function_str, extra_info);
 }
 
 template <typename Callable, typename... Args>
-void ProtocolGame::addGameTaskTimed(uint32_t delay, std::string context, Callable function, Args &&... args) {
-	g_dispatcher().addTask(std::bind(function, &g_game(), std::forward<Args>(args)...), context, delay);
+void ProtocolGame::addGameTaskTimedWithStats(uint32_t delay, std::string context, Callable function, const std::string &function_str, const std::string &extra_info, Args &&... args) {
+	g_dispatcher().addTaskWithStats(std::bind(function, &g_game(), std::forward<Args>(args)...), context, delay, function_str, extra_info);
 }
 
 void ProtocolGame::AddItem(NetworkMessage &msg, uint16_t id, uint8_t count, uint8_t tier) {

src/server/network/protocol/protocolgame.hpp

@@ -70,9 +70,9 @@ class ProtocolGame final : public Protocol {
 private:
 	// Helpers so we don't need to bind every time
 	template <typename Callable, typename... Args>
-	void addGameTask(Callable function, Args &&... args);
+	void addGameTaskWithStats(Callable function, const std::string &function_str, const std::string &extra_info, Args &&... args);
 	template <typename Callable, typename... Args>
-	void addGameTaskTimed(uint32_t delay, std::string context, Callable function, Args &&... args);
+	void addGameTaskTimedWithStats(uint32_t delay, std::string context, Callable function, const std::string &function_str, const std::string &extra_info, Args &&... args);
 
 	ProtocolGame_ptr getThis() {
 		return std::static_pointer_cast<ProtocolGame>(shared_from_this());

src/utils/CMakeLists.txt

@@ -1,4 +1,5 @@
 target_sources(${PROJECT_NAME}_lib PRIVATE
+    stats.cpp
     pugicast.cpp
     tools.cpp
     wildcardtree.cpp

vcproj/canary.vcxproj

@@ -218,6 +218,7 @@
     <ClInclude Include="..\src\utils\hash.hpp" />
     <ClInclude Include="..\src\utils\pugicast.hpp" />
     <ClInclude Include="..\src\utils\simd.hpp" />
+    <ClInclude Include="..\src\utils\stats.hpp" />
     <ClInclude Include="..\src\utils\tools.hpp" />
     <ClInclude Include="..\src\utils\utils_definitions.hpp" />
     <ClInclude Include="..\src\utils\vectorset.hpp" />
@@ -398,6 +399,7 @@
     <ClCompile Include="..\src\server\network\webhook\webhook.cpp" />
     <ClCompile Include="..\src\server\server.cpp" />
     <ClCompile Include="..\src\server\signals.cpp" />
+    <ClCompile Include="..\src\utils\stats.cpp" />
     <ClCompile Include="..\src\utils\pugicast.cpp" />
     <ClCompile Include="..\src\utils\tools.cpp" />
     <ClCompile Include="..\src\utils\wildcardtree.cpp" />