Open Bug 1198168 Opened 9 years ago Updated 1 year ago

Intermittent dom/media/test/test_bug1113600.html | single tracking bug

Categories

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

x86_64
Windows 10
defect

Tracking

()

Tracking Status
firefox43 --- affected

People

(Reporter: nigelb, Unassigned, NeedInfo)

References

(Depends on 2 open bugs, Regression, )

Details

(4 keywords, Whiteboard: [retriggered][stockwell fixed:patch][stockwell needswork:owner])

Attachments

(3 files)

No description provided.
Priority: -- → P5
20:42:16 INFO - 43412 INFO [finished detodos.opus-9] remaining= seek.webm-7 Looks like we have problem at all platforms for the seek.webm file.
Component: Audio/Video → Audio/Video: Playback
JW got this one on a try. Any ideas what could have timed out. As far as I can tell the reader was finished. https://treeherder.mozilla.org/logviewer.html#?job_id=26093610&repo=try#L3138
Might be a regression of bug 1201363.
Blocks: 1201363
Component: Audio/Video: Playback → Audio/Video: MediaStreamGraph
Looks like the gizmo.mp4 not running to the onended....not the known symptom of the regression for bug 1201363...Digging... 06:37:56 INFO - 184 INFO TEST-PASS | dom/media/test/test_bug1113600.html | [started gizmo.mp4-10 t=3.369] Length of array should match number of running tests 06:37:56 INFO - 185 INFO detodos.opus capture started at 0.847562. Duration=2.9135 06:37:56 INFO - 186 INFO TEST-PASS | dom/media/test/test_bug1113600.html | detodos.opus ended 06:37:56 INFO - 187 INFO [finished detodos.opus-9] remaining= gizmo.mp4-10 06:37:56 INFO - 188 INFO TEST-PASS | dom/media/test/test_bug1113600.html | [finished detodos.opus-9 t=4.239] Length of array should match number of running tests 06:37:56 INFO - 189 INFO TEST-PASS | dom/media/test/test_bug1113600.html | [started flac-s24.flac-11 t=4.239] Length of array should match number of running tests 06:37:56 INFO - 190 INFO gizmo.mp4 capture started at 1.45602. Duration=5.56 06:37:56 INFO - 191 INFO flac-s24.flac capture started at 1.26907. Duration=4.04 06:37:56 INFO - 192 INFO TEST-PASS | dom/media/test/test_bug1113600.html | flac-s24.flac ended 06:37:56 INFO - 193 INFO [finished flac-s24.flac-11] remaining= gizmo.mp4-10 06:37:56 INFO - 194 INFO TEST-PASS | dom/media/test/test_bug1113600.html | [finished flac-s24.flac-11 t=5.869] Length of array should match number of running tests 06:37:56 INFO - 195 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | Test timed out.
Comment on attachment 8783788 [details] Bug 1198168 - Skip the test on video 320x240.ogv. . https://reviewboard.mozilla.org/r/73466/#review71334 ::: dom/media/test/test_bug1113600.html:15 (Diff revision 1) > + // The duration of 320x240.ogv is too short for do a proper > + // mozCaptureStreamUntilEnded. So skip this video. > + if (test.name == "320x240.ogv") { > + return; > + } Then it'll end before the captureStream has gotten applied. This is fine.
Attachment #8783788 - Flags: review-
Sorry, didn't see that the review request had been cancelled. IIRC, this test was originally from a bug where telling MediaDecoder to capture into a stream would stall and freeze playback (because it would switch clocks and there were bugs). It shouldn't have anything to do with MediaStreamVideoSinks.
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #69) > Sorry, didn't see that the review request had been cancelled. > > > IIRC, this test was originally from a bug where telling MediaDecoder to > capture into a stream would stall and freeze playback (because it would > switch clocks and there were bugs). It shouldn't have anything to do with > MediaStreamVideoSinks. Yeap, the capturedStream is not assigned to any media element. So I don't think the regression should be caused by bug 1201363. Remove the dependency.
No longer blocks: 1201363
Depends on: 1299021
Let's see if bug 1299021 fixes the timeout.
Attachment #8806250 - Flags: review?(kaku)
Comment on attachment 8806250 [details] Bug 1198168 - add debugging logs. https://reviewboard.mozilla.org/r/89756/#review89182 ::: dom/media/test/test_bug1113600.html:12 (Diff revision 1) > <script type="text/javascript" src="manifest.js"></script> > </head> > <body> > <pre id="test"> > <script class="testbody" type="text/javascript"> > +PARALLEL_TESTS = 1; Is the timeout still reproducable if we limit the prrallel run to 1?
Attachment #8806250 - Flags: review?(kaku) → review+
Comment on attachment 8806250 [details] Bug 1198168 - add debugging logs. https://reviewboard.mozilla.org/r/89756/#review89182 > Is the timeout still reproducable if we limit the prrallel run to 1? I don't know. I change the number to 1 to avoid interleaved logs produced by different media elements.
(In reply to OrangeFactor Robot from comment #104) > 4 failures in 947 pushes (0.004 failures/push) were associated with this bug > in the last 7 days. > > Repository breakdown: > * autoland: 3 > * mozilla-inbound: 1 > > Platform breakdown: > * windows10-64-stylo-disabled: 3 > * windows10-64: 1 > > For more details, see: > https://brasstacks.mozilla.com/orangefactor/ > ?display=Bug&bugid=1198168&startday=2017-10-09&endday=2017-10-15&tree=all Windows 10 timeout.
Depends on: 1407553
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression

While it wouldn't be impossible, your retrigger results seem inconclusive at best.

Edit: Ah, I assumed all unclassified oranges were this test failing, but that was not the case. Yes, then this seems reasonable.

Flags: needinfo?(apehrson)
Assignee: nobody → apehrson
Status: NEW → ASSIGNED
Whiteboard: [retriggered]

Bug 1600063 changed the chunk-dropping logic from dropping when we had started
playing a chunk, to when we had finished playing a chunk -- i.e., started
playing the next chunk.

But when a chunk is the very last chunk in the media resource, we cannot start
playing the next chunk, because there is no next chunk. Making this check
inclusive seems reasonable.

Regressed by: 1600063
Pushed by pehrsons@gmail.com: https://hg.mozilla.org/integration/autoland/rev/f137c5089ad2 Since we're now checking the end time of the last chunk, make it inclusive. r=padenot
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered]
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell fixed:patch]

This failure is occuring on mozilla-beta as well, can the fix be uplifted?

Flags: needinfo?(aryx.bugmail)

Paul, shall this be uplifted to also fix it on beta?

Flags: needinfo?(aryx.bugmail) → needinfo?(padenot)

I don't think so, it has lots of dependencies.

Flags: needinfo?(padenot)
Has Regression Range: --- → yes
Assignee: apehrson → nobody
Status: ASSIGNED → NEW
Severity: normal → S3

There have been 38 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
[task 2023-01-12T15:38:21.127Z] 15:38:21     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | Reason cannot be empty 
[task 2023-01-12T15:38:21.127Z] 15:38:21     INFO - Buffered messages finished
[task 2023-01-12T15:38:21.128Z] 15:38:21     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | Test timed out! 
[task 2023-01-12T15:38:21.128Z] 15:38:21     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:404:16
[task 2023-01-12T15:38:21.128Z] 15:38:21     INFO -     onTimeout@dom/media/test/manifest.js:2366:9
[task 2023-01-12T15:38:21.128Z] 15:38:21     INFO - small-shot.m4a-1 timed out!
[task 2023-01-12T15:38:21.129Z] 15:38:21     INFO - [finished small-shot.m4a-1] remaining= 
[task 2023-01-12T15:38:21.129Z] 15:38:21     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished small-shot.m4a-1 t=180.531] Length of array should match number of running tests 

There have been 30 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • macosx1015-64-qr
  • macosx1015-64-shippable-qr
[task 2023-02-18T08:01:31.426Z] 08:01:31     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | Reason cannot be empty 
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO - Buffered messages finished
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | Test timed out! 
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:404:16
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO - small-shot-mp3.mp4-3 timed out!
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO - [finished small-shot-mp3.mp4-3] remaining= 
[task 2023-02-18T08:01:31.427Z] 08:01:31     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished small-shot-mp3.mp4-3 t=182.266] Length of array should match number of running tests 

Alastor do you know any similar timeouts for playback on Mac? I'm really wondering whether this is generic or specific to mozCaptureStreamUntilEnded.

Flags: needinfo?(alwu)

No, I didn't see any similar timeout on Mac recently.

Flags: needinfo?(alwu)

There have been 32 total failures in the last 7 days.
There are:

  • 7 failures on macosx1015-64-qr opt and debug
  • 2 failures on macosx1015-64-shippable-qr opt
  • 23 failures on macosx1100-64-shippable-qr opt

Recent failure log.

Paul , as the owner of this component, can you help us assign the bug to someone? Thank you.

Flags: needinfo?(padenot)
Whiteboard: [retriggered][stockwell fixed:patch] → [retriggered][stockwell fixed:patch][stockwell needswork:owner]
Summary: Intermittent dom/media/test/test_bug1113600.html | Test timed out → Intermittent dom/media/test/test_bug1113600.html | single tracking bug
Duplicate of this bug: 1350507
Duplicate of this bug: 1354346
Duplicate of this bug: 1544465

Update

There have been 30 failures within the last 7 days:

  • 4 failures on OS X 10.15 WebRender opt
  • 1 failure on OS X 10.15 WebRender Shippable opt
  • 25 failures on OS X 11 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=419406021&repo=autoland&lineNumber=3565

[task 2023-06-15T11:19:16.993Z] 11:19:16     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | Reason cannot be empty 
[task 2023-06-15T11:19:16.993Z] 11:19:16     INFO - Buffered messages finished
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | Test timed out! 
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:424:16
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     onTimeout@dom/media/test/manifest.js:2380:9
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:2387:57
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     startTest@dom/media/test/test_bug1113600.html:22:11
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2433:12
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     startTest/v.onended@dom/media/test/test_bug1113600.html:39:13
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     EventHandlerNonNull*startTest@dom/media/test/test_bug1113600.html:36:3
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2433:12
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     startTest/v.onended@dom/media/test/test_bug1113600.html:39:13
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     EventHandlerNonNull*startTest@dom/media/test/test_bug1113600.html:36:3
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-15T11:19:16.994Z] 11:19:16     INFO -     MediaTestManager/this.runTests/<@dom/media/test/manifest.js:2356:12
[task 2023-06-15T11:19:16.995Z] 11:19:16     INFO -     Async*MediaTestManager/this.runTests@dom/media/test/manifest.js:2355:19
[task 2023-06-15T11:19:16.995Z] 11:19:16     INFO -     @dom/media/test/test_bug1113600.html:46:9
[task 2023-06-15T11:19:16.995Z] 11:19:16     INFO - small-shot.mp3-2 timed out!
[task 2023-06-15T11:19:16.995Z] 11:19:16     INFO - [finished small-shot.mp3-2] remaining= 
[task 2023-06-15T11:19:16.995Z] 11:19:16     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished small-shot.mp3-2 t=181.085] Length of array should match number of running tests 
Depends on: 1715707

MediaDecoder and AudioSinkWrapper verbose logging was enabled for a "gizmo-short.mp4-10 timed out!" failure.

Depends on: 1838365

Update

There have been 33 failures within the last 7 days:

  • 6 failures on OS X 10.15 WebRender opt/debug
  • 27 failures on OS X 11 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=426481945&repo=autoland&lineNumber=3755

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: