Fix video encoder timing

[iche033]

The video encoder timing is incorrect when the source that's being encoded runs at a dynamic / slower FPS than the default video encoding rate (25 FPS). In ignition gazebo, this often happens when recording simulations with fluctuating GUI FPS (e.g. due to objects loading and unloading or complex scene), resulting in videos that have a shorter duration than expected.

More info:
The main cause of the problem is from setting the frame number associated with an input frame to be encoded. When a new frame arrives and is ready to be encoded, the frame is appended to the video by always setting it's frame number to frame count + 1. However, if the frame arrives late, e.g. several seconds late, the frame number should not just be incremented by 1 but a larger number (depending on how late the frame arrives and the video FPS). The timing issue is fixed in this PR by computing the absolute frame number based on the timestamp of the input frame and the specified FPS.

Signed-off-by: Ian Chen [email protected]

[codecov]

Codecov Report

Merging #105 (d6607ee) into ign-common3 (8eb57de) will increase coverage by 1.25%.
The diff coverage is 97.36%.

@@               Coverage Diff               @@
##           ign-common3     #105      +/-   ##
===============================================
+ Coverage        73.99%   75.25%   +1.25%     
===============================================
  Files               69       69              
  Lines             9433     9447      +14     
===============================================
+ Hits              6980     7109     +129     
+ Misses            2453     2338     -115     

Impacted Files	Coverage Δ
av/src/VideoEncoder.cc	72.24% <97.22%> (+23.91%)	⬆️
av/src/Video.cc	53.84% <100.00%> (+53.84%)	⬆️

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 8eb57de...d6607ee. Read the comment docs.

[jennuine]

To test I ran the record_playback_events script before pulling the recent changes. Several of the generated videos were shorter than the specified length. After pulling the recent changes, then running the script again, the videos are now over the specified length. I've discussed this with @iche033 and he is looking into this

[iche033]

update: fc60fbe. Best viewed without white space: https://github.com/ignitionrobotics/ign-common/pull/105/files?w=1

Some decoders (e.g. vlc) are not happy if the jump in frame number is too large. So now encoding duplicate frames to ensure continuous frames to make decoders happy.

[iche033]

After pulling the recent changes, then running the script again, the videos are now over the specified length. I've discussed this with @iche033 and he is looking into this

gazebosim/gz-sim#414 addresses this issue

[jennuine]

Can confirm that these changes along with gazebosim/gz-sim#414 have the generated videos closer to the specified length (1 sec. under). The only thing is that jumps (due to level loading/unloading) are now more exaggerated, making them more noticeable.

For example, before the changes:

After:

[nkoenig]

It looks like the server has moved the robot forward, but the GUI missed those changes. Look at the edge of the robot's light cone. It seems to skip forward. And, the skip is in both the before and after videos.

[nkoenig]

It looks like the server has moved the robot forward, but the GUI missed those changes. Look at the edge of the robot's light cone. It seems to skip forward. And, the skip is in both the before and after videos.

It would be interesting to monitor /clock during a level load.

[iche033]

The only thing is that jumps (due to level loading/unloading) are now more exaggerated, making them more noticeable.

yeah that's a side effect of better timing. It takes into account the actual timing of the pause that happens in the simulation render window. Before this change, the frames just keep getting appended to the end of video, ignoring the pause, and so some of the videos generated have shorter video length.

[iche033]

It looks like the server has moved the robot forward, but the GUI missed those changes.

yeah that's correct. The renderer on the gui side runs at it's own throttled rate and skips rendering any sim states if it can't keep up. Since the gui does not lockstep with server, I think one workaround for reducing the pause effect is to store some of the states in a buffer and try to catch up on rendering some of them after levels finish loading - and we should probably only do this when recording in sim time is enabled.

[nkoenig]

yeah that's correct. The renderer on the gui side runs at it's own throttled rate and skips rendering any sim states if it can't keep up. Since the gui does not lockstep with server, I think one workaround for reducing the pause effect is to store some of the states in a buffer and try to catch up on rendering some of them after levels finish loading - and we should probably only do this when recording in sim time is enabled.

That buffer would be on the server or client side?

[nkoenig]

Is it possible to playback logs without levels enabled? This would prevent level-loading-pauses.

[iche033]

That buffer would be on the server or client side?

on the client side

Is it possible to playback logs without levels enabled?

Currently the log playback system has strict checks to make sure that the playback world state is exactly the same as when its recorded. So it removes all objects that are not supposed to be there in a particular time step. It does not know if objects were added / removed due to levels or users deleting them. We would probably need to add the ability to log level data so we can identify them during playback

[nkoenig]

I think I might have an alternative solution. I've managed to run the gui and server in a single process, and haven't noticed jumps.

[nkoenig]

I think I might have an alternative solution. I've managed to run the gui and server in a single process, and haven't noticed jumps.

Potential fix: gazebosim/gz-sim#417

[iche033]

another potential fix for the video pause/jump issue: gazebosim/gz-sim#419

[mjcarroll]

Overall looks good and makes sense.

Is there any sort of test that we can add that exercises this functionality?

[iche033]

@jennuine do you want to give it a go at writing a test for this? I'm thinking of a test that encodes few frames using AddFrame, saves it to a file, reads it back using the Video class, and verifies the duration of the video, possibly by using a new Duration() function in the Video class. We're using gtest and here's the existing unit test as example. The test I described is more of an integration test that should live in test/integration

[jennuine]

Yes, I'll work on writing a test. Thanks!

[peci1]

I've found another point where more synchronization is needed - the video recorder suffers from the quantum observer effect :-D

When I launch subt simulator with a robot and GUI and start recording, the video runs more or less the same speed all the time. However, if I lock my screen during the recording, the resulting video runs much faster (contains less frames???). Observer affects the system!

sim.zip

sim-unlocked.mp4 shows the video when screen was unlocked all the time
sim-locked.mp4 shows the video when I locked the screen shortly after starting the recording, and unlocked it a while later (about a minute)

[iche033]

I've found another point where more synchronization is needed - the video recorder suffers from the quantum observer effect :-D

I think the lockstep recording feature in gazebosim/gz-sim#419 should help address this issue (unless you're already using this branch?)

[peci1]

unless you're already using this branch?

No, that was with the released version if ign-gazebo. I'll try to figure out a way to test with the lockstep PRs.

Interestingly, rendering into XVFB (which is basically a graphical black hole, but supports reading the render buffer back, so the rendering step can't be skipped) doesn't suffer from the observer effect.

[peci1]

So I've done some tests with the subt simulator, this PR and gazebosim/gz-sim#419 .

The results are here: https://app.box.com/s/s2dtqi5vg2d3cw5pc8fo42oc0g33vnp8 .

In summary, screen locking no longer speeds up the video. That is fixed by #105 itself. PR 419 helps with getting the video timestamped by sim time and getting a smoother outcome. Generally, locked screen means more "tearing" in the resulting video, as if less frames were rendered by the simulator (maybe an optimization of the GPU/OS?).

Description of the files (there's always a lock and nolock version that differ by the fact whether I locked my screen during the recording):

sim-no_pr419-no_lockstep-nolock.mp4 : Only #105 was used. Everything okay, but playback speed matches sim speed.

sim-pr419_lockstep-realtime-nolock.mp4 PR 419 was used, lockstep=true, use_sim_time=false. This is a weird config and it didn't end up well. The simulator got basically stuck during the recording. It might be a good idea to prevent users accidentally setting this config.

sim-pr419_lockstep-simtime-nolock.mp4 PR 419 was used, lockstep=true, use_sim_time=true. Nice smooth videos without visible tearing (even when screen is locked).

sim-pr419_no_lockstep-realtime-nolock.mp4 PR 419 was used, lockstep=false, use_sim_time=false. Playback speed matches sim speed, the video basically matches the one with #105 only (which makes sense because all 419 features are turned off).

sim-pr419_no_lockstep-simtime-nolock.mp4 PR 419 was used, lockstep=false, use_sim_time=true. Not that smooth as with lockstep. Locked screen makes very visible tearing.

[mjcarroll]

Apologies, ended up having to do a force-push to make DCO happy. With @jennuine's test, I'm happy with this, just going to let it pass CI.

[iche033]

@peci1 thanks for testing the posting the results back! They are inline with what I expect. Good call about lockstep=true, use_sim_time=false, I'll add an warning msg in ign-gazebo when this configuration is used.