526411 - after pausing a video it often won't restart playing later

Status: RESOLVED FIXED

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

Description

[Christopher Blizzard (:blizzard)]

This appears to be linux-specific.  Can't reproduce on Win 7.

Run a 3.6 nightly and loading the URL above it will start playing when the page loads, but if you pause and restart it a few times it will eventually stop playing once you unpause.  Sometimes it's one click, sometimes it's three.

Running this on Fedora 11.  Will check for a regression from 3.5.

Comment 1

[Christopher Blizzard (:blizzard)]

Affects 3.5 on Fedora 11 as well.

Comment 2

[cajbir (:cajbir)]

Possibly related to bug 525401?

Comment 3

[Gustav Hartvigsson]

same:
Mozilla Firefox 3.5.5 on Ubuntu GNU/Linux 9.10 x86_64

any additional info needed?

Comment 4

[Rogutės]

It happens every time I toggle a playing video. Press play, press pause - video is stuck. Otherwise, videos play/seek perfectly.

By 'stuck' I mean that UI (controls) is responsive, but there is no reaction from video/audio.

When the video is stuck, I can issue .load() and it successfully restarts from the beginning. Choosing 'Full Screen' from the context menu helps as well - video resumes (but pressing pause, play makes it stuck again).

I'm on Linux x86_64, have reproduced this with Firefox 3.5.5 and a current (Nov 18) 3.6b4pre nightly. Funny, but I can't reproduce this on Firefox launched through X11 Forwarding (ssh).

It happens with any video I choose (even videos in local disk, referenced via src="file://..."), e.g.:
http://videos.mozilla.org/firefox/3.5/meet/meet.ogv
http://tinyvid.tv/show/yulvgbtf3kdu

Comment 5

[Sandro Mani]

Same here on fedora 12 Firefox 3.6 Beta 3, experiencing the problem with audio (haven't tested with video): as soon as I pause a track, it will never resume playback on play, neither via the default controls nor via javascript.

Comment 7

[Matthew Gregan [:kinetik]]

I'm not sure if this is related to bug 525401, but I've pushed a potential fix for that bug to the try server.  You can get a copy of the build to test with from https://build.mozilla.org/tryserver-builds/[e-mail]-try-7b6e4f397796/

Comment 8

[Jan Gerber]

(In reply to comment #7)
> https://build.mozilla.org/tryserver-builds/[e-mail]-try-7b6e4f397796/
does not change anything here, local files will still not play again after pressing pause the first time.

Comment 11

[Gervase Markham [:gerv]]

Doesn't our test plan include pausing and playing? Given that blizzard can repro it on his machine on 3.5, and also trunk, how did we ship 3.5 with a bug this big? :-((

Anything I can do to help debug it?

Gerv

Comment 12

[Chris Pearce [:cpearce (Not reading bugmail)]]

(In reply to comment #11)
> Doesn't our test plan include pausing and playing? Given that blizzard can
> repro it on his machine on 3.5, and also trunk, how did we ship 3.5 with a bug
> this big? :-((

If this is an audio underrun, the reason our tests don't pick this up is because the tinderbox test machines don't have audio, they do timing off the system clock and so audio underruns can't happen.

Comment 13

[cajbir (:cajbir)]

It's also dependent on what audio system they're using. I'm not using PulseAudio on my Linux system and it works fine for me.

Comment 14

[Christopher Blizzard (:blizzard)]

Note that I have been able to reproduce this on Windows, although it's very rare.

Comment 15

[Christopher Blizzard (:blizzard)]

This video plays for me every 4-5 page loads on windows.  It probably does the pause/buffer/play pattern and might be this bug:

http://openvideo.dailymotion.com/video/xbf2rl_branson-unveils-virgin-spaceship_news

Comment 16

[Matthew Gregan [:kinetik]]

I looked at the DailyMotion issue a bit.  I'm seeing two problems.  In one case, the media is failing to load and we fire an error event, but the custom player UI doesn't react to it, so there's no indication of a problem.  In the other case, the video loads fine (and we fire canplaythrough, which the player UI uses to trigger playback), but playback never begins.

The first issue is a bug in the custom player UI.  I'm not sure what the second issue is yet, so I'll keep looking...

Comment 17

[Gervase Markham [:gerv]]

CCing dailymotion person. Please note the dailymotion bug referenced in comment #16 :-)

Gerv

Comment 18

[Christopher Blizzard (:blizzard)]

I sent private mail on this as well.  Matthew was looking into it.

Comment 19

[Tanner Filip [:tanner]]

if it matters, I can reproduce on Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.3a1pre) Gecko/20091210 Minefield/3.7a1pre ID:20091210031150 too.

Comment 20

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Let's get some record/replay on this next week.

Comment 21

[Gervase Markham [:gerv]]

roc: did that record/replay happen?

Gerv

Comment 22

[Robert O'Callahan (:roc) (email my personal email if necessary)]

No, not yet.

Comment 24

[juan becerra [:juanb]]

It's going to be a little more visible in the next few days as we launch 3.6 and as we advertise with http://www.mozilla.com/en-US/firefox/comingsoon/ (I see it consistently on Ubuntu machines)

Comment 25

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Would a video debug log be helpful here?

Comment 26

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Yes.

Comment 27

[Matthew Gregan [:kinetik]]

Looks like another case where we get stuck in the PlayFrame loop.  We're waiting for a small amount of audio to play (~7ms in the case I reproduced), but there is no audio left to play on the current frame or buffered in the audio stream, and the audio clock is not advancing.

Comment 30

[Daniël]

Attachment: Problematic audio example

It looks like it really is an audio issue

Comment 31

[kalle.alm]

I've tried this on two linux machines (one AMD64, one 32-bit, one Ubuntu 9.10, one Xubuntu 9.10), and they both fail to resume playing an OGG file.

Using a WAV file, it works "much better" but I see the failure to resume there as well, just not at a 100% ratio.

Comment 32

[Christopher Blizzard (:blizzard)]

Can we get some focus on this?  It's a pretty long-standing problem.

Comment 33

[Matthew Gregan [:kinetik]]

I'm on it.

Comment 34

[Matthew Gregan [:kinetik]]

The symptoms I'm seeing are these: when resuming playback (after buffering or a user-initiated pause), PlayFrame() expects the audio clock to reach the presentation time of the current frame, so it poll-waits in the loop at http://hg.mozilla.org/mozilla-central/file/c99505cf0eff/content/media/ogg/nsOggDecoder.cpp#l930.  The repeated calls to PlayAudio() write any buffered audio we have (on the frame, or stored in mBufferOverflow on the nsAudioStream instance) to be written to the ALSA backend.  At this stage, we've written out all of the audio data that we have bufferd, the audio backend is in the "playing" state, and the audio clock never advances to the current frame time.

The problem seems to be that PulseAudio-backed ALSA installations require a minimum amount of buffer filling before playback actually begins (and starts ticking the audio clock), and we're not writing enough audio data out to meet this minimum fill level.  Increasing OGGPLAY_AUDIO_OFFSET (e.g. from 250ms to 500ms) or reducing the latency parameter passed to snd_pcm_set_params (from 500ms to 200ms) seems to solve this problem.  Reducing the requested latency is probably a good short term fix as it makes some sense that we'd need to write more than 250ms of audio to satisfy a requested buffering/latency target of 500ms.  A more correct fix might be to work out if we can query the minimum buffer fill level and ensure that we always write at least that much audio data before expecting the audio clock to resume ticking.

Comment 35

[Matthew Gregan [:kinetik]]

The fill level is the prebuf field of a pa_buffer_attr struct.  The PulseAudio ALSA plugin sets prebuf to buffer_size - period_size.  Querying ALSA for the buffer, period, and start threshold sizes at the end of sa_stream_open reveals the following for a stereo 16-bit 48kHz stream:

Period: 6000 (125ms) Buffer: 24000 (500ms) Threshold: 24000 (500ms)

Which would result in prebuf being set to 18000 frames, or 375ms.  That's with the existing code.  Our current OGGPLAY_AUDIO_OFFSET of 250ms means we usually won't have more than 250ms of audio available ahead of the current video frame.  Changing snd_pcm_set_set_params to request 200ms latency reduces the above values to:

Period: 2400 (50ms) Buffer: 9600 (200ms) Threshold: 9600 (200ms)

Which results in a prebuf setting of 7200 frames, or 150ms.

Comment 36

[Matthew Gregan [:kinetik]]

Attachment: short term fix v0

This needs more testing before I request review.  I've pushed the patch to the try servers, and I'll post a link so that people can test the patch once the builds complete.

Comment 37

[Matthew Gregan [:kinetik]]

I'm classing comments 14-18 as a different problem, so this bug is Linux specific as far as I'm concerned.

Comment 38

[Matthew Gregan [:kinetik]]

Linux build including this fix is available at:

https://build.mozilla.org/tryserver-builds/[e-mail]-try-fa41cf19ba45/try-fa41cf19ba45-linux.tar.bz2

Please test and let me know your feedback.

Comment 39

[Jan Gerber]

Tested on 2 Ubuntu 9.10 installs. Pause and play for local videos worked without any problems. Without the patch the video would not play after pressing pause once.

Comment 40

[Eugene Crosser]

Might the problem have anything to do with this?

http://www.pulseaudio.org/ticket/440

Despite that one is marked "fixed", the stock mplayer that comes with karmic still reports:

[pulse] working around probably broken pause functionality,
        see http://www.pulseaudio.org/ticket/440

Comment 41

[kalle.alm]

Tested, and works great, but if I start/stop it rapidly enough I tend to be able to make it fail again. With enough start, stop, start, stop, it more or less always ends up silent.

Comment 42

[Eugene Crosser]

test build from comment #38 works somewhat better for me: is often resumes after pause, but after a few tries it still gets stuck.

Comment 43

[Matthew Gregan [:kinetik]]

Thanks for the link, Eugene.  I don't think that problem is this bug, but it
might be a similar one we've run into in the past.

Thanks for the feedback so far.  Can anybody that is still seeing problems
(e.g. comment 41 and 42) please list your specific configuration: distro version,
pulseaudio (if pulseaudio is in use) and alsa-plugins (or alsa-plugins-pulse)
version, and sound hardware.

Also, mind that you're not running into bug 525401 now, which is where the resume from a pause can take up to the current play time to resume (e.g. if you've played 30s of video, resuming from pause may take up to 30s), but that bug only happens with specific poorly muxed files.

Comment 44

[kalle.alm]

$ uname -a
Linux zabre 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 17:01:44 UTC 2009 x86_64 GNU/Linux
$ pulseaudio --version
pulseaudio 0.9.19

Hardware info:
- CPU: AMD Athlon(tm) 64 X2 Dual Core Processor 4400+
- RAM: 2 GB (Corsair)

Comment 45

[kalle.alm]

Oops, thought 'uname -a' included distro name. Ubuntu 9.10.

Comment 46

[Eugene Crosser]

Stock karmic, 32bit, kernel 2.6.31-17-generic
dual Intel T2600  @ 2.16GHz, 82801G (ICH7 Family) audio.
pulseaudio 0.9.19-0ubuntu4.1 0
alsa-base: 1.0.20+dfsg-1ubuntu5

Comment 47

[Gustav Hartvigsson]

FireFox --verion:
Mozilla Firefox 3.6.2pre, Copyright (c) 1998 - 2010 mozilla.org

uname -a:
Linux <0_o> 2.6.31-18-generic #55-Ubuntu SMP Fri Jan 8 14:54:52 UTC 2010 x86_64 GNU/Linux

distro:
Ubuntu 9.10

Comment 48

[Gervase Markham [:gerv]]

Works great for me, although I only tested it for a minute or so!
Linux kitten 2.6.31-17-generic #54-Ubuntu SMP Thu Dec 10 16:20:31 UTC 2009 i686 GNU/Linux
Ubuntu 9.10.

Gerv

Comment 49

[Matthew Gregan [:kinetik]]

Tested on Fedora 12 x86_64, Ubuntu 8.10 i386, and Ubuntu 9.10 x86_64 running under Virtualbox (with emulated ICH AC97 sound and guest additions installed), and Fedora 12 i386 running natively on a Thinkpad x60s with Intel HDA (ICH7) sound.

I can still reproduce the problem on Ubuntu 8.10, but unlike the original problem, playback back be resumed by cycling play/pause a second time.

Comment 50

[pevr]

Tested on OpenSuse 11.2 x86_64 (Linux vr 2.6.31.5-0.1-desktop #1 SMP PREEMPT 2009-10-26 15:49:03 +0100 x86_64 x86_64 x86_64 GNU/Linux), Mozilla/5.0 (X11; U; Linux i686 (x86_64); en-US; rv:1.9.3a1pre) Gecko/20100202 Minefield/3.7a1pre, alsa-plugins-pulse 1.0.21-3.3, pulseaudio 0.9.19-2.3, Intel Corporation 82801G (ICH7 Family) High Definition Audio Controller (rev 01).

I can still reproduce the issue but only with this video:

	http://techne.cse.ucsc.edu/media/house_proceeding_12-08-09.ogg

(and other videos from the same server)

Comment 51

[Matthew Gregan [:kinetik]]

(In reply to comment #50)
> I can still reproduce the issue but only with this video:
> 
>     http://techne.cse.ucsc.edu/media/house_proceeding_12-08-09.ogg
> 
> (and other videos from the same server)

Thanks.  I can reproduce that pause problem on Windows too, it's bug 525401.

Comment 52

[Matthew Gregan [:kinetik]]

Comment on attachment 424936 [details] [diff] [review]
short term fix v0

This fixes the majority of the problems, so let's get it reviewed and checked in.  I'll post a patch for the other pause problem (bug 525401), and once we've got them both checked in we'll see how many problems people are still experiencing.

Comment 53

[Matthew Gregan [:kinetik]]

There's another tryserver build containing this patch and my latest patch for bug 525401 here: https://build.mozilla.org/tryserver-builds/[e-mail]-try-0273a05e8920/try-0273a05e8920-linux.tar.bz2

Comment 54

[Christopher Blizzard (:blizzard)]

Just tried that on Fedora 12.  Stopping and starting seemed to work OK.  Seeking around eventually caused it to stop playing the video.

Comment 55

[Matthew Gregan [:kinetik]]

Thanks Chris.  Is that easily reproducible for you?  Using a particular video, or did you try with more than one?

There are probably some other cases where we could hit this problem.  If there's not enough audio available in the decoded frames when we try to resume playback we won't be able to hit the prebuf limit that resumes playback.

Maybe we should call snd_pcm_start in sa_stream_write so that playback always begins as soon as we've written some audio data, or shrink the prebuf size significantly.  The former would make the behaviour match the Mac backend, and the latter would match the Win32 backend where the "prebuf" buffer size is fixed at 1024 bytes (around 5-6ms of audio).  What we really want is the behaviour of all of the backends to match as much as possible, but that's a bigger project.

Comment 56

[Matthew Gregan [:kinetik]]

Never mind... I can't reproduce it at will, but I just had this bug occur in my Fedora 12 VM with all of the patches applied.

Comment 57

[Matthew Gregan [:kinetik]]

Note to self: change the PlayFrame loop break condition to allow breaking out of the loop if the decoder state is SEEKING.  This at least allows the user to recover from stuck videos by seeking to another point in the video.

Comment 58

[Matthew Gregan [:kinetik]]

http://hg.mozilla.org/mozilla-central/rev/8c84037f3ad9

I pushed the existing patch because we definitely want this fix as it improves things significantly and is the right thing to do.  I'm following up the remaining problems now.

Comment 59

[Eugene Crosser]

The test build from comment #53 did not fix the problem for me.
After running into the end of already-downloaded portion of the file, the player starts to display "buffering" animation and never starts to play again.
After once hitting "pause", hitting "play" does not make it run again.
I am running stock karmic.

Here is the video: http://www.average.org/tmp/03102009053.html

Eugene

Comment 60

[Matthew Gregan [:kinetik]]

Yeah, with that video there's definitely still a problem.  Thanks, that's a great testcase!  That video is a little unusual in that it's extremely high bitrate for web video (60 fps and 7.5 Mb/s), so we might not be getting enough audio data decoded to resume playback.

Comment 61

[Matthew Gregan [:kinetik]]

I've got a more comprehensive fix for this bug, but it's not quite ready yet.  I'm seeing a hang during playback of bug516323.ogv because the needs-silence code in nsOggDecodeStateMachine::NextFrame never kicks in.

Comment 62

[Matthew Gregan [:kinetik]]

That problem is caused by the needs-silence test using |type == OGGPLAY_INACTIVE| to determine if the track has finished, which is incorrect and only becomes true at some point after the track has actually finished.  Changing the test to |stream_info == OGGPLAY_STREAM_LAST_DATA || stream_info == OGGPLAY_STREAM_UNINITIALISED| looks like the correct fix.

Comment 63

[Matthew Gregan [:kinetik]]

Try server builds of the latest patch available here: http://build.mozilla.org/tryserver-builds/[e-mail]-try-5b627a9edba6

Comment 64

[kalle.alm]

Tried server builds and works flawlessly on my end. Tried <video> only.

Comment 65

[Eugene Crosser]

Build from comment #63 when tested on the video from comment #59 (sorry for having inadvertently removed it; I've put it back now), resumes playing after running into the end of downloaded portion of the file. However, after clicking pause and then play or moving the slider, it does not resume playing.

Comment 66

[Matthew Gregan [:kinetik]]

Now that I'm at home, I've tested this patch on my F12 VM and it's showing the same symptoms Eugene just mentioned.  Interestingly, an earlier version of the same patch doesn't show these symptoms (I tried popping the new patch and pushing the old patch, and I can't break it), but the two patches should be doing the same thing--the new one is just cleaner.  The old patch has a bunch of debug logging in it, including lots of calls to sa_stream_get_write_size, so that could be affecting the behaviour.

When playback is stuck with the new patch applied, we have audio data ready to write in mBufferOverflow and we're actively calling nsAudioStream::Write to flush it, but sa_stream_get_write_size is reporting 0.  This sounds like the PulseAudio bug Eugene mentioned in comment 40, but I'm running 
0.9.21-4.fc12, so it *should* be fixed already.  I'll keep investigating.

Comment 67

[Matthew Gregan [:kinetik]]

Sure enough, disabling the debug logging in the older patch causes the problem to appear.

I looked at the workaround mplayer is using for PA bug 440, but I'm not sure how to map it on to the ALSA API to test if it works correctly.  Basically, if they detect a PA version which is "known bad", their audio resume function resets the playback stream.  Even if I could get this workaround to work, it will break A/V sync whenever it kicks in.

Comment 68

[Matthew Gregan [:kinetik]]

Attachment: wip patch v0

Comment 69

[Matthew Gregan [:kinetik]]

Here's the situation I'm seeing.  In PlayFrame, stuck in the loop waiting for the current frame time to elapse:

(gdb) p mAudioStream.mRawPtr->mBufferOverflow.Length()
$4 = 4114
(gdb) p snd_pcm_state(s->output_unit)
$5 = 3 [RUNNING]
(gdb) p snd_pcm_avail_update(s->output_unit)
$6 = 0
(gdb) p snd_pcm_writei(s->output_unit, data, 1)
[New Thread 0x7f6d628ff710 (LWP 8876)]
[...]

Tried to write a small amount of garbage to the stream to see if that kicked things into life, but the write blocked indefinitely.

Comment 70

[Matthew Gregan [:kinetik]]

Another case I'm seeing is snd_pcm_avail_update is returning 0, but snd_pcm_state reports the pcm is in XRUN state (which means avail_update should be returning -EPIPE).  Any attempt to recover (or prepare) the pcm fails.

Comment 71

[Matthew Gregan [:kinetik]]

The new Ogg backend (bug 531340) landed recently and will have changed the behaviour (including buffering more audio like my WIP patch attached to this bug does) fairly dramatically (hopefully for the better).  Can people seeing this problem please test a recent nightly trunk build and update the bug if they're still seeing problems?

Comment 72

[Daniël]

Can not reproduce this issue with current build.
However, I have another issue with this audio file hosted in this bug entry:
https://bug526411.bugzilla.mozilla.org/attachment.cgi?id=423236
The seeker skips to the end each ~300/400 ms when loading and playing. Is that a known bug?

Comment 73

[Matthew Gregan [:kinetik]]

That looks new, would you mind filing a bug for it?  At a guess the controls might need to be modified to handle the fact that the new backend fires durationchange events regularly when it's unable to calculate the file's duration during the initial load.

Comment 74

[Eugene Crosser]

I tried nightly build from http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-trunk/ dated 05-Apr-2010 03:15. It works on my video, whatever I do - pause/play, move the slider, try to make it run into the end of downloaded portion. Thanks to the developers, good job!

Comment 75

[Christopher Blizzard (:blizzard)]

Yeah, it's looking good here, too.  I beat the crap out of it and couldn't get it to stop playing.

Comment 76

[Matthew Gregan [:kinetik]]

It doesn't seem to be possible to fix this reliably with the old backend because liboggplay produces "frames" with both audio and video attached.  We need the ability to decode audio ahead of video, which is impossible with liboggplay without major changes.  My WIP patches attached to this bug tried to compromise by increasing the number of "frames" we'd decode and queue, but as this isn't able to guarantee any particular audio/video decoded ratio, it doesn't solve every instance of this problem.

Comment 77

[u279076]

Mozilla/5.0 (X11; U; Linux i686 (x86_64); en-US; rv:1.9.2.3pre) Gecko/20100405 Firefox/3.6.3plugin1

URL: http://videos.mozilla.org/firefox/3.6/getpersonas.ogv

Looks like this did not make it into the 3.6.3 OOPP backport.  I strongly urge we get that in.

Comment 78

[Matthew Gregan [:kinetik]]

Comment on attachment 424936 [details] [diff] [review]
short term fix v0

I don't think we can fix this completely with the old backend, but this small patch helped a lot for the common case.  It's a safe change and has had plenty of time baking on trunk already.

Comment 79

[LegNeato]

Comment on attachment 424936 [details] [diff] [review]
short term fix v0

a=LegNeato for 1.9.2.5. Please *only* land it on mozilla-1.9.2 default, as we are still working on the 3.6.4 relbranch and do not want this landed there

Comment 80

[Matthew Gregan [:kinetik]]

http://hg.mozilla.org/releases/mozilla-1.9.2/rev/2daf974e2a5e

Comment 81

[Matthew Gregan [:kinetik]]

Worth noting for anyone following this bug who is seeing problems: make sure you're running a current version of PulseAudio.  The version shipped with F12 has a bug that causes the hanging snd_pcm_writei that I ran into in this bug (comment 69), but an update to 0.9.21-5 is available in Fedora updates.  There's a bunch of investigation of this specific problem over in bug 573924 for the curious.