Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove filtering from realtime factor (RTF) calculation #1942

Merged
merged 3 commits into from
Apr 12, 2023
Merged

Remove filtering from realtime factor (RTF) calculation #1942

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
ae7abdc
Improve realtime factor (RTF) calculation
azeey Mar 15, 2023
0add541
Merge remote-tracking branch 'origin/gz-sim7' into improve_rtf
azeey Apr 6, 2023
40e7163
Remove filtering and transfer to WorldStats plugin
azeey Apr 6, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion examples/worlds/camera_sensor.sdf
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@
<plugin
filename="gz-sim-sensors-system"
name="gz::sim::systems::Sensors">
<render_engine>ogre</render_engine>
<render_engine>ogre2</render_engine>
</plugin>
<plugin
filename="gz-sim-user-commands-system"
Expand Down
70 changes: 32 additions & 38 deletions src/SimulationRunner.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -278,8 +278,8 @@ void SimulationRunner::UpdateCurrentInfo()
if (this->requestedRewind)
{
gzdbg << "Rewinding simulation back to initial time." << std::endl;
this->realTimes.clear();
this->simTimes.clear();
this->simTimeDelayed.reset();
this->realTimeDelayed.reset();
this->realTimeFactor = 0;

this->currentInfo.dt = this->simTimeEpoch - this->currentInfo.simTime;
Expand All @@ -301,8 +301,8 @@ void SimulationRunner::UpdateCurrentInfo()
gzdbg << "Seeking to " << std::chrono::duration_cast<std::chrono::seconds>(
this->requestedSeek.value()).count() << "s." << std::endl;

this->realTimes.clear();
this->simTimes.clear();
this->simTimeDelayed.reset();
this->realTimeDelayed.reset();
this->realTimeFactor = 0;

this->currentInfo.dt = this->requestedSeek.value() -
Expand All @@ -319,40 +319,34 @@ void SimulationRunner::UpdateCurrentInfo()

// Regular time flow

// Store the real time and sim time only if not paused.
if (this->realTimeWatch.Running())
{
this->realTimes.push_back(this->realTimeWatch.ElapsedRunTime());
this->simTimes.push_back(this->currentInfo.simTime);
}

// Maintain a window size of 20 for realtime and simtime.
if (this->realTimes.size() > 20)
this->realTimes.pop_front();
if (this->simTimes.size() > 20)
this->simTimes.pop_front();
const double simTimeCount =
static_cast<double>(this->currentInfo.simTime.count());
const double realTimeCount =
static_cast<double>(this->currentInfo.realTime.count());

// Compute the average sim and real times.
std::chrono::steady_clock::duration simAvg{0}, realAvg{0};
std::list<std::chrono::steady_clock::duration>::iterator simIter,
realIter;

simIter = ++(this->simTimes.begin());
realIter = ++(this->realTimes.begin());
while (simIter != this->simTimes.end() && realIter != this->realTimes.end())
if (realTimeCount > 0)
{
simAvg += ((*simIter) - this->simTimes.front());
realAvg += ((*realIter) - this->realTimes.front());
++simIter;
++realIter;
}

// RTF, only compute this if the realTime count is greater than zero. The
// realtTime count could be zero if simulation was started paused.
if (realAvg.count() > 0)
{
this->realTimeFactor = math::precision(
static_cast<double>(simAvg.count()) / realAvg.count(), 4);
// Store the real time and sim time only if not paused.
constexpr double kAlpha = 0.999;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just wondering if this would too aggressive? Sometimes spikes are important for development / debugging purposes. On the other hand, for debugging we could also just compute the per-iteration RTF values if needed using simTime / realTime so I don't have a strong opinion on this. The smooth RTF is great when trying to figure out the overall sim performance.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found when debugging, it's helpful to actually look at a histogram, I have used this one in the past: https://github.com/mjcarroll/ign_imgui

Maybe we should move this into a more main-line place if others would find it useful.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe we create a new filtered_stats topic that outputs this and the current stats topic can just be the instantaneous RTF (Δ simTime/Δ realTime). We can then use the filtered_stats for the GUI and the stats topic for development/debugging. For reference, gazebo-classic had an infinite window and computed RTF = total simTime/total realTime so it didn't fluctuate as much: https://github.com/gazebosim/gazebo-classic/blob/d3584008b47c745c1732a6cd07af68726cd900fa/gazebo/util/Diagnostics.cc#L104-L123

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe we create a new filtered_stats topic that outputs this and the current stats topic can just be the instantaneous RTF (Δ simTime/Δ realTime).

We could also just compute the filtered stats / RTF on the GUI end instead of on the server? I haven't paid attention to the diagnostics much in classic. As for the RTF displayed in the GUI in gazebo-classic, it's computed on the GUI side and uses a size of 20. It subscribes to the ~/world_stats topic which is published at 100Hz (real time). So assuming sim is running at the same speed on real time, that's roughly 2 second window?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, my mistake. I assumed the RTF calculation in the diagnostics was what was displayed in the GUI of gazebo-classic. So I guess the big difference comes from the fact that it's published at 100Hz. With a size of 20, I calculate a 200ms second window, but in gz-sim, assuming we're running at 1000Hz, the window is 20ms.

My main concern was the GUI, so I can put this logic there. We can leave the RTF calculation in SimulationRunner intact so we don't change behavior for now, and change it to instantaneous RTF in Harmonic. Does that sound okay?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ah yes 200ms window ha 😓

We can leave the RTF calculation in SimulationRunner intact so we don't change behavior for now, and change it to instantaneous RTF in Harmonic. Does that sound okay?

sounds good to me!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done in 40e7163 and follow-up PR in gazebosim/gz-gui#529

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found when debugging, it's helpful to actually look at a histogram, I have used this one in the past: https://github.com/mjcarroll/ign_imgui

Maybe we should move this into a more main-line place if others would find it useful.

It could be added as an example in gz-sim. Better yet, it could be a feature of the "Topic Plotting" GUI plugin 😉.

this->simTimeDelayed =
kAlpha * this->simTimeDelayed.value_or(simTimeCount) +
(1.0 - kAlpha) * simTimeCount;

this->realTimeDelayed =
kAlpha * this->realTimeDelayed.value_or(realTimeCount) +
(1.0 - kAlpha) * realTimeCount;

// Compute the average sim and real times.
const double realTimeFiltered = realTimeCount - (*this->realTimeDelayed);
const double simTimeFiltered = simTimeCount - (*this->simTimeDelayed);

// RTF, only compute this if the realTime count is greater than zero. The
// realtTime count could be zero if simulation was started paused.
if (realTimeFiltered > 0)
{
this->realTimeFactor =
math::precision(simTimeFiltered / realTimeFiltered, 4);
}
}

// Fill the current update info
Expand Down Expand Up @@ -413,8 +407,8 @@ void SimulationRunner::UpdatePhysicsParams()
}
if (updated)
{
this->simTimes.clear();
this->realTimes.clear();
this->simTimeDelayed.reset();
this->realTimeDelayed.reset();
// Set as OneTimeChange to make sure the update is not missed
this->entityCompMgr.SetChanged(worldEntity, components::Physics::typeId,
ComponentState::OneTimeChange);
Expand Down
10 changes: 6 additions & 4 deletions src/SimulationRunner.hh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -440,11 +440,13 @@ namespace gz
/// All simulation times will be larger than the epoch. It defaults to 0.
private: std::chrono::steady_clock::duration simTimeEpoch{0};

/// \brief List of simulation times used to compute averages.
private: std::list<std::chrono::steady_clock::duration> simTimes;
/// \brief Holds the delayed simTime which is used to compute a filter
/// real time factor
private: std::optional<double> simTimeDelayed;

/// \brief List of real times used to compute averages.
private: std::list<std::chrono::steady_clock::duration> realTimes;
/// \brief Holds the delayed realTime which is used to compute a filter
/// real time factor
private: std::optional<double> realTimeDelayed;

/// \brief Node for communication.
private: std::unique_ptr<transport::Node> node{nullptr};
Expand Down