Closed Bug 557432 Opened 14 years ago Closed 14 years ago

Intermittent timeout in test_playback.html and test_playback_errors.html

Categories

(Core :: Audio/Video, defect)

Product:
Core
Component:
Audio/Video
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
VERIFIED FIXED
Tracking Flags:
Tracking Status
status1.9.2 --- .11-fixed

People

(Reporter: philor, Assigned: cpearce)

References

Details

(Keywords: intermittent-failure)

Attachments

(3 files, 1 obsolete file)

Patch 2
1.02 KB, patch
kinetik
: review+
Details | Diff | Splinter Review
Patch: De-parallelize the media mochitests
76.93 KB, patch
roc
: review+
roc
: approval2.0+
Details | Diff | Splinter Review
Patch: Disable test on Windows on 1.9.2
1.14 KB, patch
dveditz
: approval1.9.2.11+
Details | Diff | Splinter Review 
Second "video/audio test timing out" bug I've filed today (also bug 557393), which makes me really suspicious.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270525639.1270527345.653.gz
Linux mozilla-central debug test mochitests-1/5 on 2010/04/05 20:47:19
s: moz2-linux-slave41

45143 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.


Also

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270503599.1270504672.5148.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/05 14:39:59
s: win32-slave29

which I foolishly claimed was bug 507996 despite clearly not being, which I blame on sdwilsh claiming that

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270490435.1270491773.29642.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/05 11:00:35
s: win32-slave19

and

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270489166.1270492187.31083.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2010/04/05 10:39:26
s: win32-slave23
(which was a "300 seconds without output" timeout, unlike the other three)

were as well.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270526567.1270527399.764.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/05 21:02:47
s: win32-slave33
My kingdom for a callstack!
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270530540.1270531346.10328.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/05 22:09:00
s: win32-slave33
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270543602.1270544726.18416.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 01:46:42
s: win32-slave19
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270564727.1270565545.946.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 07:38:47
s: win32-slave05
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270600233.1270601109.17945.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 17:30:33
s: win32-slave31
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270605868.1270606723.32618.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 19:04:28
s: win32-slave31
(In reply to comment #9)
> http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270605868.1270606723.32618.gz
> WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 19:04:28
> s: win32-slave31

Yay. crashinjectdll.dll crashed, giving us lots of callstacks.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270629837.1270630871.29952.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/07 01:43:57
s: win32-slave05
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270658684.1270659431.4220.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/07 09:44:44
s: win32-slave05
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270681038.1270681920.8881.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/07 15:57:18
s: win32-slave05
Adding in the timeouts in test_playback_errors.html, since at least one of the logs above was both, though I missed seeing it at the time, and I'll be astonished if there isn't a single cause for the sudden flurry of timing-out in media tests.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270683345.1270686286.21865.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2010/04/07 16:35:45
s: win32-slave15

44707 INFO TEST-PASS | /tests/content/media/test/test_playback.html | Name should match test.name #4
44708 INFO TEST-PASS | /tests/content/media/test/test_playback.html | bug500311.ogv time should run forwards: p=1.8619999885559082 c=1.8769999742507935
44709 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
44711 INFO Running /tests/content/media/test/test_playback_errors.html...
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output

command timed out: 1200 seconds without output
Summary: Intermittent timeout in test_playback.html → Intermittent timeout in test_playback.html and test_playback_errors.html
(In reply to comment #10)
> (In reply to comment #9)
> > http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270605868.1270606723.32618.gz
> > WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/06 19:04:28
> > s: win32-slave31
> 
> Yay. crashinjectdll.dll crashed, giving us lots of callstacks.

Hmm...

Thread 36
 5  winmm.dll + 0x1a7c7
    eip = 0x76aba7c8   esp = 0x116ffe64   ebp = 0x116ffe84
    Found by: previous frame's frame pointer
 6  xul.dll!closeAudio [sydney_audio_waveapi.c:6c32102f5594 : 498 + 0x8]
    eip = 0x10449400   esp = 0x116ffe8c   ebp = 0x00000000
    Found by: previous frame's frame pointer
 7  xul.dll!sa_stream_destroy [sydney_audio_waveapi.c:6c32102f5594 : 227 + 0x5]
    eip = 0x10449683   esp = 0x116ffea0   ebp = 0x116ffefc
    Found by: call frame info with scanning
 8  xul.dll!nsAudioStream::Shutdown() [nsAudioStream.cpp:6c32102f5594 : 113 + 0x5]
    eip = 0x1045514b   esp = 0x116ffeac   ebp = 0x116ffefc
    Found by: call frame info with scanning
 9  xul.dll!nsAudioStream::Drain() [nsAudioStream.cpp:6c32102f5594 : 232 + 0x5]
    eip = 0x10497ec4   esp = 0x116ffeb8   ebp = 0x116ffefc
    Found by: call frame info with scanning
10  nspr4.dll!PR_TestAndEnterMonitor + 0x3
    eip = 0x003459b0   esp = 0x116ffec4   ebp = 0x116ffefc
    Found by: call frame info with scanning
11  xul.dll!nsRunnableMethod<nsOggDecoder,void>::Run() [nsThreadUtils.h:6c32102f5594 : 282 + 0x2]
    eip = 0x10416e72   esp = 0x116fff04   ebp = 0x00000001
    Found by: previous frame's frame pointer

It's a bit of a long shot, and I don't understand how we get into nsAudioStream::Drain() from a runable method, it this should only be called on the DecodeLoop/thread, probably optimizations, but anyway... Perhaps the problem is that we're not acquiring the mAudioMonitor while calling nsAudioStream::GetPosition()? Based on the stack I copied above, nsAudioStream::Drain() is failing, and so we shut down the audio stream. Perhaps while that's happening we're inside nsAudioStream::GetPosition() (as another thread play state machine thread is in that log, though I can't tell if its for the same state machine or not) just as the DecodeLoop() finishes, and that Drain()s, fails, and then shuts down the audio hardware while we're querying its position, and that is hanging.

We should acquire the audio monitor before calling nsAudioStream::GetPosition() in nsOggPlayStateMachine::AdvanceFrame(). Even if it doesn't fix the orange, we should do this for safety, and to rule it out.
Patch to ensure we always have the audio monitor before using the audio stream. This will prevent the situation I outlined in my previous comment.

Chris Double: Can you review this please? I'd like to get this in the tree ASAP so that I can either fix this, or rule this out as a potential cause.
Assignee: nobody → chris
Attachment #437752 - Flags: review?(chris.double)
Comment on attachment 437752 [details] [diff] [review]
Patch - always acquire audio monitor before using nsAudioStream

> // Close the audop stream so that next time audio is used a new stream

Not added by this patch but it'd be nice to fix the 'audop' typo while doing it.
Attachment #437752 - Flags: review?(chris.double) → review+
Pushed Patch 1.
http://hg.mozilla.org/mozilla-central/rev/b64df24f4910

We'll wait a day or so to see if the intermittent failures stop before closing this bug...
Linux mozilla-central opt test mochitests-1/5 on 2010/04/08 01:50:36
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270716636.1270717436.4630.gz

Looks like Patch 1 didn't fix this. :(
(In reply to comment #21)
> Pushed Patch 1.
> http://hg.mozilla.org/mozilla-central/rev/b64df24f4910
> 
> We'll wait a day or so to see if the intermittent failures stop before closing
> this bug...

This patch has degraded performance a lot, and causes us to drop a lot of frames. This is because we're doing blocking writes while holding the audio lock, which blocks AdvanceFrame() as it's calling GetAudioClock(). We still should keep the patch until we figure out a better way to do this. It seems to have prevented a lot of orange on Windows, though we still get the occasional orange on Linux.
Backed out Patch 1, performance hit was too much on Linux. I will work on a more permanent fix...

http://hg.mozilla.org/mozilla-central/rev/5022d0baf80c
http://hg.mozilla.org/mozilla-central/rev/49d669800db9
So, given the callstacks I pointed out in comment 18, we must have audio hardware enabled on the Windows mochitest machines! We can only go down those call paths if we have initialized audio playback. Previously we'd all thought the Tinderbox machines didn't have audio.

Here's the problem (I think, on Windows at least the Linux failures must be something else):

1. We call nsAudioStream::Drain() when we've played the last chunk of audio data.
2. Drain() calls sa_stream_drain() which on Windows returns SA_ERROR_INVALID if the audio stream is not playing. I think this can happen if we've just transitioned to buffering state and back to decoding state.
3. Drain() interprets that as total failure, and then calls nsAudioStream::Shutdown().
4. While Shutdown() is running, our play state machine thread (which could still be playing video if there's a video overhang) calls nsAudioStream::GetPosition(), while holding the decoder monitor, but GetPosition() never returns.
5. The main thread calls some nsOggDecoder accessor method, which tries to acquire the decoder monitor, but the play state machine thread is never going to release it, cos it's hung.

We can fix this by having nsAudioStream::Drain() not consider sa_stream_drain() returning SA_ERROR_INVALID due to it being paused as an error, and not have it shutdown the stream. That is, not Shutdown() the nsAudioStream when Drain() is called if its not playing. We'll Shutdown() the nsAudioStream normally in the state machine thread.

We then won't need to worry about acquiring the audio monitor before calling nsAudioStream::GetPosition(), as it shouldn't hang...
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270872882.1270875606.10841.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2010/04/09 21:14:42
s: win32-slave41
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1270959750.1270960566.22220.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/10 21:22:30
s: win32-slave23
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1271015022.1271015808.8860.gz
WINNT 5.2 mozilla-central opt test mochitests-1/5 on 2010/04/11 12:43:42
s: win32-slave27
Attached patch Patch 2 — — Splinter Review 
* Don't shutdown nsAudioStream when Drain() fails due to the nsAudioStream not being playing when Drain() was called.
Attachment #437752 - Attachment is obsolete: true
Attachment #438388 - Flags: review?(kinetik)
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1271018276.1271021314.23105.gz
WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2010/04/11 13:37:56
s: win32-slave14
Comment on attachment 438388 [details] [diff] [review]
Patch 2

> Previously we'd all thought
the Tinderbox machines didn't have audio.

I'm pretty sure Mac machines have audio too as they're running natively on Mac minis.
Attachment #438388 - Flags: review?(kinetik) → review+
Ignore the 19:02 in comment 38, that and comment 39 are both before-the-patch. However,

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1271039377.1271040680.4973.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/04/11 19:29:37
s: talos-r3-fed64-018

46346 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output

is after :(
Patch 2 should only help on Windows. The hangs on Linux are caused by something else... :(
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1271183674.1271185483.22196.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/04/13 11:34:34
s: talos-r3-fed64-009

46353 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
(In reply to comment #47)
> masayuki@d-toybox.com
> http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1271852585.1271853825.32606.gz
> Rev3 Fedora 12 mozilla-central opt test mochitests-1/5, Started 05:23, finished
> 05:44


Thread 16
 0  linux-gate.so + 0x424
    eip = 0x00d0b424   esp = 0x955eaf54   ebp = 0x955eaf78   ebx = 0x955eafa0
    esi = 0x00000000   edi = 0x00c58ff4   eax = 0x00000001   ecx = 0x00000001
    edx = 0xffffffff   efl = 0x00200293
    Found by: given as instruction pointer in context
 1  libasound.so.2.0.0 + 0x4b835
    eip = 0x055cc836   esp = 0x955eaf80   ebp = 0x955eaff8
    Found by: previous frame's frame pointer
 2  libasound.so.2.0.0 + 0x4ba0a
    eip = 0x055cca0b   esp = 0x955eb000   ebp = 0x955eb018
    Found by: previous frame's frame pointer
 3  libasound.so.2.0.0 + 0x4bb4a
    eip = 0x055ccb4b   esp = 0x955eb020   ebp = 0x955eb068
    Found by: previous frame's frame pointer
 4  libasound.so.2.0.0 + 0x901ea
    eip = 0x056111eb   esp = 0x955eb070   ebp = 0x955eb0f8
    Found by: previous frame's frame pointer
 5  libasound.so.2.0.0 + 0x4611b
    eip = 0x055c711c   esp = 0x955eb100   ebp = 0x955eb138
    Found by: previous frame's frame pointer
 6  libxul.so!sa_stream_write [sydney_audio_alsa.c:d16525937c8b : 197 + 0x9]
    eip = 0x01479942   esp = 0x955eb140   ebp = 0xa497b000
    Found by: previous frame's frame pointer
 7  libxul.so!nsAudioStream::Write [nsAudioStream.cpp:d16525937c8b : 187 + 0x15]
    eip = 0x0143b926   esp = 0x955eb170   ebp = 0x00000800   ebx = 0x01c52a3c
    esi = 0x00000800   edi = 0xa497c000
    Found by: call frame info
 8  libxul.so!nsOggPlayStateMachine::AudioLoop [nsOggPlayStateMachine.cpp:d16525937c8b : 370 + 0x12]
    eip = 0x01475f67   esp = 0x955eb1b0   ebp = 0xa5513900   ebx = 0x01c52a3c
    esi = 0xa4a1fca0   edi = 0xa42d2440
    Found by: call frame info
 9  libxul.so!nsRunnableMethod<nsOggPlayStateMachine, void>::Run [nsThreadUtils.h : 282 + 0x10]
    eip = 0x01476b7e   esp = 0x955eb1e0   ebp = 0x00000001   ebx = 0x01c52a3c
    esi = 0xa4241b20   edi = 0xa4a15880
    Found by: call frame info
10  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:d16525937c8b : 527 + 0xa]
    eip = 0x01887207   esp = 0x955eb200   ebp = 0x00000001   ebx = 0x01c52a3c
    esi = 0x00000000   edi = 0xa4a15880
    Found by: call frame info

I assume this means we're never returning from snd_pcm_writei() in sa_stream_write() in nsAudioStream::Write(). This must be a bug in ALSA; which would explain why we only see this on the Linux boxes now.

This log also proves that sound hardware must be enabled on Linux Tinderboxen as well. So we now know that sounds is enabled on at the three major platforms on Tinderbox.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1272386578.1272387783.15060.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/04/27 09:42:58  

47505 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1272397240.1272398857.18385.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/04/27 12:40:40  
s: talos-r3-fed64-011

47492 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1272666669.1272668152.12119.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/04/30 15:31:09
s: talos-r3-fed64-014
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1272906650.1272907886.16088.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/03 10:10:50
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273076004.1273077798.6591.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/05 09:13:24
s: talos-r3-fed64-005
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273120050.1273121722.28416.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/05 21:27:30
s: talos-r3-fed64-009
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273160380.1273161698.19471.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/06 08:39:40
s: talos-r3-fed64-016
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273546628.1273548111.5480.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/10 19:57:08
s: talos-r3-fed64-010
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273550862.1273552505.21744.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/10 21:07:42
s: talos-r3-fed64-016
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273700850.1273702344.12937.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/12 14:47:30
s: talos-r3-fed64-018

46963 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
Hmm... This seems to have gotten a lot more frequent since I landed Bug 562840 and Bug 564734. It's also failing on our generic Linux boxes again, rather than just on Fedora only. Bug 564734 changed Windows specific code and there has been one timeout since that was pushed, so that's likely caused that. The failures on our generic Linux boxes were likely caused by the checkin from bug 562840 therefore.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefo/1273812537.1273813350.32757.gz
Linux mozilla-central opt test mochitests-1/5 on 2010/05/13 21:48:57

s: moz2-linux-slave11
45893 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
(In reply to comment #86)
> Hmm... This seems to have gotten a lot more frequent since I landed Bug 562840
> and Bug 564734. It's also failing on our generic Linux boxes again, rather than
> just on Fedora only. Bug 564734 changed Windows specific code and there has
> been one timeout since that was pushed, so that's likely caused that. The
> failures on our generic Linux boxes were likely caused by the checkin from bug
> 562840 therefore.

Can we back out 562840 until you have some time to spend on this?  I know you're busy for the next few days, but the frequency of orange here is starting to be a real impediment for development I think.
I have encountered issues with video playback stopping while working on my current stuff related to this code. The issue I came across was the audio thread stopping audio data from being read and since timing came from the audio thread everything stops. The fix for that was to change:

    if (audioDecoded > AMPLE_AUDIO_MS ||
        (skipToNextKeyframe && audioDecoded > audioPumpThresholdMs)) {

to:

    if (audioDecoded > AMPLE_AUDIO_MS)) {

(ie. remove the second part of the condition in nsBuiltinDecoderOggStateMachine.cpp)

cpearce, could this possibly fix the test_playback orange issue?

A way to reproduce the playback stop more consistently is to increase the value of LOW_AUDIO_MS to something highesh (say 500) so that the keyframe skipping logic occurs.
(In reply to comment #108)
> Can we back out 562840 until you have some time to spend on this?  I know
> you're busy for the next few days, but the frequency of orange here is starting
> to be a real impediment for development I think.

The orange is concerning, but if we backout bug 562840, then when you play a video there's a reasonable chance that the first few frames of any video will be dropped. That's not a good first impression for HTML5 video!
(In reply to comment #109)
> I have encountered issues with video playback stopping while working on my
> current stuff related to this code. The issue I came across was the audio
> thread stopping audio data from being read and since timing came from the audio
> thread everything stops. The fix for that was to change:
> 
>     if (audioDecoded > AMPLE_AUDIO_MS ||
>         (skipToNextKeyframe && audioDecoded > audioPumpThresholdMs)) {
> 
> to:
> 
>     if (audioDecoded > AMPLE_AUDIO_MS)) {
> 
> (ie. remove the second part of the condition in
> nsBuiltinDecoderOggStateMachine.cpp)
> 
> cpearce, could this possibly fix the test_playback orange issue?

I'm not sure. It's probably worth removing that condition, just to see if it helps. We could also disable the keyframe skipping logic if it doesn't help, and then come back and fix it.

> 
> A way to reproduce the playback stop more consistently is to increase the value
> of LOW_AUDIO_MS to something highesh (say 500) so that the keyframe skipping
> logic occurs.

If you increase LOW_AUDIO_MS without increasing audioPumpThresholdMs it's not surprising that keyframes to skip; if audioPumpThresholdMs is less than  LOW_AUDIO_MS, when audiopump is set to PR_FALSE, it's likely that we've decoded less than LOW_AUDIO_MS of audio, so we'll go into the keyframe skip early. What happens if you scale audioPumpThresholdMs by the same factor as LOW_AUDIO_MS?
(In reply to comment #111)
> 
> If you increase LOW_AUDIO_MS without increasing audioPumpThresholdMs it's not
> surprising that keyframes to skip; 

I know - the point of my suggestion to increase LOW_AUDIO_MS is to make keyframe's skip. The point of that is that it trigger's the code that stops the audio from being processed which result's in playback stopping. If this happens due to slight adjustment's to LOW_AUDIO_MS I'm sure it can happen 'intermittently' depending on load.
I raised bug 566241 with a fix for the issue mentioned in comment 109.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274158695.1274160366.1517.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5

47072 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274163200.1274164626.18624.gz
Linux mozilla-central debug test mochitests-1/5 on 2010/05/17 23:13:20
s: moz2-linux-slave28
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274296094.1274297477.11902.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/19 12:08:14
s: talos-r3-fed64-014

47168 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274305693.1274308264.26648.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/19 14:48:13

47096 INFO Running /tests/content/media/test/test_playback_errors.html...
47097 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | Name should match test.name #4
47098 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | redirect.sjs?http://mochi.test:8888/tests/content/media/test/320x240.ogv time should run forwards: p=0.26600000262260437 c=0.26600000262260437
++DOMWINDOW == 13 (0x5a58540) [serial = 1415] [outer = 0x30d8ee0]
WARNING: Stream data not in RIFF format: file /builds/slave/mozilla-central-linux64-debug/build/content/media/wave/nsWaveDecoder.cpp, line 982
47099 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.wav only one error fired
47100 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.ogv only one error fired
47101 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274317592.1274319854.11394.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/19 18:06:32
s: talos-r3-fed64-005

47180 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274380185.1274382442.8903.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/20 11:29:45
s: talos-r3-fed64-032

47183 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
(In reply to comment #119)
> I raised bug 566241 with a fix for the issue mentioned in comment 109.

I've just pushed the patch for bug 566241, hopefully it will help!
It looks like the landing of bug 566241 and stopped the near constant orange of test_playback.html.
(In reply to comment #184)
> It looks like the landing of bug 566241 and stopped the near constant orange of
> test_playback.html.

Yay! Less orange.

The recent spate of failures on WINNT on 1.9.2 started 23 minutes after after bug 533822 landed on 1.9.2. It's not obvious to me that the patch from bug 533822 could cause this though.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274831150.1274833738.7075.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/25 16:45:50
s: talos-r3-fed64-034

47295 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274892368.1274894528.9222.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/26 09:46:08
s: talos-r3-fed64-034

47245 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275074621.1275077033.12903.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/28 12:23:41
s: talos-r3-fed64-036

47352 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275094727.1275096640.1160.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/28 17:58:47
s: talos-r3-fed64-007

47333 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275104269.1275106254.6470.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/28 20:37:49
s: talos-r3-fed64-037
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275200314.1275202249.6522.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/29 23:18:34
s: talos-r3-fed64-033

47299 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275264196.1275267039.4909.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/30 17:03:16

48308 INFO Running /tests/content/media/test/test_playback_errors.html...
48309 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | Name should match test.name #4
48310 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | redirect.sjs?domain=mochi.test:8888&file=320x240.ogv duration (0.26600000262260437) should be around 0.233
48311 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | redirect.sjs?domain=mochi.test:8888&file=320x240.ogv time should run forwards: p=0.26600000262260437 c=0.26600000262260437
++DOMWINDOW == 13 (0x78f1680) [serial = 1430] [outer = 0x3052700]
WARNING: Stream data not in RIFF format: file /builds/slave/mozilla-central-linux64-debug/build/content/media/wave/nsWaveDecoder.cpp, line 982
48312 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.wav only one error fired
48313 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | bogus.ogv only one error fired
48314 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275354988.1275356432.4560.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/05/31 18:16:28
s: talos-r3-fed64-033

48328 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275545181.1275546756.25974.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/02 23:06:21
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275602258.1275603680.13036.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/03 14:57:38
s: talos-r3-fed64-015

49024 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275659524.1275661019.4329.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/04 06:52:04
s: talos-r3-fed64-005

49389 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/05 02:44:06
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275731046.1275732250.6649.gz
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275761634.1275762883.30863.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/05 11:13:54
s: talos-r3-fed64-015

49449 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276146780.1276149603.1726.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/09 22:13:00
s: talos-r3-fed64-021

49749 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired - 1 should equal 1
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276195342.1276197503.16085.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/10 11:42:22
s: talos-r3-fed64-021

49655 INFO TEST-PASS | /tests/content/media/test/test_playback_errors.html | 448636.ogv only one error fired - 1 should equal 1
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276227984.1276229453.24465.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/06/10 20:46:24

s: talos-r3-fed64-049
TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback_errors.html | application timed out after 330 seconds with no output
PROCESS-CRASH | /tests/content/media/test/test_playback_errors.html | application crashed (minidump found)
TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | missing output line for total leaks!
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1276318214.1276319862.28307.gz

s: win32-slave36
41083 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
Bug 557432 - Intermittent timeout in test_playback.html and test_playback_errors.html
Bug 507996 - random failure in test_playback.html | [SimpleTest/SimpleTest.js, window.onerror] An error occurred: [ [object ProgressEvent]
Bug 560784 - rev 3 Fedora 'pthread_mutex_destroy(&m->mutex) == 0' 'pa_atomic_load(&(c)->_ref) >= 1' fatal assertions during test_playback.html | bug461281.ogg
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1276315080.1276317474.15330.gz

s: win32-slave30
41090 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
Depends on: 573405
It won't help the test_playback problems at all.

It'll fix the Fedora x64 test_playback_errors crashes/timeouts, of which this bug seems to contain quite a few instances.  It's possible it'd fix test_playback_errors problems on 32-bit machines as well, but (without having looked at the code) I was under the impression that Theora would already have been correctly failing to initialize due to the frame size exceeding the 32-bit pointer size.
Depends on: 571798
Depends on: 573924
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277406652.1277410132.15281.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 12:10:52
s: win32-slave59
41029 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277407802.1277410570.17540.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 12:30:02
s: win32-slave32
41093 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277407652.1277410226.15842.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 12:27:32

s: win32-slave47
41052 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277400546.1277402502.12760.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 10:29:06

s: win32-slave28
41082 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277402264.1277404899.23773.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 10:57:44

s: win32-slave39
41087 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
53618 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_497898.html | Test timed out.
53683 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[153,193], [0,0,0,0]
53684 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[153,193], [0,20,0,20]
53686 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[144,183], [0,0,1,0]
53688 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[144,183], [0,0,1,1]
53689 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[77,240], [0,0,0,0]
53690 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[77,240], [1,0,0,0]
53691 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[77,240], [0,0,1,0]
53692 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[77,240], [1,0,1,0]
53695 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[39,212], [0,0,10,0]
53696 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[39,212], [10,1,30,0]
53697 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[39,212], [10,5,30,0]
53698 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[39,212], [10,15,30,0]
53699 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[18,330], [0,0,0,0]
53700 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[18,330], [0,0.5,0,0]
53701 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[18,330], [0,0,0.5,0]
53702 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[18,330], [0,0.25,0.5,0]
53703 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [18,330], [0,0.5,0.5,0]
53704 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [144,330.5], [0,0,0,0]
53705 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[144.5,330.5], [0,0,0,0]
53706 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [144.5,330.5], [0,0,0,0.1]
53707 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [15,410], [0,30,50,0]
53713 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Different number of nodes for rect[61,671], [0,0,0,0]
53714 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [61,671], [0,30,0,10]
53715 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/tests/mochitest/general/test_nodesFromRect.html | Unexpected node #0 for rect [61,671], [0,30,90,10]
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277421143.1277423436.10999.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 16:12:23
s: win32-slave34

41090 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277422341.1277425051.18185.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 16:32:21

s: win32-slave58
41061 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277422338.1277425173.18696.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 16:32:18

s: win32-slave28
41090 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277423101.1277425995.22102.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 16:45:01

s: win32-slave37
41084 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277427043.1277429532.6440.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 17:50:43

s: mw32-ix-slave03
41109 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277426488.1277430623.11485.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 17:41:28

s: win32-slave19
41093 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
57306 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_bug450930.xhtml | scrolled-out invalidation should notify in subdoc
alqahira at ardisson dot org
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277428632.1277431127.13447.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 18:17:12

s: mw32-ix-slave18
41117 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277431646.1277434545.29607.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 19:07:26
s: win32-slave35

41078 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277436400.1277439951.20788.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 20:26:40

s: win32-slave56
41081 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277437842.1277440743.24193.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 20:50:42

s: mw32-ix-slave13
41096 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277439113.1277441348.26921.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 21:11:53

s: win32-slave19
41075 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277442094.1277445081.10952.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/24 22:01:34

s: win32-slave06
41088 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277444772.1277447079.19418.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/24 22:46:12

s: mw32-ix-slave02
41117 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277513513.1277516028.3834.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/25 17:51:53

s: win32-slave36
41087 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277516028.1277518600.15174.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/25 18:33:48

s: win32-slave53
41074 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277521830.1277524700.7131.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2010/06/25 20:10:30

s: mw32-ix-slave19
41102 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6/1277528146.1277529772.26241.gz
WINNT 5.2 mozilla-1.9.2 opt test mochitests on 2010/06/25 21:55:46

s: mw32-ix-slave18
41106 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1278638031.1278643830.4994.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-1/5 on 2010/07/08 18:13:51

s: talos-r3-fed64-035
49233 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_playback.html | Test timed out.
buildbot.slave.commands.TimeoutError: command timed out: 5400 seconds elapsed, killing pid 2007
It appears that there has not been a single mozilla-1.9.2 run of this test on the Win2003 systems that has passed in quite some time.
(In reply to comment #484)
> It appears that there has not been a single mozilla-1.9.2 run of this test on
> the Win2003 systems that has passed in quite some time.
When I say this test I mean test_playback.html
(In reply to comment #485)
> (In reply to comment #484)
> > It appears that there has not been a single mozilla-1.9.2 run of this test on
> > the Win2003 systems that has passed in quite some time.
> When I say this test I mean test_playback.html

Perhaps we should disable test_playback on 1.9.2? We've got a new decoder backend on m-c now, so we can't "back port a fix" unless we merge content/media and the layers layers code from m-c onto 1.9.2, which I'm sure dveditz won't want to do.
It's not doing so hot on trunk either -- do we know why that is?
Most (all?) of the trunk failures are Linux, which is bug 573924 (blocked on bug 574190) and possibly bug 571798.
And those last three trunk fails from today weren't this, they were from bug 490705, since backed out.
I was going to just go ahead and disable it on 1.9.2, when I realized that it's failing in the pretty much the same place every time, so I could probably just disable a test file or two.

However, the ones where it stalls were added by a bug that's still security-sensitive.

Maybe we should actually investigate it, rather than wallpaper over it?
This patch reduces the amount of parallelism in the media mochitests.

This is needed because each non-ended media element requires 4 threads on Linux, and each thread has a 10MB stack. We're getting OOM errors during mochitest runs on 32bit Linux on TinderBox.

This patch reduces most mochitests to use at most 2 media elements at once. There are still a few others which use more, but we've not had problems reported with them, we can come back and deal with them later if need be.

I also reduced the randomness of seek6.js tests. This should speed up the test_seek, and may even help reduce random timeouts in test_seek. I believe that tests still tests the condition it was originally testing with this change.
Attachment #469346 - Flags: review?(roc)
Attachment #469346 - Flags: approval2.0?
Comment on attachment 469346 [details] [diff] [review]
Patch: De-parallelize the media mochitests

(In reply to comment #500)
> This is needed because each non-ended media element requires 4 threads on
> Linux, and each thread has a 10MB stack.

It's 10MB of virtual address space, not 10MB of allocated memory. You should reword the comments to make that clear.

Is 2 tests at a time really all we can handle? I would have hoped we can handle more.
Attachment #469346 - Flags: review?(roc)
Attachment #469346 - Flags: review+
Attachment #469346 - Flags: approval2.0?
Attachment #469346 - Flags: approval2.0+
(In reply to comment #501)
> Comment on attachment 469346 [details] [diff] [review]
> Patch: De-parallelize the media mochitests
> 
> (In reply to comment #500)
> > This is needed because each non-ended media element requires 4 threads on
> > Linux, and each thread has a 10MB stack.
> 
> It's 10MB of virtual address space, not 10MB of allocated memory. You should
> reword the comments to make that clear.

Thanks, I'll make that change.

> Is 2 tests at a time really all we can handle? I would have hoped we can handle
> more.

That's the level of parallelism we were using in test_playback*.

We can change PARALLEL_TESTS in manifest.js to change our parallelism across the board now, so we can tweak it easily. I'll try increasing it a bit, and see if that causes problems.
Reduced parallelism of media mochitests landed:
http://hg.mozilla.org/mozilla-central/rev/65f20938e5d6

I also added some forced GCs to ensure that we free the decoders' thread stacks in between tests, and I found a few more tests to de-parallelize once I figured out how to count app threads easily.

I left PARALLEL_TESTS at 2, we can increase it if there's no problems.
This test is basically perma-orange on Windows on 1.9.2. We should just disable it, since the only fix would be to back-port the new decoder architecture from m-c, which has diverged significantly.

r=test-fix.

Requesting approval 1.9.2.
Attachment #476281 - Flags: approval1.9.2.11?
Comment on attachment 476281 [details] [diff] [review]
Patch: Disable test on Windows on 1.9.2

Approved for 1.9.2.11, a=dveditz
Attachment #476281 - Flags: approval1.9.2.11? → approval1.9.2.11+
"status1.9.2=.11-fixed" isn't quite correct here, right? This isn't so much fixed as just disabled, on that branch.

Just mentioning because that status means this bug shows up in the "complete list of changes" bugzilla query for 1.9.2.11, in the "What's New" section of
http://www.mozillamessaging.com/en-US/thunderbird/3.1.xrc/releasenotes/?version=3.1.5
and it stands out in that list a bit because its status is still NEW instead of RESOLVED (presumably because it's not actually fixed)
It's highly likely that the recent spate of Linux timeouts here are caused by the same issue as bug 615134, for which a fix has now been checked in.
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
Status: RESOLVED → VERIFIED
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: