1311422 - devtools leaks compartments in nightly 52

Status: RESOLVED WORKSFORME

(DevTools :: General, defect, P2)

Description

[Ben Kelly [:bkelly, not reviewing]]

Attachment: memory-report.json.gz

The last few days I've noticed my nightly using large amounts of memory.  This slows the entire browser down due to large GC pauses.

The attached memory report is from a nightly 52.0a1 (2016-10-18) (64-bit).  Here I have shutdown all tabs except an example.com tab to keep the content process alive.  You can see that js-nonwindow is taking a ton of memory in the content process:

1,096.15 MB (100.0%) -- explicit
├────674.16 MB (61.50%) -- js-non-window
│    ├──630.78 MB (57.55%) -- zones
│    │  ├──625.20 MB (57.04%) -- zone(0x25a3b2c3000)
│    │  │  ├──262.06 MB (23.91%) ++ compartment([System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:283))
│    │  │  ├──107.68 MB (09.82%) ++ shapes
│    │  │  ├───81.86 MB (07.47%) ++ compartment([System Principal], resource://gre/modules/commonjs/toolkit/loader.js)
│    │  │  ├───66.57 MB (06.07%) ++ scopes
│    │  │  ├───44.73 MB (04.08%) ++ (139 tiny)
│    │  │  ├───30.39 MB (02.77%) ── type-pool
│    │  │  ├───19.25 MB (01.76%) ++ object-groups
│    │  │  └───12.65 MB (01.15%) ++ compartment([System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:185))
│    │  └────5.58 MB (00.51%) ++ (3 tiny)
│    ├───30.77 MB (02.81%) ++ runtime
│    └───12.61 MB (01.15%) ++ gc-heap
├────312.10 MB (28.47%) -- heap-overhead
│    ├──289.48 MB (26.41%) ── bin-unused
│    ├───21.72 MB (01.98%) ── bookkeeping
│    └────0.90 MB (00.08%) ── page-cache
├─────98.63 MB (09.00%) ── heap-unclassified
└─────11.26 MB (01.03%) ++ (17 tiny)

This seems to be because there a ton of devtools compartments lying around:

1,865 (100.0%) -- js-main-runtime-compartments
├──1,861 (99.79%) -- system
│  ├────430 (23.06%) ── [System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:283) [430]
│  ├────429 (23.00%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:185) [429]
│  ├────429 (23.00%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:209) [429]
│  ├────429 (23.00%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:24) [429]
│  └────144 (07.72%) ++ (130 tiny)
└──────4 (00.21%) ++ user

I've noticed that I can reliably cause these compartments to grow by doing the following:

1) Open about:debugging on the worker tab.  This leaks a few compartments.
2) Click the debug link on about:debugging to debug a worker.  This leaks many compartments.

Right now this issue is causing me to have to restart nightly every day or two.

Nick, any thoughts?

Comment 1

[Ben Kelly [:bkelly, not reviewing]]

[Tracking Requested - why for this release]:

Requesting tracking because this memory issue is severe enough that I have to restart nightly every day or two.  That's not very good uptime for our users.

Comment 2

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Eddy and Julian know about:debugging and service worker debugger-y stuff.

Comment 3

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Next steps would be running find-roots.py on the cc logs to figure out what's holding.

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

I could not capture CC logs for the content process.  It just gave me zero bytes.  I think this is a windows issue.  Maybe someone would have better luck on mac or linux.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

Some related info in bug 1283587.  Maybe the same issue getting worse or a new issue.  Hard to tell.

Comment 6

[Marcia Knous [:marcia]]

Tracking 52+, especially if this leak is forcing users to have to restart.

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

I experienced something similar today after using devtools in FF50 beta 8.  I was trying to debug an issue on a partner site.  I heavily used these tools:

* web console
* debugger
* performance timeline
* network monitor

And only lightly used:

* about:debugging
* service worker debugger

I ended up with:

├────677.08 MB (36.97%) -- js-non-window
│    ├──596.69 MB (32.58%) -- zones
│    │  ├──568.78 MB (31.06%) -- zone(0x23dc0d8c800)
│    │  │  ├──367.68 MB (20.08%) ++ compartment([System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:249))
│    │  │  ├───87.14 MB (04.76%) ++ (139 tiny)
│    │  │  ├───66.85 MB (03.65%) ++ compartment([System Principal], resource://gre/modules/commonjs/toolkit/loader.js)
│    │  │  ├───28.29 MB (01.54%) ++ object-groups
│    │  │  └───18.82 MB (01.03%) ── type-pool
│    │  ├───23.43 MB (01.28%) ++ zone(0x23dc0d7d000)
│    │  └────4.48 MB (00.24%) ++ (12 tiny)

And:

2,181 (100.0%) -- js-main-runtime-compartments
├──2,042 (93.63%) -- system
│  ├────317 (14.53%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:185) [317]
│  ├────317 (14.53%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:211) [317]
│  ├────317 (14.53%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:222) [317]
│  ├────317 (14.53%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:229) [317]
│  ├────317 (14.53%) ── [System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:24) [317]
│  ├────317 (14.53%) ── [System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:249) [317]
│  └────140 (06.42%) ++ (129 tiny)
└────139 (06.37%) ++ user

Since I'm unsure which tool is at fault I'm widening the scope of the bug a bit.

Comment 8

[Eric Rahm [:erahm]]

(In reply to Ben Kelly [:bkelly] from comment #4)
> I could not capture CC logs for the content process.  It just gave me zero
> bytes.  I think this is a windows issue.  Maybe someone would have better
> luck on mac or linux.

Ben, there should be '-incomplete' files next to the zero byte files. They are probably actually complete. Can you try checking those?

Comment 9

[Ben Kelly [:bkelly, not reviewing]]

Sorry, that sessions and set of files are long gone.  I'll keep that in mind if I see it again, though.  (Also, I don't remember seeing incomplete files left, but maybe I missed them.)

Comment 10

[Julian Descottes [:jdescottes]]

This could be related to Bug 1315044, which is currently being worked on. Would be interesting to test again after it get fixed.

Comment 11

[Eddy Bruel [:ejpbruel]]

Sorry for the late reply here. Unfortunately, I have no idea what could be causing this from the back of my head. I'd have to page back in a lot of information in my head before I could say anything useful about it.

Based on comment 10, it seems to me the best course of action is to await the results of bug 1315044. If that doesn't fix the issue, I can try to take a closer look at this.

Comment 12

[Julien Cristau [:jcristau] (back April 22)]

Bug 1315044 mentioned in comment 10 should be fixed now in nightly.  Ben, can you still reproduce the leak?

Comment 13

[Ben Kelly [:bkelly, not reviewing]]

Unfortunately I don't have STR here.  Its just something I noticed on a long running session.

Its great to hear that about:debugging leak was fixed, though!  I think I have some other open bugs on that.

Comment 14

[Ben Kelly [:bkelly, not reviewing]]

Argh, this is that other bug!  I thought this was the leak bug I wrote earlier this week.  Sorry for my confusion.

I'll see if I can reproduce this.

Comment 15

[Ben Kelly [:bkelly, not reviewing]]

I haven't seen this recently.  Lets mark WFM and we can open a new bug if we see it again.