diff --git a/application/application.cpp b/application/application.cpp index f3dc7544..bb8e6bc8 100644 --- a/application/application.cpp +++ b/application/application.cpp @@ -496,10 +496,12 @@ int eu07_application::run() if (m_headtrack) m_headtrack->update(); - - begin_ui_frame(); Timer::subsystem.loop_input.stop(); + Timer::subsystem.loop_ui_frame.start(); + begin_ui_frame(); + Timer::subsystem.loop_ui_frame.stop(); + // ------------------------------------------------------------------- // multiplayer command relaying logic can seem a bit complex // diff --git a/application/drivermode.cpp b/application/drivermode.cpp index e27c7c76..3979927a 100644 --- a/application/drivermode.cpp +++ b/application/drivermode.cpp @@ -434,6 +434,8 @@ bool driver_mode::update() Timer::subsystem.sim_precipitation.stop(); Timer::subsystem.sim_total.stop(); + // the parts of the vehicle update made in the frame, none when paused + Timer::subsystem.commit_frame(); Timer::subsystem.loop_audio.start(); simulation::Region->update_sounds(); diff --git a/rendering/opengl46/opengl46renderer.cpp b/rendering/opengl46/opengl46renderer.cpp index 1cd93fcd..9d5071ad 100644 --- a/rendering/opengl46/opengl46renderer.cpp +++ b/rendering/opengl46/opengl46renderer.cpp @@ -808,7 +808,7 @@ void opengl46_renderer::SwapBuffers() // a line of a table of times: the name indented and padded to a column, then the time(s) auto const timeline = []( int const Indent, std::string const &Name, std::string const &Values ) { auto line { std::string( static_cast( Indent ), ' ' ) + Name }; - line.resize( std::max( line.size() + 1, 34 ), ' ' ); + line.resize( std::max( line.size() + 1, 44 ), ' ' ); return line + Values + "\n"; }; auto const ms = []( double const Value, int const Precision = 2 ) { @@ -828,15 +828,35 @@ void opengl46_renderer::SwapBuffers() + timers.sim_secondary.average() + timers.sim_trains.average() + timers.sim_events.average() + timers.sim_lights.average() + timers.sim_commands.average() + timers.sim_ui.average() + timers.sim_camera.average() }; auto const loopparts { - timers.loop_input.average() + simulation + timers.loop_audio.average() + timers.loop_particles.average() + timers.loop_renderer_update.average() + timers.loop_input.average() + timers.loop_ui_frame.average() + simulation + timers.loop_audio.average() + timers.loop_particles.average() + timers.loop_renderer_update.average() + timers.loop_terrain.average() + timers.loop_tasks.average() + render + swap }; std::string text; text += timeline( 0, "main loop", ms( mainloop ) + " ms (" + std::to_string( static_cast( std::round( 1000.f / std::max( mainloop, 0.001f ) ) ) ) + " fps)" ); - text += timeline( 1, "input, start of the ui frame", ms( timers.loop_input.average() ) ); + text += timeline( 1, "input, head tracking", ms( timers.loop_input.average() ) ); + text += timeline( 1, "start of the ui frame", ms( timers.loop_ui_frame.average() ) ); text += timeline( 1, "simulation", ms( simulation ) ); text += timeline( 2, "clocks, scripting", ms( timers.sim_scripting.average() ) ); text += timeline( 2, "environment", ms( timers.sim_environment.average() + timers.sim_precipitation.average() ) ); text += timeline( 2, "vehicles (physics, ai)", ms( timers.sim_dynamics.average() ) ); + { + auto const &counts { timers.vehicleslast }; + auto const dynamicsparts { + timers.sim_animations.average() + timers.sim_powergrid.average() + timers.sim_roads.average() + + timers.vehicles_prepare.average() + timers.vehicles_forces.average() + timers.vehicles_update.average() }; + text += timeline( 3, "scenery animations", ms( timers.sim_animations.average() ) ); + text += timeline( 3, "power grid", ms( timers.sim_powergrid.average() ) ); + text += timeline( 3, "road junctions, spawn points", ms( timers.sim_roads.average() ) ); + text += timeline( 3, "wires, constants, neighbours", ms( timers.vehicles_prepare.average() ) ); + text += timeline( 3, "forces, " + std::to_string( counts.steps ) + " steps", ms( timers.vehicles_forces.average() ) ); + text += timeline( 3, "vehicle update", ms( timers.vehicles_update.average() ) ); + text += timeline( 4, "of it ai drivers", ms( timers.vehicles_ai.average() ) ); + text += timeline( 3, "rest", ms( timers.sim_dynamics.average() - dynamicsparts ) ); + text += timeline( + 3, + std::to_string( counts.all ) + " vehicles: " + std::to_string( counts.enabled ) + " enabled, " + std::to_string( counts.active ) + " active, " + + std::to_string( counts.road ) + " road, " + std::to_string( counts.ai ) + " ai", + "" ); + } text += timeline( 2, "secondary steps", ms( timers.sim_secondary.average() ) ); text += timeline( 2, "trains (cabs)", ms( timers.sim_trains.average() ) ); text += timeline( 2, "events", ms( timers.sim_events.average() ) ); diff --git a/simulation/simulation.cpp b/simulation/simulation.cpp index a3f48b5d..20368066 100644 --- a/simulation/simulation.cpp +++ b/simulation/simulation.cpp @@ -31,6 +31,7 @@ http://mozilla.org/MPL/2.0/. #include "vehicle/Train.h" #include "application/application.h" #include "utilities/Logs.h" +#include "utilities/Timer.h" #include "vehicle/Driver.h" namespace simulation { @@ -128,12 +129,18 @@ state_manager::update( double const Deltatime, int Iterationcount ) { auto const totaltime { Deltatime * Iterationcount }; // NOTE: we perform animations first, as they can determine factors like contact with powergrid + Timer::subsystem.sim_animations.start(); TAnimModel::AnimUpdate( totaltime ); // wykonanie zakolejkowanych animacji + Timer::subsystem.sim_animations.stop(); + Timer::subsystem.sim_powergrid.start(); simulation::Powergrid.update( totaltime ); + Timer::subsystem.sim_powergrid.stop(); // road junctions, level crossings and the points road vehicles appear at; ahead of the vehicles, so the drivers act on what these decide + Timer::subsystem.sim_roads.start(); simulation::Junctions.update( totaltime ); simulation::Roadpoints.update( totaltime ); + Timer::subsystem.sim_roads.stop(); simulation::Vehicles.update( Deltatime, Iterationcount ); } diff --git a/utilities/Timer.h b/utilities/Timer.h index dbee4ccd..a59ed80b 100644 --- a/utilities/Timer.h +++ b/utilities/Timer.h @@ -51,6 +51,31 @@ private: std::chrono::microseconds m_last; }; +// time of a part made many times in a frame (for each vehicle, for each step of the physics): the times are added up in the +// frame, and the sums averaged over the frames the way stopwatch averages them. commit() ends the frame +class frame_stopwatch { + +public: + void + start() { + m_start = std::chrono::steady_clock::now(); } + void + stop() { + m_frame += std::chrono::duration( std::chrono::steady_clock::now() - m_start ).count(); } + void + commit() { + m_accumulator = 0.95f * m_accumulator + m_frame; + m_frame = 0.f; } + float + average() const { + return m_accumulator / 20.f; } + +private: + std::chrono::time_point m_start { std::chrono::steady_clock::now() }; + float m_frame { 0.f }; + float m_accumulator { 0.f }; +}; + struct subsystem_stopwatches { stopwatch gfx_total; stopwatch gfx_color; @@ -73,9 +98,37 @@ struct subsystem_stopwatches { stopwatch sim_commands; stopwatch sim_ui; // 50 Hz routines: ui panels, tooltips stopwatch sim_camera; + // parts of sim_dynamics, simulation::state_manager::update() and vehicle_table::update(), made a few times in a frame + frame_stopwatch sim_animations; // queued animations of the scenery models + frame_stopwatch sim_powergrid; + frame_stopwatch sim_roads; // road junctions, level crossings, spawn points of road vehicles + frame_stopwatch vehicles_prepare; // traction wires, constants, neighbours + frame_stopwatch vehicles_forces; // forces and the steps of the physics + frame_stopwatch vehicles_update; // TDynamicObject::Update(), with the ai in it + frame_stopwatch vehicles_ai; // TController::Update() of the vehicles with a driver + // what the vehicle update went through in the last frame: vehicles, of them enabled, road vehicles, with a driver run by the + // ai, with the physics active; and the steps of the physics + struct vehicle_counts { + unsigned int all { 0 }; + unsigned int enabled { 0 }; + unsigned int road { 0 }; + unsigned int ai { 0 }; + unsigned int active { 0 }; + unsigned int steps { 0 }; + }; + vehicle_counts vehicles; // of the frame under way + vehicle_counts vehicleslast; // of the last frame + // ends the frame of the frame_stopwatches and of the counts + void + commit_frame() { + for( auto *part : { &sim_animations, &sim_powergrid, &sim_roads, &vehicles_prepare, &vehicles_forces, &vehicles_update, &vehicles_ai } ) { + part->commit(); } + vehicleslast = vehicles; + vehicles = {}; } stopwatch mainloop_total; // parts of the main loop outside the simulation and Render(), for the debug panel - stopwatch loop_input; // events, head tracking, start of the ui frame + stopwatch loop_input; // events, head tracking + stopwatch loop_ui_frame; // start of the ui frame stopwatch loop_audio; // sounds of the scenery and the audio renderer stopwatch loop_particles; // cpu particles stopwatch loop_renderer_update; // gfx_renderer::Update() diff --git a/vehicle/DynObj.cpp b/vehicle/DynObj.cpp index 32ba307f..854f4820 100644 --- a/vehicle/DynObj.cpp +++ b/vehicle/DynObj.cpp @@ -3556,7 +3556,9 @@ bool TDynamicObject::Update(double dt, double dt1) MED_oldFED = FzadED; } + Timer::subsystem.vehicles_ai.start(); Mechanik->Update(dt1); // przebłyski świadomości AI + Timer::subsystem.vehicles_ai.stop(); } // fragment "z EXE Kursa" @@ -8606,6 +8608,20 @@ vehicle_table::update( double Deltatime, int Iterationcount ) { // na którą by się zapisywały wszystkie pojazdy będące w ruchu // pojazdy stojące nie potrzebują aktualizacji, chyba że np. ktoś im zmieni nastawę hamulca // oddzielną listę można by zrobić na pojazdy z napędem, najlepiej posortowaną wg typu napędu + // what the update goes through, for the debug panel. the counts are of the last call in the frame + auto &counts { Timer::subsystem.vehicles }; + counts.all = static_cast( m_items.size() ); + counts.enabled = counts.road = counts.ai = counts.active = 0; + counts.steps += static_cast( std::max( Iterationcount, 1 ) ); + for( auto const *vehicle : m_items ) { + if( false == vehicle->bEnabled ) { continue; } + ++counts.enabled; + if( vehicle->MoverParameters->CategoryFlag & 2 ) { ++counts.road; } + if( ( vehicle->Mechanik != nullptr ) && vehicle->Mechanik->AIControllFlag ) { ++counts.ai; } + if( vehicle->MoverParameters->PhysicActivation || vehicle->MechInside ) { ++counts.active; } + } + + Timer::subsystem.vehicles_prepare.start(); for( auto *vehicle : m_items ) { if( false == vehicle->bEnabled ) { continue; } // Ra: zmienić warunek na sprawdzanie pantografów w jednej zmiennej: czy pantografy i czy podniesione @@ -8615,6 +8631,8 @@ vehicle_table::update( double Deltatime, int Iterationcount ) { vehicle->MoverParameters->ComputeConstans(); vehicle->update_neighbours(); } + Timer::subsystem.vehicles_prepare.stop(); + Timer::subsystem.vehicles_forces.start(); if( Iterationcount > 1 ) { // ABu: ponizsze wykonujemy tylko jesli wiecej niz jedna iteracja for( int iteration = 0; iteration < Iterationcount - 1; ++iteration ) { @@ -8629,13 +8647,16 @@ vehicle_table::update( double Deltatime, int Iterationcount ) { for( auto *vehicle : m_items ) { vehicle->UpdateForce( Deltatime ); } + Timer::subsystem.vehicles_forces.stop(); auto const totaltime { Deltatime * Iterationcount }; // całkowity czas + Timer::subsystem.vehicles_update.start(); for( auto *vehicle : m_items ) { // Ra 2015-01: tylko tu przelicza sieć trakcyjną vehicle->Update( Deltatime, totaltime ); } + Timer::subsystem.vehicles_update.stop(); // jeśli jest coś do usunięcia z listy, to trzeba na końcu erase_disabled();