Intermittent dom/media/webaudio/test/test_bug1447273.html | Test timed out.

REOPENED
Assigned to

Status

()

defect
P5
normal
REOPENED
Last year
6 days ago

People

(Reporter: intermittent-bug-filer, Assigned: apavel)

Tracking

({intermittent-failure, leave-open})

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [retriggered][stockwell disabled])

Attachments

(1 attachment, 1 obsolete attachment)

Filed by: csabou [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=195301410&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/Tas2gAa1QDqw7utMal2e7Q/runs/0/artifacts/public/logs/live_backing.log

[task 2018-08-22T15:06:42.491Z] 15:06:42     INFO -  102 INFO TEST-UNEXPECTED-FAIL | dom/media/webaudio/test/test_bug1447273.html | Test timed out.
[task 2018-08-22T15:06:42.491Z] 15:06:42     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-08-22T15:06:42.492Z] 15:06:42     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-08-22T15:06:42.493Z] 15:06:42     INFO -  103 INFO TEST-OK | dom/media/webaudio/test/test_bug1447273.html | took 306450ms
[task 2018-08-22T15:06:53.419Z] 15:06:53     INFO -  104 ERROR [SimpleTest.finish()] this test already called finish!
[task 2018-08-22T15:15:30.527Z] 15:15:30     INFO -  150 INFO TEST-START | dom/media/webaudio/test/test_convolverNodeChannelInterpretationChanges.html
[task 2018-08-22T15:24:25.482Z] 15:24:25     INFO -  Buffered messages logged at 15:19:11
[task 2018-08-22T15:24:25.484Z] 15:24:25     INFO -  151 INFO TEST-PASS | dom/media/webaudio/test/test_convolverNodeChannelInterpretationChanges.html | Test up-mixing in ConvolverNode after ChannelInterpretation change - Test up-mixing in ConvolverNode after ChannelInterpretation change: Elided 4 passes or known failures.
[task 2018-08-22T15:24:25.484Z] 15:24:25     INFO -  Buffered messages finished
[task 2018-08-22T15:24:25.485Z] 15:24:25     INFO -  152 INFO TEST-UNEXPECTED-FAIL | dom/media/webaudio/test/test_convolverNodeChannelInterpretationChanges.html | Test timed out. - Test timed out.
Component: Audio/Video → Audio/Video: Playback
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 11 months ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=200433665&repo=mozilla-inbound&lineNumber=1587

[task 2018-09-20T12:02:28.323Z] 12:02:28     INFO -  87 INFO TEST-START | dom/media/webaudio/test/test_bug1447273.html
[task 2018-09-20T12:08:26.165Z] 12:08:26     INFO -  Buffered messages logged at 12:02:32
[task 2018-09-20T12:08:26.168Z] 12:08:26     INFO -  88 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | A valid string reason is expected
[task 2018-09-20T12:08:26.169Z] 12:08:26     INFO -  89 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Reason cannot be empty
[task 2018-09-20T12:08:26.170Z] 12:08:26     INFO -  Buffered messages logged at 12:04:52
[task 2018-09-20T12:08:26.170Z] 12:08:26     INFO -  90 INFO TEST-FAIL | dom/media/webaudio/test/test_bug1447273.html | The author of the test has indicated that flaky timeouts are expected.  Reason: This test uses a live audio context and uses a setTimeout to schedule a change to the graph.
[task 2018-09-20T12:08:26.171Z] 12:08:26     INFO -  Buffered messages logged at 12:05:12
[task 2018-09-20T12:08:26.171Z] 12:08:26     INFO -  91 INFO Gain explicitly set!
[task 2018-09-20T12:08:26.171Z] 12:08:26     INFO -  Buffered messages logged at 12:08:14
[task 2018-09-20T12:08:26.171Z] 12:08:26     INFO -  92 INFO maxNoGainChange: 0.25
[task 2018-09-20T12:08:26.171Z] 12:08:26     INFO -  93 INFO maxExplicitAssignment: 0.5
[task 2018-09-20T12:08:26.172Z] 12:08:26     INFO -  94 INFO maxSetValueAtTime: 0.5
[task 2018-09-20T12:08:26.173Z] 12:08:26     INFO -  95 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Gain should be explicitly assinged during test!
[task 2018-09-20T12:08:26.174Z] 12:08:26     INFO -  Buffered messages logged at 12:08:15
[task 2018-09-20T12:08:26.175Z] 12:08:26     INFO -  96 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Volume should increase due to explicit assignment to gain.value
[task 2018-09-20T12:08:26.175Z] 12:08:26     INFO -  97 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Volume should increase due to setValueAtTime on gain.value
[task 2018-09-20T12:08:26.176Z] 12:08:26     INFO -  Buffered messages finished
[task 2018-09-20T12:08:26.177Z] 12:08:26     INFO -  98 INFO TEST-UNEXPECTED-FAIL | dom/media/webaudio/test/test_bug1447273.html | Test timed out.
[task 2018-09-20T12:08:26.177Z] 12:08:26     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-09-20T12:08:26.178Z] 12:08:26     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-09-20T12:08:26.179Z] 12:08:26     INFO -  99 INFO TEST-OK | dom/media/webaudio/test/test_bug1447273.html | took 354461ms
[task 2018-09-20T12:08:36.997Z] 12:08:36     INFO -  100 ERROR [SimpleTest.finish()] this test already called finish!
[task 2018-09-20T12:08:36.998Z] 12:08:36     INFO -  101 INFO TEST-UNEXPECTED-ERROR | dom/media/webaudio/test/test_bug1447273.html | called finish() multiple times
[task 2018-09-20T12:08:36.998Z] 12:08:36     INFO -  TEST-INFO
[task 2018-09-20T12:08:47.822Z] 12:08:47     INFO -  102 INFO TEST-START | dom/media/webaudio/test/test_bug808374.html
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 11 months ago8 months ago
Resolution: --- → INCOMPLETE
Fail reappeared on autoland.
Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=218237017&repo=autoland&lineNumber=1569

Log snippet:

[task 2018-12-20T23:25:03.702Z] 23:25:03     INFO -  87 INFO TEST-START | dom/media/webaudio/test/test_bug1447273.html
[task 2018-12-20T23:30:36.806Z] 23:30:36     INFO -  Buffered messages logged at 23:24:57
[task 2018-12-20T23:30:36.807Z] 23:30:36     INFO -  88 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | A valid string reason is expected
[task 2018-12-20T23:30:36.807Z] 23:30:36     INFO -  Buffered messages logged at 23:24:58
[task 2018-12-20T23:30:36.809Z] 23:30:36     INFO -  89 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Reason cannot be empty
[task 2018-12-20T23:30:36.810Z] 23:30:36     INFO -  Buffered messages logged at 23:28:44
[task 2018-12-20T23:30:36.810Z] 23:30:36     INFO -  90 INFO TEST-FAIL | dom/media/webaudio/test/test_bug1447273.html | The author of the test has indicated that flaky timeouts are expected.  Reason: This test uses a live audio context and uses a setTimeout to schedule a change to the graph.
[task 2018-12-20T23:30:36.811Z] 23:30:36     INFO -  Buffered messages logged at 23:29:03
[task 2018-12-20T23:30:36.811Z] 23:30:36     INFO -  91 INFO Gain explicitly set!
[task 2018-12-20T23:30:36.811Z] 23:30:36     INFO -  Buffered messages finished
[task 2018-12-20T23:30:36.812Z] 23:30:36     INFO -  92 INFO TEST-UNEXPECTED-FAIL | dom/media/webaudio/test/test_bug1447273.html | Test timed out.
[task 2018-12-20T23:30:36.812Z] 23:30:36     INFO -      SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
[task 2018-12-20T23:30:36.812Z] 23:30:36     INFO -      reportError@SimpleTest/TestRunner.js:121:7
[task 2018-12-20T23:30:36.812Z] 23:30:36     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
[task 2018-12-20T23:30:47.428Z] 23:30:47     INFO -  93 INFO maxNoGainChange: 0.25
[task 2018-12-20T23:30:47.428Z] 23:30:47     INFO -  94 INFO maxExplicitAssignment: 0.25
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  95 INFO maxSetValueAtTime: 0.5
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  96 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Gain should be explicitly assinged during test!
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  97 INFO TEST-UNEXPECTED-FAIL | dom/media/webaudio/test/test_bug1447273.html | Volume should increase due to explicit assignment to gain.value
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -      SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -      source.onended@dom/media/webaudio/test/test_bug1447273.html:136:5
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  98 INFO TEST-PASS | dom/media/webaudio/test/test_bug1447273.html | Volume should increase due to setValueAtTime on gain.value
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  99 ERROR [SimpleTest.finish()] this test already called finish!
[task 2018-12-20T23:30:47.429Z] 23:30:47     INFO -  100 INFO TEST-UNEXPECTED-ERROR | dom/media/webaudio/test/test_bug1447273.html | called finish() multiple times
[task 2018-12-20T23:30:47.430Z] 23:30:47     INFO -  TEST-INFO took 346902ms
[task 2018-12-20T23:30:47.431Z] 23:30:47     INFO -  101 INFO TEST-OK | dom/media/webaudio/test/test_bug1447273.html
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
(In reply to Narcis Beleuzu [:NarcisB] from comment #10)
> There are 32 failures in the last 3 days.
> All of them on android-em-4-3-armv7-api16 , debug.
> 
> I did some retriggers and it started from
> https://hg.mozilla.org/integration/autoland/rev/
> dca16fc55e60d74323807411fb441b4a6c60c97c
> 
> Retrigs:
> https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=android%2C4.
> 3%2Capi16%2B%2Cdebug%2Cmochitests%2Ctest-android-em-4.3-arm7-api-16%2Fdebug-
> mochitest-media-
> 2%2Cm%28mda2%29&tochange=28c8818e06b81f0ee302a6fec2582902bfaa1741&fromchange=
> 69899db5ee27f613e28a68af03f4e97d8693841e
> 
> Mike, could you please take a look?

That changeset only has a configure-time effect on Windows. It shouldn't even have a build time effect on Windows, and even less on android tests.
Flags: needinfo?(mh+mozilla)
Well, there is no way to explain how a Windows build-time change can do anything to an android test.
Actually, that just emphasizes the fact that it started on your push. The mda failures up to your push are a different bug, Bug 1454929.
In the last 7 days there have been 50 occurrences on Android 4.3 Debug.
Assignee: nobody → apavel
Attachment #9034307 - Flags: review?(jmaher)
Comment on attachment 9034307 [details] [diff] [review]
test disabled on android debug

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

::: dom/media/webaudio/test/mochitest.ini
@@ +108,4 @@
>  [test_bug1267579.html]
>  [test_bug1355798.html]
>  [test_bug1447273.html]
> +skip-if = android && debug # bug 1485407

android needs to be:
toolkit == 'android'
Attachment #9034307 - Flags: review?(jmaher) → review-
Joel, please take a look.
Attachment #9034540 - Flags: review?(jmaher)
Attachment #9034307 - Attachment is obsolete: true
Attachment #9034540 - Flags: review?(jmaher) → review+
Whiteboard: [retriggered] → [retriggered][stockwell disabled]
Pushed by rmaries@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ab4bb599096c
test disabled on android debug r=jmaher
Keywords: checkin-needed
You need to log in before you can comment on or make changes to this bug.