phaneron/Kelsidavis-WoWee
1
0
Fork 0
mirror of https://github.com/Kelsidavis/WoWee.git synced 2026-04-26 21:13:51 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions

Remove per-frame chrono profiling from application and game handler

Browse source 
Strip ~30 chrono::now() calls per frame from Application::update() and
GameHandler::update() that existed only for periodic LOG_DEBUG dumps.
Retain renderer timing used by the live performance HUD overlay.
This commit is contained in:
Kelsi 2026-02-23 04:41:22 -08:00
parent 9e1a913060
commit 2cfa9d6b19
2 changed files with 0 additions and 145 deletions
Download patch file Download diff file Expand all files Collapse all files

99
src/core/application.cpp
View file

@ -327,11 +327,6 @@ void Application::run() {
// Update input // Update input
Input::getInstance().update(); Input::getInstance().update();
// Timing breakdown
static int frameCount = 0;
static double totalUpdateMs = 0, totalRenderMs = 0, totalSwapMs = 0;
auto t1 = std::chrono::steady_clock::now();
// Update application state // Update application state
try { try {
update(deltaTime); update(deltaTime);
@ -344,8 +339,6 @@ void Application::run() {
", dt=", deltaTime, "): ", e.what()); ", dt=", deltaTime, "): ", e.what());
throw; throw;
} }
auto t2 = std::chrono::steady_clock::now();
// Render // Render
try { try {
render(); render();
@ -356,8 +349,6 @@ void Application::run() {
LOG_ERROR("Exception during Application::render (state=", static_cast<int>(state), "): ", e.what()); LOG_ERROR("Exception during Application::render (state=", static_cast<int>(state), "): ", e.what());
throw; throw;
} }
auto t3 = std::chrono::steady_clock::now();
// Swap buffers // Swap buffers
try { try {
window->swapBuffers(); window->swapBuffers();
@ -368,21 +359,6 @@ void Application::run() {
LOG_ERROR("Exception during swapBuffers: ", e.what()); LOG_ERROR("Exception during swapBuffers: ", e.what());
throw; throw;
} }
auto t4 = std::chrono::steady_clock::now();
totalUpdateMs += std::chrono::duration<double, std::milli>(t2 - t1).count();
totalRenderMs += std::chrono::duration<double, std::milli>(t3 - t2).count();
totalSwapMs += std::chrono::duration<double, std::milli>(t4 - t3).count();
if (++frameCount >= 60) {
if (frameProfileEnabled && core::Logger::getInstance().shouldLog(core::LogLevel::DEBUG)) {
LOG_DEBUG("[Frame] Update: ", totalUpdateMs / 60.0,
"ms Render: ", totalRenderMs / 60.0,
"ms Swap: ", totalSwapMs / 60.0, "ms");
}
frameCount = 0;
totalUpdateMs = totalRenderMs = totalSwapMs = 0;
}
} }
LOG_INFO("Main loop ended"); LOG_INFO("Main loop ended");
@ -625,14 +601,6 @@ void Application::update(float deltaTime) {
throw; throw;
} }
}; };
// Application update profiling
updateCheckpoint = "in_game: profile init";
static int appProfileCounter = 0;
static float ghTime = 0.0f, worldTime = 0.0f, spawnTime = 0.0f;
static float creatureQTime = 0.0f, goQTime = 0.0f, mountTime = 0.0f;
static float npcMgrTime = 0.0f, questMarkTime = 0.0f, syncTime = 0.0f;
auto gh1 = std::chrono::high_resolution_clock::now();
inGameStep = "gameHandler update"; inGameStep = "gameHandler update";
updateCheckpoint = "in_game: gameHandler update"; updateCheckpoint = "in_game: gameHandler update";
runInGameStage("gameHandler->update", [&] { runInGameStage("gameHandler->update", [&] {
@ -640,9 +608,6 @@ void Application::update(float deltaTime) {
gameHandler->update(deltaTime); gameHandler->update(deltaTime);
} }
}); });
auto gh2 = std::chrono::high_resolution_clock::now();
ghTime += std::chrono::duration<float, std::milli>(gh2 - gh1).count();
// Always unsheath on combat engage. // Always unsheath on combat engage.
inGameStep = "auto-unsheathe"; inGameStep = "auto-unsheathe";
updateCheckpoint = "in_game: auto-unsheathe"; updateCheckpoint = "in_game: auto-unsheathe";
@ -667,7 +632,6 @@ void Application::update(float deltaTime) {
} }
} }
auto w1 = std::chrono::high_resolution_clock::now();
inGameStep = "world update"; inGameStep = "world update";
updateCheckpoint = "in_game: world update"; updateCheckpoint = "in_game: world update";
runInGameStage("world->update", [&] { runInGameStage("world->update", [&] {
@ -675,10 +639,6 @@ void Application::update(float deltaTime) {
world->update(deltaTime); world->update(deltaTime);
} }
}); });
auto w2 = std::chrono::high_resolution_clock::now();
worldTime += std::chrono::duration<float, std::milli>(w2 - w1).count();
auto cq1 = std::chrono::high_resolution_clock::now();
inGameStep = "spawn/equipment queues"; inGameStep = "spawn/equipment queues";
updateCheckpoint = "in_game: spawn/equipment queues"; updateCheckpoint = "in_game: spawn/equipment queues";
runInGameStage("spawn/equipment queues", [&] { runInGameStage("spawn/equipment queues", [&] {
@ -688,9 +648,6 @@ void Application::update(float deltaTime) {
// Process deferred equipment compositing (max 1 per frame to avoid stutter) // Process deferred equipment compositing (max 1 per frame to avoid stutter)
processDeferredEquipmentQueue(); processDeferredEquipmentQueue();
}); });
auto cq2 = std::chrono::high_resolution_clock::now();
creatureQTime += std::chrono::duration<float, std::milli>(cq2 - cq1).count();
// Self-heal missing creature visuals: if a nearby UNIT exists in // Self-heal missing creature visuals: if a nearby UNIT exists in
// entity state but has no render instance, queue a spawn retry. // entity state but has no render instance, queue a spawn retry.
inGameStep = "creature resync scan"; inGameStep = "creature resync scan";
@ -739,41 +696,23 @@ void Application::update(float deltaTime) {
} }
} }
auto goq1 = std::chrono::high_resolution_clock::now();
inGameStep = "gameobject/transport queues"; inGameStep = "gameobject/transport queues";
updateCheckpoint = "in_game: gameobject/transport queues"; updateCheckpoint = "in_game: gameobject/transport queues";
runInGameStage("gameobject/transport queues", [&] { runInGameStage("gameobject/transport queues", [&] {
processGameObjectSpawnQueue(); processGameObjectSpawnQueue();
processPendingTransportDoodads(); processPendingTransportDoodads();
}); });
auto goq2 = std::chrono::high_resolution_clock::now();
goQTime += std::chrono::duration<float, std::milli>(goq2 - goq1).count();
auto m1 = std::chrono::high_resolution_clock::now();
inGameStep = "pending mount"; inGameStep = "pending mount";
updateCheckpoint = "in_game: pending mount"; updateCheckpoint = "in_game: pending mount";
runInGameStage("processPendingMount", [&] { runInGameStage("processPendingMount", [&] {
processPendingMount(); processPendingMount();
}); });
auto m2 = std::chrono::high_resolution_clock::now();
mountTime += std::chrono::duration<float, std::milli>(m2 - m1).count();
auto nm1 = std::chrono::high_resolution_clock::now();
auto nm2 = std::chrono::high_resolution_clock::now();
npcMgrTime += std::chrono::duration<float, std::milli>(nm2 - nm1).count();
auto qm1 = std::chrono::high_resolution_clock::now();
// Update 3D quest markers above NPCs // Update 3D quest markers above NPCs
inGameStep = "quest markers"; inGameStep = "quest markers";
updateCheckpoint = "in_game: quest markers"; updateCheckpoint = "in_game: quest markers";
runInGameStage("updateQuestMarkers", [&] { runInGameStage("updateQuestMarkers", [&] {
updateQuestMarkers(); updateQuestMarkers();
}); });
auto qm2 = std::chrono::high_resolution_clock::now();
questMarkTime += std::chrono::duration<float, std::milli>(qm2 - qm1).count();
auto sync1 = std::chrono::high_resolution_clock::now();
// Sync server run speed to camera controller // Sync server run speed to camera controller
inGameStep = "post-update sync"; inGameStep = "post-update sync";
updateCheckpoint = "in_game: post-update sync"; updateCheckpoint = "in_game: post-update sync";
@ -1155,24 +1094,6 @@ void Application::update(float deltaTime) {
// Movement heartbeat is sent from GameHandler::update() to avoid // Movement heartbeat is sent from GameHandler::update() to avoid
// duplicate packets from multiple update loops. // duplicate packets from multiple update loops.
auto sync2 = std::chrono::high_resolution_clock::now();
syncTime += std::chrono::duration<float, std::milli>(sync2 - sync1).count();
// Log profiling every 60 frames
if (++appProfileCounter >= 60) {
updateCheckpoint = "in_game: profile log";
if (core::Logger::getInstance().shouldLog(core::LogLevel::DEBUG)) {
LOG_DEBUG("APP UPDATE PROFILE (60 frames): gameHandler=", ghTime / 60.0f,
"ms world=", worldTime / 60.0f, "ms spawn=", spawnTime / 60.0f,
"ms creatureQ=", creatureQTime / 60.0f, "ms goQ=", goQTime / 60.0f,
"ms mount=", mountTime / 60.0f, "ms npcMgr=", npcMgrTime / 60.0f,
"ms questMark=", questMarkTime / 60.0f, "ms sync=", syncTime / 60.0f, "ms");
}
appProfileCounter = 0;
ghTime = worldTime = spawnTime = 0.0f;
creatureQTime = goQTime = mountTime = 0.0f;
npcMgrTime = questMarkTime = syncTime = 0.0f;
}
} catch (const std::bad_alloc& e) { } catch (const std::bad_alloc& e) {
LOG_ERROR("OOM inside AppState::IN_GAME at step '", inGameStep, "': ", e.what()); LOG_ERROR("OOM inside AppState::IN_GAME at step '", inGameStep, "': ", e.what());
throw; throw;
@ -1189,11 +1110,7 @@ void Application::update(float deltaTime) {
} }
// Update renderer (camera, etc.) only when in-game // Update renderer (camera, etc.) only when in-game
static int rendererProfileCounter = 0;
static float rendererTime = 0.0f, uiTime = 0.0f;
updateCheckpoint = "renderer update"; updateCheckpoint = "renderer update";
auto r1 = std::chrono::high_resolution_clock::now();
if (renderer && state == AppState::IN_GAME) { if (renderer && state == AppState::IN_GAME) {
try { try {
renderer->update(deltaTime); renderer->update(deltaTime);
@ -1205,12 +1122,8 @@ void Application::update(float deltaTime) {
throw; throw;
} }
} }
auto r2 = std::chrono::high_resolution_clock::now();
rendererTime += std::chrono::duration<float, std::milli>(r2 - r1).count();
// Update UI // Update UI
updateCheckpoint = "ui update"; updateCheckpoint = "ui update";
auto u1 = std::chrono::high_resolution_clock::now();
if (uiManager) { if (uiManager) {
try { try {
uiManager->update(deltaTime); uiManager->update(deltaTime);
@ -1222,18 +1135,6 @@ void Application::update(float deltaTime) {
throw; throw;
} }
} }
auto u2 = std::chrono::high_resolution_clock::now();
uiTime += std::chrono::duration<float, std::milli>(u2 - u1).count();
updateCheckpoint = "renderer/ui profile log";
if (state == AppState::IN_GAME && ++rendererProfileCounter >= 60) {
if (core::Logger::getInstance().shouldLog(core::LogLevel::DEBUG)) {
LOG_DEBUG("RENDERER/UI PROFILE (60 frames): renderer=", rendererTime / 60.0f,
"ms ui=", uiTime / 60.0f, "ms");
}
rendererProfileCounter = 0;
rendererTime = uiTime = 0.0f;
}
} catch (const std::bad_alloc& e) { } catch (const std::bad_alloc& e) {
LOG_ERROR("OOM in Application::update checkpoint '", updateCheckpoint, "': ", e.what()); LOG_ERROR("OOM in Application::update checkpoint '", updateCheckpoint, "': ", e.what());
throw; throw;

46
src/game/game_handler.cpp
View file

@ -524,16 +524,6 @@ bool GameHandler::isConnected() const {
} }
void GameHandler::update(float deltaTime) { void GameHandler::update(float deltaTime) {
// Timing profiling (log every 60 frames to reduce spam)
static int profileCounter = 0;
static float socketTime = 0.0f;
static float taxiTime = 0.0f;
static float distanceCheckTime = 0.0f;
static float entityUpdateTime = 0.0f;
static float totalTime = 0.0f;
auto updateStart = std::chrono::high_resolution_clock::now();
// Fire deferred char-create callback (outside ImGui render) // Fire deferred char-create callback (outside ImGui render)
if (pendingCharCreateResult_) { if (pendingCharCreateResult_) {
pendingCharCreateResult_ = false; pendingCharCreateResult_ = false;
@ -547,12 +537,9 @@ void GameHandler::update(float deltaTime) {
} }
// Update socket (processes incoming data and triggers callbacks) // Update socket (processes incoming data and triggers callbacks)
auto socketStart = std::chrono::high_resolution_clock::now();
if (socket) { if (socket) {
socket->update(); socket->update();
} }
auto socketEnd = std::chrono::high_resolution_clock::now();
socketTime += std::chrono::duration<float, std::milli>(socketEnd - socketStart).count();
// Detect server-side disconnect (socket closed during update) // Detect server-side disconnect (socket closed during update)
if (socket && !socket->isConnected() && state != WorldState::DISCONNECTED) { if (socket && !socket->isConnected() && state != WorldState::DISCONNECTED) {
@ -792,9 +779,6 @@ void GameHandler::update(float deltaTime) {
} }
} }
// Taxi logic timing
auto taxiStart = std::chrono::high_resolution_clock::now();
// Detect taxi flight landing: UNIT_FLAG_TAXI_FLIGHT (0x00000100) cleared // Detect taxi flight landing: UNIT_FLAG_TAXI_FLIGHT (0x00000100) cleared
if (onTaxiFlight_) { if (onTaxiFlight_) {
updateClientTaxi(deltaTime); updateClientTaxi(deltaTime);
@ -912,18 +896,12 @@ void GameHandler::update(float deltaTime) {
} }
} }
auto taxiEnd = std::chrono::high_resolution_clock::now();
taxiTime += std::chrono::duration<float, std::milli>(taxiEnd - taxiStart).count();
// Update transport manager // Update transport manager
if (transportManager_) { if (transportManager_) {
transportManager_->update(deltaTime); transportManager_->update(deltaTime);
updateAttachedTransportChildren(deltaTime); updateAttachedTransportChildren(deltaTime);
} }
// Distance check timing
auto distanceStart = std::chrono::high_resolution_clock::now();
// Leave combat if auto-attack target is too far away (leash range) // Leave combat if auto-attack target is too far away (leash range)
// and keep melee intent tightly synced while stationary. // and keep melee intent tightly synced while stationary.
if (autoAttackRequested_ && autoAttackTarget != 0) { if (autoAttackRequested_ && autoAttackTarget != 0) {
@ -1081,12 +1059,6 @@ void GameHandler::update(float deltaTime) {
} }
} }
auto distanceEnd = std::chrono::high_resolution_clock::now();
distanceCheckTime += std::chrono::duration<float, std::milli>(distanceEnd - distanceStart).count();
// Entity update timing
auto entityStart = std::chrono::high_resolution_clock::now();
// Update entity movement interpolation (keeps targeting in sync with visuals) // Update entity movement interpolation (keeps targeting in sync with visuals)
// Only update entities within reasonable distance for performance // Only update entities within reasonable distance for performance
const float updateRadiusSq = 150.0f * 150.0f; // 150 unit radius const float updateRadiusSq = 150.0f * 150.0f; // 150 unit radius
@ -1113,24 +1085,6 @@ void GameHandler::update(float deltaTime) {
} }
} }
auto entityEnd = std::chrono::high_resolution_clock::now();
entityUpdateTime += std::chrono::duration<float, std::milli>(entityEnd - entityStart).count();
}
auto updateEnd = std::chrono::high_resolution_clock::now();
totalTime += std::chrono::duration<float, std::milli>(updateEnd - updateStart).count();
// Log profiling every 60 frames
if (++profileCounter >= 60) {
LOG_DEBUG("UPDATE PROFILE (60 frames): socket=", socketTime / 60.0f, "ms taxi=", taxiTime / 60.0f,
"ms distance=", distanceCheckTime / 60.0f, "ms entity=", entityUpdateTime / 60.0f,
"ms TOTAL=", totalTime / 60.0f, "ms");
profileCounter = 0;
socketTime = 0.0f;
taxiTime = 0.0f;
distanceCheckTime = 0.0f;
entityUpdateTime = 0.0f;
totalTime = 0.0f;
} }
} }