1840914 - High frequency [tier 2] wmfme dom/media/test/< test> | Test timed out!

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

Filed by: sstanca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=420956555&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/a8C1eWu0TCytxEh1hMNQTA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2023-06-28T17:36:55.412Z] 17:36:55     INFO - TEST-PASS | dom/media/test/test_buffered.html | [finished bug482461-theora.ogv-12 t=1.587] Length of array should match number of running tests 
[task 2023-06-28T17:36:55.412Z] 17:36:55     INFO - Buffered messages finished
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_buffered.html | Test timed out! 
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:424:16
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     onTimeout@dom/media/test/manifest.js:2380:9
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:2387:57
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     startTest@dom/media/test/test_buffered.html:106:11
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2433:12
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     testBuffered@dom/media/test/test_buffered.html:69:11
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     EventListener.handleEvent*onfetched@dom/media/test/test_buffered.html:102:7
[task 2023-06-28T17:36:55.414Z] 17:36:55     INFO -     loaded@dom/media/test/test_buffered.html:82:23
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     EventListener.handleEvent*fetch@dom/media/test/test_buffered.html:88:7
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     startTest@dom/media/test/test_buffered.html:107:8
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2433:12
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     testBuffered@dom/media/test/test_buffered.html:69:11
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     EventListener.handleEvent*onfetched@dom/media/test/test_buffered.html:102:7
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     loaded@dom/media/test/test_buffered.html:82:23
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     EventListener.handleEvent*fetch@dom/media/test/test_buffered.html:88:7
[task 2023-06-28T17:36:55.415Z] 17:36:55     INFO -     startTest@dom/media/test/test_buffered.html:107:8
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2433:12
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     testBuffered@dom/media/test/test_buffered.html:69:11
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     EventListener.handleEvent*onfetched@dom/media/test/test_buffered.html:102:7
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     loaded@dom/media/test/test_buffered.html:82:23
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     EventListener.handleEvent*fetch@dom/media/test/test_buffered.html:88:7
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     startTest@dom/media/test/test_buffered.html:107:8
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2461:12
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     MediaTestManager/this.runTests/<@dom/media/test/manifest.js:2356:12
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     Async*MediaTestManager/this.runTests@dom/media/test/manifest.js:2355:19
[task 2023-06-28T17:36:55.416Z] 17:36:55     INFO -     @dom/media/test/test_buffered.html:112:9
[task 2023-06-28T17:36:55.417Z] 17:36:55     INFO - split.webm-7 timed out!
[task 2023-06-28T17:36:55.419Z] 17:36:55     INFO - [finished split.webm-7] remaining= 
[task 2023-06-28T17:36:55.419Z] 17:36:55     INFO - TEST-PASS | dom/media/test/test_buffered.html | [finished split.webm-7 t=180.611] Length of array should match number of running tests 
[task 2023-06-28T17:36:55.421Z] 17:36:55     INFO - Finished at Wed Jun 28 2023 17:36:55 GMT+0000 (Coordinated Universal Time) (1687973815.306s)
[task 2023-06-28T17:36:55.422Z] 17:36:55     INFO - Running time: 180.668s
[task 2023-06-28T17:36:55.422Z] 17:36:55     INFO - GECKO(3288) | MEMORY STAT | vsize 2103990MB | vsizeMaxContiguous 67850303MB | residentFast 124MB | heapAllocated 10MB
[task 2023-06-28T17:36:55.423Z] 17:36:55     INFO - TEST-OK | dom/media/test/test_buffered.html | took 180776ms

Comment 1

[Serban Stanca [:SerbanS]]

Hello Karl! This seems to be frequent after your latest changes reached Central, as it can be seen here. Could you please take a look at this?

PS There are several lines of failure :
TEST-UNEXPECTED-FAIL | dom/media/test/test_load_candidates.html | Test timed out!
TEST-UNEXPECTED-FAIL | dom/media/test/test_reset_src.html | Test timed out!
TEST-UNEXPECTED-FAIL | dom/media/test/test_arraybuffer.html | Test timed out!
TEST-UNEXPECTED-FAIL | dom/media/test/test_buffered.html | Test timed out!

Thank you!

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1829068

Comment 3

[Karl Tomlinson (:karlt)]

https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=test-windows11-64-2009-ccov-qr%2Fopt-mochitest-media-wmfme%2Cmda&tochange=278111760071e7020784fe662a6744d18488698d&fromchange=9f3ca0bd481197e41a684d17dfbf91b132c29596&selectedTaskRun=Y3_Hc-n0RnmdXPiQ98m7LQ.0

Comment 4

[BugBot [:suhaib / :marco/ :calixte]]

:alwu, since you are the author of the regressor, bug 1839938, could you take a look?

For more information, please visit BugBot documentation.

Comment 5

[Intermittent Failures Robot]

15 failures in 815 pushes (0.018 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 11
• autoland: 4

Platform and build breakdown:

• windows11-64-2009-ccov-qr: 9
  • opt: 9
• windows11-64-2009-qr: 3
  • opt: 2
  • debug: 1
• windows11-64-2009-asan-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1840914&startday=2023-06-28&endday=2023-06-28&tree=all

Comment 6

[Intermittent Failures Robot]

27 failures in 3594 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 19
• autoland: 8

Platform and build breakdown:

• windows11-64-2009-ccov-qr: 11
  • opt: 11
• windows11-64-2009-qr: 8
  • opt: 4
  • debug: 4
• windows11-64-2009-asan-qr: 6
  • opt: 6
• windows11-64-2009-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1840914&startday=2023-06-26&endday=2023-07-02&tree=all

Comment 7

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1839938

Comment 8

[Alastor Wu [:alwu]]

Still debugging this one, but didn't understand why bug1839938 can cause these regression...

Comment 9

[Intermittent Failures Robot]

21 failures in 590 pushes (0.036 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 8
• autoland: 13

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 7
  • opt: 7
• windows11-64-2009-qr: 8
  • debug: 5
  • opt: 3
• windows11-64-2009-asan-qr: 4
  • opt: 4
• windows11-64-2009-ccov-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1840914&startday=2023-07-05&endday=2023-07-05&tree=all

Comment 10

[Alastor Wu [:alwu]]

I found that sometime the media engine couldn't create dcomp surface handle successfully. I've tried to add a retry mechanism, but once that issue appears, all function calls to create the dcomp handle would fail as well. That might be caused by limited resources controlled by DXVA/media engine or other window frameworks, so when we run tests too frequently and parallelly, there won't be enough resource to create the handle.

The workaround I found is to disable the parallel test for media engine test, which seems help for the media engine (or whatever controls the resource) to properly release the old resource so that we can always create the handle successfully.

Comment 11

[Cristina Horotan [:chorotan]]

There have been 33 total failures](https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2023-07-01&endday=2023-07-08&tree=trunk&bug=1840914) in the last 7 days.
There are:

• 6 failures on windows11-64-2009-asan-qr opt
• 3 failures on windows11-64-2009-ccov-qr opt
• 14 failures n windows11-64-2009-qr opt and debug
• 10 failures on windows11-64-2009-shippable-qr opt

Recent failure log.

Comment 12

[Intermittent Failures Robot]

36 failures in 2956 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 11
• autoland: 25

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 10
  • opt: 10
• windows11-64-2009-qr: 13
  • debug: 7
  • opt: 6
• windows11-64-2009-asan-qr: 11
  • opt: 11
• windows11-64-2009-ccov-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1840914&startday=2023-07-03&endday=2023-07-09&tree=all

Comment 13

[Alastor Wu [:alwu]]

Attachment: Bug 1840914 - part1 : add log and marker to capture the failure of updating video size.

Comment 14

[Alastor Wu [:alwu]]

Attachment: Bug 1840914 - part2 : disable parallel test for media engine tests.

The intermittent failure is due to the media engine couldn't create a
dcomp surface handle sucessfully.

The error didn't show much information to us, and one possible reason is
that running too much test parallelly consumes hardware resources very
fast so that there won't be enough resource to create a new dcomp
handle.

I've tried to call GetVideoSwapchainHandle() later multiple times if
we fail to create the handle at the first try. However, it didn't work.
Once we got that error, all following calls for
GetVideoSwapchainHandle() would be error as well.

This seems the media engine internal issue, which we couldn't solve in
our end. Therefore, we workaround this problem by disabling the parallel
test when running the media engine tests.

Depends on D183182

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/cb5af72a426a
part1 : add log and marker to capture the failure of updating video size. r=media-playback-reviewers,chunmin
https://hg.mozilla.org/integration/autoland/rev/1c909f267af6
part2 : disable parallel test for media engine tests. r=media-playback-reviewers,chunmin

Comment 16

[Cosmin Sabou [:CosminS]]

Backed out for causing gpu failures.

Push with failures: https://treeherder.mozilla.org/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel&revision=1c909f267af625b4c370b6735113e1cafc94bbad&selectedTaskRun=LV7f7x3dQG-KcOqMIYxX6g.0

Failure log:

• https://treeherder.mozilla.org/logviewer?job_id=422164719&repo=autoland
• https://treeherder.mozilla.org/logviewer?job_id=422165226&repo=autoland

Backout link: https://hg.mozilla.org/integration/autoland/rev/c1d366824c2e549c4ee43f30c1da386287b6c070

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/79d3f546d9fc
part1 : add log and marker to capture the failure of updating video size. r=media-playback-reviewers,chunmin
https://hg.mozilla.org/integration/autoland/rev/1098fbc31aff
part2 : disable parallel test for media engine tests. r=media-playback-reviewers,chunmin

Comment 18

[Iulian Moraru]

https://hg.mozilla.org/mozilla-central/rev/79d3f546d9fc
https://hg.mozilla.org/mozilla-central/rev/1098fbc31aff

Comment 19

[BugBot [:suhaib / :marco/ :calixte]]

The patch landed in nightly and beta is affected.
:alwu, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox116 to wontfix.

For more information, please visit BugBot documentation.

Comment 20

[Intermittent Failures Robot]

15 failures in 3309 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• mozilla-central: 6

Platform and build breakdown:

• windows11-64-2009-shippable-qr: 4
  • opt: 4
• windows11-64-2009-qr: 6
  • opt: 3
  • debug: 3
• windows11-64-2009-asan-qr: 4
  • opt: 4
• windows11-64-2009-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1840914&startday=2023-07-10&endday=2023-07-16&tree=all