Closed Bug 750769 Opened 8 years ago Closed 4 years ago

[disabled on Win32] Intermittent content/media/test/test_streams_element_capture_reset.html | Test timed out.

Categories

(Core :: Audio/Video: Playback, defect, P5)

15 Branch
x86
macOS
defect

Tracking

()

RESOLVED FIXED
mozilla15

People

(Reporter: emorley, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [test disabled])

Attachments

(7 files, 1 obsolete file)

Attached image Screenshot
Rev3 MacOSX Leopard 10.5.8 mozilla-inbound opt test mochitests-1/5 on 2012-05-01 03:38:07 PDT for push d60f77b10824

slave: talos-r3-leopard-033

https://tbpl.mozilla.org/php/getParsedLog.php?id=11354681&tree=Mozilla-Inbound

{
84530 INFO TEST-END | /tests/content/media/test/test_streams_element_capture.html | finished in 4982ms
84531 INFO TEST-START | /tests/content/media/test/test_streams_element_capture_reset.html
84532 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Initial timeupdate
84533 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Finished seeking
84534 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture_reset.html | Test timed out.
args: ['arch', '-arch', 'i386', '/usr/sbin/screencapture', '-C', '-x', '-t', 'png', '/var/folders/Xr/Xr--yJnSEY0U11ET5NZuMU+++TM/-Tmp-/mozilla-test-fail_nc-0p5']
SCREENSHOT: <snip>
84535 INFO TEST-END | /tests/content/media/test/test_streams_element_capture_reset.html | finished in 316512ms
}
Attached patch fix (obsolete) — Splinter Review
I think this might fix it.

I think the current test can hang in the following way:
-- timeupdate event queued
-- media playback ends
-- timeupdate event runs
-- seek triggered
-- seek completes
-- playback is stopped since media playback already ended, so nothing else ever happens

So this patch stops playback in the first timeupdate (with currentTime > 0), before seeking, then starts playback again in the "seeked" event handler.
Assignee: nobody → roc
Attachment #620575 - Flags: review?(cpearce)
Comment on attachment 620575 [details] [diff] [review]
fix

Review of attachment 620575 [details] [diff] [review]:
-----------------------------------------------------------------

As discussed, we should be still "potentially playing" when playback reaches the end of the media, so playing/pausing here shouldn't make any difference.
Attachment #620575 - Flags: review?(cpearce) → review-
Attached patch collect dataSplinter Review
Attachment #620575 - Attachment is obsolete: true
Attachment #620580 - Flags: review?(cpearce)
Attachment #620580 - Flags: review?(cpearce) → review+
Here's an extract from the log:

84857 INFO TEST-START | /tests/content/media/test/test_streams_element_capture_reset.html
GOT EVENT playing
GOT EVENT timeupdate currentTime=0.021174
84858 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Initial timeupdate
GOT EVENT timeupdate currentTime=0.1165
GOT EVENT seeking
GOT EVENT timeupdate currentTime=0.1165
GOT EVENT seeked
84859 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Finished seeking
GOT EVENT timeupdate currentTime=0.1165
GOT EVENT ended
84860 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture_reset.html | Test timed out.

We did not deliberately pause, yet the last timeupdate before 'ended' fires is at 0.1165 (which is duration/2, which is what we seek to). Let's try some more logging...
Attachment #621498 - Flags: review?(cpearce) → review+
(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #17)
> Created attachment 621498 [details] [diff] [review]
> collect more data

https://hg.mozilla.org/mozilla-central/rev/a4b6547caf9d
Status: NEW → ASSIGNED
Target Milestone: --- → mozilla15
84931 INFO TEST-START | /tests/content/media/test/test_streams_element_capture_reset.html
GOT EVENT playing currentTime=0.03036 paused=false ended=false readyState=4
GOT EVENT timeupdate currentTime=0.03036 paused=false ended=false readyState=4
84932 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Initial timeupdate
GOT EVENT timeupdate currentTime=0.1165 paused=false ended=false readyState=2
GOT EVENT seeking currentTime=0.1165 paused=false ended=false readyState=2
GOT EVENT timeupdate currentTime=0.1165 paused=false ended=false readyState=2
GOT EVENT seeked currentTime=0.1165 paused=false ended=true readyState=4
84933 INFO TEST-PASS | /tests/content/media/test/test_streams_element_capture_reset.html | Finished seeking
GOT EVENT timeupdate currentTime=0.1165 paused=false ended=true readyState=4
GOT EVENT ended currentTime=0.1165 paused=false ended=true readyState=4
84934 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_streams_element_capture_reset.html | Test timed out.

This is somewhat odd. Playback ends while seeking?
Attachment #623943 - Flags: review?(cpearce) → review+
Attachment #623948 - Flags: review?(cpearce) → review+
Attachment #623950 - Flags: review?(cpearce) → review+
Whiteboard: [orange] → [orange][leave open]
Attachment #624660 - Flags: review?(cpearce) → review+
Depends on: 769188
Whiteboard: [orange][leave open] → [orange]
Disabled in bug 752796.
Summary: Intermittent content/media/test/test_streams_element_capture_reset.html | Test timed out. → [disabled on Win32] Intermittent content/media/test/test_streams_element_capture_reset.html | Test timed out.
Whiteboard: [orange] → [orange][test disabled]
Blocks: 801512
Whiteboard: [orange][test disabled] → [test disabled]
Component: Audio/Video → Audio/Video: Playback
P5
Priority: -- → P5
Assignee: roc → nobody
Status: ASSIGNED → NEW
Last active reports were in 2013, and all for pandas (now decomm'd)
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.