1636192 - Intermittent dt fission leakcheck | tab 370625 bytes leaked (APZEventState, ActiveElementManager, AsyncFreeSnowWhite, BackstagePass, BrowserChild, ...)

Status: RESOLVED FIXED

(DevTools :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=301235060&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ApPYKrUUT8yXdzgMWC5ZSA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-05-07T16:05:00.248Z] 16:05:00 INFO - TEST-START | browser/base/content/test/general/browser_windowactivation.js
[task 2020-05-07T16:05:22.527Z] 16:05:22 INFO - TEST-INFO | leakcheck | tab leaked 5 xpc::CompartmentPrivate
[task 2020-05-07T16:05:22.527Z] 16:05:22 INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 370625 bytes leaked (APZEventState, ActiveElementManager, AsyncFreeSnowWhite, BackstagePass, BrowserChild, ...)
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO -
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - leakcheck | Processing leak log file c:\users\task_1588865779\appdata\local\temp\tmp5iskn2.mozrunner\runtests_leaks_tab_pid7256.log
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO -
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 7256
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO -
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - 0 |TOTAL | 40 0| 439454 0|
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO -
[task 2020-05-07T16:05:22.528Z] 16:05:22 INFO - nsTraceRefcnt::DumpStatistics: 1100 entries
[task 2020-05-07T16:05:22.529Z] 16:05:22 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-05-07T16:05:22.529Z] 16:05:22 INFO - leakcheck | Processing leak log file c:\users\task_1588865779\appdata\local\temp\tmp5iskn2.mozrunner\runtests_leaks_tab_pid7548.log

Comment 1

[Intermittent Failures Robot]

3 failures in 5276 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform breakdown:

• windows10-64-qr: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-04&endday=2020-05-10&tree=all

Comment 2

[Intermittent Failures Robot]

23 failures in 970 pushes (0.024 failures/push) were associated with this bug yesterday.

Repository breakdown:

• try: 13
• mozilla-central: 6
• autoland: 4

Platform breakdown:

• linux1804-64: 16
• windows10-64: 2
• windows10-64-qr: 4
• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-14&endday=2020-05-14&tree=all

Comment 3

[Intermittent Failures Robot]

70 failures in 5488 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #18 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 18
• autoland: 31
• mozilla-central: 21

Platform breakdown:

• linux1804-64: 32
• windows10-64: 15
• windows7-32: 2
• windows10-64-qr: 20
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-11&endday=2020-05-17&tree=all

Comment 4

[Intermittent Failures Robot]

17 failures in 718 pushes (0.024 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 8
• mozilla-central: 7
• try: 2

Platform breakdown:

• windows10-64-qr: 5
• linux1804-64: 8
• windows10-64: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-18&endday=2020-05-18&tree=all

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

The Linux devtools failures start with devtools.browsertoolbox.fission getting set to true in bug 1637012.

Comment 6

[Julian Descottes [:jdescottes]]

This is quite surprising because:

• the change from Bug 1637012 is a noop on Nightly (the pref is already true there)
• the test modified in Bug 1637012 is not running in the suite that fails here (I checked several devtools failures from https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-05-12&endday=2020-05-19&tree=trunk&bug=1636192 )

Are you sure they are related?

Comment 7

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Sorry. https://hg.mozilla.org/mozilla-central/pushloghtml?changeset=59d4ec4ce296162c447f1cfe83abb4be3c0c3333 is the changelog. Any idea what started it?

Comment 8

[Julian Descottes [:jdescottes]]

Did a few retriggers on autoland https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=dt4%2Cfis&tochange=8662bbb6d68de0d0e1bd64a313eb0588c1fd55a5&fromchange=c1dc821824959b7cee0ac800e79651b464eb1f85&selectedTaskRun=F91jIRITQaaiTN0k_ldrzQ-0

If it's a permafail then Bug 1620966 would be the regressing bug. (https://hg.mozilla.org/integration/autoland/rev/2b7abe98c721313c13553a43309755d233c53cbe)

Comment 9

[Alexandre Poirot [:ochameau]]

Isn't it a duplicated of bug 1607569, which was already close to be a permafail.
I also see bug 1607569's patch in the changelog of comment 7.

Comment 10

[Andrew McCreight [:mccr8]]

The tree herder link in comment 8 makes it look like this failure wasn't happening until your patch landed. I did a few retriggers, and they were green before your patch and orange after.

It looks like the leaking process was created during the test devtools/client/webconsole/test/browser/browser_jsterm_evaluation_context_selector_targets_update.js

I looked at one failure log in bug bug 1607569,, and it was being created during
devtools/client/webconsole/test/browser/browser_console_clear_closed_tab.js

That said, it does look like there are a bunch of other failures getting bundled in here. A lot of them are in mochitest-plain-e10s-5, which is neither devtools nor Fission.

Comment 11

[Andrew McCreight [:mccr8]]

At least in one log I looked at, the mochitest-plain-e10s-5 leak was happening with a content process created while running the tests in dom/security/test/general/

Comment 12

[Alexandre Poirot [:ochameau]]

Thanks for the help Andrew, I was able to repro it locally thanks to your hint.

It looks like my patch is introducing an exception in these two tests leading to leak reports, but without making the test to fail.
We can probably enhance our exception detection while running tests...

I'll have a look at that tomorrow!

Comment 13

[Alexandre Poirot [:ochameau]]

(In reply to Alexandre Poirot [:ochameau] from comment #12)

It looks like my patch is introducing an exception in these two tests leading to leak reports, but without making the test to fail.

Scratch that. I no longer reproduce this exception. The test seems to be running fine.
The leak is related to the page reload when running devtools/client/webconsole/test/browser/browser_console_clear_closed_tab.js.
We should probably leak somethin on page reload in the context of the browser console, but it is hard to guess what.
I tracked the calls to Services.console.registerListener/unregisterListener and it looks correct.

I tried the DMD script (mochitest doesn't accept --mode=scan, so I'm running without), I got the cc-edges logs, but I don't know where to start.
There is no particular address of leaked object/window in mochitest logs.

Comment 14

[Alexandre Poirot [:ochameau]]

(In reply to Alexandre Poirot [:ochameau] from comment #13)

Scratch that. I no longer reproduce this exception. The test seems to be running fine.
The leak is related to the page reload when running devtools/client/webconsole/test/browser/browser_console_clear_closed_tab.js.
We should probably leak somethin on page reload in the context of the browser console, but it is hard to guess what.

s/page reload/tab closing/
i.e. this one line

Comment 15

[Alexandre Poirot [:ochameau]]

Ok. I think I found it.

We are not trying to do much cleanup when DevTools code is running and the content process is meant to be destroyed.
We just assume that the whole process will be destroyed and do nothing.

If I start listening to "xpcom-shutdown" and destroy DevTools listeners (including the various console related ones: Services.console and Services.obs.addObserver(console-api-log-event)), the leak goes away (locally at least).

I'm not sure bug 1620966 changed anything around this. This leak was probably around for a while!

Comment 16

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1636192 - Clean Content process Target actor on process shutdown.

Before this patch, we were not trying to cleanup anything when the process
was known to be in process of destruction. We assumed that everything would
be cleaned up anyway.
But mochitest is actually asserting that nothing is leaked on process shutdown,
and we are easily leaking many thing when not destroying the target actor!

Comment 17

[Alexandre Poirot [:ochameau]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=b5a7386ad50bfe04c6ae2843bee87ce86d6e66f9

Comment 18

[Andrew McCreight [:mccr8]]

(In reply to Alexandre Poirot [:ochameau] from comment #15)

If I start listening to "xpcom-shutdown" and destroy DevTools listeners (including the various console related ones: Services.console and Services.obs.addObserver(console-api-log-event)), the leak goes away (locally at least).

The problem with this is that if this DevTools stuff is holding references to web pages then it means we may be leaking pages until shutdown, which is bad. So your proposed fix would only be hiding leaks from the leak checker, not fixing them. The leak here is a window and a document.

That said, we have a different checker for leaked windows and documents in browser mochitests, and I thought devtools mochitests used that, so I'm not sure why it wouldn't be detected with that. I'll try to figure out what window is leaking.

Comment 19

[Alexandre Poirot [:ochameau]]

(In reply to Andrew McCreight [:mccr8] from comment #18)

(In reply to Alexandre Poirot [:ochameau] from comment #15)

If I start listening to "xpcom-shutdown" and destroy DevTools listeners (including the various console related ones: Services.console and Services.obs.addObserver(console-api-log-event)), the leak goes away (locally at least).

The problem with this is that if this DevTools stuff is holding references to web pages then it means we may be leaking pages until shutdown, which is bad. So your proposed fix would only be hiding leaks from the leak checker, not fixing them. The leak here is a window and a document.

Let me rephrase.
DevTools cleans things up when it closes itself! When DevTools closes, we go through all processes and try to cleanup all our stuff everywhere.
(We might have bugs in this process, but I haven't identified a bug in this here. And we really meant to clean everything.)
But while it is opened, if one content process shuts down, DevTools doesn't try to cleanup anything, it just let the process be destroyed and assume everything will be cleaned up. Is that really an issue to leak something when we know the process is in process of shutting down?

To be slightly more concrete about what I identified here. We were destroying all DevTools "Targets actors" for all content processes, all but the one related to the closed tab, which is closed in middle of the test, while DevTools are opened. All others were explicitely destroyed by DevTools code when we are closing the Browser Console.
"Target actors" are the topmost class in DevTools backend, which holds everything alive.

Comment 20

[Intermittent Failures Robot]

40 failures in 4727 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

This is the #31 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 12
• mozilla-central: 24
• try: 4

Platform breakdown:

• windows10-64-qr: 8
• linux1804-64: 25
• windows10-64: 6
• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-18&endday=2020-05-24&tree=all

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d45a9f533b34
Clean Content process Target actor on process shutdown. r=nchevobbe

Comment 22

[Alexandre Poirot [:ochameau]]

(In reply to Alexandre Poirot [:ochameau] from comment #17)

https://treeherder.mozilla.org/#/jobs?repo=try&revision=b5a7386ad50bfe04c6ae2843bee87ce86d6e66f9

Looking at this try run, while I fixed a leak locally, it doesn't seem to address the leak happening on try.
I pushed this first patch and I'll keep watching this bug.

Comment 23

[Narcis Beleuzu [:NarcisB]]

Backed out for xpcshell crashes on test_xpcshell_debugging.js

Backout link: https://hg.mozilla.org/integration/autoland/rev/8038b21a4d0b1aab5719f83104701e6d2580764a
Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=303586015&repo=autoland&lineNumber=4985

Comment 24

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0c1e8493381e
Clean Content process Target actor on process shutdown. r=nchevobbe

Comment 25

[Raul Gurzau (:RaulG)]

https://hg.mozilla.org/mozilla-central/rev/0c1e8493381e

Comment 26

[Intermittent Failures Robot]

14 failures in 5458 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 13
• try: 1

Platform breakdown:

• linux1804-64: 14

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1636192&startday=2020-05-25&endday=2020-05-31&tree=all