Closed Bug 1523454 Opened 8 months ago Closed 7 months ago

Perma devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | leaked 2 window(s) until shutdown [url = about:debugging] after timeout

Categories

(DevTools :: about:debugging, defect, P5)

defect

Tracking

(firefox67 fixed)

RESOLVED FIXED
Firefox 67
Tracking Status
firefox67 --- fixed

People

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

References

Details

(Keywords: intermittent-failure)

Attachments

(3 files)

#[markdown(off)]
Filed by: rmaries [at] mozilla.com

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

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

[task 2019-01-28T22:57:58.069Z] 22:57:58 INFO - TEST-START | Shutdown
[task 2019-01-28T22:57:58.070Z] 22:57:58 INFO - Browser Chrome Test Summary
[task 2019-01-28T22:57:58.071Z] 22:57:58 INFO - Passed: 251
[task 2019-01-28T22:57:58.071Z] 22:57:58 INFO - Failed: 1
[task 2019-01-28T22:57:58.072Z] 22:57:58 INFO - Todo: 0
[task 2019-01-28T22:57:58.073Z] 22:57:58 INFO - Mode: e10s
[task 2019-01-28T22:57:58.073Z] 22:57:58 INFO - *** End BrowserChrome Test Results ***

[task 2019-01-28T22:58:10.333Z] 22:58:10 INFO - GECKO(1084) | => Process ID: 1084, Thread ID: 139876985521984
[task 2019-01-28T22:58:10.391Z] 22:58:10 INFO - TEST-INFO | Main app process: exit 0
[task 2019-01-28T22:58:10.392Z] 22:58:10 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | leaked 2 window(s) until shutdown [url = about:debugging]
[task 2019-01-28T22:58:10.394Z] 22:58:10 INFO - TEST-INFO | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | windows(s) leaked: [pid = 1084] [serial = 246], [pid = 1084] [serial = 248]
[task 2019-01-28T22:58:10.395Z] 22:58:10 ERROR - TEST-UNEXPECTED-FAIL | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | leaked 1 docShell(s) until shutdown
[task 2019-01-28T22:58:10.397Z] 22:58:10 INFO - TEST-INFO | devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | docShell(s) leaked: [pid = 1084] [id = {a49839d2-f346-47a7-841e-0c374d8a2b3e}]
[task 2019-01-28T22:58:10.398Z] 22:58:10 INFO - runtests.py | Application ran for: 0:17:45.093815
[task 2019-01-28T22:58:10.400Z] 22:58:10 INFO - zombiecheck | Reading PID log: /tmp/tmpST848rpidlog
[task 2019-01-28T22:58:10.401Z] 22:58:10 INFO - ==> process 1084 launched child process 1114
[task 2019-01-28T22:58:10.402Z] 22:58:10 INFO - ==> process 1084 launched child process 1176
[task 2019-01-28T22:58:10.408Z] 22:58:10 INFO - ==> process 1084 launched child process 1195
[task 2019-01-28T22:58:10.409Z] 22:58:10 INFO - ==> process 1084 launched child process 1251
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1279
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1310
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1332 launched child process 1351
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1332 launched child process 1404
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1332 launched child process 1439
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1489
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1510
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1523
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1542
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1566
[task 2019-01-28T22:58:10.418Z] 22:58:10 INFO - ==> process 1084 launched child process 1594
[task 2019-01-28T22:58:10.420Z] 22:58:10 INFO - ==> process 1084 launched child process 1624
[task 2019-01-28T22:58:10.421Z] 22:58:10 INFO - ==> process 1084 launched child process 1686
[task 2019-01-28T22:58:10.421Z] 22:58:10 INFO - ==> process 1084 launched child process 1714
[task 2019-01-28T22:58:10.422Z] 22:58:10 INFO - ==> process 1084 launched child process 1742
[task 2019-01-28T22:58:10.423Z] 22:58:10 INFO - ==> process 1084 launched child process 1769
[task 2019-01-28T22:58:10.423Z] 22:58:10 INFO - ==> process 1084 launched child process 1799
[task 2019-01-28T22:58:10.424Z] 22:58:10 INFO - ==> process 1084 launched child process 1837
[task 2019-01-28T22:58:10.424Z] 22:58:10 INFO - ==> process 1084 launched child process 1862
[task 2019-01-28T22:58:10.424Z] 22:58:10 INFO - ==> process 1084 launched child process 1881
[task 2019-01-28T22:58:10.425Z] 22:58:10 INFO - ==> process 1084 launched child process 1900
[task 2019-01-28T22:58:10.426Z] 22:58:10 INFO - ==> process 1084 launched child process 1920
[task 2019-01-28T22:58:10.427Z] 22:58:10 INFO - ==> process 1084 launched child process 1939
[task 2019-01-28T22:58:10.427Z] 22:58:10 INFO - ==> process 1084 launched child process 1958
[task 2019-01-28T22:58:10.427Z] 22:58:10 INFO - ==> process 1084 launched child process 1977
[task 2019-01-28T22:58:10.428Z] 22:58:10 INFO - ==> process 1084 launched child process 1997
[task 2019-01-28T22:58:10.428Z] 22:58:10 INFO - ==> process 1084 launched child process 2009
[task 2019-01-28T22:58:10.429Z] 22:58:10 INFO - ==> process 1084 launched child process 2014
[task 2019-01-28T22:58:10.430Z] 22:58:10 INFO - ==> process 1084 launched child process 2022
[task 2019-01-28T22:58:10.430Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1920
[task 2019-01-28T22:58:10.431Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1542
[task 2019-01-28T22:58:10.432Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1799
[task 2019-01-28T22:58:10.433Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1939
[task 2019-01-28T22:58:10.434Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1686
[task 2019-01-28T22:58:10.434Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 2009
[task 2019-01-28T22:58:10.435Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1176
[task 2019-01-28T22:58:10.441Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1566
[task 2019-01-28T22:58:10.442Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1439
[task 2019-01-28T22:58:10.443Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1958
[task 2019-01-28T22:58:10.443Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1195
[task 2019-01-28T22:58:10.444Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1837
[task 2019-01-28T22:58:10.445Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1714
[task 2019-01-28T22:58:10.446Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1310
[task 2019-01-28T22:58:10.447Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1977
[task 2019-01-28T22:58:10.448Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1594
[task 2019-01-28T22:58:10.449Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1862
[task 2019-01-28T22:58:10.450Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1351
[task 2019-01-28T22:58:10.450Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1997
[task 2019-01-28T22:58:10.451Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1742
[task 2019-01-28T22:58:10.451Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1489
[task 2019-01-28T22:58:10.452Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1624
[task 2019-01-28T22:58:10.453Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1881
[task 2019-01-28T22:58:10.454Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1114
[task 2019-01-28T22:58:10.455Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 2014
[task 2019-01-28T22:58:10.455Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1251
[task 2019-01-28T22:58:10.457Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 2022
[task 2019-01-28T22:58:10.457Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1510
[task 2019-01-28T22:58:10.458Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1769
[task 2019-01-28T22:58:10.459Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1900
[task 2019-01-28T22:58:10.460Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1523
[task 2019-01-28T22:58:10.461Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1404
[task 2019-01-28T22:58:10.461Z] 22:58:10 INFO - zombiecheck | Checking for orphan process with PID: 1279
[task 2019-01-28T22:58:10.461Z] 22:58:10 INFO - Stopping web server
[task 2019-01-28T22:58:10.471Z] 22:58:10 INFO - Stopping web socket server
[task 2019-01-28T22:58:10.492Z] 22:58:10 INFO - Stopping ssltunnel
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - leakcheck | Processing log file /tmp/tmp5gnlsQ.mozrunner/runtests_leaks.log
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.515Z] 22:58:10 INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 400 bytes
[task 2019-01-28T22:58:10.516Z] 22:58:10 INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.517Z] 22:58:10 INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2019-01-28T22:58:10.518Z] 22:58:10 INFO - leakcheck | Processing leak log file /tmp/tmp5gnlsQ.mozrunner/runtests_leaks_tab_pid1310.log
[task 2019-01-28T22:58:10.520Z] 22:58:10 INFO -
[task 2019-01-28T22:58:10.520Z] 22:58:10 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1310
[task 2019-01-28T22:58:10.521Z] 22:58:10 INFO -
[task 2019-01-28T22:58:10.522Z] 22:58:10 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2019-01-28T22:58:10.523Z] 22:58:10 INFO - | | Per-Inst Leaked| Total Rem|
[task 2019-01-28T22:58:10.524Z] 22:58:10 INFO - 0 |TOTAL | 39 0| 137198 0|
[task 2019-01-28T22:58:10.529Z] 22:58:10 INFO -
[task 2019-01-28T22:58:10.530Z] 22:58:10 INFO - nsTraceRefcnt::DumpStatistics: 790 entries
[task 2019-01-28T22:58:10.531Z] 22:58:10 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2019-01-28T22:58:10.532Z] 22:58:10 INFO - leakcheck | Processing leak log file /tmp/tmp5gnlsQ.mozrunner/runtests_leaks_tab_pid1769.log
[task 2019-01-28T22:58:10.533Z] 22:58:10 INFO -

Blocks: 1504173

The logic in devtools for detecting the "registering" status of a service worker was relying on the limitations of the previous service worker platform implementation. Consequently the refactor "breaks" the devtools test that checks for service worker status.

We can either disable the test for the refactor (skip-if = serviceworker_e10s) or we can try fixing it.

Assignee: nobody → jdescottes
Status: NEW → ASSIGNED

This will fix the test browser_aboutdebugging_serviceworker_status.js when running with dom.serviceWorkers.parent_intercept=true

Depends on D18365.

Not mandatory, but relying on the computed state seems better than duplicating the logic around isActive/isRunning.

Summary: Intermittent devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | leaked 2 window(s) until shutdown [url = about:debugging] → Perma devtools/client/aboutdebugging-new/test/browser/browser_aboutdebugging_serviceworker_status.js | leaked 2 window(s) until shutdown [url = about:debugging] after timeout
Attachment #9040761 - Attachment description: Bug 1523454 - Fix service worker active status for sw refactor;r=ladybenko → Bug 1523454 - Fix service worker active status for sw refactor;r=daisuke
Attachment #9040762 - Attachment description: Bug 1523454 - Remove isActive and isRunning from worker details;r=ladybenko → Bug 1523454 - Remove isActive and isRunning from worker details;r=daisuke

Andrew, a question about how to detect if we are using the sw refactor or not. You can read the review and discussion at https://phabricator.services.mozilla.com/D18365#inline-100033

We are reading the preference dom.serviceWorkers.parent_intercept to know if the refactor is on or not. The concern is that if the preference is flipped by the user after starting the browser, we might read an incorrect value and won't really know the state. Do we have an alternate way of checking if the browser is currently running with the refactor, or should we assume users will not flip the preference?

Flags: needinfo?(bugmail)

We can expose the value of ServiceWorkerParentInterceptEnabled() on nsIServiceWorkerManager if that helps. It would only be okay to check in the parent process, however. Does that sound good? I'll file a spin-off and put a patch up if it does.

Flags: needinfo?(bugmail) → needinfo?(jdescottes)

Yes that sounds good, thanks Andrew!
It won't work with the approach used in my current patch, but I can move part of the logic to the parent process.

Flags: needinfo?(jdescottes)

Let us know when the other bug has been created.
I think I will skip-if = serviceworker_e10s the test in the meantime to avoid the "intermittent" failures.

Flags: needinfo?(bugmail)

Feel free to cancel the review if you already have a patch or if you wanted another approach.
Mostly wrote this patch to make sure the DevTools patch on top of it would work.

Your most excellent patch accomplishes the goal nicely, thank you! (No need for a separate bug for that now!)

Flags: needinfo?(bugmail)
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0dca936d2e9e
Expose isParentInterceptEnabled in nsIServiceWorkerManager;r=asuth
https://hg.mozilla.org/integration/autoland/rev/1d79453b1f68
Fix service worker active status for sw refactor;r=daisuke
https://hg.mozilla.org/integration/autoland/rev/1a88323932cb
Remove isActive and isRunning from worker details;r=daisuke
Status: ASSIGNED → RESOLVED
Closed: 7 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 67
You need to log in before you can comment on or make changes to this bug.