Closed Bug 1661862 Opened 4 years ago Closed 2 years ago

Intermittent PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()]

Categories

(Core :: DOM: Navigation, defect, P3)

defect

Tracking

()

RESOLVED FIXED
102 Branch
Tracking Status
firefox-esr91 --- wontfix
firefox100 --- wontfix
firefox101 --- wontfix
firefox102 --- fixed

People

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

References

Details

(Keywords: crash, intermittent-failure, memory-leak, Whiteboard: [stockwell unknown])

Crash Data

Attachments

(1 file)

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


[task 2020-08-28T22:46:14.394Z] 22:46:14 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()]
[task 2020-08-28T22:46:14.395Z] 22:46:14 INFO - Crash dump filename: /tmp/tmpVnJk9V.mozrunner/minidumps/0c7460c1-ba3e-07b5-152b-415b881cd521.dmp
[task 2020-08-28T22:46:14.395Z] 22:46:14 INFO - Operating system: Linux
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - CPU: amd64
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - family 6 model 85 stepping 7
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - 2 CPUs
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO -
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - GPU: UNKNOWN
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO -
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2020-08-28T22:46:14.396Z] 22:46:14 INFO - Crash address: 0x0
[task 2020-08-28T22:46:14.397Z] 22:46:14 INFO - Process uptime: not available
[task 2020-08-28T22:46:14.397Z] 22:46:14 INFO -
[task 2020-08-28T22:46:14.397Z] 22:46:14 INFO - Thread 0 (crashed)
[task 2020-08-28T22:46:14.398Z] 22:46:14 INFO - 0 libxul.so!mozilla::LinkedList<nsSHistory>::~LinkedList() [LinkedList.h:7a0b9b3e465b78b30bc5f7dc632c514039eec84a : 439 + 0x36]
[task 2020-08-28T22:46:14.398Z] 22:46:14 INFO - rax = 0x00005589c85e5e68 rdx = 0x0000000000000000
[task 2020-08-28T22:46:14.399Z] 22:46:14 INFO - rcx = 0x0000000000000b40 rbx = 0x00005589c85e5e70
[task 2020-08-28T22:46:14.399Z] 22:46:14 INFO - rsi = 0x00007f16f0a698b0 rdi = 0x00007f16f0a68680
[task 2020-08-28T22:46:14.399Z] 22:46:14 INFO - rbp = 0x00007ffcefb5eda0 rsp = 0x00007ffcefb5ed90
[task 2020-08-28T22:46:14.399Z] 22:46:14 INFO - r8 = 0x00007f16f0a698b0 r9 = 0x00007f16f1964780
[task 2020-08-28T22:46:14.399Z] 22:46:14 INFO - r10 = 0x0000000000000002 r11 = 0x0000000000000000
[task 2020-08-28T22:46:14.400Z] 22:46:14 INFO - r12 = 0x00007f16f0a67718 r13 = 0x0000000000000106
[task 2020-08-28T22:46:14.400Z] 22:46:14 INFO - r14 = 0x00007f16f0a6c628 r15 = 0x00007f16f0273000
[task 2020-08-28T22:46:14.400Z] 22:46:14 INFO - rip = 0x00007f16e38caa10
[task 2020-08-28T22:46:14.401Z] 22:46:14 INFO - Found by: given as instruction pointer in context
[task 2020-08-28T22:46:14.401Z] 22:46:14 INFO - 1 libc.so.6 + 0x430f1
[task 2020-08-28T22:46:14.401Z] 22:46:14 INFO - rbx = 0x0000000000000001 rbp = 0x0000000000000000
[task 2020-08-28T22:46:14.401Z] 22:46:14 INFO - rsp = 0x00007ffcefb5edb0 r12 = 0x00007f16f0a67718
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - r13 = 0x0000000000000106 r14 = 0x00007f16f0a6c628
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - r15 = 0x00007f16f0273000 rip = 0x00007f16f06bf0f1
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - Found by: call frame info
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - 2 firefox-bin + 0xda0a0
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - rsp = 0x00007ffcefb5edd8 rip = 0x00005589c85e20a0
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - Found by: stack scanning
[task 2020-08-28T22:46:14.402Z] 22:46:14 INFO - 3 firefox-bin + 0x41000
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - rsp = 0x00007ffcefb5ede0 rip = 0x00005589c8549000
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - Found by: stack scanning
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - 4 libc.so.6 + 0x431ea
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - rsp = 0x00007ffcefb5ee00 rip = 0x00007f16f06bf1ea
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - Found by: stack scanning
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - 5 firefox-bin + 0xda0a0
[task 2020-08-28T22:46:14.403Z] 22:46:14 INFO - rsp = 0x00007ffcefb5ee08 rip = 0x00005589c85e20a0
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - Found by: stack scanning
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - 6 libc.so.6 + 0x21b9e
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - rsp = 0x00007ffcefb5ee10 rip = 0x00007f16f069db9e
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - Found by: stack scanning
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - 7 firefox-bin!mozilla::UniquePtr<mozilla::Bootstrap, mozilla::Bootstrap::BootstrapDelete>::~UniquePtr() [UniquePtr.h:7a0b9b3e465b78b30bc5f7dc632c514039eec84a : 253 + 0x17]
[task 2020-08-28T22:46:14.404Z] 22:46:14 INFO - rsp = 0x00007ffcefb5ee30 rip = 0x00005589c85491a1
[task 2020-08-28T22:46:14.405Z] 22:46:14 INFO - Found by: stack scanning

Component: MFBT → DOM: Navigation

This is likely not caused within MFBT, but rather by the uses with nsSHistory.

In the last 7 days there have been 22 occurrences on linux1804-64 debug.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=315567827&repo=autoland&lineNumber=10189

Neha, could you, please, point this to someone who can take a look?

Flags: needinfo?(nkochar)
Whiteboard: [stockwell needswork:owner]

Could be part of one of Peter's pending patches...

Flags: needinfo?(nkochar) → needinfo?(peterv)

INFO - TEST-INFO | Confirming we saw 69 DOCSHELL created and 68 destroyed log strings.

Someone is leaking a DocShell in a content process. This leak seems to allows happen after the browser/components/newtab tests:

https://treeherder.mozilla.org/logviewer?job_id=323689104&repo=mozilla-central&lineNumber=13597-13649

Moving to New Tab component.

Severity: normal → --
Component: DOM: Navigation → New Tab Page
Keywords: memory-leak
Product: Core → Firefox
Flags: needinfo?(sdowne)
Whiteboard: [stockwell unknown] → [stockwell unknown][stockwell needswork:owner]
Assignee: nobody → sdowne
Flags: needinfo?(sdowne)

I ran all newtab tests with --verify, and I got 1 test timeout that's on the list :cpeterson linked to. It is browser/components/newtab/test/browser/browser_topsites_contextMenu_options.js

It's weird to me though if this is related, but possible? If a test times out, wouldn't the errors we're hitting in this bug report the error as timed out, and not something else? Either way, it's not a good thing.

I also looked at recent commit history for that test, and nothing really matches the timing on this bug, there is 2019-07-05 and 2020-11-26, but that doesn't necessarily rule anything out, as something else could have changed that caused this test to start timing out.

I tried running only browser/components/newtab tests on Linux 18.04 x64 debug:
https://treeherder.mozilla.org/jobs?repo=try&revision=1891bb57b4c07fbf665b0e076cfb1a00b4ce2255

Not sure if I'm going about this the wrong way, but tracking which ++DOCSHELL were created after a TEST-START and seeing if there's a missing --DOCSHELL they seem to be associated to these tests:

TEST-START | browser/components/newtab/test/browser/browser_open_tab_focus.js missing 1 docshells
TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_no_cache.js missing 1 docshells
TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_no_startup_actions.js missing 1 docshells
TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_overwrite_cache.js missing 1 docshells
TEST-START | browser/components/newtab/test/browser/abouthomecache/browser_process_crash.js missing 5 docshells

However doing the same thing from the log from comment 20 which ran not just newtab tests, I see:

TEST-START | browser/components/newtab/test/browser/browser_asrouter_cfr.js missing 1 docshells
TEST-START | security/manager/ssl/tests/mochitest/browser/browser_certViewer.js missing 11 docshells
TEST-START | security/manager/ssl/tests/mochitest/browser/browser_certificateManager.js missing 1 docshells
TEST-START | security/manager/ssl/tests/mochitest/browser/browser_clientAuthRememberService.js missing 6 docshells

Although not sure why the summary after security/manager/ssl says Confirming we saw 126 DOCSHELL created and 126 destroyed log strings.

Is there someone that can help that knows the test suite well to help track down which test(s) is causing the issue? I don't think I know enough to start working on this, and I couldn't pinpoint a test yet.

If I get more time I'll take another stab at it, but any info I can get in the meantime would be super helpful.

(In reply to Scott [:thecount] Downe from comment #36)

Is there someone that can help that knows the test suite well to help track down which test(s) is causing the issue? I don't think I know enough to start working on this, and I couldn't pinpoint a test yet.

If I get more time I'll take another stab at it, but any info I can get in the meantime would be super helpful.

Andrew, do you have any memory leak debugging tips to help Scott pinpoint which test in this test suite is causing the reported leak?

Flags: needinfo?(continuation)

The most common test suite this has been happening in recently is mochitest-plain-e10s-7, and I checked two logs and they were happening in dom/security/test/csp/ for what it is worth.

Something like Comment 32 is probably the best way to try to figure out what test a docshell was created during. However, I think the doc shell is reused for across multiple tests, so maybe a similar analysis on inner windows would be better. Unfortunately we no longer log ++DOMWINDOW and ++DOCSHELL in Mochitest plain by default.

FWIW, it looks like the linked list that is asserting is here:
static LinkedList<nsSHistory> gSHistoryList;

I don't see how anything ever gets removed from this.
There's a comment in GloballyEvictContentViewers that says: " Make global eviction work for session history in the parent and remove mIsRemote.". Maybe that is related?

The leaks might be the result of some individual tests, but I think that making sure this assertion stops happening is the responsibility of Docshell.

Component: New Tab Page → DOM: Navigation
Flags: needinfo?(continuation)
Product: Firefox → Core
Assignee: sdowne → nobody

https://searchfox.org/mozilla-central/rev/d537e47349944c0fbd0100bd52c30e493e748c2e/mfbt/LinkedList.h#200 should get called on nsSHistory entries when they are being deleted.
So the assertion is there just because of the leak. It can't be really fixed if we keep leaking nsShistory.

Severity: -- → S3
Priority: -- → P3

I'm not actually sure what is the right component for this. My guess is that there are couple of different bugs causing the leaks.

Fuzz bug 1699223 has a Pernosco session for this leak assertion, though it doesn't have a test case:

https://pernos.co/debug/2SpN8-NhX5s3rstQoevOaA/index.html

Crash Signature: [@ mozilla::LinkedList<nsSHistory>::~LinkedList()] → [@ mozilla::LinkedList<nsSHistory>::~LinkedList()] [@ libc.so.6 + 0x430f1]

I hit this once in a while just locally running debug builds, FYI

Crash Signature: [@ mozilla::LinkedList<nsSHistory>::~LinkedList()] [@ libc.so.6 + 0x430f1] → [@ mozilla::LinkedList<nsSHistory>::~LinkedList()] [@ libc.so.6 + 0x430f1]
Whiteboard: [stockwell unknown][stockwell unknown] → [stockwell unknown]

There are 37 total failures in the last 7 days on linux1804-64-qr debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=367642120&repo=autoland&lineNumber=61770

[task 2022-02-12T07:48:36.686Z] 07:48:36     INFO -   chrome://reftest/content/crashtests/widget/cocoa/crashtests/444260-1.xhtml
[task 2022-02-12T07:48:36.687Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/444864-1.html
[task 2022-02-12T07:48:36.688Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/444864-1.html
[task 2022-02-12T07:48:36.688Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/449111-1.html
[task 2022-02-12T07:48:36.689Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/449111-1.html
[task 2022-02-12T07:48:36.689Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/460349-1.xhtml
[task 2022-02-12T07:48:36.690Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/460349-1.xhtml
[task 2022-02-12T07:48:36.690Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/460387-1.html
[task 2022-02-12T07:48:36.691Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/460387-1.html
[task 2022-02-12T07:48:36.692Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/464589-1.html
[task 2022-02-12T07:48:36.692Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/cocoa/crashtests/464589-1.html
[task 2022-02-12T07:48:36.693Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-1.html
[task 2022-02-12T07:48:36.693Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-1.html?
[task 2022-02-12T07:48:36.694Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-1.html?
[task 2022-02-12T07:48:36.695Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-1.html
[task 2022-02-12T07:48:36.695Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-2.html
[task 2022-02-12T07:48:36.696Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/303901-2.html
[task 2022-02-12T07:48:36.696Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/380359-1.xhtml
[task 2022-02-12T07:48:36.697Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/380359-1.xhtml
[task 2022-02-12T07:48:36.697Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/1128214.html
[task 2022-02-12T07:48:36.698Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/crashtests/1128214.html
[task 2022-02-12T07:48:36.699Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/gtk/crashtests/540078-1.xhtml
[task 2022-02-12T07:48:36.699Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/gtk/crashtests/540078-1.xhtml
[task 2022-02-12T07:48:36.700Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/gtk/crashtests/673390-1.html
[task 2022-02-12T07:48:36.700Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/widget/gtk/crashtests/673390-1.html
[task 2022-02-12T07:48:36.701Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/xpcom/string/crashtests/394275-1.html
[task 2022-02-12T07:48:36.702Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/xpcom/string/crashtests/394275-1.html
[task 2022-02-12T07:48:36.702Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/xpcom/string/crashtests/395651-1.html
[task 2022-02-12T07:48:36.703Z] 07:48:36     INFO -   file:///builds/worker/workspace/build/tests/reftest/tests/xpcom/string/crashtests/395651-1.html
[task 2022-02-12T07:48:36.704Z] 07:48:36     INFO - Hit MOZ_CRASH(mozilla::LinkedList<nsSHistory>::~LinkedList() [T = nsSHistory] has a buggy user: it should have removed all this list's elements before the list's destruction) at /builds/worker/workspace/obj-build/dist/include/mozilla/LinkedList.h:444
[task 2022-02-12T07:48:36.704Z] 07:48:36     INFO - #01: mozilla::LinkedList<nsSHistory>::~LinkedList() [mfbt/LinkedList.h:440]
[task 2022-02-12T07:48:36.705Z] 07:48:36     INFO - #02: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x430f1]
[task 2022-02-12T07:48:36.705Z] 07:48:36     INFO - #03: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x431ea]
[task 2022-02-12T07:48:36.706Z] 07:48:36     INFO - #04: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b9e]
[task 2022-02-12T07:48:36.707Z] 07:48:36     INFO - #05: ??? [/builds/worker/workspace/build/application/firefox/firefox-bin + 0x42e19]
[task 2022-02-12T07:48:36.707Z] 07:48:36     INFO - #06: ??? (???:???)
[task 2022-02-12T07:48:36.846Z] 07:48:36     INFO - [Parent 1476, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3354
[task 2022-02-12T07:48:36.918Z] 07:48:36     INFO - [Parent 1476, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4460
[task 2022-02-12T07:48:36.958Z] 07:48:36     INFO - REFTEST INFO | Copy/paste: /builds/worker/fetches/minidump_stackwalk/minidump_stackwalk --symbols-url=https://symbols.mozilla.org/ --human /tmp/tmp8icki34n.mozrunner/minidumps/3d523483-615a-dd0c-1acc-fa1e90f34e09.dmp /builds/worker/workspace/build/symbols
[task 2022-02-12T07:48:40.403Z] 07:48:40     INFO - REFTEST INFO | Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/3d523483-615a-dd0c-1acc-fa1e90f34e09.dmp
[task 2022-02-12T07:48:40.428Z] 07:48:40     INFO - REFTEST PROCESS-CRASH | xpcom/string/crashtests/1113005.html (finished) | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()]
[task 2022-02-12T07:48:40.429Z] 07:48:40     INFO - Crash dump filename: /tmp/tmp8icki34n.mozrunner/minidumps/3d523483-615a-dd0c-1acc-fa1e90f34e09.dmp
[task 2022-02-12T07:48:40.429Z] 07:48:40     INFO - Operating system: Linux
[task 2022-02-12T07:48:40.429Z] 07:48:40     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2022-02-12T07:48:40.430Z] 07:48:40     INFO - CPU: amd64
[task 2022-02-12T07:48:40.431Z] 07:48:40     INFO -      family 6 model 85 stepping 7
[task 2022-02-12T07:48:40.431Z] 07:48:40     INFO -      2 CPUs
[task 2022-02-12T07:48:40.431Z] 07:48:40     INFO - Linux Ubuntu 18.04 - bionic (Ubuntu 18.04.6 LTS)
[task 2022-02-12T07:48:40.432Z] 07:48:40     INFO - 
[task 2022-02-12T07:48:40.432Z] 07:48:40     INFO - Crash reason:  SIGSEGV / SEGV_MAPERR
[task 2022-02-12T07:48:40.433Z] 07:48:40     INFO - Crash address: 0x0
[task 2022-02-12T07:48:40.433Z] 07:48:40     INFO - Process uptime: not available
[task 2022-02-12T07:48:40.433Z] 07:48:40     INFO - 
[task 2022-02-12T07:48:40.433Z] 07:48:40     INFO - Thread 0 file:// Content (crashed)
[task 2022-02-12T07:48:40.433Z] 07:48:40     INFO -  0  libxul.so!mozilla::LinkedList<nsSHistory>::~LinkedList() [LinkedList.h:761755ec9388386f51e64fe52e9741f51a508041 : 440 + 0x36]
task 2022-02-12T07:48:40.434Z] 07:48:40     INFO -     rax = 0x000055bd4245ef88   rdx = 0x0000000000000000
[task 2022-02-12T07:48:40.435Z] 07:48:40     INFO -     rcx = 0x0000000000000b40   rbx = 0x000055bd4245ef90
[task 2022-02-12T07:48:40.435Z] 07:48:40     INFO -     rsi = 0x00007fcef39d28b0   rdi = 0x00007fcef39d1680
[task 2022-02-12T07:48:40.435Z] 07:48:40     INFO -     rbp = 0x00007ffd7813c320   rsp = 0x00007ffd7813c310
[task 2022-02-12T07:48:40.436Z] 07:48:40     INFO -      r8 = 0x00007fcef39d28b0    r9 = 0x00007fcef48c6780
[task 2022-02-12T07:48:40.436Z] 07:48:40     INFO -     r10 = 0x0000000000000000   r11 = 0x0000000000000000
[task 2022-02-12T07:48:40.437Z] 07:48:40     INFO -     r12 = 0x00007fcef39d0718   r13 = 0x000000000000080f
[task 2022-02-12T07:48:40.437Z] 07:48:40     INFO -     r14 = 0x00007fcef39d5628   r15 = 0x00007fcef31bd500
[task 2022-02-12T07:48:40.437Z] 07:48:40     INFO -     rip = 0x00007fcee681cc53
[task 2022-02-12T07:48:40.438Z] 07:48:40     INFO -     Found by: given as instruction pointer in context
[task 2022-02-12T07:48:40.438Z] 07:48:40     INFO -  1  libc.so.6!__run_exit_handlers [exit.c : 108 + 0x5]
[task 2022-02-12T07:48:40.439Z] 07:48:40     INFO -     rbx = 0x0000000000000001   rbp = 0x0000000000000000
[task 2022-02-12T07:48:40.439Z] 07:48:40     INFO -     rsp = 0x00007ffd7813c330   r12 = 0x00007fcef39d0718
[task 2022-02-12T07:48:40.439Z] 07:48:40     INFO -     r13 = 0x000000000000080f   r14 = 0x00007fcef39d5628
[task 2022-02-12T07:48:40.440Z] 07:48:40     INFO -     r15 = 0x00007fcef31bd500   rip = 0x00007fcef36280f1
[task 2022-02-12T07:48:40.440Z] 07:48:40     INFO -     Found by: call frame info
[task 2022-02-12T07:48:40.441Z] 07:48:40     INFO -  2  libc.so.6!__GI_exit [exit.c : 139 + 0xe]
[task 2022-02-12T07:48:40.441Z] 07:48:40     INFO -     rbx = 0x0000000000000000   rbp = 0x000055bd42458ec0
[task 2022-02-12T07:48:40.441Z] 07:48:40     INFO -     rsp = 0x00007ffd7813c380   r12 = 0x000055bd423b6df0
[task 2022-02-12T07:48:40.442Z] 07:48:40     INFO -     r13 = 0x00007ffd7813c460   r14 = 0x0000000000000000
[task 2022-02-12T07:48:40.442Z] 07:48:40     INFO -     r15 = 0x0000000000000000   rip = 0x00007fcef36281ea
[task 2022-02-12T07:48:40.443Z] 07:48:40     INFO -     Found by: call frame info
[task 2022-02-12T07:48:40.443Z] 07:48:40     INFO -  3  libc.so.6!__libc_start_main [libc-start.c : 344 + 0x6]
[task 2022-02-12T07:48:40.443Z] 07:48:40     INFO -     rbx = 0x0000000000000000   rbp = 0x000055bd42458ec0
[task 2022-02-12T07:48:40.444Z] 07:48:40     INFO -     rsp = 0x00007ffd7813c390   r12 = 0x000055bd423b6df0
[task 2022-02-12T07:48:40.444Z] 07:48:40     INFO -     r13 = 0x00007ffd7813c460   r14 = 0x0000000000000000
[task 2022-02-12T07:48:40.445Z] 07:48:40     INFO -     r15 = 0x0000000000000000   rip = 0x00007fcef3606b9e
[task 2022-02-12T07:48:40.445Z] 07:48:40     INFO -     Found by: call frame info
[task 2022-02-12T07:48:40.445Z] 07:48:40     INFO -  4  firefox-bin!_start + 0x28
[task 2022-02-12T07:48:40.446Z] 07:48:40     INFO -     rbx = 0x0000000000000000   rbp = 0x0000000000000000
[task 2022-02-12T07:48:40.446Z] 07:48:40     INFO -     rsp = 0x00007ffd7813c450   r12 = 0x000055bd423b6df0
[task 2022-02-12T07:48:40.447Z] 07:48:40     INFO -     r13 = 0x00007ffd7813c460   r14 = 0x0000000000000000
[task 2022-02-12T07:48:40.447Z] 07:48:40     INFO -     r15 = 0x0000000000000000   rip = 0x000055bd423b6e19
[task 2022-02-12T07:48:40.447Z] 07:48:40     INFO -     Found by: call frame info
Flags: needinfo?(peterv)

Hsin-Yi could you please take a look?

Flags: needinfo?(htsai)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

(In reply to Andreea Pavel [:apavel] from comment #98)

Hsin-Yi could you please take a look?

We looked into this a bit in our team meeting. The assertion means there was a leak but not necessarily in Session history, and it's hard to know from the log where the leak was from.

Andreea,
From the date range, the failure spike was obviously from Feb. 11. And all the logs of failures occurring after Feb. 11 did point out " xpcom/string/crashtests/1113005.html (finished) | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()"
Is it possible to get a regression range around Feb. 11 for this symptom?

Thanks!

Flags: needinfo?(htsai) → needinfo?(apavel)

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #99)

(In reply to Andreea Pavel [:apavel] from comment #98)

Hsin-Yi could you please take a look?

We looked into this a bit in our team meeting. The assertion means there was a leak but not necessarily in Session history, and it's hard to know from the log where the leak was from.

Andreea,
From the date range, the failure spike was obviously from Feb. 11. And all the logs of failures occurring after Feb. 11 did point out " xpcom/string/crashtests/1113005.html (finished) | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()"
Is it possible to get a regression range around Feb. 11 for this symptom?

Thanks!

This particular symptom " xpcom/string/crashtests/1113005.html (finished) | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()" seems to be gone after Feb. 12. The failure rate went down accordingly.

(In reply to Hsin-Yi Tsai [:hsinyi] from comment #99)

(In reply to Andreea Pavel [:apavel] from comment #98)

Hsin-Yi could you please take a look?

We looked into this a bit in our team meeting. The assertion means there was a leak but not necessarily in Session history, and it's hard to know from the log where the leak was from.

Andreea,
From the date range, the failure spike was obviously from Feb. 11. And all the logs of failures occurring after Feb. 11 did point out " xpcom/string/crashtests/1113005.html (finished) | application crashed [@ mozilla::LinkedList<nsSHistory>::~LinkedList()"
Is it possible to get a regression range around Feb. 11 for this symptom?

Thanks!

Hi. I apologize for the late reply, I was on leave.

Backfills range

I looked in TH starting with the 11th and saw the cause was bug 1720353 which got backed out here backout and the failures on the 11th should have been classified as fixed by commit.

Flags: needinfo?(apavel)

There are 48 total failures in the last 7 days on linux1804-64-qr debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=377520634&repo=autoland&lineNumber=50397

[task 2022-05-10T08:53:26.772Z] 08:53:26     INFO - TEST-START | dom/serviceworkers/test/browser_unregister_with_containers.js
[task 2022-05-10T08:53:26.775Z] 08:53:26     INFO - GECKO(16673) | Chrome file doesn't exist: /builds/worker/workspace/build/tests/mochitest/browser/dom/serviceworkers/test/head.js
[task 2022-05-10T08:53:26.823Z] 08:53:26     INFO - GECKO(16673) | [Child 18652: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 7f9216446800 == 1 [pid = 18652] [id = 0]
[task 2022-05-10T08:53:26.823Z] 08:53:26     INFO - GECKO(16673) | [Child 18652: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (7f922c295bc0) [pid = 18652] [serial = 1] [outer = 0]

[task 2022-05-10T08:53:39.779Z] 08:53:39     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2022-05-10T08:53:45.900Z] 08:53:45     INFO - GECKO(16673) | #01: NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:496]
[task 2022-05-10T08:53:45.901Z] 08:53:45     INFO - GECKO(16673) | #02: nsAtomSubTable::GCLocked(GCKind) [xpcom/ds/nsAtomTable.cpp:444]
[task 2022-05-10T08:53:45.902Z] 08:53:45     INFO - GECKO(16673) | #03: nsAtomTable::GC(GCKind) [xpcom/ds/nsAtomTable.cpp:361]
[task 2022-05-10T08:53:45.902Z] 08:53:45     INFO - GECKO(16673) | #04: NS_ShutdownAtomTable() [xpcom/ds/nsAtomTable.cpp:482]
[task 2022-05-10T08:53:45.904Z] 08:53:45     INFO - GECKO(16673) | #05: mozilla::ShutdownXPCOM(nsIServiceManager*) [xpcom/build/XPCOMInit.cpp:812]
[task 2022-05-10T08:53:45.905Z] 08:53:45     INFO - GECKO(16673) | #06: ScopedXPCOMStartup::~ScopedXPCOMStartup() [toolkit/xre/nsAppRunner.cpp:2050]
[task 2022-05-10T08:53:45.905Z] 08:53:45     INFO - GECKO(16673) | #07: mozilla::UniquePtr<ScopedXPCOMStartup, mozilla::DefaultDelete<ScopedXPCOMStartup> >::reset(ScopedXPCOMStartup*) [mfbt/UniquePtr.h:305]
[task 2022-05-10T08:53:45.906Z] 08:53:45     INFO - GECKO(16673) | #08: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5958]
[task 2022-05-10T08:53:45.913Z] 08:53:45     INFO - GECKO(16673) | #09: XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5992]
[task 2022-05-10T08:53:45.913Z] 08:53:45     INFO - GECKO(16673) | #10: ??? [/builds/worker/workspace/build/application/firefox/firefox + 0x443dd]
[task 2022-05-10T08:53:45.914Z] 08:53:45     INFO - GECKO(16673) | #11: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b97]
[task 2022-05-10T08:53:45.914Z] 08:53:45     INFO - GECKO(16673) | #12: ??? [/builds/worker/workspace/build/application/firefox/firefox + 0x43f89]
[task 2022-05-10T08:53:45.915Z] 08:53:45     INFO - GECKO(16673) | #13: ??? (???:???)
[task 2022-05-10T08:53:45.915Z] 08:53:45     INFO - GECKO(16673) | [Parent 16673, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4571
[task 2022-05-10T08:53:45.916Z] 08:53:45     INFO - GECKO(16673) | Leaked URLs:
[task 2022-05-10T08:53:45.916Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/
[task 2022-05-10T08:53:45.916Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-05-10T08:53:45.916Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.917Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.917Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.918Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.919Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/
[task 2022-05-10T08:53:45.919Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.920Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-05-10T08:53:45.920Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.920Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-05-10T08:53:45.921Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.921Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.922Z] 08:53:45     INFO - GECKO(16673) |   https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-05-10T08:53:45.922Z] 08:53:45     INFO - GECKO(16673) | Hit MOZ_CRASH(mozilla::LinkedList<nsSHistory>::~LinkedList() [T = nsSHistory] has a buggy user: it should have removed all this list's elements before the list's destruction) at /builds/worker/workspace/obj-build/dist/include/mozilla/LinkedList.h:466
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #01: mozilla::LinkedList<nsSHistory>::~LinkedList() [mfbt/LinkedList.h:462]
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #02: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x430f1]
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #03: ??? [/lib/x86_64-linux-gnu/libc.so.6 + 0x431ea]
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #04: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6 + 0x21b9e]
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #05: ??? [/builds/worker/workspace/build/application/firefox/firefox + 0x43f89]
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - GECKO(16673) | #06: ??? (???:???)
[task 2022-05-10T08:53:45.923Z] 08:53:45     INFO - TEST-INFO | Main app process: killed by SIGSEGV
[task 2022-05-10T08:53:45.924Z] 08:53:45     INFO - TEST-INFO | Confirming we saw 97 DOCSHELL created and 97 destroyed log strings.
[task 2022-05-10T08:53:45.924Z] 08:53:45     INFO - TEST-INFO | Confirming we saw 280 DOMWINDOW created and 280 destroyed log strings.
[task 2022-05-10T08:53:45.924Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_antitracking.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.925Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_antitracking.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.925Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_antitracking_subiframes.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.925Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_antitracking_subiframes.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.925Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_download.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.926Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_download.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.926Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_download_canceled.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.927Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_download_canceled.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.927Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_force_refresh.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.927Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_force_refresh.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.937Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_intercepted_channel_process_swap.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.938Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_intercepted_channel_process_swap.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.943Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_intercepted_worker_script.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.944Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_intercepted_worker_script.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.944Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_navigation_fetch_fault_handling.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.945Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_navigation_fetch_fault_handling.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.946Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_remote_type_process_swap.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.946Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_remote_type_process_swap.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.947Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_storage_recovery.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.947Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_storage_recovery.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.948Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_unregister_with_containers.js | This test created 1 hidden window(s)
[task 2022-05-10T08:53:45.948Z] 08:53:45     INFO - TEST-INFO | dom/serviceworkers/test/browser_unregister_with_containers.js | This test created 1 hidden docshell(s)
[task 2022-05-10T08:53:45.949Z] 08:53:45     INFO - Buffered messages finished
[task 2022-05-10T08:53:45.949Z] 08:53:45    ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code -11
[task 2022-05-10T08:53:45.950Z] 08:53:45     INFO - runtests.py | Application ran for: 0:01:32.906152
[task 2022-05-10T08:53:45.950Z] 08:53:45     INFO - zombiecheck | Reading PID log: /tmp/tmpqhezbl1upidlog
[task 2022-05-10T08:53:45.950Z] 08:53:45     INFO - ==> process 16673 launched child process 16691
[task 2022-05-10T08:53:45.950Z] 08:53:45     INFO - ==> process 16673 launched child process 16748

[task 2022-05-10T08:53:46.278Z] 08:53:46     INFO - nsTraceRefcnt::DumpStatistics: 2439 entries
[task 2022-05-10T08:53:46.278Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 BackstagePass
[task 2022-05-10T08:53:46.279Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 BrowserParent
[task 2022-05-10T08:53:46.280Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 BrowsingContext
[task 2022-05-10T08:53:46.280Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 BrowsingContextGroup
[task 2022-05-10T08:53:46.281Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 BrowsingContextWebProgress
[task 2022-05-10T08:53:46.281Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 CanonicalBrowsingContext
[task 2022-05-10T08:53:46.282Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ChannelEventQueue
[task 2022-05-10T08:53:46.282Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ChannelWrapper::ChannelWrapperStub
[task 2022-05-10T08:53:46.283Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ChildSHistory
[task 2022-05-10T08:53:46.284Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 8 CondVar
[task 2022-05-10T08:53:46.289Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ConsoleReportCollector
[task 2022-05-10T08:53:46.290Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ContentParent
[task 2022-05-10T08:53:46.291Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 CookieJarSettings
[task 2022-05-10T08:53:46.291Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 CookieService
[task 2022-05-10T08:53:46.292Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 DataStorage
[task 2022-05-10T08:53:46.292Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ExpirationTrackerObserver
[task 2022-05-10T08:53:46.293Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 HttpBaseChannel
[task 2022-05-10T08:53:46.293Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 HttpChannelParent
[task 2022-05-10T08:53:46.294Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 JS Object
[task 2022-05-10T08:53:46.295Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 LoadContext
[task 2022-05-10T08:53:46.295Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 LoadInfo
[task 2022-05-10T08:53:46.296Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 21 Mutex
[task 2022-05-10T08:53:46.296Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 PBrowserParent
[task 2022-05-10T08:53:46.297Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 PContentParent
[task 2022-05-10T08:53:46.298Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 PHttpChannelParent
[task 2022-05-10T08:53:46.298Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ParentChannelListener
[task 2022-05-10T08:53:46.299Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 Permission
[task 2022-05-10T08:53:46.299Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 PollableEvent
[task 2022-05-10T08:53:46.300Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ReentrantMonitor
[task 2022-05-10T08:53:46.300Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 RefCountedMonitor
[task 2022-05-10T08:53:46.301Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ReferrerInfo
[task 2022-05-10T08:53:46.302Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 RequestContextService
[task 2022-05-10T08:53:46.302Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 SHEntrySharedParentState
[task 2022-05-10T08:53:46.303Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ServiceWorkerInterceptController
[task 2022-05-10T08:53:46.303Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 SessionHistoryEntry
[task 2022-05-10T08:53:46.304Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 TaskQueue
[task 2022-05-10T08:53:46.305Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ThirdPartyUtil
[task 2022-05-10T08:53:46.305Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ThreadEventTarget
[task 2022-05-10T08:53:46.306Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 ThreadSafeWeakReference
[task 2022-05-10T08:53:46.306Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ThreadTargetSink
[task 2022-05-10T08:53:46.307Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 ThrottledEventQueue
[task 2022-05-10T08:53:46.307Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 ThrottledEventQueue::Inner
[task 2022-05-10T08:53:46.308Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 4 WeakReference
[task 2022-05-10T08:53:46.309Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCNativeInterface
[task 2022-05-10T08:53:46.309Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCNativeMember
[task 2022-05-10T08:53:46.310Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCNativeSet
[task 2022-05-10T08:53:46.310Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCWrappedNative
[task 2022-05-10T08:53:46.311Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCWrappedNativeProto
[task 2022-05-10T08:53:46.312Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 XPCWrappedNativeTearOff
[task 2022-05-10T08:53:46.312Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 ipc::MessageChannel
[task 2022-05-10T08:53:46.313Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 mozilla::dom::HistoryEntryCounterForBr
[task 2022-05-10T08:53:46.313Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsAuthURLParser
[task 2022-05-10T08:53:46.314Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsCategoryObserver
[task 2022-05-10T08:53:46.314Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsEffectiveTLDService
[task 2022-05-10T08:53:46.315Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 nsHttpAuthCache::OriginClearObserver
[task 2022-05-10T08:53:46.316Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsHttpChannel
[task 2022-05-10T08:53:46.316Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsHttpConnectionMgr
[task 2022-05-10T08:53:46.317Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsHttpHandler
[task 2022-05-10T08:53:46.317Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsHttpRequestHead
[task 2022-05-10T08:53:46.318Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsIDNService
[task 2022-05-10T08:53:46.319Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsIOService
[task 2022-05-10T08:53:46.319Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 8 nsJSPrincipals
[task 2022-05-10T08:53:46.320Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsLayoutHistoryState
[task 2022-05-10T08:53:46.320Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 nsLocalFile
[task 2022-05-10T08:53:46.321Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 3 nsMainThreadPtrHolder<T>
[task 2022-05-10T08:53:46.322Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsNetworkLinkService
[task 2022-05-10T08:53:46.322Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsNodeWeakReference
[task 2022-05-10T08:53:46.323Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsObserverService
[task 2022-05-10T08:53:46.324Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsPrefBranch
[task 2022-05-10T08:53:46.324Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 2 nsRedirectHistoryEntry
[task 2022-05-10T08:53:46.325Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsSHistory
[task 2022-05-10T08:53:46.325Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsSecureBrowserUI
[task 2022-05-10T08:53:46.326Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsSiteSecurityService
[task 2022-05-10T08:53:46.327Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsSocketTransportService
[task 2022-05-10T08:53:46.327Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 14 nsStandardURL
[task 2022-05-10T08:53:46.328Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 158 nsStringBuffer
[task 2022-05-10T08:53:46.328Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsThread
[task 2022-05-10T08:53:46.329Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 1 nsVariant
[task 2022-05-10T08:53:46.330Z] 08:53:46     INFO - TEST-INFO | leakcheck | default leaked 12 nsWeakReference
[task 2022-05-10T08:53:46.332Z] 08:53:46     INFO - TEST-UNEXPECTED-FAIL | leakcheck | default 30600 bytes leaked (BackstagePass, BrowserParent, BrowsingContext, BrowsingContextGroup, BrowsingContextWebProgress, ...)
[task 2022-05-10T08:53:46.332Z] 08:53:46     INFO - 
[task 2022-05-10T08:53:46.333Z] 08:53:46     INFO - leakcheck | Processing leak log file /tmp/tmped5ukwii.mozrunner/runtests_leaks_tab_pid18837.log
[task 2022-05-10T08:53:46.333Z] 08:53:46     INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2022-05-10T08:53:46.334Z] 08:53:46     INFO - leakcheck | Processing leak log file /tmp/tmped5ukwii.mozrunner/runtests_leaks_tab_pid16812.log
[task 2022-05-10T08:53:46.335Z] 08:53:46     INFO - TEST-PASS | leakcheck | tab no leaks detected!

Hi Hsin-Yi, could you please take another look into this?
Thank you.

Flags: needinfo?(htsai)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

I tried to look at the reports from April to May.

In April, 15 out of 50 failures were on mochitest-browser-chrome-spi-nw-fis-e10s. In May, 6 out of 56 fell into this suite. And in the log, there were "leaked URLs".
Leaked URLs:
[task 2022-04-28T09:19:52.301Z] 09:19:52 INFO - GECKO(8838) | https://example.com/
[task 2022-04-28T09:19:52.301Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-04-28T09:19:52.302Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.302Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.303Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.303Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.303Z] 09:19:52 INFO - GECKO(8838) | https://example.com/
[task 2022-04-28T09:19:52.304Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.304Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-04-28T09:19:52.304Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.305Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty.js
[task 2022-04-28T09:19:52.305Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.306Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html
[task 2022-04-28T09:19:52.306Z] 09:19:52 INFO - GECKO(8838) | https://example.com/browser/dom/serviceworkers/test/empty_with_utils.html

In May so far, 21 out of 56 failures were on "mochitest-browser-chrome-swr-nofis-e10s". In several logs, I saw the console error:
Console message: [JavaScript Error: "Invalid ETag value "undefined"" {file: "resource://services-settings/SyncHistory.jsm" line: 50}]
[task 2022-05-10T01:39:41.207Z] 01:39:41 INFO - store@resource://services-settings/SyncHistory.jsm:50:13

In May, 18 out of 56 failures were on "mochitest-browser-chrome-spi-nw-nofis-e10s". I wasn't able to see obvious errors.

Andrew, I am not sure if the above information is relevant or not, but it looks there could be various underlying causes. Could you help take a further look? Thank you.

Flags: needinfo?(htsai) → needinfo?(continuation)

nsSHistories are kept in a linked list. When we leak one, we hit
a linked list assertion. This patch works around that by adding
a helper that removes everything from the list before it is
destroyed. We'll still have test failures, but they'll be in
the leak checker, which is hopefully more informative.

Assignee: nobody → continuation
Status: NEW → ASSIGNED

I tested my patch by leaking every nsSHistory and then running some Mochitests. (My initial patch didn't work...)

Flags: needinfo?(continuation)

Given that the test failures are in service worker directories, I suspect that these failures will turn into one of the RemoteWorker leaks, like bug 1749068, as those are very frequent. But at least with my patch we'll be able to see what is leaking.

Pushed by amccreight@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/68895ba20051 Don't assert when we leak nsSHistories. r=peterv
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 102 Branch

This could be backported if necessary, as it is debug-only, but I don't see any failures outside of m-c and autoland in the last 30 days, so it doesn't seem necessary for now.

The last failure should have been starred with bug 1745864.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: