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.
This commit is contained in:
Kelsi 2026-04-05 20:18:39 -07:00
parent 069dd36698
commit c2681eead1
8 changed files with 44 additions and 46 deletions

View file

@ -834,7 +834,7 @@ void Application::run() {
} }
void Application::shutdown() { 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 // Hide the window immediately so the OS doesn't think the app is frozen
// during the (potentially slow) resource cleanup below. // during the (potentially slow) resource cleanup below.
@ -851,20 +851,20 @@ void Application::shutdown() {
if (renderer && renderer->getWMORenderer()) { if (renderer && renderer->getWMORenderer()) {
size_t cacheSize = renderer->getWMORenderer()->getFloorCacheSize(); size_t cacheSize = renderer->getWMORenderer()->getFloorCacheSize();
if (cacheSize > 0) { if (cacheSize > 0) {
LOG_WARNING("Saving WMO floor cache (", cacheSize, " entries)..."); LOG_DEBUG("Saving WMO floor cache (", cacheSize, " entries)...");
renderer->getWMORenderer()->saveFloorCache(); renderer->getWMORenderer()->saveFloorCache();
LOG_WARNING("Floor cache saved."); LOG_DEBUG("Floor cache saved.");
} }
} }
// Explicitly shut down the renderer before destroying it — this ensures // Explicitly shut down the renderer before destroying it — this ensures
// all sub-renderers free their VMA allocations in the correct order, // all sub-renderers free their VMA allocations in the correct order,
// before VkContext::shutdown() calls vmaDestroyAllocator(). // before VkContext::shutdown() calls vmaDestroyAllocator().
LOG_WARNING("Shutting down renderer..."); LOG_DEBUG("Shutting down renderer...");
if (renderer) { if (renderer) {
renderer->shutdown(); renderer->shutdown();
} }
LOG_WARNING("Renderer shutdown complete, resetting..."); LOG_DEBUG("Renderer shutdown complete, resetting...");
renderer.reset(); renderer.reset();
// Shutdown audio coordinator after renderer (renderer may reference audio during shutdown) // Shutdown audio coordinator after renderer (renderer may reference audio during shutdown)
@ -873,22 +873,22 @@ void Application::shutdown() {
} }
audioCoordinator_.reset(); audioCoordinator_.reset();
LOG_WARNING("Resetting world..."); LOG_DEBUG("Resetting world...");
world.reset(); world.reset();
LOG_WARNING("Resetting gameHandler..."); LOG_DEBUG("Resetting gameHandler...");
gameHandler.reset(); gameHandler.reset();
gameServices_ = {}; gameServices_ = {};
LOG_WARNING("Resetting authHandler..."); LOG_DEBUG("Resetting authHandler...");
authHandler.reset(); authHandler.reset();
LOG_WARNING("Resetting assetManager..."); LOG_DEBUG("Resetting assetManager...");
assetManager.reset(); assetManager.reset();
LOG_WARNING("Resetting uiManager..."); LOG_DEBUG("Resetting uiManager...");
uiManager.reset(); uiManager.reset();
LOG_WARNING("Resetting window..."); LOG_DEBUG("Resetting window...");
window.reset(); window.reset();
running = false; running = false;
LOG_WARNING("Application shutdown complete"); LOG_DEBUG("Application shutdown complete");
} }
void Application::setState(AppState newState) { void Application::setState(AppState newState) {

View file

@ -103,25 +103,23 @@ bool Window::initialize() {
return true; 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() { void Window::shutdown() {
LOG_WARNING("Window::shutdown - vkContext..."); LOG_DEBUG("Window::shutdown - vkContext...");
if (vkContext) { if (vkContext) {
vkContext->shutdown(); vkContext->shutdown();
vkContext.reset(); vkContext.reset();
} }
LOG_WARNING("Window::shutdown - SDL_DestroyWindow..."); LOG_DEBUG("Window::shutdown - SDL_DestroyWindow...");
if (window) { if (window) {
SDL_DestroyWindow(window); SDL_DestroyWindow(window);
window = nullptr; window = nullptr;
} }
LOG_WARNING("Window::shutdown - SDL_Quit..."); LOG_DEBUG("Window::shutdown - SDL_Quit...");
SDL_Vulkan_UnloadLibrary(); SDL_Vulkan_UnloadLibrary();
SDL_Quit(); SDL_Quit();
LOG_WARNING("Window shutdown complete"); LOG_DEBUG("Window shutdown complete");
} }
void Window::pollEvents() { void Window::pollEvents() {

View file

@ -866,7 +866,7 @@ void WorldLoader::loadOnlineWorldTerrain(uint32_t mapId, float x, float y, float
auto* tm = gameHandler_->getTransportManager(); auto* tm = gameHandler_->getTransportManager();
if (renderer_->getWMORenderer()) tm->setWMORenderer(renderer_->getWMORenderer()); if (renderer_->getWMORenderer()) tm->setWMORenderer(renderer_->getWMORenderer());
if (renderer_->getM2Renderer()) tm->setM2Renderer(renderer_->getM2Renderer()); 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")); " m2R=", (renderer_->getM2Renderer() ? "yes" : "NULL"));
} }

View file

@ -264,7 +264,7 @@ bool WardenHandler::loadWardenCRFile(const std::string& moduleHashHex) {
for (int i = 0; i < 9; i++) { for (int i = 0; i < 9; i++) {
char s[16]; snprintf(s, sizeof(s), "%s=0x%02X ", names[i], wardenCheckOpcodes_[i]); opcHex += s; 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<size_t>(fileSize) - CR_HEADER_SIZE) / CR_ENTRY_SIZE; size_t entryCount = (static_cast<size_t>(fileSize) - CR_HEADER_SIZE) / CR_ENTRY_SIZE;
@ -383,7 +383,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) {
std::vector<uint8_t> resp = { 0x00 }; // WARDEN_CMSG_MODULE_MISSING std::vector<uint8_t> resp = { 0x00 }; // WARDEN_CMSG_MODULE_MISSING
sendWardenResponse(resp); sendWardenResponse(resp);
wardenState_ = WardenState::WAIT_MODULE_CACHE; 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; break;
} }
@ -407,7 +407,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) {
decrypted.begin() + 3, decrypted.begin() + 3,
decrypted.begin() + 3 + chunkSize); 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_); wardenModuleData_.size(), "/", wardenModuleSize_);
// Check if module download is complete // Check if module download is complete
@ -504,7 +504,7 @@ void WardenHandler::handleWardenData(network::Packet& packet) {
} }
if (match) { 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) // Send HASH_RESULT (opcode 0x04 + 20-byte reply)
std::vector<uint8_t> resp; std::vector<uint8_t> resp;
@ -518,12 +518,12 @@ void WardenHandler::handleWardenData(network::Packet& packet) {
std::vector<uint8_t> newDecryptKey(match->serverKey, match->serverKey + 16); std::vector<uint8_t> newDecryptKey(match->serverKey, match->serverKey + 16);
wardenCrypto_->replaceKeys(newEncryptKey, newDecryptKey); wardenCrypto_->replaceKeys(newEncryptKey, newDecryptKey);
LOG_WARNING("Warden: Switched to CR key set"); LOG_DEBUG("Warden: Switched to CR key set");
wardenState_ = WardenState::WAIT_CHECKS; wardenState_ = WardenState::WAIT_CHECKS;
break; break;
} else { } 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), // ChromieCraft/AzerothCore tolerates the silence (no ban, no kick),
// but REJECTS a wrong hash and closes the connection immediately. // but REJECTS a wrong hash and closes the connection immediately.
// Staying silent lets the server continue the session without Warden checks. // 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)"); " — no CR match, skipping response (server tolerates silence)");
wardenState_ = WardenState::WAIT_CHECKS; wardenState_ = WardenState::WAIT_CHECKS;
break; break;

View file

@ -592,38 +592,38 @@ bool Renderer::initialize(core::Window* win) {
void Renderer::shutdown() { void Renderer::shutdown() {
destroySecondaryCommandResources(); destroySecondaryCommandResources();
LOG_WARNING("Renderer::shutdown - terrainManager stopWorkers..."); LOG_DEBUG("Renderer::shutdown - terrainManager stopWorkers...");
if (terrainManager) { if (terrainManager) {
terrainManager->stopWorkers(); terrainManager->stopWorkers();
LOG_WARNING("Renderer::shutdown - terrainManager reset..."); LOG_DEBUG("Renderer::shutdown - terrainManager reset...");
terrainManager.reset(); terrainManager.reset();
} }
LOG_WARNING("Renderer::shutdown - terrainRenderer..."); LOG_DEBUG("Renderer::shutdown - terrainRenderer...");
if (terrainRenderer) { if (terrainRenderer) {
terrainRenderer->shutdown(); terrainRenderer->shutdown();
terrainRenderer.reset(); terrainRenderer.reset();
} }
LOG_WARNING("Renderer::shutdown - waterRenderer..."); LOG_DEBUG("Renderer::shutdown - waterRenderer...");
if (waterRenderer) { if (waterRenderer) {
waterRenderer->shutdown(); waterRenderer->shutdown();
waterRenderer.reset(); waterRenderer.reset();
} }
LOG_WARNING("Renderer::shutdown - minimap..."); LOG_DEBUG("Renderer::shutdown - minimap...");
if (minimap) { if (minimap) {
minimap->shutdown(); minimap->shutdown();
minimap.reset(); minimap.reset();
} }
LOG_WARNING("Renderer::shutdown - worldMap..."); LOG_DEBUG("Renderer::shutdown - worldMap...");
if (worldMap) { if (worldMap) {
worldMap->shutdown(); worldMap->shutdown();
worldMap.reset(); worldMap.reset();
} }
LOG_WARNING("Renderer::shutdown - skySystem..."); LOG_DEBUG("Renderer::shutdown - skySystem...");
if (skySystem) { if (skySystem) {
skySystem->shutdown(); skySystem->shutdown();
skySystem.reset(); skySystem.reset();
@ -650,7 +650,7 @@ void Renderer::shutdown() {
swimEffects.reset(); swimEffects.reset();
} }
LOG_WARNING("Renderer::shutdown - characterRenderer..."); LOG_DEBUG("Renderer::shutdown - characterRenderer...");
if (characterRenderer) { if (characterRenderer) {
characterRenderer->shutdown(); characterRenderer->shutdown();
characterRenderer.reset(); characterRenderer.reset();
@ -659,7 +659,7 @@ void Renderer::shutdown() {
// Shutdown AnimationController before renderers it references (§4.2) // Shutdown AnimationController before renderers it references (§4.2)
animationController_.reset(); animationController_.reset();
LOG_WARNING("Renderer::shutdown - wmoRenderer..."); LOG_DEBUG("Renderer::shutdown - wmoRenderer...");
if (wmoRenderer) { if (wmoRenderer) {
wmoRenderer->shutdown(); wmoRenderer->shutdown();
wmoRenderer.reset(); wmoRenderer.reset();
@ -671,7 +671,7 @@ void Renderer::shutdown() {
spellVisualSystem_.reset(); spellVisualSystem_.reset();
} }
LOG_WARNING("Renderer::shutdown - m2Renderer..."); LOG_DEBUG("Renderer::shutdown - m2Renderer...");
if (m2Renderer) { if (m2Renderer) {
m2Renderer->shutdown(); m2Renderer->shutdown();
m2Renderer.reset(); m2Renderer.reset();

View file

@ -1527,10 +1527,10 @@ void TerrainManager::unloadTile(int x, int y) {
void TerrainManager::stopWorkers() { void TerrainManager::stopWorkers() {
if (!workerRunning.load()) { if (!workerRunning.load()) {
LOG_WARNING("stopWorkers: already stopped"); LOG_DEBUG("stopWorkers: already stopped");
return; return;
} }
LOG_WARNING("stopWorkers: signaling ", workerThreads.size(), " workers to stop..."); LOG_DEBUG("stopWorkers: signaling ", workerThreads.size(), " workers to stop...");
workerRunning.store(false); workerRunning.store(false);
queueCV.notify_all(); queueCV.notify_all();
@ -1540,12 +1540,12 @@ void TerrainManager::stopWorkers() {
// std::thread object thinking it's still joinable → std::terminate on dtor). // std::thread object thinking it's still joinable → std::terminate on dtor).
for (size_t i = 0; i < workerThreads.size(); i++) { for (size_t i = 0; i < workerThreads.size(); i++) {
if (workerThreads[i].joinable()) { if (workerThreads[i].joinable()) {
LOG_WARNING("stopWorkers: joining worker ", i, "..."); LOG_DEBUG("stopWorkers: joining worker ", i, "...");
workerThreads[i].join(); workerThreads[i].join();
} }
} }
workerThreads.clear(); workerThreads.clear();
LOG_WARNING("stopWorkers: done"); LOG_DEBUG("stopWorkers: done");
} }
void TerrainManager::unloadAll() { void TerrainManager::unloadAll() {

View file

@ -108,7 +108,7 @@ bool VkContext::initialize(SDL_Window* window) {
void VkContext::shutdown() { void VkContext::shutdown() {
if (!device && !instance) return; // Already shut down or never initialized if (!device && !instance) return; // Already shut down or never initialized
LOG_WARNING("VkContext::shutdown - vkDeviceWaitIdle..."); LOG_DEBUG("VkContext::shutdown - vkDeviceWaitIdle...");
if (device) { if (device) {
vkDeviceWaitIdle(device); vkDeviceWaitIdle(device);
} }
@ -122,7 +122,7 @@ void VkContext::shutdown() {
deferredCleanup_[fi].clear(); deferredCleanup_[fi].clear();
} }
LOG_WARNING("VkContext::shutdown - destroyImGuiResources..."); LOG_DEBUG("VkContext::shutdown - destroyImGuiResources...");
destroyImGuiResources(); destroyImGuiResources();
// Destroy sync objects // Destroy sync objects
@ -165,7 +165,7 @@ void VkContext::shutdown() {
sInstance_ = nullptr; sInstance_ = nullptr;
LOG_WARNING("VkContext::shutdown - destroySwapchain..."); LOG_DEBUG("VkContext::shutdown - destroySwapchain...");
destroySwapchain(); destroySwapchain();
// Skip vmaDestroyAllocator — it walks every allocation to free it, which // 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. // everything on process exit. Skipping this makes shutdown instant.
allocator = VK_NULL_HANDLE; allocator = VK_NULL_HANDLE;
LOG_WARNING("VkContext::shutdown - vkDestroyDevice..."); LOG_DEBUG("VkContext::shutdown - vkDestroyDevice...");
if (device) { vkDestroyDevice(device, nullptr); device = VK_NULL_HANDLE; } if (device) { vkDestroyDevice(device, nullptr); device = VK_NULL_HANDLE; }
if (surface) { vkDestroySurfaceKHR(instance, surface, nullptr); surface = 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; } 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<void()>&& fn) { void VkContext::deferAfterFrameFence(std::function<void()>&& fn) {

View file

@ -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 // 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 // Note: InvisibleButton only tracks left-click by default, so use IsItemHovered+IsMouseClicked
if (ImGui::IsItemHovered() && ImGui::IsMouseClicked(ImGuiMouseButton_Right) && !holdingItem && !ImGui::GetIO().KeyShift && gameHandler_) { if (ImGui::IsItemHovered() && ImGui::IsMouseClicked(ImGuiMouseButton_Right) && !holdingItem && !ImGui::GetIO().KeyShift && gameHandler_) {
LOG_WARNING("Right-click slot: kind=", static_cast<int>(kind), LOG_DEBUG("Right-click slot: kind=", static_cast<int>(kind),
" backpackIndex=", backpackIndex, " backpackIndex=", backpackIndex,
" bagIndex=", bagIndex, " bagSlotIndex=", bagSlotIndex, " bagIndex=", bagIndex, " bagSlotIndex=", bagSlotIndex,
" vendorMode=", vendorMode_, " vendorMode=", vendorMode_,