Closed Bug 569163 Opened 16 years ago Closed 15 years ago

Intermittent failure in test_play_events.html | Last event should be canplaythrough for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav - got "canplay", expected "canplaythrough"

Categories

(Core :: Audio/Video, defect)

Product:
Core
Component:
Audio/Video
Platform:
x86
Windows Server 2003
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED

People

(Reporter: ehsan.akhgari, Assigned: kinetik)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

patch v1
1.92 KB, patch
cpearce
: review+
roc
: approval2.0+
Details | Diff | Splinter Review
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275261088.1275262403.19080.gz WINNT 5.2 mozilla-central debug test mochitests-1/5 on 2010/05/30 16:11:28 45219 INFO Running /tests/content/media/test/test_play_events.html... 45220 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | small-shot.ogg must not be paused after end 45221 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | small-shot.ogg must not be paused after end 45222 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | 320x240.ogv must not be paused after end ++DOMWINDOW == 18 (13C1DD3C) [serial = 1426] [outer = 084797B0] 45223 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got play at 0 for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45224 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got play at 0 for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45225 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got play at 0 for http://mochi.test:8888/tests/content/media/test/small-shot.ogg WARNING: NS_ENSURE_TRUE(mIsPending) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/netwerk/protocol/http/src/nsHttpChannel.cpp, line 4202 45226 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at play for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45227 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45228 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45229 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at play for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45230 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45231 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45232 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at play for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45233 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45234 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45235 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at canplaythrough for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45236 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45237 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45238 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at canplaythrough for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45239 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45240 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45241 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at canplaythrough for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45242 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45243 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/content/media/test/320x240.ogv WARNING: NS_ENSURE_TRUE(mSuspendCount > 0) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/netwerk/protocol/http/src/nsHttpChannel.cpp, line 4219 45244 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at canplaythrough for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45245 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45246 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at playing for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45247 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45248 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Last event should be canplaythrough for http://mochi.test:8888/tests/content/media/test/small-shot.ogg 45249 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Last event should be canplaythrough for http://mochi.test:8888/tests/content/media/test/320x240.ogv 45250 INFO TEST-PASS | /tests/content/media/test/test_play_events.html | Check expected event got canplay at playing for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav 45251 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_play_events.html | Last event should be canplaythrough for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav - got "canplay", expected "canplaythrough" WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610 WARNING: NS_ENSURE_TRUE(mDocument && mDocShell) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/parser/html/nsHtml5TreeOpExecutor.cpp, line 610
Whiteboard: [random] → [orange]
philringnalda%gmail.com http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276231028.1276232101.32477.gz Linux mozilla-central debug test mochitests-1/5 on 2010/06/10 21:37:08 s: moz2-linux-slave23 46280 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 56 bytes during test execution This could be bug 538462. TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of Image with size 16 bytes TEST-UNEXPECTED-FAIL | automationutils.processLeakLog() | leaked 1 instance of VideoData with size 40 bytes
I can reproduce this fairly reliably when running Fx inside valgrind.
54305 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav The spec says, for HAVE_ENOUGH_DATA, the following events should be fired: canplay, playing (if "potentially playing"), then canplaythrough. We call play() when the element is created, so it should be "potentially playing" by the time we see the canplaythrough event. This suggests the "potentially playing" test is failing for some reason, so we don't fire playing.
On SeaMonkey Win32: [http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1286910293.1286916090.25010.gz] 54907 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_play_events.html | Check expected event got canplaythrough at canplay for http://mochi.test:8888/tests/content/media/test/r11025_s16_c1.wav uneval(event.type)="canplaythrough" typeof(event.type)=string uneval(v._state)="canplay" typeof(v._state)=string tokens[canplay]=playing tokens[canplay].indexOf(event.type)=-1
The decoder is reaching the ended state before any of the ready state update events are processed (including MetadataLoaded). Specifically, ResourceLoaded would usually occur while the decoder was running and cause "canplay", "playing", and "canplaythrough" to be fired. In the failing case, the decoder has already reached the ended state by the time ResourceLoaded is called, so "playing" is not fired.
I thought a simple fix would be to maintain the ended state on the decoder only, and update that from the state machine via the PlaybackEnded event, but there is existing code in PlaybackEnded() that drops that event if the state machine's ended flag is no longer true--this is necessary for the case where a seek occurs when the state machine has ended playback but before the ended event is seen by content script, which we treat as not-ended.
Blocks: 573232
Blocks: 562004
Attached patch patch v0 (obsolete) — — Splinter Review
That led me to the correct fix, anyway: maintain the decoder's ended state separately from the state machine's. Use the state machine's ended state to cancel changes to the decoder's ended state (for the seek before ended is externally visible case I mentioned), and use the decoder's ended state exclusively as the externally visible ended state.
Assignee: nobody → kinetik
Status: NEW → ASSIGNED
Attachment #490034 - Flags: review?(chris)
Comment on attachment 490034 [details] [diff] [review] patch v0 Makes sense. Nice catch!
Attachment #490034 - Flags: review?(chris)
Attachment #490034 - Flags: review+
Attachment #490034 - Flags: approval2.0?
Status: ASSIGNED → RESOLVED
Closed: 15 years ago
Resolution: --- → FIXED
Backed out: http://hg.mozilla.org/mozilla-central/rev/4988b81e8474 http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1289777311.1289778279.12016.gz s: talos-r3-fed-007 55147 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_bug465498.html | Checking ended is no longer true for r11025_s16_c1.wav 55149 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_bug465498.html | Checking ended is false for r11025_s16_c1.wav 56164 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_play_twice.html | Expect at least one playing event 57367 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_replay_metadata.html | ended shouldn't be true once seeking has begun for r11025_s16_c1.wav 57368 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_replay_metadata.html | Test timed out.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached patch patch v1 — — Splinter Review
I thought I ran the complete mochitests on Friday evening, but apparently not. Anyway, the breakage is stupid and the fix is obvious: reset mEnded when reusing the decoder. All of content/media passes with this.
Attachment #490034 - Attachment is obsolete: true
Attachment #490501 - Flags: review?(chris)
Attachment #490501 - Flags: approval2.0?
Attachment #490501 - Flags: review?(chris) → review+
http://hg.mozilla.org/mozilla-central/rev/be27bc809788
Status: REOPENED → RESOLVED
Closed: 15 years ago → 15 years ago
Resolution: --- → FIXED
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: