1360545 - OGV Video remains stuck after forwarding the seekbar to an non-buffered zone

Status: NEW

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

Description

[Emil Ghitta, QA [:emilghitta]]

[Affected versions]:
Firefox 55.0a1 (Build Id:20170428100438)
Firefox 54.0b2 (Build Id:20170427162447)
Firefox 53.0 (Build Id:20170414022702)

[Affected platforms]:
Windows 10 32bit
Mac OS X 10.10
Ubuntu 16.04 LTS 64bit

[Steps to reproduce]:
1.Launch Firefox.
2.Got to https://www.s-config.com/core/wp-content/uploads/2015/09/Ukidig.ogv webpage.
3.Forward the seekbar to an non-buffered zone.
4.Observe that the video remains freezed while the audio continues to playback.

[Expected result]:
The Video successfully resumes.

[Actual result]:
The Video remains freezed.

[Regression range]:
This seems like an old regression and we'll return with more info as soon as possible.

[Additional notes]:
Please note that on Windows and Mac, the video resumes after refreshing the page or changing the seekbar’s position.

Please note that,on Ubuntu, this issue can be reproduced even if refreshing the webpage and repeating step 3.

Please observe the following link for more information regarding this issue: https://drive.google.com/open?id=0B94iuIVMr-TEQWlnSmdwajI0a3c

Comment 1

[Emil Ghitta, QA [:emilghitta]]

This is an old regression:

Last good revision: e5859dfe0bcbd40f4e33f4a633f73ea3473a7849
First bad revision: 221b74c4836302adc88d0ab296ec9128e0df085f

Pushlog:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=e5859dfe0bcbd40f4e33f4a633f73ea3473a7849&tochange=221b74c4836302adc88d0ab296ec9128e0df085f

Comment 2

[Liz Henry (:lizzard Please n-i to RyanVM, jcristau, or pascal)]

Too late for a fix for 53. We might still be able to take a patch for 54.

Comment 3

[Gerry Chang [:gchang]]

This is too late for 54 and it's not a new regression. Mark 54 won't fix.

Comment 4

[Gyula Palko[:gpalko]]

This issue is still reproducible on Nightly 64.

Comment 6

[Andreas Pehrson [:pehrsons] (back in Aug)]

Bug 1490971 got closed as I was looking at it. I'll post the log I got so far. It starts as the seek completes and ends at the first sight of a video demuxing error.

> 20530 2018-09-13 14:06:40.412197 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::OnAudioSeekCompleted: Audio seeked to 46073437
> 20531 2018-09-13 14:06:40.412512 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Processing update for Video
> 20532 2018-09-13 14:06:40.412600 UTC - [(null) 16657: MediaPlayback #3]: V/MediaDecoder MediaDecoderStateMachine[0x61e000129c80] Decoder=6160001b5480 Queueing video task - queued=0, decoder-queued=0, stime=0
> 20533 2018-09-13 14:06:40.412717 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Update(Video) ni=0 no=0 in:0 out:0 qs=0 decoding:0 flushing:0 desc:theora video decoder pending:0 waiting:0 eos:0 ds:0 sid:4294967295 waitcdm:0
> 20534 2018-09-13 14:06:40.412805 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: No need for additional input (pending:0)
> 20535 2018-09-13 14:06:40.412836 UTC - [(null) 16657: MediaPlayback #3]: V/MediaDecoder MediaDecoderStateMachine[0x61e000129c80] Decoder=6160001b5480 Queueing audio task - queued=0, decoder-queued=0
> 20536 2018-09-13 14:06:40.412877 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Processing update for Audio
> 20537 2018-09-13 14:06:40.413047 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Update(Audio) ni=0 no=0 in:0 out:0 qs=0 decoding:0 flushing:0 desc:opus audio decoder pending:0 waiting:0 eos:0 ds:0 sid:4294967295 waitcdm:0
> 20538 2018-09-13 14:06:40.413126 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: No need for additional input (pending:0)
> 20539 2018-09-13 14:06:40.413228 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::RequestVideoData: RequestVideoData(0)
> 20540 2018-09-13 14:06:40.413310 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::ScheduleUpdate: SchedulingUpdate(Video)
> 20541 2018-09-13 14:06:40.413380 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::RequestAudioData:
> 20542 2018-09-13 14:06:40.413462 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::ScheduleUpdate: SchedulingUpdate(Audio)
> 20543 2018-09-13 14:06:40.413591 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Processing update for Video
> 20544 2018-09-13 14:06:40.413775 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Update(Video) ni=1 no=1 in:0 out:0 qs=0 decoding:0 flushing:0 desc:theora video decoder pending:0 waiting:0 eos:0 ds:0 sid:4294967295 waitcdm:0
> 20545 2018-09-13 14:06:40.413838 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::RequestDemuxSamples: Requesting extra demux Video
> 20546 2018-09-13 14:06:40.413946 UTC - [(null) 16657: MediaPDecoder #2]: D/MediaDemuxer OggDemuxer[0x619000a34d80] ::DemuxUntilPacketAvailable: no packet yet, reading some more
> 20547 2018-09-13 14:06:40.414003 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Processing update for Audio
> 20548 2018-09-13 14:06:40.414106 UTC - [(null) 16657: MediaPDecoder #2]: D/MediaDemuxer OggDemuxer[0x619000a34d80] ::DemuxUntilPacketAvailable: no more pages to read in resource?
> 20549 2018-09-13 14:06:40.414182 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::Update: Update(Audio) ni=1 no=1 in:0 out:0 qs=0 decoding:0 flushing:0 desc:opus audio decoder pending:0 waiting:0 eos:0 ds:0 sid:4294967295 waitcdm:0
> 20550 2018-09-13 14:06:40.414244 UTC - [(null) 16657: MediaPlayback #2]: V/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::RequestDemuxSamples: Requesting extra demux Audio
> 20551 2018-09-13 14:06:40.414432 UTC - [(null) 16657: MediaPlayback #2]: D/MediaFormatReader MediaFormatReader[0x61f00017ca80] ::OnDemuxFailed: Failed to demux video, failure:NS_ERROR_DOM_MEDIA_END_OF_STREAM

Comment 7

[laszlo.bialis]

The issue is present on Nightly 66.0a1 (20190107214730) also, reproduced with the above steps on Win8 x32.

Comment 8

[Timea Cernea [:tbabos][inactive]]

Reproduced on latest Nightly 67.0a1 (2019-02-04) (32-bit) on Windows 8.1 x32

Comment 9

[Rares Doghi]

Reproduced in the Latest Nightly 68.0a1 (2019-03-18) on Windows 10 x64.

Comment 10

[Rares Doghi]

Reproduced in the Latest Nightly 69.0a1 (2019-05-26).

Comment 11

[Marcela (Please NI request to Brindusa Tot)]

Reproduced in the Latest Nightly 69.0a1 (2019-05-27) for Windows 10

Comment 12

[Timea Cernea [:tbabos][inactive]]

Reproduced in the Latest Nightly 70.0a1 (2019-07-16).

Comment 13

[Andrei Purice]

Reproduced on latest Nightly build 71.0a1 (2019-09-12) on Windows 7 x64.

Comment 14

[Alin Ilea]

Reproduced on latest Nightly build 72.0a1 (2019-11-03) on Windows 8.