1924428 - Linux VA-API H.264 video hesitates every few seconds, but only with one web site.

Status: RESOLVED WORKSFORME

(Core :: Audio/Video: Playback, defect)

Description

[Bob Hill]

Attachment: ffmpegvideo-5.txt

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:130.0) Gecko/20100101 Firefox/130.0

Steps to reproduce:

I watched H.264 streaming TV on www.saktv.ch, using Linux Firefox 130.0.1 and VA-API.

Actual results:

The TV video stream hesitated every few seconds.

Expected results:

The TV video stream should have played smoothly.

Comment 1

[Bob Hill]

This bug is not an actual bug report (yet), but at the moment just a request for clarification, because there is no evidence (yet) of any bug in Firefox.

The attached Linux FFmpegVideo:5 log arises from a VA-API H.264 video, which hesitates every few seconds with the following messages, and then proceeds to re-initialize VA-API, also every few seconds:

[RDD 1246: MediaPDecoder #1]: D/FFmpegVideo FFMPEG: ProcessFlush()
[RDD 1246: MediaPDecoder #1]: D/FFmpegVideo FFMPEG: FFmpegDataDecoder: flushing buffers
[RDD 1246: MediaPDecoder #2]: D/FFmpegVideo FFMPEG: FFmpegDataDecoder: shutdown
[RDD 1246: MediaSupervisor #1]: D/FFmpegVideo FFMPEG: FFmpegVideoDecoder::FFmpegVideoDecoder MIME video/avc Codec ID 27
[RDD 1246: MediaPDecoder #1]: D/FFmpegVideo FFMPEG: Initialising VA-API FFmpeg decoder
[RDD 1246: MediaPDecoder #1]: D/FFmpegVideo FFMPEG:   Format h264 is accelerated
[RDD 1246: MediaPDecoder #1]: D/FFmpegVideo FFMPEG:   codec h264 : H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10

This only happens with one particular web site (www.saktv.ch, which is a subscription-only H.264 TV streamer), but not with any other H.264 web sites, not even with other H.264 TV streamers. All three possible settings of media.ffmpeg.vaapi.force-surface-zero-copy (0, 1 and 2) have been tested (restarting Firefox each time), all with the same results as shown above.

Three questions, in order to understand this better (and in order to more intelligently describe the issue to Technical Support at www.saktv.ch, should the need arise):

1. Exactly what is "FFMPEG: ProcessFlush()", and what purpose does it serve?

2. Which component might typically trigger an "FFMPEG: ProcessFlush()", and for what reason(s)?
   Either: the web server (e.g. server sends a request "please flush buffers" to the browser)?
   and/or: Firefox itself?
   and/or: the "external" FFmpeg code which Firefox uses to hardware-decode H.264?
   and/or: the H.264 hardware-decode firmware in the GPU?

3. What can be done to stop "FFMPEG: ProcessFlush()" every few seconds?

Even if it does not turn out to be a Firefox bug, any assistance with this would be very much appreciated.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

The Bugbug bot thinks this bug should belong to the 'Core::Audio/Video: Playback' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Comment 3

[Paul Adenot (:padenot)]

(In reply to Bob Hill from comment #1)

1. Exactly what is "FFMPEG: ProcessFlush()", and what purpose does it serve?

2. Which component might typically trigger an "FFMPEG: ProcessFlush()", and for what reason(s)?
   Either: the web server (e.g. server sends a request "please flush buffers" to the browser)?
   and/or: Firefox itself?
   and/or: the "external" FFmpeg code which Firefox uses to hardware-decode H.264?
   and/or: the H.264 hardware-decode firmware in the GPU?

3. What can be done to stop "FFMPEG: ProcessFlush()" every few seconds?

Even if it does not turn out to be a Firefox bug, any assistance with this would be very much appreciated.

Comment 4

[Paul Adenot (:padenot)]

Bob, thanks for filing a ticket, answers to your three questions below (sorry I clicked submit by mistake, you must have received a mostly empty email):

(In reply to Bob Hill from comment #1)

1. Exactly what is "FFMPEG: ProcessFlush()", and what purpose does it serve?

ProcessFlush is a function that asks the underlying video decoder (could be software, could be hardware) to output all video frames it has buffered internally. The cause could be multiple, but generally, it's because the media was seeked (the play position was set), the media has ended (and we want the last few video frames), or the stream has changed (e.g. because of automatic quality adjustment: it's common for stream to start lower resolution and become higher quality, or the opposite in case of network slowness: we want to play all frames we have, and then switch to the higher quality media).

2. Which component might typically trigger an "FFMPEG: ProcessFlush()", and for what reason(s)?
   Either: the web server (e.g. server sends a request "please flush buffers" to the browser)?
   and/or: Firefox itself?
   and/or: the "external" FFmpeg code which Firefox uses to hardware-decode H.264?
   and/or: the H.264 hardware-decode firmware in the GPU?

It could be, one way to do so is simply to set the currentTime attribute to a media element to another time, or to enqueue a buffer that has a different quality. This is top-down, Firefox tells the decoder to flush, and in fact "something" tells Firefox to flush in general (except when the end of the video has ended, in which case we issue a single flush).

3. What can be done to stop "FFMPEG: ProcessFlush()" every few seconds?

The website decides what to do, directly (by setting currentTime) or indirectly (by switching quality, or other things in the byte stream). It is hard to say for certain without being about to try ourselves.

If you go to about:logging, there's a media preset in the dropdown. If you select it, start logging with the button, reproduce the problem, stop logging, and share the profile (top right button in the new tab that has opened), we can investigate, but it's hard to know if we can't test ourselves. Additionally, since you know how to gather logs, you can probably just use the string for this preset in MOZ_LOG and proceed as you did to open this bug:

HTMLMediaElement:4,HTMLMediaElementEvents:4,cubeb:5,PlatformDecoderModule:5,AudioSink:5,AudioSinkWrapper:5,MediaDecoderStateMachine:4,MediaDecoder:4,MediaFormatReader:5,GMP:5,EME:5,MediaSource:5,MediaSourceSamples:5,Autoplay:5

https://paul.cx/public/about-logging-presentation.webm is a demo video of that tool (on youtube, for the sake of the example).

The idea behind this module selection is to log a lot of things, and then to try to understand what caused the flush to happen.

Even if it does not turn out to be a Firefox bug, any assistance with this would be very much appreciated.

We can, but it's a lot easier with logs and such.

Comment 5

[Bob Hill]

Attachment: Log file "Media Playback"

Paul, Thank you very much for taking the time and trouble to answer my questions so thoroughly - really appreciated. I used the MOZ_LOG method rather than about:logging because I am more familiar with the former, and the resulting log file is attached. HOWEVER, with all that logging going on (presumably consuming additional CPU cycles) the TV stream played an awful lot worse than my initial efforts with just MOZ_LOG="FFmpegVideo:5" (where the CPU runs at less than 100%, and where other H.264 web sites play nice and smooth). With the "Media Playback" preset (13 loggers) the TV stream hardly plays at all - lots of blank screen, so I really doubt that this new log file is of any use, because Firefox is presumably not keeping up with the web site in any case.

Might it be possible, for the purposes of this particular problem, to remove some of those 13 loggers from MOZ_LOG, and/or to make some of them less verbose (i.e. less than "4" or "5"), in the hope that the TV stream is not so badly affected? Bob.

Comment 6

[Paul Adenot (:padenot)]

Yes, I suspect you can remove everything talking about audio, and it we should have the same info and it should be light. We like to use the about:logging / profiler version because we can log everything without slowdown. We can add FFmpegVideo:5 into the mix as well.

HTMLMediaElement:4,HTMLMediaElementEvents:4,PlatformDecoderModule:5,MediaDecoderStateMachine:4,MediaDecoder:4,MediaFormatReader:5,GMP:5,EME:5,MediaSource:5,MediaSourceSamples:5,Autoplay:5,FFmpegVideo:5

Comment 7

[Bob Hill]

Paul, I have suddenly realized that I have been unaware of "the elephant in the room" until now: Full-HD "1080p" streams (1920x1080=2073600 pixels) carry data at a rate about twice that of Standard-HD "720p" streams (1280x720=921600 pixels).

H.264 web sites streaming 720p (such as Free-TV sites, or YouTube set to 720p) play smoothly on my very slow PC, but use about 90% CPU (!), despite H.264 VA-API working fine (verified with an FFmpegVideo:5 log).

H.264 web sites streaming 1080p (such as www.saktv.ch, or YouTube set to 1080p) hesitate every few seconds on the same PC, because my CPU cannot cope with about twice as much incoming data as 720p.

The fix for my problem with 1080p streams is to get a PC with a CPU at least twice as fast. This bug can be closed.

I thank you very much for your prompt responses and for your thorough answers to my questions, and I apologize for wasting your time. Bob.

Comment 8

[Paul Adenot (:padenot)]

Bob,

No need to apologize, we're always happy to help. There is often a non-linearity in the relation between pixel count and the time to decode a single frame: in general, it is faster than twice as slow to decode a frame that has twice as many pixels, because of CPU cache effects, and various other factors. But if your machine is at 90% with 720p, I would tend to say your analysis is correct, and maybe it should be restricted to 720p videos for the time being.

Even with VA-API (that uses a specialized hardware component for decoding), it is often the case that the entire process of decoding video frames uses the CPU anyway for some parts of the pipeline. Engineers on the graphics side of things (related to displaying the frame vs. decoding it) are in the process of optimizing things, so it is possible that playing video at 1080p works in the future on the same machine.

I'm closing this, but please don't hesitate to open a new ticket if something looks off (on this configuration or others).