From 058846d687bef214fe6216938d4cf8bf2c79290e Mon Sep 17 00:00:00 2001 From: sfan5 Date: Sat, 22 Jan 2022 17:56:35 +0100 Subject: [PATCH] Rework drawtime and related timekeeping code to use microseconds --- src/client/camera.cpp | 2 +- src/client/camera.h | 4 +- src/client/game.cpp | 153 ++++++++++++++++++++------------------ src/client/game.h | 2 +- src/client/gameui.cpp | 8 +- src/client/gameui.h | 2 + src/gui/profilergraph.cpp | 15 +++- 7 files changed, 101 insertions(+), 85 deletions(-) diff --git a/src/client/camera.cpp b/src/client/camera.cpp index 3712d77ea..d1f19adb3 100644 --- a/src/client/camera.cpp +++ b/src/client/camera.cpp @@ -308,7 +308,7 @@ void Camera::addArmInertia(f32 player_yaw) } } -void Camera::update(LocalPlayer* player, f32 frametime, f32 busytime, f32 tool_reload_ratio) +void Camera::update(LocalPlayer* player, f32 frametime, f32 tool_reload_ratio) { // Get player position // Smooth the movement when walking up stairs diff --git a/src/client/camera.h b/src/client/camera.h index 3e1cb4fdf..403d6024c 100644 --- a/src/client/camera.h +++ b/src/client/camera.h @@ -140,9 +140,7 @@ public: void step(f32 dtime); // Update the camera from the local player's position. - // busytime is used to adjust the viewing range. - void update(LocalPlayer* player, f32 frametime, f32 busytime, - f32 tool_reload_ratio); + void update(LocalPlayer* player, f32 frametime, f32 tool_reload_ratio); // Update render distance void updateViewingRange(); diff --git a/src/client/game.cpp b/src/client/game.cpp index 7478e225f..8959b5f15 100644 --- a/src/client/game.cpp +++ b/src/client/game.cpp @@ -575,10 +575,19 @@ public: /**************************************************************************** ****************************************************************************/ -const float object_hit_delay = 0.2; +const static float object_hit_delay = 0.2; struct FpsControl { - u32 last_time, busy_time, sleep_time; + FpsControl() : last_time(0), busy_time(0), sleep_time(0) {} + + void reset(); + + void limit(IrrlichtDevice *device, f32 *dtime); + + u32 getBusyMs() const { return busy_time / 1000; } + + // all values in microseconds (us) + u64 last_time, busy_time, sleep_time; }; @@ -712,7 +721,7 @@ protected: void updatePlayerControl(const CameraOrientation &cam); void step(f32 *dtime); void processClientEvents(CameraOrientation *cam); - void updateCamera(u32 busy_time, f32 dtime); + void updateCamera(f32 dtime); void updateSound(f32 dtime); void processPlayerInteraction(f32 dtime, bool show_hud, bool show_debug); /*! @@ -743,8 +752,6 @@ protected: void updateShadows(); // Misc - void limitFps(FpsControl *fps_timings, f32 *dtime); - void showOverlayMessage(const char *msg, float dtime, int percent, bool draw_clouds = true); @@ -1056,14 +1063,14 @@ void Game::run() RunStats stats = { 0 }; CameraOrientation cam_view_target = { 0 }; CameraOrientation cam_view = { 0 }; - FpsControl draw_times = { 0 }; + FpsControl draw_times; f32 dtime; // in seconds /* Clear the profiler */ Profiler::GraphValues dummyvalues; g_profiler->graphGet(dummyvalues); - draw_times.last_time = m_rendering_engine->get_timer_time(); + draw_times.reset(); set_light_table(g_settings->getFloat("display_gamma")); @@ -1095,7 +1102,7 @@ void Game::run() // Calculate dtime = // m_rendering_engine->run() from this iteration // + Sleep time until the wanted FPS are reached - limitFps(&draw_times, &dtime); + draw_times.limit(device, &dtime); // Prepare render data for next iteration @@ -1125,7 +1132,7 @@ void Game::run() step(&dtime); processClientEvents(&cam_view_target); updateDebugState(); - updateCamera(draw_times.busy_time, dtime); + updateCamera(dtime); updateSound(dtime); processPlayerInteraction(dtime, m_game_ui->m_flags.show_hud, m_game_ui->m_flags.show_basic_debug); @@ -1495,15 +1502,15 @@ bool Game::connectToServer(const GameStartData &start_data, try { input->clear(); - FpsControl fps_control = { 0 }; + FpsControl fps_control; f32 dtime; f32 wait_time = 0; // in seconds - fps_control.last_time = m_rendering_engine->get_timer_time(); + fps_control.reset(); while (m_rendering_engine->run()) { - limitFps(&fps_control, &dtime); + fps_control.limit(device, &dtime); // Update client and server client->step(dtime); @@ -1570,14 +1577,14 @@ bool Game::getServerContent(bool *aborted) { input->clear(); - FpsControl fps_control = { 0 }; + FpsControl fps_control; f32 dtime; // in seconds - fps_control.last_time = m_rendering_engine->get_timer_time(); + fps_control.reset(); while (m_rendering_engine->run()) { - limitFps(&fps_control, &dtime); + fps_control.limit(device, &dtime); // Update client and server client->step(dtime); @@ -1774,10 +1781,10 @@ void Game::updateProfilers(const RunStats &stats, const FpsControl &draw_times, } // Update update graphs - g_profiler->graphAdd("Time non-rendering [ms]", + g_profiler->graphAdd("Time non-rendering [us]", draw_times.busy_time - stats.drawtime); - g_profiler->graphAdd("Sleep [ms]", draw_times.sleep_time); + g_profiler->graphAdd("Sleep [us]", draw_times.sleep_time); g_profiler->graphAdd("FPS", 1.0f / dtime); } @@ -1810,9 +1817,9 @@ void Game::updateStats(RunStats *stats, const FpsControl &draw_times, /* Busytime average and jitter calculation */ jp = &stats->busy_time_jitter; - jp->avg = jp->avg + draw_times.busy_time * 0.02; + jp->avg = jp->avg + draw_times.getBusyMs() * 0.02; - jitter = draw_times.busy_time - jp->avg; + jitter = draw_times.getBusyMs() - jp->avg; if (jitter > jp->max) jp->max = jitter; @@ -2932,7 +2939,7 @@ void Game::updateChat(f32 dtime) m_game_ui->updateChatSize(); } -void Game::updateCamera(u32 busy_time, f32 dtime) +void Game::updateCamera(f32 dtime) { LocalPlayer *player = client->getEnv().getLocalPlayer(); @@ -2971,7 +2978,7 @@ void Game::updateCamera(u32 busy_time, f32 dtime) float tool_reload_ratio = runData.time_from_last_punch / full_punch_interval; tool_reload_ratio = MYMIN(tool_reload_ratio, 1.0); - camera->update(player, dtime, busy_time / 1000.0f, tool_reload_ratio); + camera->update(player, dtime, tool_reload_ratio); camera->step(dtime); v3f camera_position = camera->getPosition(); @@ -3847,6 +3854,24 @@ void Game::updateFrame(ProfilerGraph *graph, RunStats *stats, f32 dtime, ); } + /* + Damage camera tilt + */ + if (player->hurt_tilt_timer > 0.0f) { + player->hurt_tilt_timer -= dtime * 6.0f; + + if (player->hurt_tilt_timer < 0.0f) + player->hurt_tilt_strength = 0.0f; + } + + /* + Update minimap pos and rotation + */ + if (mapper && m_game_ui->m_flags.show_hud) { + mapper->setPos(floatToInt(player->getPosition(), BS)); + mapper->setAngle(player->getYaw()); + } + /* Get chat messages from client */ @@ -3920,11 +3945,11 @@ void Game::updateFrame(ProfilerGraph *graph, RunStats *stats, f32 dtime, } while (false); /* - Drawing begins + ==================== Drawing begins ==================== */ - const video::SColor &skycolor = sky->getSkyColor(); + const video::SColor skycolor = sky->getSkyColor(); - TimeTaker tt_draw("Draw scene"); + TimeTaker tt_draw("Draw scene", nullptr, PRECISION_MICRO); driver->beginScene(true, true, skycolor); bool draw_wield_tool = (m_game_ui->m_flags.show_hud && @@ -3963,25 +3988,7 @@ void Game::updateFrame(ProfilerGraph *graph, RunStats *stats, f32 dtime, } /* - Damage camera tilt - */ - if (player->hurt_tilt_timer > 0.0f) { - player->hurt_tilt_timer -= dtime * 6.0f; - - if (player->hurt_tilt_timer < 0.0f) - player->hurt_tilt_strength = 0.0f; - } - - /* - Update minimap pos and rotation - */ - if (mapper && m_game_ui->m_flags.show_hud) { - mapper->setPos(floatToInt(player->getPosition(), BS)); - mapper->setAngle(player->getYaw()); - } - - /* - End scene + ==================== End scene ==================== */ if (++m_reset_HW_buffer_counter > 500) { /* @@ -4004,11 +4011,12 @@ void Game::updateFrame(ProfilerGraph *graph, RunStats *stats, f32 dtime, driver->removeAllHardwareBuffers(); m_reset_HW_buffer_counter = 0; } + driver->endScene(); stats->drawtime = tt_draw.stop(true); - g_profiler->avg("Game::updateFrame(): draw scene [ms]", stats->drawtime); - g_profiler->graphAdd("Update frame [ms]", tt_update.stop(true)); + g_profiler->graphAdd("Draw scene [us]", stats->drawtime); + g_profiler->avg("Game::updateFrame(): update frame [ms]", tt_update.stop(true)); } /* Log times and stuff for visualization */ @@ -4052,47 +4060,46 @@ void Game::updateShadows() Misc ****************************************************************************/ -/* On some computers framerate doesn't seem to be automatically limited - */ -inline void Game::limitFps(FpsControl *fps_timings, f32 *dtime) +void FpsControl::reset() { - // not using getRealTime is necessary for wine - device->getTimer()->tick(); // Maker sure device time is up-to-date - u32 time = device->getTimer()->getTime(); - u32 last_time = fps_timings->last_time; + last_time = porting::getTimeUs(); +} - if (time > last_time) // Make sure time hasn't overflowed - fps_timings->busy_time = time - last_time; - else - fps_timings->busy_time = 0; - - u32 frametime_min = 1000 / ( +/* + * On some computers framerate doesn't seem to be automatically limited + */ +void FpsControl::limit(IrrlichtDevice *device, f32 *dtime) +{ + const u64 frametime_min = 1000000.0f / ( device->isWindowFocused() && !g_menumgr.pausesGame() ? g_settings->getFloat("fps_max") : g_settings->getFloat("fps_max_unfocused")); - if (fps_timings->busy_time < frametime_min) { - fps_timings->sleep_time = frametime_min - fps_timings->busy_time; - device->sleep(fps_timings->sleep_time); + u64 time = porting::getTimeUs(); + + if (time > last_time) // Make sure time hasn't overflowed + busy_time = time - last_time; + else + busy_time = 0; + + if (busy_time < frametime_min) { + sleep_time = frametime_min - busy_time; + if (sleep_time > 1000) + sleep_ms(sleep_time / 1000); } else { - fps_timings->sleep_time = 0; + sleep_time = 0; } - /* Get the new value of the device timer. Note that device->sleep() may - * not sleep for the entire requested time as sleep may be interrupted and - * therefore it is arguably more accurate to get the new time from the - * device rather than calculating it by adding sleep_time to time. - */ + // Read the timer again to accurately determine how long we actually slept, + // rather than calculating it by adding sleep_time to time. + time = porting::getTimeUs(); - device->getTimer()->tick(); // Update device timer - time = device->getTimer()->getTime(); - - if (time > last_time) // Make sure last_time hasn't overflowed - *dtime = (time - last_time) / 1000.0; + if (time > last_time) // Make sure last_time hasn't overflowed + *dtime = (time - last_time) / 1000000.0f; else *dtime = 0; - fps_timings->last_time = time; + last_time = time; } void Game::showOverlayMessage(const char *msg, float dtime, int percent, bool draw_clouds) diff --git a/src/client/game.h b/src/client/game.h index fbbf106db..d87e747c5 100644 --- a/src/client/game.h +++ b/src/client/game.h @@ -33,7 +33,7 @@ struct Jitter { }; struct RunStats { - u32 drawtime; + u64 drawtime; // (us) Jitter dtime_jitter, busy_time_jitter; }; diff --git a/src/client/gameui.cpp b/src/client/gameui.cpp index ecb8e0ec4..bae5241b1 100644 --- a/src/client/gameui.cpp +++ b/src/client/gameui.cpp @@ -104,16 +104,16 @@ void GameUI::update(const RunStats &stats, Client *client, MapDrawControl *draw_ // Minimal debug text must only contain info that can't give a gameplay advantage if (m_flags.show_minimal_debug) { - static float drawtime_avg = 0; - drawtime_avg = drawtime_avg * 0.95 + stats.drawtime * 0.05; - u16 fps = 1.0 / stats.dtime_jitter.avg; + const u16 fps = 1.0 / stats.dtime_jitter.avg; + m_drawtime_avg *= 0.95f; + m_drawtime_avg += 0.05f * (stats.drawtime / 1000); std::ostringstream os(std::ios_base::binary); os << std::fixed << PROJECT_NAME_C " " << g_version_hash << " | FPS: " << fps << std::setprecision(0) - << " | drawtime: " << drawtime_avg << "ms" + << " | drawtime: " << m_drawtime_avg << "ms" << std::setprecision(1) << " | dtime jitter: " << (stats.dtime_jitter.max_fraction * 100.0) << "%" diff --git a/src/client/gameui.h b/src/client/gameui.h index 3f31f1b57..cc9377bdc 100644 --- a/src/client/gameui.h +++ b/src/client/gameui.h @@ -110,6 +110,8 @@ public: private: Flags m_flags; + float m_drawtime_avg = 0; + gui::IGUIStaticText *m_guitext = nullptr; // First line of debug text gui::IGUIStaticText *m_guitext2 = nullptr; // Second line of debug text diff --git a/src/gui/profilergraph.cpp b/src/gui/profilergraph.cpp index b29285e2f..f71ef3799 100644 --- a/src/gui/profilergraph.cpp +++ b/src/gui/profilergraph.cpp @@ -94,20 +94,29 @@ void ProfilerGraph::draw(s32 x_left, s32 y_bottom, video::IVideoDriver *driver, show_min = 0; } - s32 texth = 15; + const s32 texth = 15; char buf[10]; - porting::mt_snprintf(buf, sizeof(buf), "%.3g", show_max); + if (floorf(show_max) == show_max) + porting::mt_snprintf(buf, sizeof(buf), "%.5g", show_max); + else + porting::mt_snprintf(buf, sizeof(buf), "%.3g", show_max); font->draw(utf8_to_wide(buf).c_str(), core::rect(textx, y - graphh, textx2, y - graphh + texth), meta.color); - porting::mt_snprintf(buf, sizeof(buf), "%.3g", show_min); + + if (floorf(show_min) == show_min) + porting::mt_snprintf(buf, sizeof(buf), "%.5g", show_min); + else + porting::mt_snprintf(buf, sizeof(buf), "%.3g", show_min); font->draw(utf8_to_wide(buf).c_str(), core::rect(textx, y - texth, textx2, y), meta.color); + font->draw(utf8_to_wide(id).c_str(), core::rect(textx, y - graphh / 2 - texth / 2, textx2, y - graphh / 2 + texth / 2), meta.color); + s32 graph1y = y; s32 graph1h = graphh; bool relativegraph = (show_min != 0 && show_min != show_max);