Closed Bug 1822938 Opened 2 years ago Closed 1 year ago

Intermittent leakcheck | tab 536 bytes leaked (LoadedScript, ModuleScript, ScriptFetchOptions, nsAuthURLParser, nsStandardURL, ...)

Categories

(Core :: JavaScript Engine, defect, P2)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1871075

People

(Reporter: intermittent-bug-filer, Assigned: allstars.chh)

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered][stockwell disable-recommended])

Attachments

(2 obsolete files)

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


[task 2023-03-16T21:49:49.095Z] 21:49:49     INFO - TEST-OK | dom/workers/test/test_worker_interfaces_secureContext.html | took 699ms
[task 2023-03-16T21:49:49.096Z] 21:49:49     INFO - GECKO(3269) | [Parent 3269, Main Thread] WARNING: Received `load` event on unbridged BrowserParent!: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:3923
[task 2023-03-16T21:49:49.096Z] 21:49:49     INFO - GECKO(3269) | [Parent 3269, Main Thread] WARNING: Received `load` event on unbridged BrowserParent!: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:3923
[task 2023-03-16T21:49:49.097Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/checkouts/gecko/widget/cocoa/nsAppShell.mm:826
[task 2023-03-16T21:49:49.097Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: A runnable was posted to a worker that is already shutting down!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:1584
[task 2023-03-16T21:49:49.098Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: Failed to dispatch offline status change event!: file /builds/worker/checkouts/gecko/dom/workers/WorkerPrivate.cpp:2068
[task 2023-03-16T21:49:49.107Z] 21:49:49     INFO - TEST-START | Shutdown
[task 2023-03-16T21:49:49.107Z] 21:49:49     INFO - Passed:  674
[task 2023-03-16T21:49:49.108Z] 21:49:49     INFO - Failed:  0
[task 2023-03-16T21:49:49.108Z] 21:49:49     INFO - Todo:    1
[task 2023-03-16T21:49:49.109Z] 21:49:49     INFO - Mode:    e10s
[task 2023-03-16T21:49:49.109Z] 21:49:49     INFO - Slowest: 11328ms - https://example.org:443/tests/dom/workers/test/test_subworkers_suspended.html
[task 2023-03-16T21:49:49.110Z] 21:49:49     INFO - SimpleTest FINISHED
[task 2023-03-16T21:49:49.110Z] 21:49:49     INFO - TEST-INFO | Ran 1 Loops
[task 2023-03-16T21:49:49.110Z] 21:49:49     INFO - SimpleTest FINISHED
[task 2023-03-16T21:49:49.139Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3396
[task 2023-03-16T21:49:49.140Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2023-03-16T21:49:49.146Z] 21:49:49     INFO - GECKO(3269) | [Child 3277, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4689
[task 2023-03-16T21:49:49.153Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.153Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.156Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.159Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.168Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.169Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.177Z] 21:49:49     INFO - GECKO(3269) | [Child 3272, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:44
[task 2023-03-16T21:49:49.182Z] 21:49:49     INFO - GECKO(3269) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 576: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2023-03-16T21:49:49.183Z] 21:49:49     INFO - GECKO(3269) | [Parent 3269, Main Thread] WARNING: Embedder already asked to shutdown.: file /builds/worker/checkouts/gecko/docshell/base/CanonicalBrowsingContext.cpp:1998
[task 2023-03-16T21:49:49.237Z] 21:49:49     INFO - GECKO(3269) | 1679003389236	Marionette	TRACE	Received observer notification quit-application
[task 2023-03-16T21:49:49.238Z] 21:49:49     INFO - GECKO(3269) | 1679003389237	Marionette	INFO	Stopped listening on port 2828
[task 2023-03-16T21:49:49.238Z] 21:49:49     INFO - GECKO(3269) | 1679003389237	Marionette	DEBUG	Marionette stopped listening
<...>
[task 2023-03-16T21:49:50.778Z] 21:49:50     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2023-03-16T21:49:50.779Z] 21:49:50     INFO - leakcheck | Processing leak log file /var/folders/h5/2vq9847j2z51_w_vymktkx18000014/T/tmpgtzwo1px.mozrunner/runtests_leaks_tab_pid3183.log
[task 2023-03-16T21:49:50.779Z] 21:49:50     INFO - 
[task 2023-03-16T21:49:50.779Z] 21:49:50     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 3183
[task 2023-03-16T21:49:50.780Z] 21:49:50     INFO - 
[task 2023-03-16T21:49:50.780Z] 21:49:50     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2023-03-16T21:49:50.780Z] 21:49:50     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2023-03-16T21:49:50.781Z] 21:49:50     INFO -    0 |TOTAL                                 |       63      536|   25612        6|
[task 2023-03-16T21:49:50.781Z] 21:49:50     INFO -  210 |LoadedScript                          |       48       48|      24        1|
[task 2023-03-16T21:49:50.782Z] 21:49:50     INFO -  236 |ModuleScript                          |       80       80|      21        1|
[task 2023-03-16T21:49:50.782Z] 21:49:50     INFO -  432 |ScriptFetchOptions                    |       40       40|      20        1|
[task 2023-03-16T21:49:50.782Z] 21:49:50     INFO -  607 |nsAuthURLParser                       |       24       24|       2        1|
[task 2023-03-16T21:49:50.783Z] 21:49:50     INFO -  779 |nsStandardURL                         |      336      336|     661        1|
[task 2023-03-16T21:49:50.783Z] 21:49:50     INFO -  785 |nsStringBuffer                        |        8        8|   11087        1|
[task 2023-03-16T21:49:50.784Z] 21:49:50     INFO - 
[task 2023-03-16T21:49:50.784Z] 21:49:50     INFO - nsTraceRefcnt::DumpStatistics: 858 entries
[task 2023-03-16T21:49:50.784Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 LoadedScript
[task 2023-03-16T21:49:50.784Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ModuleScript
[task 2023-03-16T21:49:50.785Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 ScriptFetchOptions
[task 2023-03-16T21:49:50.785Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 nsAuthURLParser
[task 2023-03-16T21:49:50.785Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStandardURL
[task 2023-03-16T21:49:50.786Z] 21:49:50     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2023-03-16T21:49:50.786Z] 21:49:50     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 536 bytes leaked (LoadedScript, ModuleScript, ScriptFetchOptions, nsAuthURLParser, nsStandardURL, ...)
[task 2023-03-16T21:49:50.786Z] 21:49:50     INFO - 
[task 2023-03-16T21:49:50.787Z] 21:49:50     INFO - leakcheck | Processing leak log file /var/folders/h5/2vq9847j2z51_w_vymktkx18000014/T/tmpgtzwo1px.mozrunner/runtests_leaks_tab_pid3197.log
[task 2023-03-16T21:49:50.787Z] 21:49:50     INFO - TEST-PASS | leakcheck | tab no leaks detected!
<...>
[task 2023-03-16T21:49:57.332Z] 21:49:57     INFO - TEST-START | dom/xhr/tests/test_XHR.html

First occurrence so far, in this range of retriggers and backfills

Whiteboard: [retriggered]

Update

There have been 34 failures within the last 7 days:

  • 33 failures on Linux 18.04 x64 WebRender debug
  • 1 failure on OS X 10.15 WebRender debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=432026063&repo=autoland&lineNumber=9204

[task 2023-10-10T20:07:10.384Z] 20:07:10     INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 5312
[task 2023-10-10T20:07:10.385Z] 20:07:10     INFO - 
[task 2023-10-10T20:07:10.385Z] 20:07:10     INFO -      |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2023-10-10T20:07:10.386Z] 20:07:10     INFO -      |                                      | Per-Inst   Leaked|   Total      Rem|
[task 2023-10-10T20:07:10.386Z] 20:07:10     INFO -    0 |TOTAL                                 |       54      560| 2405181        6|
[task 2023-10-10T20:07:10.387Z] 20:07:10     INFO -  287 |LoadedScript                          |       48       48|     505        1|
[task 2023-10-10T20:07:10.387Z] 20:07:10     INFO -  325 |ModuleScript                          |       80       80|      42        1|
[task 2023-10-10T20:07:10.388Z] 20:07:10     INFO -  600 |ScriptFetchOptions                    |       64       64|    1386        1|
[task 2023-10-10T20:07:10.389Z] 20:07:10     INFO -  842 |nsAuthURLParser                       |       24       24|       2        1|
[task 2023-10-10T20:07:10.389Z] 20:07:10     INFO - 1063 |nsStandardURL                         |      336      336|   35522        1|
[task 2023-10-10T20:07:10.390Z] 20:07:10     INFO - 1070 |nsStringBuffer                        |        8        8|  203054        1|
[task 2023-10-10T20:07:10.390Z] 20:07:10     INFO - 
[task 2023-10-10T20:07:10.391Z] 20:07:10     INFO - nsTraceRefcnt::DumpStatistics: 1155 entries
[task 2023-10-10T20:07:10.391Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 LoadedScript
[task 2023-10-10T20:07:10.392Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ModuleScript
[task 2023-10-10T20:07:10.393Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 ScriptFetchOptions
[task 2023-10-10T20:07:10.393Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 nsAuthURLParser
[task 2023-10-10T20:07:10.394Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStandardURL
[task 2023-10-10T20:07:10.394Z] 20:07:10     INFO - TEST-INFO | leakcheck | tab leaked 1 nsStringBuffer
[task 2023-10-10T20:07:10.395Z] 20:07:10     INFO - TEST-UNEXPECTED-FAIL | leakcheck | tab 560 bytes leaked (LoadedScript, ModuleScript, ScriptFetchOptions, nsAuthURLParser, nsStandardURL, ...)
[task 2023-10-10T20:07:10.395Z] 20:07:10     INFO - 

Eden, can you help us assign this to someone?
Thank you.

Flags: needinfo?(echuang)

According to the leak object name in the comment 31, I guess this could be related to the module script support. Yoshi, could you help to take a look? Thank you.

Flags: needinfo?(echuang) → needinfo?(allstars.chh)

Forward to Will to decide whether this should be handled by SM

Flags: needinfo?(allstars.chh) → needinfo?(wmedina)

Update

There have been 79 failures within the last 7 days, all of them on Linux 18.04 x64 WebRender debug.

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell needswork:owner]

Update

There have been 64 failures within the last 7 days, all of them on Linux 18.04 x64 WebRender debug.

==Recent log:== https://treeherder.mozilla.org/logviewer?job_id=436257539&repo=mozilla-central&lineNumber=8946

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell needswork:owner]
Assignee: nobody → allstars.chh
Flags: needinfo?(wmedina)

Update

There have been 53 total failures within the last 7 days:

  • 1 failure on OS X 10.15 WebRender debug
  • 52 failures on Linux 18.04 x64 WebRender debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=437758156&repo=mozilla-central&lineNumber=9044

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell needswork:owner]
Component: DOM: Workers → JavaScript Engine
Priority: -- → P2
Duplicate of this bug: 1867033
Duplicate of this bug: 1867032

I think I've fixed the memory leak, however, from the try result, it looks like the fix causes other memory leak in nsGlobalWindowInner

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

I noticed in a recent Try run that this seems to affect 30% of test runs in several mochitest-13 flavors nowadays.

Here's one recent Try run to demonstrate:
https://treeherder.mozilla.org/jobs?repo=try&0&searchStr=mochitest%2C13&revision=af52ca0f5a1c74c374fb9560385c84c4b23d0252
This had 10 runs of the test-linux1804-64-qr/debug-mochitest-plain-xorig-13 task.

  • 3 of them (30%) were orange with this leak
  • 2 were orange for an unrelated intermittent failure
  • 5 were green

So there's probably some specific test in that "13" batch that pretty-reliably does the right set of things to trigger this leak, which is bad for this being a spammy failure, but good for this being something that we have the power to investigate, I hope.

Here's another recent Try run with a different mochitest flavor, also hitting this in 3/10 test runs:
https://treeherder.mozilla.org/jobs?repo=try&searchStr=mochitest%2C13&revision=c13094c1ebf47600e5ff9ef003f3f2e293952f99
10 runs of test-linux1804-64-qr/debug-mochitest-plain-nofis-13 task:

  • 3 of them (30%) were orange with this leak
  • 7 were green

Also worth noting, ModuleScript is only leaked some of the time, but the rest of the list of objects here seems to always be consistent:

LoadedScript, ScriptFetchOptions, nsAuthURLParser, nsStandardURL, nsStringBuffer

(Note that when ModuleScript is listed, then the final leaked object nsStringBuffer gets ellipsized away, but it's still there as shown e.g. in the BloatView chart in comment 0 here.)

Attachment #9366093 - Attachment description: Bug 1822938 - Part 2. Add PendingDynamicReferencingPrivates → Bug 1822938 - Part 2. Add PendingDynamicReferencingPrivates.

Update

There have been 102 failures within the last 7 days, all of them on Linux 18.04 x64 WebRender debug.

The last most recent failure was on Thu, Dec 21. Bug 1871075 might have done something to stop the failure from occurring.

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell needswork:owner]
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered]
Attachment #9366092 - Attachment is obsolete: true
Attachment #9366093 - Attachment is obsolete: true

No new crashes since bug 1871075 landed so marking this fixed.

Status: NEW → RESOLVED
Closed: 1 year ago
Duplicate of bug: 1871075
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: