1787589 - Intermittent leakcheck | gpu 40 bytes leaked (FOG IPC Payload getting full)

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P1)

Description

[Treeherder Bug Filer]

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

---

[task 2022-08-27T02:13:14.002Z] 02:13:14     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.002Z] 02:13:14     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 1000 bytes
[task 2022-08-27T02:13:14.003Z] 02:13:14     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2022-08-27T02:13:14.003Z] 02:13:14     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.004Z] 02:13:14     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.004Z] 02:13:14     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.004Z] 02:13:14     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.005Z] 02:13:14     INFO - TEST-INFO | leakcheck | sandboxbroker process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.005Z] 02:13:14     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.006Z] 02:13:14     INFO - TEST-INFO | leakcheck | utility process: leak threshold set at 0 bytes
[task 2022-08-27T02:13:14.006Z] 02:13:14     INFO - leakcheck | Processing leak log file C:\Users\task_166156086463538\AppData\Local\Temp\tmpf0h_84cv.mozrunner\runtests_leaks.log
[task 2022-08-27T02:13:14.009Z] 02:13:14     INFO - TEST-PASS | leakcheck | default no leaks detected!
[task 2022-08-27T02:13:14.009Z] 02:13:14     INFO - leakcheck | Processing leak log file C:\Users\task_166156086463538\AppData\Local\Temp\tmpf0h_84cv.mozrunner\runtests_leaks_gpu_pid6020.log
[task 2022-08-27T02:13:14.010Z] 02:13:14     INFO - 
[task 2022-08-27T02:13:14.010Z] 02:13:14     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, gpu process 6020
[task 2022-08-27T02:13:14.011Z] 02:13:14     INFO - 
[task 2022-08-27T02:13:14.011Z] 02:13:14     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2022-08-27T02:13:14.011Z] 02:13:14     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2022-08-27T02:13:14.012Z] 02:13:14     INFO -    0 |TOTAL                                 |       68       40| 1640664        1|
[task 2022-08-27T02:13:14.012Z] 02:13:14     INFO -   67 |FOG IPC Payload getting full          |       40       40|       2        1|
[task 2022-08-27T02:13:14.012Z] 02:13:14     INFO - 
[task 2022-08-27T02:13:14.013Z] 02:13:14     INFO - nsTraceRefcnt::DumpStatistics: 377 entries
[task 2022-08-27T02:13:14.013Z] 02:13:14     INFO - TEST-INFO | leakcheck | gpu leaked 1 FOG IPC Payload getting full
[task 2022-08-27T02:13:14.013Z] 02:13:14     INFO - TEST-UNEXPECTED-FAIL | leakcheck | gpu 40 bytes leaked (FOG IPC Payload getting full)
[task 2022-08-27T02:13:14.014Z] 02:13:14     INFO - 

Comment 1

[Natalia Csoregi [:nataliaCs]]

Appeared during shutdown, after toolkit/components/antitracking/test/browser/browser_contentBlockingTelemetry.js | took 3939ms successfully passed.

Comment 2

[Andrew McCreight [:mccr8]]

There's a runnable with that name in Glean, so I assume it was being dispatched to the main thread too late so we leaked it.

Comment 3

[Intermittent Failures Robot]

1 failures in 3293 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1787589&startday=2022-08-22&endday=2022-08-28&tree=all

Comment 4

[Chris H-C :chutten]

How late's too late? We can pretty trivially gate this on AppShutdown::IsInOrBeyond if we know which phase to aim for, but I'd have figured the DispatchToMainThread itself to have failed were the main thread unavailable?

(Though honestly, if we're beyond XPCOMShutdown FOG (and thus Glean) has already been shut down, so I'll start with that).

Comment 5

[Chris H-C :chutten]

...this is tweaking a memory in my mind of bug 1763593 where I had to manually handle the runnable and dispatch because of shutdown races. I had to work around deliberate leaks in NS_DispatchToMainThread. I wonder if this is related...

Comment 6

[Andrew McCreight [:mccr8]]

There's this in the log:

[GPU 6020, IPC I/O Child] ###!!! ASSERTION: Failed NS_DispatchToMainThread() in shutdown; leaking: 'false', file /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:222

We default to leaking the runnable because many places in the codebase use a runnable like this to destroy a main thread only object on the main thread, so it isn't safe to destroy the runnable. For this particular case, it looks like the data on the runnable isn't something that needs to be destroyed on the main thread, so you could just check for something at the start of the function and bail out if we're in shutdown before attempting to dispatch the runnable.

Comment 7

[Chris H-C :chutten]

Knew it sounded familiar.

Well, as per before we shutdown the main thread during XPCOMShutdown so that's a decent enough candidate for a shutdown phase to guard with.

Comment 8

[Chris H-C :chutten]

Attachment: Bug 1787589 - Avoid flushing FOG IPC too late in shutdown r?perry.mcmanis!

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ff8dc8eb9994
Avoid flushing FOG IPC too late in shutdown r=perry.mcmanis

Comment 10

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/ff8dc8eb9994