Closed Bug 671745 Opened 13 years ago Closed 13 years ago

Intermittent failure in test_replay_metadata.html | Should have received two ended events for 320x240.ogv (or small-shot.ogg) - got 3, expected 2; followed by v.parentNode is null

Categories

(Core :: Audio/Video, defect)

x86
All
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla9

People

(Reporter: heycam, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

http://tinderbox.mozilla.org/showlog.cgi?log=Mozilla-Inbound/1310687356.1310691112.15053.gz
Rev3 Fedora 12 mozilla-inbound debug test mochitests-1/5 on 2011/07/14 16:49:16

68645 INFO TEST-START | /tests/content/media/test/test_replay_metadata.html
WARNING: NS_ENSURE_TRUE(mState == STATE_TRANSFERRING) failed: file ../../../../netwerk/base/src/nsSocketTransport2.cpp, line 1889
++DOMWINDOW == 573 (0xe912360) [serial = 2143] [outer = 0x9c7e958]
68646 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | No more than 1 onloadedmetadata event for r11025_s16_c1.wav
68647 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | r11025_s16_c1.wav duration (1) should be around 1
68648 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | No more than 1 onloadeddata event for r11025_s16_c1.wav
68649 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | No more than 1 onloadedmetadata event for 320x240.ogv
68650 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | 320x240.ogv video width - 320 should equal 320
68651 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | 320x240.ogv video height - 240 should equal 240
68652 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | 320x240.ogv duration (0.266664) should be around 0.233
68653 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | No more than 1 onloadeddata event for 320x240.ogv
68654 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | CurrentTime (0.266664) should be around 0.266664 for 320x240.ogv
68655 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | seeking should be true for 320x240.ogv
68656 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | ended shouldn't be true once seeking has begun for 320x240.ogv
68657 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | CurrentTime (0.266664) should be around 0.266664 for 320x240.ogv
68658 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have received seekended for 320x240.ogv
68659 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have received seekstarted for 320x240.ogv
68660 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have 1 onloadeddata event for 320x240.ogv - 1 should equal 1
68661 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have 1 onloadedmetadata event for 320x240.ogv - 1 should equal 1
68662 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have received two ended events for 320x240.ogv - 2 should equal 2
68663 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have at least one playing event for 320x240.ogv
68664 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | CurrentTime (1) should be around 1 for r11025_s16_c1.wav
68665 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | seeking should be true for r11025_s16_c1.wav
68666 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | ended shouldn't be true once seeking has begun for r11025_s16_c1.wav
68667 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | CurrentTime (0.266664) should be around 0.266664 for 320x240.ogv
68668 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have received seekended for 320x240.ogv
68669 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have received seekstarted for 320x240.ogv
68670 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have 1 onloadeddata event for 320x240.ogv - 1 should equal 1
68671 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have 1 onloadedmetadata event for 320x240.ogv - 1 should equal 1
NEXT ERROR 68672 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_replay_metadata.html | Should have received two ended events for 320x240.ogv - got 3, expected 2
68673 INFO TEST-PASS | /tests/content/media/test/test_replay_metadata.html | Should have at least one playing event for 320x240.ogv
68674 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_replay_metadata.html | [SimpleTest/SimpleTest.js, window.onerror] - An error occurred: v.parentNode is null at http://mochi.test:8888/tests/content/media/test/test_replay_metadata.html:78
JavaScript error: http://mochi.test:8888/tests/content/media/test/test_replay_metadata.html, line 78: v.parentNode is null
68675 INFO TEST-END | /tests/content/media/test/test_replay_metadata.html | finished in 5397ms
OS: Linux → All
Summary: Intermittent failure in test_replay_metadata.html | Should have received two ended events for 320x240.ogv - got 3, expected 2; followed by v.parentNode is null → Intermittent failure in test_replay_metadata.html | Should have received two ended events for 320x240.ogv (or small-shot.ogg) - got 3, expected 2; followed by v.parentNode is null
Attached patch Fix testSplinter Review
I think this bug is caused by an incorrect test. The test does the following:

1. Load media and call play() in loadedmetadata handler.
2. On the first ended event, seek to 0 and call play().
3. In the seeked handler call play().
4. In the ended handler (after we've replayed the media a second time) end the test.

The problem is the "ended" event is firing three times. I think in between step 2 and 3 we're playing the entire media through, so calling play() again in step 3 is causing us to play through a third time, causing the extra ended event, and this failure.

This patch removes the play() call in step 3.
Assignee: nobody → chris
Status: NEW → ASSIGNED
Attachment #553575 - Flags: review?(chris.double)
Attachment #553575 - Flags: review?(chris.double) → review+
http://hg.mozilla.org/integration/mozilla-inbound/rev/8d4257d1967c
Whiteboard: [orange] → [orange][inbound]
Target Milestone: --- → mozilla9
(In reply to Chris Pearce (:cpearce) (Mozilla Corporation) from comment #27)
> http://hg.mozilla.org/integration/mozilla-inbound/rev/8d4257d1967c

Hmm, still failing randomly on m-i with this test change. Must be caused by something else...
I missed this the first time. We call play() in the "loadedmetadata" handler, but also in the "seeked" handler. We don't need to call play() in the seeked handler, as we'll still be in playing state from the first call (as specified, despite playing through to the end and seeking). So the test can still fail similar to as I described in comment 11.

This patch removes this further unnecessary play() call.
Attachment #554190 - Flags: review?(chris.double)
Attachment #554190 - Flags: review?(chris.double) → review+
(In reply to Chris Pearce (:cpearce) (Mozilla Corporation) from comment #39)
> Created attachment 554190 [details] [diff] [review]
> Patch: Another attempt to fix test

http://hg.mozilla.org/integration/mozilla-inbound/rev/33479afad8bf
http://hg.mozilla.org/mozilla-central/rev/33479afad8bf
Status: ASSIGNED → RESOLVED
Closed: 13 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Whiteboard: [orange][inbound] → [orange]
This is obviously still failing, and appears to be failing the same way it was originally, so reopening.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee: chris → nobody
Nah, you're just forgetting the delights of the rapid release train: it stopped failing on m-c the second it was pushed; it stopped failing on m-a when that got merged (September 27th must have been the last merge day); it'll stop failing on m-b next mergeday; nobody ever looks at test results on mozilla-release so there's nobody to care that it'll stop failing there six weeks after that.
Status: REOPENED → RESOLVED
Closed: 13 years ago13 years ago
Resolution: --- → FIXED
Oh, duh, thanks!
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: