1608640 - Perma Beta TEST-UNEXPECTED-FAIL | devtools/client/application/test/browser/browser_application_panel_start-service-worker.js | Test timed out - when Gecko merges to Beta on 2020-02-10

Status: VERIFIED FIXED

(DevTools :: Application Panel, defect, P1)

Description

[Alexandru Michis [:malexandru]]

Central as Beta simulation:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=291a9ff0d936e01cac4631a3846283cb97cb40ef&searchStr=windows%2C10%2Cx64%2Casan%2Cmochitests%2Ctest-windows10-64-asan%2Fopt-mochitest-devtools-chrome-e10s-3%2Cm%28dt3%29&group_state=expanded&selectedJob=284538598

Failure log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=284538598&repo=try&lineNumber=1253

[task 2020-01-11T13:36:24.003Z] 13:36:24 INFO - TEST-START | devtools/client/application/test/browser/browser_application_panel_start-service-worker.js
[task 2020-01-11T13:36:24.041Z] 13:36:24 INFO - GECKO(7564) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-01-11T13:36:24.597Z] 13:36:24 INFO - GECKO(7564) | Empty service worker registered
[task 2020-01-11T13:42:24.066Z] 13:42:24 INFO - TEST-INFO | started process screenshot
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - TEST-INFO | screenshot: exit 0
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - Buffered messages logged at 13:36:24
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - Entering test bound
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - Set a low service worker idle timeout
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - Adding a new tab with URL: http://example.com/browser/devtools/client/application/test/browser/resources/service-workers/simple.html
[task 2020-01-11T13:42:24.286Z] 13:42:24 INFO - Tab added and finished loading
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Buffered messages logged at 13:36:25
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome://global/content/elements/panel.js" line: 62}]
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Buffered messages logged at 13:36:26
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Selecting application page: service-workers
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Wait until the registration appears on the window
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Wait until the service worker appears in the application panel
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Wait until the start button is displayed and enabled
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Buffered messages logged at 13:37:54
[task 2020-01-11T13:42:24.287Z] 13:42:24 INFO - Longer timeout required, waiting longer... Remaining timeouts: 3
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Buffered messages logged at 13:39:24
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Longer timeout required, waiting longer... Remaining timeouts: 2
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Buffered messages logged at 13:40:26
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Console message: [JavaScript Error: "getScreenshot(http://example.com/browser/devtools/client/application/test/browser/resources/manifest/load-ok.html) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO -
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Buffered messages logged at 13:40:54
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Longer timeout required, waiting longer... Remaining timeouts: 1
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - Buffered messages finished
[task 2020-01-11T13:42:24.288Z] 13:42:24 INFO - TEST-UNEXPECTED-FAIL | devtools/client/application/test/browser/browser_application_panel_start-service-worker.js | Test timed out -
[task 2020-01-11T13:42:24.482Z] 13:42:24 INFO - Removing tab.
[task 2020-01-11T13:42:24.482Z] 13:42:24 INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2020-01-11T13:42:24.503Z] 13:42:24 INFO - Got event: 'TabClose' on [object XULElement].
[task 2020-01-11T13:42:24.532Z] 13:42:24 INFO - Tab removed and finished closing
[task 2020-01-11T13:42:24.593Z] 13:42:24 INFO - TEST-PASS | devtools/client/application/test/browser/browser_application_panel_start-service-worker.js | The main process DebuggerServer has no pending connection when the test ends -
[task 2020-01-11T13:42:24.662Z] 13:42:24 INFO - GECKO(7564) | MEMORY STAT | vsize 19406312MB | vsizeMaxContiguous 65574919MB | residentFast 1204MB
[task 2020-01-11T13:42:24.662Z] 13:42:24 INFO - TEST-OK | devtools/client/application/test/browser/browser_application_panel_start-service-worker.js | took 360662ms
[task 2020-01-11T13:42:24.721Z] 13:42:24 INFO - checking window state
[task 2020-01-11T13:42:24.759Z] 13:42:24 INFO - TEST-START | devtools/client/application/test/browser/browser_application_panel_target-switching.js

Belén,
Could this be caused by the changes in Bug 1600263?

Comment 1

[Belén [:ladybenko]]

Thanks for the head's up, I'll look into this.

Comment 2

[Julian Descottes [:jdescottes]]

Some interesting things:

• we have a similar aboutdebugging test (browser_aboutdebugging_serviceworker_start.js). This one is not failing at all
• with the requestLongerTimeout, browser_application_panel_start-service-worker.js seems to consistently take 320,000ms (more than 5 minutes!) on windows asan on central
• on this same platform, the aboutdebugging test takes only 6 seconds.
• the application panel has another very similar test: browser_application_panel_disable-start-service-worker.js. And this one runs just fine, in 5-6 seconds on windows asan. The only difference is that for this one the debugger windowless sw pref is set to false. I wondered if the debugger might attach to the serviceworker and therefore prevent the timeout, but we don't seem to start the debugger at any point, so this is unlikely

Maybe having two tests that tweak the SW timeout in the same suite (and which use the same page+sw) makes asan unhappy? Also note that on beta, sw e10s refactor is turned off, so this can be the source of some differences when comparing with central runs.

Comment 3

[Belén [:ladybenko]]

Attachment: Bug 1608640 - disable 'start-service-worker' test on asan and when the sw refactor is not enabled

This patch reverts the requestLongerTimeout change for the failing test (start-service-worker), and disables the test on asan (all platforms) and when the sw refactor is not enabled

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/96122766dc92
disable 'start-service-worker' test on asan and when the sw refactor is not enabled r=jdescottes

Comment 5

[Cristian Brindusan [:cbrindusan]]

https://hg.mozilla.org/mozilla-central/rev/96122766dc92

Comment 6

[Cosmin Sabou [:CosminS]]

Verified "fix" in today's beta-sim: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=success%2Cusercancel%2Ctestfailed%2Cbusted%2Cexception&author=csabou%40mozilla.com&fromchange=912ac9b4ef0418a47fd8b88b80adbce36f9ceb92&searchStr=windows%2C10%2Cx64%2Casan%2Cmochitests%2Ctest-windows10-64-asan%2Fopt-mochitest-devtools-chrome-e10s-3%2Cm%28dt3%29&selectedJob=285017925