From 11e00a8dedd8f430f6528d2852169d134c17367a Mon Sep 17 00:00:00 2001 From: Kae <80987908+Novaenia@users.noreply.github.com> Date: Mon, 3 Jul 2023 16:04:17 +1000 Subject: [PATCH] Change debug render time logging to use microseconds --- source/client/StarClientApplication.cpp | 16 +++++++++++----- source/core/StarTime.cpp | 13 +++++++++++++ source/core/StarTime.hpp | 3 +++ source/frontend/StarMainInterface.cpp | 4 ++-- source/game/StarWorldClient.cpp | 4 ++-- source/rendering/StarWorldPainter.cpp | 4 ++-- 6 files changed, 33 insertions(+), 11 deletions(-) diff --git a/source/client/StarClientApplication.cpp b/source/client/StarClientApplication.cpp index 7a813c4..ebaa211 100644 --- a/source/client/StarClientApplication.cpp +++ b/source/client/StarClientApplication.cpp @@ -386,20 +386,26 @@ void ClientApplication::render() { WorldClientPtr worldClient = m_universeClient->worldClient(); RendererPtr renderer = Application::renderer(); if (worldClient) { - int64_t start = Time::monotonicMilliseconds(); - + auto start = Time::monotonicMicroseconds(); renderer->switchEffectConfig("world"); worldClient->render(m_renderData, TilePainter::BorderTileSize); + LogMap::set("render_world_client", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); + + start = Time::monotonicMicroseconds(); m_worldPainter->render(m_renderData, [&]() { worldClient->waitForLighting(); }); + LogMap::set("render_world_painter", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); + + start = Time::monotonicMicroseconds(); m_mainInterface->renderInWorldElements(); + LogMap::set("render_world_elements", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); renderer->switchEffectConfig("default"); - LogMap::set("render_world", strf("{}ms", Time::monotonicMilliseconds() - start)); + LogMap::set("render_world_total", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); } - int64_t start = Time::monotonicMilliseconds(); + auto start = Time::monotonicMicroseconds(); m_mainInterface->render(); m_cinematicOverlay->render(); - LogMap::set("render_ui", strf("{}ms", Time::monotonicMilliseconds() - start)); + LogMap::set("render_interface", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); } if (!m_errorScreen->accepted()) diff --git a/source/core/StarTime.cpp b/source/core/StarTime.cpp index abb6aae..622ea50 100644 --- a/source/core/StarTime.cpp +++ b/source/core/StarTime.cpp @@ -20,6 +20,10 @@ int64_t Time::monotonicMilliseconds() { return ticksToMilliseconds(monotonicTicks(), monotonicTickFrequency()); } +int64_t Time::monotonicMicroseconds() { + return ticksToMicroseconds(monotonicTicks(), monotonicTickFrequency()); +} + String Time::printDuration(double time) { String hours; String minutes; @@ -58,6 +62,11 @@ int64_t Time::ticksToMilliseconds(int64_t ticks, int64_t tickFrequency) { return (ticks + ticksPerMs / 2) / ticksPerMs; } +int64_t Time::ticksToMicroseconds(int64_t ticks, int64_t tickFrequency) { + int64_t ticksPerUs = (tickFrequency + 500000) / 1000000; + return (ticks + ticksPerUs / 2) / ticksPerUs; +} + int64_t Time::secondsToTicks(double seconds, int64_t tickFrequency) { return round(seconds * tickFrequency); } @@ -66,6 +75,10 @@ int64_t Time::millisecondsToTicks(int64_t milliseconds, int64_t tickFrequency) { return milliseconds * ((tickFrequency + 500) / 1000); } +int64_t Time::microsecondsToTicks(int64_t microseconds, int64_t tickFrequency) { + return microseconds * ((tickFrequency + 500000) / 1000000); +} + Clock::Clock(bool start) { m_elapsedTicks = 0; m_running = false; diff --git a/source/core/StarTime.hpp b/source/core/StarTime.hpp index a071df5..0905a5d 100644 --- a/source/core/StarTime.hpp +++ b/source/core/StarTime.hpp @@ -14,6 +14,7 @@ namespace Time { double monotonicTime(); int64_t monotonicMilliseconds(); + int64_t monotonicMicroseconds(); // Pretty print a duration of time (In days, hours, minutes, seconds, and milliseconds) String printDuration(double time); @@ -34,8 +35,10 @@ namespace Time { double ticksToSeconds(int64_t ticks, int64_t tickFrequency); int64_t ticksToMilliseconds(int64_t ticks, int64_t tickFrequency); + int64_t ticksToMicroseconds(int64_t ticks, int64_t tickFrequency); int64_t secondsToTicks(double seconds, int64_t tickFrequency); int64_t millisecondsToTicks(int64_t milliseconds, int64_t tickFrequency); + int64_t microsecondsToTicks(int64_t microseconds, int64_t tickFrequency); } // Keeps track of elapsed real time since a given moment. Guaranteed diff --git a/source/frontend/StarMainInterface.cpp b/source/frontend/StarMainInterface.cpp index 83eb1b4..fb28e84 100644 --- a/source/frontend/StarMainInterface.cpp +++ b/source/frontend/StarMainInterface.cpp @@ -1263,7 +1263,7 @@ void MainInterface::renderDebug() { m_guiContext->setFont(m_config->debugFont); m_guiContext->setLineSpacing(0.5f); m_guiContext->setFontProcessingDirectives(m_config->debugFontDirectives); - m_guiContext->setFontColor(Color::Green.toRgba()); + m_guiContext->setFontColor(Color::White.toRgba()); m_guiContext->setFontMode(FontMode::Normal); bool clearMap = m_debugMapClearTimer.wrapTick(); @@ -1277,7 +1277,7 @@ void MainInterface::renderDebug() { int counter = 0; for (auto const& pair : logMapValues) { TextPositioning positioning = {Vec2F(m_config->debugOffset[0], windowHeight() - m_config->debugOffset[1] - m_config->fontSize * interfaceScale() * counter++)}; - String& text = formatted.emplace_back(strf("^white;{}^lightgray;:^reset; {}", pair.first, pair.second)); + String& text = formatted.emplace_back(strf("{}^lightgray;:^green,set; {}", pair.first, pair.second)); m_debugTextRect.combine(m_guiContext->determineTextSize(text, positioning).padded(m_config->debugBackgroundPad)); } diff --git a/source/game/StarWorldClient.cpp b/source/game/StarWorldClient.cpp index 486105a..d1c9390 100644 --- a/source/game/StarWorldClient.cpp +++ b/source/game/StarWorldClient.cpp @@ -1452,13 +1452,13 @@ void WorldClient::lightingMain() { return; if (m_renderData) { - int64_t start = Time::monotonicMilliseconds(); + int64_t start = Time::monotonicMicroseconds(); lightingTileGather(); m_lightingCalculator.calculate(m_renderData->lightMap); m_renderData = nullptr; - LogMap::set("render_light_calc", strf("{}ms", Time::monotonicMilliseconds() - start)); + LogMap::set("render_world_async_lighting_calc_time", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); } m_lightingCond.wait(m_lightingMutex); diff --git a/source/rendering/StarWorldPainter.cpp b/source/rendering/StarWorldPainter.cpp index 693b419..30ecfb7 100644 --- a/source/rendering/StarWorldPainter.cpp +++ b/source/rendering/StarWorldPainter.cpp @@ -70,9 +70,9 @@ void WorldPainter::render(WorldRenderData& renderData, function lightWai m_environmentPainter->renderFrontOrbiters(orbiterAndPlanetRatio, Vec2F(m_camera.screenSize()), renderData.skyRenderData); if (lightWaiter) { - int64_t start = Time::monotonicMilliseconds(); + auto start = Time::monotonicMicroseconds(); lightWaiter(); - LogMap::set("render_light_wait", strf("{}ms", Time::monotonicMilliseconds() - start)); + LogMap::set("render_world_async_lighting_wait_time", strf(u8"{:05d}µs", Time::monotonicMicroseconds() - start)); } if (renderData.isFullbright) {