Opened 18 months ago

Closed 7 weeks ago

#13170 closed Patch - Feature (Abandoned)

Restore realtime priority capability for vsync thread

Reported by: Doug Larrick <doug@…> Owned by: Peter Bennett
Priority: minor Milestone: unknown
Component: Ports - rPi Version: Master Head
Severity: medium Keywords:
Cc: piotr.oniszczuk@… Ticket locked: no

Description

MythTV has a settings item for using realtime scheduling for the video sync thread, but it's no longer hooked up to anything in the code. This patch restores realtime scheduling for this thread.

https://github.com/MythTV/mythtv/pull/158

Change History (24)

comment:1 Changed 18 months ago by Peter Bennett

Reporter: changed from doug@… to Doug Larrick <doug@…>

comment:2 Changed 18 months ago by Peter Bennett

Please let me know how to recreate the issue that this is solving, on Raspberry Pi. If possible supply a video file. Anything I can do which will show an improvement with realtime scheduling enabled.

comment:3 Changed 18 months ago by Peter Bennett

Status: newinfoneeded_new

comment:4 Changed 18 months ago by Doug Larrick <doug@…>

Play any file (the higher bitrate the better) with --verbose playback turned on and watch the log lines of the type:

2017-11-05 11:44:45.654422 I  Player(4): FPS:   29.88 Mean: 33463 Std.Dev:  8714 CPUs: 10% 5% 8% 6% 
2017-11-05 11:44:49.613875 I  Player(4): FPS:   30.07 Mean: 33257 Std.Dev:  8717 CPUs: 10% 6% 4% 7% 
2017-11-05 11:44:53.582721 I  Player(4): FPS:   30.00 Mean: 33337 Std.Dev:  7953 CPUs: 10% 5% 6% 5% 

Notice that with realtime scheduling enabled, the "Mean" is more even and the "Std.Dev" is lower, especially at times when CPU is higher.

comment:5 Changed 18 months ago by sphery

Dup of #12362 . FWIW, the code was explicitly removed from MythTV because of a planned switch from pthreads to QThread. See 5aee5e7393f79c86 (and #5501 ).

comment:6 Changed 18 months ago by Doug Larrick <doug@…>

Duplicate, sure, but with patch.

I would say that realtime scheduling of the video sync thread is crucial on a low-resource device such as Raspberry Pi. Certainly it helps immensely in my testing -- as it did on the PC hardware of the day back in 2004 when I originally implemented this feature. Showing the next frame at the correct time is a real-time task, after all. On a modern PC there's enough spare CPU power that it hardly matters. Unfortunately QThread does not seem to support realtime scheduling.

comment:7 Changed 18 months ago by Doug Larrick <doug@…>

comment:8 Changed 18 months ago by Peter Bennett

I tried with and without this patch, also I tried without the patch and running sudo renice -20 and the pid of mythfrontend after starting the frontend. I did not see any visible or audible difference. With the patch the standard deviations are fractionally smaller. see below. Do you set the governor before using frontend (see https://www.mythtv.org/wiki/Raspberry_Pi#System_Performance)? That makes a huge difference in the cases where the raspberry pi has decided on its own authority to go into power saving mode. Before I discovered that I was tearing my hair out because sometimes playback was perfectly smooth and sometimes it was awful.

I would like to get rid of the extra log message, Buffering: ValidVideoFrames: 0. It floods the log if you have -v playback. It always shows zero because I believe that this code is only entered when there are 0 frames available. There are so many repetitions of waiting buffers condition that the original authors instituted the code just below it to only display the buffering messages every 100ms (code starting with if (last_msg > 100)), but this message is displaying way more often than that.

Reaspberry pi normal

FPS:   30.32 Mean: 32981 Std.Dev: 10157 CPUs: 11% 17% 11% 12% 
FPS:   29.98 Mean: 33350 Std.Dev:  8692 CPUs: 1% 10% 14% 8% 
FPS:   30.12 Mean: 33202 Std.Dev:  6688 CPUs: 1% 9% 10% 9% 
FPS:   29.86 Mean: 33490 Std.Dev:  8148 CPUs: 4% 7% 14% 13% 
FPS:   29.97 Mean: 33370 Std.Dev:  7488 CPUs: 0% 7% 7% 15% 
FPS:   29.99 Mean: 33344 Std.Dev:  6871 CPUs: 1% 9% 10% 12% 
FPS:   30.00 Mean: 33336 Std.Dev:  9016 CPUs: 1% 9% 13% 11% 
FPS:   29.97 Mean: 33368 Std.Dev:  6448 CPUs: 4% 9% 9% 8% 
FPS:   29.89 Mean: 33454 Std.Dev:  8882 CPUs: 1% 9% 13% 10% 

Reaspberry pi with sudo renice -20

FPS:   29.92 Mean: 33424 Std.Dev: 12287 CPUs: 9% 14% 10% 11% 
FPS:   29.84 Mean: 33514 Std.Dev:  8227 CPUs: 12% 13% 7% 6% 
FPS:   30.10 Mean: 33227 Std.Dev:  5612 CPUs: 5% 6% 9% 11% 
FPS:   29.93 Mean: 33412 Std.Dev:  7575 CPUs: 8% 7% 9% 11% 
FPS:   29.98 Mean: 33350 Std.Dev:  8207 CPUs: 7% 11% 12% 7% 
FPS:   30.10 Mean: 33221 Std.Dev:  7890 CPUs: 4% 8% 10% 14% 
FPS:   29.93 Mean: 33405 Std.Dev:  5628 CPUs: 8% 5% 12% 13% 
FPS:   29.92 Mean: 33418 Std.Dev:  8680 CPUs: 3% 9% 14% 11% 
FPS:   29.89 Mean: 33451 Std.Dev:  7740 CPUs: 7% 8% 14% 7% 
FPS:   30.15 Mean: 33172 Std.Dev:  7769 CPUs: 10% 4% 11% 9% 

Reaspberry pi with Realtime patch

FPS:   27.94 Mean: 35787 Std.Dev: 14939 CPUs: 2% 2% 2% 2% 
FPS:   30.02 Mean: 33316 Std.Dev:  6928 CPUs: 4% 12% 8% 8% 
FPS:   30.10 Mean: 33228 Std.Dev:  4389 CPUs: 8% 10% 8% 6% 
FPS:   29.99 Mean: 33342 Std.Dev:  7143 CPUs: 4% 10% 8% 10% 
FPS:   29.98 Mean: 33359 Std.Dev:  6930 CPUs: 6% 8% 13% 9% 
FPS:   29.98 Mean: 33358 Std.Dev:  7713 CPUs: 11% 9% 11% 6% 
FPS:   29.67 Mean: 33701 Std.Dev:  7610 CPUs: 11% 12% 8% 8% 
FPS:   30.32 Mean: 32982 Std.Dev:  7176 CPUs: 7% 11% 10% 11% 
FPS:   29.97 Mean: 33368 Std.Dev:  6449 CPUs: 4% 11% 9% 11% 
FPS:   30.01 Mean: 33324 Std.Dev:  7169 CPUs: 6% 10% 7% 7% 

Laptop computer no patch or renice, for comparison

FPS:   30.26 Mean: 33045 Std.Dev:  2893 CPUs: 4% 4% 3% 5% 
FPS:   30.03 Mean: 33299 Std.Dev:   261 CPUs: 11% 29% 9% 9% 
FPS:   30.03 Mean: 33301 Std.Dev:   264 CPUs: 15% 26% 11% 9% 
FPS:   29.90 Mean: 33441 Std.Dev:  1534 CPUs: 12% 33% 10% 9% 
FPS:   30.03 Mean: 33301 Std.Dev:   268 CPUs: 15% 28% 11% 10% 
FPS:   30.03 Mean: 33301 Std.Dev:   272 CPUs: 15% 23% 12% 14% 
FPS:   30.03 Mean: 33300 Std.Dev:   275 CPUs: 10% 31% 7% 7% 
FPS:   29.90 Mean: 33441 Std.Dev:  1549 CPUs: 10% 31% 7% 11% 
FPS:   30.03 Mean: 33300 Std.Dev:   271 CPUs: 14% 24% 10% 12% 
FPS:   30.03 Mean: 33299 Std.Dev:   395 CPUs: 22% 31% 18% 18% 

comment:9 Changed 18 months ago by Peter Bennett

Status: infoneeded_newassigned

comment:10 Changed 18 months ago by Doug Larrick <doug@…>

Today I've discovered that part of the reason Std.Dev is larger for RPi than for laptop is that VideoOutputOmx::Show takes a variable amount of time. The Jitterometer (MythPlayer::output_jmeter) is called after the call to Show(). If I move the call to the jitterometer to before the call(s) to Show() it reports less jitter overall -- and a (slightly) clearer advantage to realtime threads:

Realtime off:

FPS:   29.98 Mean: 33356 Std.Dev:  4155 Min/Max:  6988/50045 CPUs: 11% 13% 9% 2% 
FPS:   30.11 Mean: 33213 Std.Dev:  4165 Min/Max: 11498/50050 CPUs: 4% 6% 7% 4% 
FPS:   29.86 Mean: 33494 Std.Dev:  4068 Min/Max:  8038/50050 CPUs: 3% 11% 5% 8% 
FPS:   29.98 Mean: 33356 Std.Dev:   789 Min/Max: 27606/39109 CPUs: 5% 9% 9% 6% 
FPS:   29.98 Mean: 33355 Std.Dev:  2283 Min/Max: 17689/50048 CPUs: 6% 9% 10% 8% 
FPS:   29.86 Mean: 33493 Std.Dev:  3899 Min/Max: 18091/50048 CPUs: 0% 11% 8% 7% 
FPS:   30.11 Mean: 33215 Std.Dev:  3996 Min/Max:  8536/50049 CPUs: 3% 10% 15% 2% 
FPS:   29.98 Mean: 33356 Std.Dev:  3995 Min/Max: 19602/50048 CPUs: 2% 6% 10% 11% 
FPS:   29.98 Mean: 33356 Std.Dev:  1517 Min/Max: 25537/41186 CPUs: 7% 0% 11% 11% 
FPS:   29.98 Mean: 33355 Std.Dev:  3537 Min/Max: 15001/50044 CPUs: 10% 0% 9% 9%

Realtime on:

FPS:   29.98 Mean: 33356 Std.Dev:  3310 Min/Max: 13170/54564 CPUs: 4% 3% 9% 16% 
FPS:   29.98 Mean: 33355 Std.Dev:  2247 Min/Max: 20582/46136 CPUs: 4% 3% 11% 10% 
FPS:   29.98 Mean: 33356 Std.Dev:  1772 Min/Max: 23100/43617 CPUs: 4% 5% 12% 10% 
FPS:   29.98 Mean: 33355 Std.Dev:  2062 Min/Max: 22830/44132 CPUs: 9% 7% 9% 8% 
FPS:   29.98 Mean: 33356 Std.Dev:  1639 Min/Max: 20939/45776 CPUs: 1% 13% 7% 6% 
FPS:   29.98 Mean: 33355 Std.Dev:  1663 Min/Max: 24632/43413 CPUs: 4% 8% 12% 8% 
FPS:   29.98 Mean: 33356 Std.Dev:  3123 Min/Max: 18933/47788 CPUs: 5% 8% 9% 8% 
FPS:   29.98 Mean: 33356 Std.Dev:  1598 Min/Max: 23257/43468 CPUs: 8% 6% 7% 10% 
FPS:   29.98 Mean: 33356 Std.Dev:  2780 Min/Max: 19303/47420 CPUs: 8% 6% 7% 13% 
FPS:   29.89 Mean: 33451 Std.Dev:  2600 Min/Max: 19417/47303 CPUs: 8% 8% 8% 7% 

I do wonder why the OMX call is adding jitter.

comment:11 Changed 17 months ago by Peter Bennett

Milestone: needs_triage30.0

comment:12 in reply to:  10 Changed 17 months ago by Stuart Auchterlonie

Replying to Doug Larrick <doug@…>:

Today I've discovered that part of the reason Std.Dev is larger for RPi than for laptop is that VideoOutputOmx::Show takes a variable amount of time. The Jitterometer (MythPlayer::output_jmeter) is called after the call to Show(). If I move the call to the jitterometer to before the call(s) to Show() it reports less jitter overall -- and a (slightly) clearer advantage to realtime threads:

So is the call to output_jmeter misplaced or is it trying to capture the jitter including the time it takes to show the frame?

What is it really trying to measure?

Regards Stuart

comment:13 Changed 17 months ago by Doug Larrick <doug@…>

Here is my understanding from having done a code safari yesterday, in MythTV code as well as two example Raspberry Pi specific video players (OMXPlayer from GitHub? and hello_video from the RPi samples). I could well be mistaken on any portion of the following.

MythTV is using only a portion of the Broadcom (OMX) hardware-assisted audio/video decoding and playback pipeline, just the decoding and "show this buffer now" portions (plus deinterlacing). MythTV does not use the audio decoding, audio/video sync, or frame rate control (sync to retrace) capabilities of OMX.

Video frame rate control in MythTV is accomplished by the 'vsync' part of mythplayer -- it waits (via sleep, event, busy-loop, etc.) until it's time to show the next frame. Then it calls the VideoOutput? subclass's "Show" method. The Jitterometer is inserted after the call to Show, as well it should be since presumably when that returns is a good measure of when the frame was actually displayed.

On other platforms, the "Show" method is either instantaneous (e.g. OpenGL buffer-swap) or takes a fixed amount of time (e.g. Xv blit). But the OMX one, I suspect, takes a variable amount of time because it does a variable amount of work. In the RPi-specific players this gets smoothed over because it's followed by the "clock" and "synchronization" pipeline stages.

I have yet to find a way to shoehorn these additional pipeline stages into the MythTV playback architecture (though I'm not giving up quite yet), and I think neither could the original author of MythTV's VideoOutputOMX. Having witnessed the buttery-smooth playback of one of my recordings (copied a .ts to the Pi and played from disk) using OMXPlayer, though, it's something that IMHO is well worth pursuing.

comment:14 in reply to:  13 Changed 17 months ago by Stuart Auchterlonie

Replying to Doug Larrick <doug@…>:

I have yet to find a way to shoehorn these additional pipeline stages into the MythTV playback architecture (though I'm not giving up quite yet), and I think neither could the original author of MythTV's VideoOutputOMX. Having witnessed the buttery-smooth playback of one of my recordings (copied a .ts to the Pi and played from disk) using OMXPlayer, though, it's something that IMHO is well worth pursuing.

The playback architecture is overdue a redesign, that is for certain.

comment:15 Changed 17 months ago by Doug Larrick <doug@…>

Resolution: fixed
Status: assignedclosed

In 356c7be85f4596883302580674e7f8be48da00dc/mythtv:

Restore realtime priority capability for vsync thread

Fixes #13170

Signed-off-by: Peter Bennett <pbennett@…>

comment:16 Changed 16 months ago by Peter Bennett

Cc: piotr.oniszczuk@… added
Resolution: fixed
Status: closednew

This is causing a problem, because it sets realtime priority but never resets it. See https://lists.gt.net/mythtv/dev/614389#614389 . After the first playback ends, other threads are getting higher priority and eventually there is a deadlock. Probably the priority should be reset after playback ends.

comment:17 Changed 16 months ago by Peter Bennett

Please provide a fix for the deadlock problem. Priority should be reset after playback ends or steps should be taken so that other threads do not get high priority.

comment:18 Changed 16 months ago by Peter Bennett

Status: newinfoneeded_new

comment:19 Changed 16 months ago by doug@…

I'm not going to have time to get to this anytime soon, sorry.

comment:20 Changed 15 months ago by Peter Bennett <pbennett@…>

In ced0516b97144d6df635d9028fc354dac21accde/mythtv:

Revert "Restore realtime priority capability for vsync thread"

Reverting this commit because more threads are getting realtime
priority if more recordings are played. Eventually a deadlock
can occur. The code should reset the priority after playback.

Refs #13170

This reverts commit 356c7be85f4596883302580674e7f8be48da00dc.

comment:21 Changed 15 months ago by Peter Bennett

I have reverted the commit for this fix. We can commit it again when the issue of resetting the priority after playback is addressed.

comment:22 Changed 12 months ago by Peter Bennett

Owner: changed from Peter Bennett to Peter Bennett

comment:23 Changed 4 months ago by Peter Bennett

Milestone: 30.0unknown

comment:24 Changed 7 weeks ago by Peter Bennett

Resolution: Abandoned
Status: infoneeded_newclosed
Note: See TracTickets for help on using tickets.