Closed Bug 528001 Opened 16 years ago Closed 16 years ago

test_videocontrols_video_direction.html and test_videocontrols_audio_direction.html time out

Categories

(Toolkit :: UI Widgets, defect)

Product:
Toolkit
Component:
UI Widgets
Platform:
x86
Windows NT
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla1.9.3a1
Tracking Flags:
Tracking Status
status1.9.2 --- beta4-fixed

People

(Reporter: dietrich, Assigned: ehsan.akhgari)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

possible patch
1.44 KB, patch
Details | Diff | Splinter Review
Switch to a wave file
10.06 KB, patch
Details | Diff | Splinter Review
Whiteboard: [orange]
Status: NEW → RESOLVED
Closed: 16 years ago
Resolution: --- → DUPLICATE
Let's reopen this bug to track the timeout as in: http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258135325.1258136118.4675.gz
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
Summary: test_videocontrols_video_direction.html fails → test_videocontrols_video_direction.html times out
Assignee: nobody → ehsan
Status: REOPENED → ASSIGNED
This should happen because the suspend even is never raised. I'm not sure how that's possible though.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258140466.1258141708.6120.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/13 11:27:46 "s: moz2-win32-slave12"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258163497.1258164365.2656.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/13 17:51:37 "s: moz2-win32-slave32"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258179481.1258180148.9756.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/13 22:18:01 "s: moz2-win32-slave15"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258201434.1258202247.30554.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/14 04:23:54
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258210028.1258211052.7325.gz Linux mozilla-central debug test mochitests-5/5 on 2009/11/14 06:47:08 s: moz2-linux-slave21
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1258182969.1258185930.7524.gz#err1 OS X 10.5.2 mozilla-1.9.2 test mochitests on 2009/11/13 23:16:09 s: bm-xserve16 110002 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_audio_direction.html | Test timed out. 110005 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
Summary: test_videocontrols_video_direction.html times out → test_videocontrols_video_direction.html and test_videocontrols_audio_direction.html time out
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1258187353.1258191198.32376.gz OS X 10.5.2 mozilla-1.9.2 test mochitests on 2009/11/14 00:29:13 s: moz2-darwin9-slave12
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258223895.1258224663.582.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/14 10:38:15 "s: moz2-win32-slave36"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258234502.1258235380.24241.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/14 13:35:02 "s: moz2-win32-slave10"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258230208.1258230907.7817.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/14 12:23:28 "s: moz2-win32-slave41"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258254597.1258255467.13705.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/14 19:09:57 "s: moz2-win32-slave10"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258258200.1258258892.19043.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/14 20:10:00 "s: moz2-win32-slave25"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258313534.1258314130.10871.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/15 11:32:14 "s: moz2-win32-slave22"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258317252.1258317936.21870.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/15 12:34:12 "s: moz2-win32-slave28"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258333161.1258334064.8425.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/15 16:59:21 "s: moz2-win32-slave31"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1258384329.1258387584.22617.gz WINNT 5.2 mozilla-1.9.2 test mochitests on 2009/11/16 07:12:09 "s: moz2-win32-slave12" 110081 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_audio_direction.html | Test timed out. 110084 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1258386694.1258389552.11454.gz OS X 10.5.2 mozilla-1.9.2 test mochitests on 2009/11/16 07:51:34 s: bm-xserve19 110007 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_audio_direction.html | Test timed out. 110010 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
The 1.9.2 failures are caused by a mistake in the changeset that I landed; I'll land a fix as soon as the tree reopens. The general timeout issue is however unrelated to that mistake. My theory on that was posted in comment 3.
Severity: blocker → normal
Has anyone been able to reproduce this locally?
I tried switching to progress events to see whether this orange gets less frequent: <http://hg.mozilla.org/mozilla-central/rev/01e3238d3ddd>
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258417855.1258419313.29767.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/16 16:30:55 "s: moz2-win32-slave05" (Note that this cycle was built from comment 32's changeset, 01e3238d3ddd)
Yes, this didn't help, so I backed it out: http://hg.mozilla.org/mozilla-central/rev/8b8621798ebe
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258464231.1258465558.32023.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/17 05:23:51 "s: moz2-win32-slave38"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258500577.1258502557.2375.gz WINNT 5.2 mozilla-central test mochitests-5/5 [testfailed] Started 15:29, finished 16:03
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258509418.1258510875.1059.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/17 17:56:58 "s: moz2-win32-slave26"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258520298.1258521384.22759.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/17 20:58:18 "s: moz2-win32-slave13"
Blocks: 438871
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258588927.1258590714.14134.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/18 16:02:07 "s: moz2-win32-slave36"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258589007.1258590734.14469.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/18 16:03:27 "s: moz2-win32-slave14"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258600557.1258601465.6647.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/18 19:15:57 "s: moz2-win32-slave06"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258606944.1258607666.9671.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/18 21:02:24 "s: moz2-win32-slave17"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258646994.1258647680.13783.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/19 08:09:54 "s: moz2-win32-slave16" 14596 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258647480.1258648574.23814.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/19 08:18:00 "s: moz2-win32-slave11" 14597 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258668972.1258670267.17217.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/19 14:16:12 "s: moz2-win32-slave26" 14567 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/content/tests/widgets/test_videocontrols_video_direction.html | Test timed out.
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258678663.1258680049.30203.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/19 16:57:43
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258680470.1258681484.14327.gz WINNT 5.2 mozilla-central opt test mochitests-5/5 on 2009/11/19 17:27:50
I can intermittently (attempts #2 and #6 out of six tries so far) reproduce this locally. I put in some additional ok() lines to figure out what is going on. In attempt #2 it was the canvas with id ref-2, in attempt #6 it was the canvas with id test-0 that failed to complete. (In both cases, test_videocontrols_video_direction.html) In both cases, the failure was that the suspend event listener was called, but it did not set a timeout. The problem appears (in attempt #6) to be that m.readyState is 2 (HAVE_CURRENT_DATA) rather than 4 (HAVE_ENOUGH_DATA). I would note additionally that aEvent.loaded and aEvent.total are both undefined, so the equality check between the two of them always passes. Could that be responsible for some of the other problems with this test?
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258687315.1258688303.27718.gz WINNT 5.2 mozilla-central test mochitests-5/5 on 2009/11/19 19:21:55 "s: moz2-win32-slave39"
ooh yeah. iframe.addEventListener("load", function() { var m = iframe.contentDocument.getElementById("av"); m.addEventListener("suspend", function(aEvent) { if (m.readyState == m.HAVE_ENOUGH_DATA && aEvent.loaded == aEvent.total) { m.removeEventListener("suspend", arguments.callee, false); setTimeout(function() { me.remotePageLoaded(callback); }, 0); } }, false); m.src = m.getAttribute("source"); }, false); Some issues here: 1) when playback reaches the end of the resource, readyState changes to HAVE_CURRENT_DATA. So if the "suspend" event (which dispatches asynchronously) fires quite late, then you might be in HAVE_CURRENT_DATA. 2) "suspend" is not a progress event. In fact, in the HTML5 spec none of the media events are progress events anymore. In our implementation many of the events still are, but "suspend" isn't. I think you could ditch the HAVE_ENOUGH_DATA check and listen for "progress" instead. We will fire a final "progress" event when we reach the end of the resource. Another thing I recommend is using Wave files for the test. Ogg files have metadata at the end and in some rare (random) cases we may actually stop reading before we reach the end, because we don't need the last chunk. You can use Wave files for <video>, they just don't have any ... unless the controls are special-casing 0x0 video and giving that special UI, I guess.
(In reply to comment #55) > I think you could ditch the HAVE_ENOUGH_DATA check and listen for "progress" > instead. We will fire a final "progress" event when we reach the end of the > resource. How do you tell which one is the final one?
Check event.loaded == event.total. The long-term fix here is to have the controls, and the tests, use the 'buffered' property to determine when the content is fully loaded. But we haven't implemented that yet.
Attached patch possible patch — — Splinter Review
I think this is basically what roc said... which is also equivalent to what Ehsan tried last plus removing the m.readyState check. And I checked that these properties do exist on the 'progress' event. Should I try landing this? I ran it three times, and it passed. (Also, for every progress event, loaded and total were equal.)
This patch complements roc's suggestion by switching to a wav file for both audio and video tests.
Ehsan, do you want to land those patches on 1.9.2?
Based on the frequency of the failures until comment 61, and the fact that we haven't had a single failure in the past three days on trunk, I'm marking this as FIXED. Thanks to all who helped fix this! Now, off to 1.9.2 landing.
Status: ASSIGNED → RESOLVED
Closed: 16 years ago → 16 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla1.9.3a1
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: