Open Bug 1198168 Opened 5 years ago Updated 2 days ago

Intermittent dom/media/test/test_bug1113600.html | Test timed out

Categories

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

Product:
Core
Component:
Audio/Video: MediaStreamGraph
Platform:
x86_64
Windows 10
Type:
defect

Tracking

()

Status:
ASSIGNED
Tracking Flags:
Tracking Status
firefox43 --- affected

People

(Reporter: nigelb, Assigned: pehrsons)

References

(Depends on 1 open bug, Regression,
URL
)

Details

(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [retriggered][stockwell fixed:patch])

Attachments

(3 files)

Bug 1198168 - Skip the test on video 320x240.ogv. .
58 bytes, text/x-review-board-request
pehrsons
: review-
Details
Bug 1198168 - add debugging logs.
58 bytes, text/x-review-board-request
kaku
: review+
Details
Bug 1198168 - Since we're now checking the end time of the last chunk, make it inclusive. r?padenot
47 bytes, text/x-phabricator-request
Details | Review 
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)
You need to log in before you can comment on or make changes to this bug.