Rework drawtime and related timekeeping code to use microseconds

This commit is contained in:
sfan5 2022-01-22 17:56:35 +01:00
parent fc161e757c
commit 058846d687
7 changed files with 101 additions and 85 deletions

@ -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

@ -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();

@ -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.
*/
device->getTimer()->tick(); // Update device timer
time = device->getTimer()->getTime();
// 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();
if (time > last_time) // Make sure last_time hasn't overflowed
*dtime = (time - last_time) / 1000.0;
*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)

@ -33,7 +33,7 @@ struct Jitter {
};
struct RunStats {
u32 drawtime;
u64 drawtime; // (us)
Jitter dtime_jitter, busy_time_jitter;
};

@ -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) << "%"

@ -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

@ -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];
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<s32>(textx, y - graphh, textx2,
y - graphh + texth),
meta.color);
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<s32>(textx, y - texth, textx2, y), meta.color);
font->draw(utf8_to_wide(id).c_str(),
core::rect<s32>(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);