Aside from the linting failure, it looks like my changes are causing persistent failures of `test_getUserMedia_basicAudio_loopback` and other media tests, but only ever for `opt` builds: ``` [task 2020-05-13T23:20:07.504Z] 23:20:07 INFO - TEST-START | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html [task 2020-05-13T23:20:07.593Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2020-05-13T23:20:07.594Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2020-05-13T23:20:07.691Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2020-05-13T23:20:07.692Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2020-05-13T23:20:07.816Z] 23:20:07 INFO - GECKO(3916) | [Parent 3916, Main Thread] WARNING: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp, line 135 [task 2020-05-13T23:20:07.816Z] 23:20:07 INFO - GECKO(3916) | (firefox:3916): Gtk-CRITICAL **: 23:20:07.813: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed [task 2020-05-13T23:20:07.852Z] 23:20:07 INFO - GECKO(3916) | [Parent 3916, Main Thread] WARNING: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp, line 135 [task 2020-05-13T23:20:07.853Z] 23:20:07 INFO - GECKO(3916) | (firefox:3916): Gtk-CRITICAL **: 23:20:07.846: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed [task 2020-05-13T23:21:07.839Z] 23:21:07 INFO - TEST-INFO | started process screentopng [task 2020-05-13T23:21:08.487Z] 23:21:08 INFO - TEST-INFO | screentopng: exit 0 [task 2020-05-13T23:21:08.488Z] 23:21:08 INFO - <snipped 834 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test> [task 2020-05-13T23:21:08.489Z] 23:21:08 INFO - Buffered messages logged at 23:21:01 [task 2020-05-13T23:21:08.490Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.491Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.492Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.493Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.494Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.495Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.497Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.497Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.499Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.500Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.500Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.502Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.502Z] 23:21:08 INFO - Buffered messages logged at 23:21:02 [task 2020-05-13T23:21:08.503Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.504Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.504Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.508Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.510Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.511Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.511Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.512Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.512Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.514Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.515Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.515Z] 23:21:08 INFO - Buffered messages logged at 23:21:03 [task 2020-05-13T23:21:08.516Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.516Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.517Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.517Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.518Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.518Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.519Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.520Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.522Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.522Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.523Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.524Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.530Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.531Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Buffered messages logged at 23:21:04 [task 2020-05-13T23:21:08.533Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.534Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.534Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.535Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.536Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.537Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.537Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.538Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.538Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.539Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Buffered messages logged at 23:21:05 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.542Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.542Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.544Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.544Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.546Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.546Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.556Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.557Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.557Z] 23:21:08 INFO - Buffered messages logged at 23:21:06 [task 2020-05-13T23:21:08.558Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Buffered messages logged at 23:21:07 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Buffered messages finished [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html | Error executing test: Error: Audio analysis timed out waitForAnalysisSuccess@https://example.com/tests/dom/media/tests/mochitest/head.js:203:26 ... @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:34:20 ... async*runTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:497:30 ... promise callback*runTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:497:6 ... @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:43 ... promise callback*@https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:16 ... [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:299:16 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - runTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:499:9 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - promise callback*runTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:498:6 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:43 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - promise callback*@https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:16 [task 2020-05-13T23:21:08.567Z] 23:21:08 ERROR - [SimpleTest.finish()] this test already called finish! [task 2020-05-13T23:21:08.567Z] 23:21:08 INFO - GECKO(3916) | MEMORY STAT | vsize 2727MB | residentFast 157MB | heapAllocated 16MB [task 2020-05-13T23:21:08.567Z] 23:21:08 INFO - TEST-UNEXPECTED-ERROR | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html | called finish() multiple times [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-INFO took 60337ms [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-OK | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-START | dom/media/tests/mochitest/test_getUserMedia_basicScreenshare.html ``` try push: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=superseded%2Cusercancel%2Cretry%2Cpending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=b9f005f1044d2bb1ce78c52142677465b490e5b7 I'd like some feedback on why this is the case. What would cause a test that would otherwise pass on `debug` builds to fail on `opt`, and specifically only webrender?
Bug 1633101 Comment 37 Edit History
Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.
Aside from the linting failure, it looks like my changes are causing persistent failures of `test_getUserMedia_basicAudio_loopback` and other media tests, but only ever for `opt` builds: ``` [task 2020-05-13T23:20:07.504Z] 23:20:07 INFO - TEST-START | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html [task 2020-05-13T23:20:07.593Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2020-05-13T23:20:07.594Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2020-05-13T23:20:07.691Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2020-05-13T23:20:07.692Z] 23:20:07 INFO - GECKO(3916) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2020-05-13T23:20:07.816Z] 23:20:07 INFO - GECKO(3916) | [Parent 3916, Main Thread] WARNING: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp, line 135 [task 2020-05-13T23:20:07.816Z] 23:20:07 INFO - GECKO(3916) | (firefox:3916): Gtk-CRITICAL **: 23:20:07.813: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed [task 2020-05-13T23:20:07.852Z] 23:20:07 INFO - GECKO(3916) | [Parent 3916, Main Thread] WARNING: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed: 'glib warning', file /builds/worker/checkouts/gecko/toolkit/xre/nsSigHandlers.cpp, line 135 [task 2020-05-13T23:20:07.853Z] 23:20:07 INFO - GECKO(3916) | (firefox:3916): Gtk-CRITICAL **: 23:20:07.846: gtk_widget_get_window: assertion 'GTK_IS_WIDGET (widget)' failed [task 2020-05-13T23:21:07.839Z] 23:21:07 INFO - TEST-INFO | started process screentopng [task 2020-05-13T23:21:08.487Z] 23:21:08 INFO - TEST-INFO | screentopng: exit 0 [task 2020-05-13T23:21:08.488Z] 23:21:08 INFO - <snipped 834 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test> [task 2020-05-13T23:21:08.489Z] 23:21:08 INFO - Buffered messages logged at 23:21:01 [task 2020-05-13T23:21:08.490Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.491Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.492Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.493Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.494Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.495Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.497Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.497Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.499Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.500Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.500Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.502Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.502Z] 23:21:08 INFO - Buffered messages logged at 23:21:02 [task 2020-05-13T23:21:08.503Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.504Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.504Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.508Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.509Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.510Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.511Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.511Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.512Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.512Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.514Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.515Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.515Z] 23:21:08 INFO - Buffered messages logged at 23:21:03 [task 2020-05-13T23:21:08.516Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.516Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.517Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.517Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.518Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.518Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.519Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.520Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.522Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.522Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.523Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.524Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.530Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.531Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.532Z] 23:21:08 INFO - Buffered messages logged at 23:21:04 [task 2020-05-13T23:21:08.533Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.534Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.534Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.535Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.536Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.537Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.537Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.538Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.538Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.539Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.540Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Buffered messages logged at 23:21:05 [task 2020-05-13T23:21:08.541Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.542Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.542Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.544Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.544Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.546Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.546Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.547Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.548Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.556Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.557Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.557Z] 23:21:08 INFO - Buffered messages logged at 23:21:06 [task 2020-05-13T23:21:08.558Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.559Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.560Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.561Z] 23:21:08 INFO - Buffered messages logged at 23:21:07 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.562Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.563Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.564Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Analysing audio frequency - low:target:high = 0:0:0 [task 2020-05-13T23:21:08.565Z] 23:21:08 INFO - Buffered messages finished [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html | Error executing test: Error: Audio analysis timed out waitForAnalysisSuccess@https://example.com/tests/dom/media/tests/mochitest/head.js:203:26 ... @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:34:20 ... async*runTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:497:30 ... promise callback*runTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:497:6 ... @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:43 ... promise callback*@https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:16 ... [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:299:16 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - runTestWhenReady/<@https://example.com/tests/dom/media/tests/mochitest/head.js:499:9 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - promise callback*runTestWhenReady@https://example.com/tests/dom/media/tests/mochitest/head.js:498:6 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - @https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:43 [task 2020-05-13T23:21:08.566Z] 23:21:08 INFO - promise callback*@https://example.com/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html:18:16 [task 2020-05-13T23:21:08.567Z] 23:21:08 ERROR - [SimpleTest.finish()] this test already called finish! [task 2020-05-13T23:21:08.567Z] 23:21:08 INFO - GECKO(3916) | MEMORY STAT | vsize 2727MB | residentFast 157MB | heapAllocated 16MB [task 2020-05-13T23:21:08.567Z] 23:21:08 INFO - TEST-UNEXPECTED-ERROR | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html | called finish() multiple times [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-INFO took 60337ms [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-OK | dom/media/tests/mochitest/test_getUserMedia_basicAudio_loopback.html [task 2020-05-13T23:21:08.568Z] 23:21:08 INFO - TEST-START | dom/media/tests/mochitest/test_getUserMedia_basicScreenshare.html ``` try push: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=superseded%2Cusercancel%2Cretry%2Cpending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=b9f005f1044d2bb1ce78c52142677465b490e5b7 :drno - why this is the case? What would cause a test that would otherwise pass on `debug` builds to fail on `opt`, and specifically only webrender?