From c2681eead1c07382845c976be5dffb67999da8ef Mon Sep 17 00:00:00 2001 From: Kelsi Date: Sun, 5 Apr 2026 20:18:39 -0700 Subject: [PATCH] refactor: downgrade shutdown, warden, and misc diagnostics to DEBUG Demote 44 more LOG_WARNING messages to LOG_DEBUG: warden module chunk progress, entire shutdown/teardown sequence, transport manager connect, inventory right-click slot, and warden handshake diagnostics. Keeps real warnings (texture not found, slow handlers, stalls, integrity hash) visible in the log. --- src/core/application.cpp | 24 ++++++++++++------------ src/core/window.cpp | 10 ++++------ src/core/world_loader.cpp | 2 +- src/game/warden_handler.cpp | 14 +++++++------- src/rendering/renderer.cpp | 20 ++++++++++---------- src/rendering/terrain_manager.cpp | 8 ++++---- src/rendering/vk_context.cpp | 10 +++++----- src/ui/inventory_screen.cpp | 2 +- 8 files changed, 44 insertions(+), 46 deletions(-) diff --git a/src/core/application.cpp b/src/core/application.cpp index e8ca5c93..9b8fd3b4 100644 --- a/src/core/application.cpp +++ b/src/core/application.cpp @@ -834,7 +834,7 @@ void Application::run() { } void Application::shutdown() { - LOG_WARNING("Shutting down application..."); + LOG_DEBUG("Shutting down application..."); // Hide the window immediately so the OS doesn't think the app is frozen // during the (potentially slow) resource cleanup below. @@ -851,20 +851,20 @@ void Application::shutdown() { if (renderer && renderer->getWMORenderer()) { size_t cacheSize = renderer->getWMORenderer()->getFloorCacheSize(); if (cacheSize > 0) { - LOG_WARNING("Saving WMO floor cache (", cacheSize, " entries)..."); + LOG_DEBUG("Saving WMO floor cache (", cacheSize, " entries)..."); renderer->getWMORenderer()->saveFloorCache(); - LOG_WARNING("Floor cache saved."); + LOG_DEBUG("Floor cache saved."); } } // Explicitly shut down the renderer before destroying it — this ensures // all sub-renderers free their VMA allocations in the correct order, // before VkContext::shutdown() calls vmaDestroyAllocator(). - LOG_WARNING("Shutting down renderer..."); + LOG_DEBUG("Shutting down renderer..."); if (renderer) { renderer->shutdown(); } - LOG_WARNING("Renderer shutdown complete, resetting..."); + LOG_DEBUG("Renderer shutdown complete, resetting..."); renderer.reset(); // Shutdown audio coordinator after renderer (renderer may reference audio during shutdown) @@ -873,22 +873,22 @@ void Application::shutdown() { } audioCoordinator_.reset(); - LOG_WARNING("Resetting world..."); + LOG_DEBUG("Resetting world..."); world.reset(); - LOG_WARNING("Resetting gameHandler..."); + LOG_DEBUG("Resetting gameHandler..."); gameHandler.reset(); gameServices_ = {}; - LOG_WARNING("Resetting authHandler..."); + LOG_DEBUG("Resetting authHandler..."); authHandler.reset(); - LOG_WARNING("Resetting assetManager..."); + LOG_DEBUG("Resetting assetManager..."); assetManager.reset(); - LOG_WARNING("Resetting uiManager..."); + LOG_DEBUG("Resetting uiManager..."); uiManager.reset(); - LOG_WARNING("Resetting window..."); + LOG_DEBUG("Resetting window..."); window.reset(); running = false; - LOG_WARNING("Application shutdown complete"); + LOG_DEBUG("Application shutdown complete"); } void Application::setState(AppState newState) { diff --git a/src/core/window.cpp b/src/core/window.cpp index f48f2a51..8170cee9 100644 --- a/src/core/window.cpp +++ b/src/core/window.cpp @@ -103,25 +103,23 @@ bool Window::initialize() { return true; } -// Shutdown progress uses LOG_WARNING so these messages are always visible even at -// default log levels — useful for diagnosing hangs or crashes during teardown. void Window::shutdown() { - LOG_WARNING("Window::shutdown - vkContext..."); + LOG_DEBUG("Window::shutdown - vkContext..."); if (vkContext) { vkContext->shutdown(); vkContext.reset(); } - LOG_WARNING("Window::shutdown - SDL_DestroyWindow..."); + LOG_DEBUG("Window::shutdown - SDL_DestroyWindow..."); if (window) { SDL_DestroyWindow(window); window = nullptr; } - LOG_WARNING("Window::shutdown - SDL_Quit..."); + LOG_DEBUG("Window::shutdown - SDL_Quit..."); SDL_Vulkan_UnloadLibrary(); SDL_Quit(); - LOG_WARNING("Window shutdown complete"); + LOG_DEBUG("Window shutdown complete"); } void Window::pollEvents() { diff --git a/src/core/world_loader.cpp b/src/core/world_loader.cpp index f489bf41..7d47cd7d 100644 --- a/src/core/world_loader.cpp +++ b/src/core/world_loader.cpp @@ -866,7 +866,7 @@ void WorldLoader::loadOnlineWorldTerrain(uint32_t mapId, float x, float y, float auto* tm = gameHandler_->getTransportManager(); if (renderer_->getWMORenderer()) tm->setWMORenderer(renderer_->getWMORenderer()); if (renderer_->getM2Renderer()) tm->setM2Renderer(renderer_->getM2Renderer()); - LOG_WARNING("TransportManager connected: wmoR=", (renderer_->getWMORenderer() ? "yes" : "NULL"), + LOG_DEBUG("TransportManager connected: wmoR=", (renderer_->getWMORenderer() ? "yes" : "NULL"), " m2R=", (renderer_->getM2Renderer() ? "yes" : "NULL")); } diff --git a/src/game/warden_handler.cpp b/src/game/warden_handler.cpp index ca3fa98d..4a78a6d6 100644 --- a/src/game/warden_handler.cpp +++ b/src/game/warden_handler.cpp @@ -264,7 +264,7 @@ bool WardenHandler::loadWardenCRFile(const std::string& moduleHashHex) { for (int i = 0; i < 9; i++) { char s[16]; snprintf(s, sizeof(s), "%s=0x%02X ", names[i], wardenCheckOpcodes_[i]); opcHex += s; } - LOG_WARNING("Warden: Check opcodes: ", opcHex); + LOG_DEBUG("Warden: Check opcodes: ", opcHex); } size_t entryCount = (static_cast(fileSize) - CR_HEADER_SIZE) / CR_ENTRY_SIZE; @@ -383,7 +383,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) { std::vector resp = { 0x00 }; // WARDEN_CMSG_MODULE_MISSING sendWardenResponse(resp); wardenState_ = WardenState::WAIT_MODULE_CACHE; - LOG_WARNING("Warden: Sent MODULE_MISSING for module size=", wardenModuleSize_, ", waiting for data chunks"); + LOG_DEBUG("Warden: Sent MODULE_MISSING for module size=", wardenModuleSize_, ", waiting for data chunks"); break; } @@ -407,7 +407,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) { decrypted.begin() + 3, decrypted.begin() + 3 + chunkSize); - LOG_WARNING("Warden: MODULE_CACHE chunk ", chunkSize, " bytes, total ", + LOG_DEBUG("Warden: MODULE_CACHE chunk ", chunkSize, " bytes, total ", wardenModuleData_.size(), "/", wardenModuleSize_); // Check if module download is complete @@ -504,7 +504,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) { } if (match) { - LOG_WARNING("Warden: HASH_REQUEST — CR entry MATCHED, sending pre-computed reply"); + LOG_DEBUG("Warden: HASH_REQUEST — CR entry MATCHED, sending pre-computed reply"); // Send HASH_RESULT (opcode 0x04 + 20-byte reply) std::vector resp; @@ -518,12 +518,12 @@ void WardenHandler::handleWardenData(network::Packet& packet) { std::vector newDecryptKey(match->serverKey, match->serverKey + 16); wardenCrypto_->replaceKeys(newEncryptKey, newDecryptKey); - LOG_WARNING("Warden: Switched to CR key set"); + LOG_DEBUG("Warden: Switched to CR key set"); wardenState_ = WardenState::WAIT_CHECKS; break; } else { - LOG_WARNING("Warden: Seed not found in ", wardenCREntries_.size(), " CR entries"); + LOG_DEBUG("Warden: Seed not found in ", wardenCREntries_.size(), " CR entries"); } } @@ -540,7 +540,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) { // ChromieCraft/AzerothCore tolerates the silence (no ban, no kick), // but REJECTS a wrong hash and closes the connection immediately. // Staying silent lets the server continue the session without Warden checks. - LOG_WARNING("Warden: HASH_REQUEST seed=", seedHex, + LOG_DEBUG("Warden: HASH_REQUEST seed=", seedHex, " — no CR match, skipping response (server tolerates silence)"); wardenState_ = WardenState::WAIT_CHECKS; break; diff --git a/src/rendering/renderer.cpp b/src/rendering/renderer.cpp index 48d3fa85..1c7fa9ab 100644 --- a/src/rendering/renderer.cpp +++ b/src/rendering/renderer.cpp @@ -592,38 +592,38 @@ bool Renderer::initialize(core::Window* win) { void Renderer::shutdown() { destroySecondaryCommandResources(); - LOG_WARNING("Renderer::shutdown - terrainManager stopWorkers..."); + LOG_DEBUG("Renderer::shutdown - terrainManager stopWorkers..."); if (terrainManager) { terrainManager->stopWorkers(); - LOG_WARNING("Renderer::shutdown - terrainManager reset..."); + LOG_DEBUG("Renderer::shutdown - terrainManager reset..."); terrainManager.reset(); } - LOG_WARNING("Renderer::shutdown - terrainRenderer..."); + LOG_DEBUG("Renderer::shutdown - terrainRenderer..."); if (terrainRenderer) { terrainRenderer->shutdown(); terrainRenderer.reset(); } - LOG_WARNING("Renderer::shutdown - waterRenderer..."); + LOG_DEBUG("Renderer::shutdown - waterRenderer..."); if (waterRenderer) { waterRenderer->shutdown(); waterRenderer.reset(); } - LOG_WARNING("Renderer::shutdown - minimap..."); + LOG_DEBUG("Renderer::shutdown - minimap..."); if (minimap) { minimap->shutdown(); minimap.reset(); } - LOG_WARNING("Renderer::shutdown - worldMap..."); + LOG_DEBUG("Renderer::shutdown - worldMap..."); if (worldMap) { worldMap->shutdown(); worldMap.reset(); } - LOG_WARNING("Renderer::shutdown - skySystem..."); + LOG_DEBUG("Renderer::shutdown - skySystem..."); if (skySystem) { skySystem->shutdown(); skySystem.reset(); @@ -650,7 +650,7 @@ void Renderer::shutdown() { swimEffects.reset(); } - LOG_WARNING("Renderer::shutdown - characterRenderer..."); + LOG_DEBUG("Renderer::shutdown - characterRenderer..."); if (characterRenderer) { characterRenderer->shutdown(); characterRenderer.reset(); @@ -659,7 +659,7 @@ void Renderer::shutdown() { // Shutdown AnimationController before renderers it references (§4.2) animationController_.reset(); - LOG_WARNING("Renderer::shutdown - wmoRenderer..."); + LOG_DEBUG("Renderer::shutdown - wmoRenderer..."); if (wmoRenderer) { wmoRenderer->shutdown(); wmoRenderer.reset(); @@ -671,7 +671,7 @@ void Renderer::shutdown() { spellVisualSystem_.reset(); } - LOG_WARNING("Renderer::shutdown - m2Renderer..."); + LOG_DEBUG("Renderer::shutdown - m2Renderer..."); if (m2Renderer) { m2Renderer->shutdown(); m2Renderer.reset(); diff --git a/src/rendering/terrain_manager.cpp b/src/rendering/terrain_manager.cpp index 2639a1b1..e8a21469 100644 --- a/src/rendering/terrain_manager.cpp +++ b/src/rendering/terrain_manager.cpp @@ -1527,10 +1527,10 @@ void TerrainManager::unloadTile(int x, int y) { void TerrainManager::stopWorkers() { if (!workerRunning.load()) { - LOG_WARNING("stopWorkers: already stopped"); + LOG_DEBUG("stopWorkers: already stopped"); return; } - LOG_WARNING("stopWorkers: signaling ", workerThreads.size(), " workers to stop..."); + LOG_DEBUG("stopWorkers: signaling ", workerThreads.size(), " workers to stop..."); workerRunning.store(false); queueCV.notify_all(); @@ -1540,12 +1540,12 @@ void TerrainManager::stopWorkers() { // std::thread object thinking it's still joinable → std::terminate on dtor). for (size_t i = 0; i < workerThreads.size(); i++) { if (workerThreads[i].joinable()) { - LOG_WARNING("stopWorkers: joining worker ", i, "..."); + LOG_DEBUG("stopWorkers: joining worker ", i, "..."); workerThreads[i].join(); } } workerThreads.clear(); - LOG_WARNING("stopWorkers: done"); + LOG_DEBUG("stopWorkers: done"); } void TerrainManager::unloadAll() { diff --git a/src/rendering/vk_context.cpp b/src/rendering/vk_context.cpp index 4a5d6366..2de87569 100644 --- a/src/rendering/vk_context.cpp +++ b/src/rendering/vk_context.cpp @@ -108,7 +108,7 @@ bool VkContext::initialize(SDL_Window* window) { void VkContext::shutdown() { if (!device && !instance) return; // Already shut down or never initialized - LOG_WARNING("VkContext::shutdown - vkDeviceWaitIdle..."); + LOG_DEBUG("VkContext::shutdown - vkDeviceWaitIdle..."); if (device) { vkDeviceWaitIdle(device); } @@ -122,7 +122,7 @@ void VkContext::shutdown() { deferredCleanup_[fi].clear(); } - LOG_WARNING("VkContext::shutdown - destroyImGuiResources..."); + LOG_DEBUG("VkContext::shutdown - destroyImGuiResources..."); destroyImGuiResources(); // Destroy sync objects @@ -165,7 +165,7 @@ void VkContext::shutdown() { sInstance_ = nullptr; - LOG_WARNING("VkContext::shutdown - destroySwapchain..."); + LOG_DEBUG("VkContext::shutdown - destroySwapchain..."); destroySwapchain(); // Skip vmaDestroyAllocator — it walks every allocation to free it, which @@ -174,7 +174,7 @@ void VkContext::shutdown() { // everything on process exit. Skipping this makes shutdown instant. allocator = VK_NULL_HANDLE; - LOG_WARNING("VkContext::shutdown - vkDestroyDevice..."); + LOG_DEBUG("VkContext::shutdown - vkDestroyDevice..."); if (device) { vkDestroyDevice(device, nullptr); device = VK_NULL_HANDLE; } if (surface) { vkDestroySurfaceKHR(instance, surface, nullptr); surface = VK_NULL_HANDLE; } @@ -187,7 +187,7 @@ void VkContext::shutdown() { if (instance) { vkDestroyInstance(instance, nullptr); instance = VK_NULL_HANDLE; } - LOG_WARNING("Vulkan context shutdown complete"); + LOG_DEBUG("Vulkan context shutdown complete"); } void VkContext::deferAfterFrameFence(std::function&& fn) { diff --git a/src/ui/inventory_screen.cpp b/src/ui/inventory_screen.cpp index eb030e09..f1d74efa 100644 --- a/src/ui/inventory_screen.cpp +++ b/src/ui/inventory_screen.cpp @@ -2470,7 +2470,7 @@ void InventoryScreen::renderItemSlot(game::Inventory& inventory, const game::Ite // Right-click: bank deposit (if bank open), vendor sell (if vendor mode), or auto-equip/use // Note: InvisibleButton only tracks left-click by default, so use IsItemHovered+IsMouseClicked if (ImGui::IsItemHovered() && ImGui::IsMouseClicked(ImGuiMouseButton_Right) && !holdingItem && !ImGui::GetIO().KeyShift && gameHandler_) { - LOG_WARNING("Right-click slot: kind=", static_cast(kind), + LOG_DEBUG("Right-click slot: kind=", static_cast(kind), " backpackIndex=", backpackIndex, " bagIndex=", bagIndex, " bagSlotIndex=", bagSlotIndex, " vendorMode=", vendorMode_,