Open Bug 1548163 Opened 6 years ago Updated 2 years ago

Assertion failure: isEmpty() in ~GlobalHelperThreadState (LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction)

Categories

(Core :: MFBT, defect)

Product:
Core
Component:
MFBT
Type:
defect

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell unknown])

Filed by: ccoroiu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=243751117&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/fZcmPwQcR-CE3DZQI9KC0g/runs/0/artifacts/public/logs/live_backing.log

[task 2019-04-30T22:08:50.531Z] 22:08:50 INFO - TEST-START | devtools/client/debugger/test/mochitest/browser_dbg-worker-scopes.js

task 2019-04-30T22:08:59.641Z] 22:08:59 INFO - GECKO(1067) | [ACTION] SET_FOCUSED_SOURCE_ITEM - {}
[task 2019-04-30T22:08:59.642Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found live SharedScriptData 0x7f9c7cbdbc00 with ref count 2 at shutdown
[task 2019-04-30T22:08:59.643Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found live SharedScriptData 0x7f9c7cbe2400 with ref count 2 at shutdown
[task 2019-04-30T22:08:59.644Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found live SharedScriptData 0x7f9c7d08b190 with ref count 2 at shutdown
[task 2019-04-30T22:08:59.645Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found live SharedScriptData 0x7f9c7c0ece20 with ref count 2 at shutdown
[task 2019-04-30T22:08:59.645Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found live SharedScriptData 0x7f9c7f302cc0 with ref count 2 at shutdown
[task 2019-04-30T22:08:59.646Z] 22:08:59 INFO - GECKO(1067) | ERROR: GC found 208 live SharedScriptData at shutdown
[task 2019-04-30T22:08:59.648Z] 22:08:59 INFO - GECKO(1067) | Assertion failure: isEmpty() (failing this assertion means this LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/LinkedList.h:433
[task 2019-04-30T22:08:59.649Z] 22:08:59 INFO - GECKO(1067) | [ACTION] SET_FOCUSED_SOURCE_ITEM - {}
[task 2019-04-30T22:08:59.812Z] 22:08:59 INFO - GECKO(1067) | [Parent 1067, Main Thread] WARNING: Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out!: '!nsContentUtils::IsChromeDoc(d)', file /builds/worker/workspace/build/src/dom/events/EventListenerManager.cpp, line 351
[task 2019-04-30T22:08:59.812Z] 22:08:59 INFO - GECKO(1067) | [Parent 1067, Main Thread] WARNING: Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out!: '!nsContentUtils::IsChromeDoc(d)', file /builds/worker/workspace/build/src/dom/events/EventListenerManager.cpp, line 351
[task 2019-04-30T22:08:59.829Z] 22:08:59 INFO - GECKO(1067) | [ACTION] SET_VIEWPORT - {"type":"SET_VIEWPORT","viewport":{"start":{"line":0,"column":0},"end":{"line":1,"column":92}}}
[task 2019-04-30T22:09:00.073Z] 22:09:00 INFO - GECKO(1067) | [ACTION] SET_VIEWPORT - {"type":"SET_VIEWPORT","viewport":{"start":{"line":3,"column":0},"end":{"line":14,"column":91}}}
[task 2019-04-30T22:09:00.152Z] 22:09:00 INFO - GECKO(1067) | [Parent 1067, Main Thread] ###!!! ASSERTION: Unexpected UpdateTransformLayer hint: '!(aChange & nsChangeHint_UpdateTransformLayer) || nsLayoutUtils::GetPrimaryFrameFromStyleFrame(aFrame) ->IsTransformed() || aFrame->StyleDisplay()->HasTransformStyle()', file /builds/worker/workspace/build/src/layout/base/RestyleManager.cpp, line 1200
[task 2019-04-30T22:09:00.154Z] 22:09:00 INFO - GECKO(1067) | #01: mozilla::RestyleManager::DoProcessPendingRestyles(mozilla::ServoTraversalFlags) [xpcom/ds/nsTArray.h:347]
[task 2019-04-30T22:09:00.154Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.156Z] 22:09:00 INFO - GECKO(1067) | #02: mozilla::PresShell::DoFlushPendingNotifications(mozilla::ChangesToFlush) [layout/base/PresShell.cpp:4160]
[task 2019-04-30T22:09:00.157Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.158Z] 22:09:00 INFO - GECKO(1067) | #03: mozilla::dom::Document::FlushPendingNotifications(mozilla::ChangesToFlush) [dom/base/Document.cpp:7341]
[task 2019-04-30T22:09:00.159Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.160Z] 22:09:00 INFO - GECKO(1067) | #04: nsIContent::GetPrimaryFrame(mozilla::FlushType) [dom/base/Element.cpp:231]
[task 2019-04-30T22:09:00.161Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.162Z] 22:09:00 INFO - GECKO(1067) | #05: mozilla::dom::Element::GetBoundingClientRect() [dom/base/Element.cpp:1032]
[task 2019-04-30T22:09:00.163Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.164Z] 22:09:00 INFO - GECKO(1067) | #06: mozilla::dom::Element_Binding::getBoundingClientRect(JSContext*, JS::Handle<JSObject*>, mozilla::dom::Element*, JSJitMethodCallArgs const&) [s3:gecko-generated-sources:64e0714a7dfd23af47026e78df788aadcbb64ee2f9c2cb7fed8716118fade166de45f305a246d7da1b12963e237a2b0c2a8934de4d26a6d37653e8c1476d322b/dom/bindings/ElementBinding.cpp::3015]
[task 2019-04-30T22:09:00.165Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.166Z] 22:09:00 INFO - GECKO(1067) | #07: bool mozilla::dom::binding_detail::GenericMethod<mozilla::dom::binding_detail::NormalThisPolicy, mozilla::dom::binding_detail::ThrowExceptions>(JSContext*, unsigned int, JS::Value*) [dom/bindings/BindingUtils.cpp:3155]
[task 2019-04-30T22:09:00.168Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.169Z] 22:09:00 INFO - GECKO(1067) | #08: CallJSNative(JSContext*, bool ()(JSContext, unsigned int, JS::Value*), JS::CallArgs const&) [js/src/vm/Interpreter.cpp:443]
[task 2019-04-30T22:09:00.170Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.171Z] 22:09:00 INFO - GECKO(1067) | #09: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) [js/src/vm/Interpreter.cpp:535]
[task 2019-04-30T22:09:00.174Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.176Z] 22:09:00 INFO - GECKO(1067) | #10: Interpret(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:3080]
[task 2019-04-30T22:09:00.177Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.178Z] 22:09:00 INFO - GECKO(1067) | #11: js::RunScript(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:423]
[task 2019-04-30T22:09:00.178Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.180Z] 22:09:00 INFO - GECKO(1067) | #12: js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) [js/src/vm/Interpreter.cpp:563]
[task 2019-04-30T22:09:00.181Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.182Z] 22:09:00 INFO - GECKO(1067) | #13: <name omitted> [js/src/vm/Interpreter.cpp:606]
[task 2019-04-30T22:09:00.183Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.184Z] 22:09:00 INFO - GECKO(1067) | #14: js::jit::InvokeFunction(JSContext*, JS::Handle<JSObject*>, bool, bool, unsigned int, JS::Value*, JS::MutableHandle<JS::Value>) [js/src/jit/VMFunctions.cpp:259]
[task 2019-04-30T22:09:00.185Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.186Z] 22:09:00 INFO - GECKO(1067) | #15: js::jit::InvokeFromInterpreterStub(JSContext*, js::jit::InterpreterStubExitFrameLayout*) [js/src/jit/VMFunctions.cpp:288]
[task 2019-04-30T22:09:00.187Z] 22:09:00 INFO -
[task 2019-04-30T22:09:00.188Z] 22:09:00 INFO - GECKO(1067) | #16: ??? (???:???)

I have done some retriggers:
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cserviceworker%2Credesign%2Ctest-linux64%2Fdebug-mochitest-devtools-chrome-sw-e10s-10%2Cm-sw%28dt10%29&tochange=1c79adcd8483d038b94b6690c65a6f868132733d&fromchange=72e61b1971a31a562b9dde08c122c44992d70474&selectedJob=243760418

Since this push https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cserviceworker%2Credesign%2Ctest-linux64%2Fdebug-mochitest-devtools-chrome-sw-e10s-10%2Cm-sw%28dt10%29&revision=05e9997b6809900677149992d3a5634ae43b3a11&selectedJob=243751117 the assertion is:
Assertion failure: isEmpty() (failing this assertion means this LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/LinkedList.h:433

Log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=243751117&repo=autoland&lineNumber=19897

Before Yulia's push, was Assertion failure: m_refCount == 1, at /builds/worker/workspace/build/src/js/src/jit/ExecutableAllocator.cpp:49

Log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=243664817&repo=autoland&lineNumber=19843

Yulia, can you please take a look at this? It's frequently failing.

Flags: needinfo?(ystartsev)
Regressed by: 1265637
Whiteboard: [stockwell needswork:owner]

It looks like the migration to use the longStringFront is what caused this to appear -- but it doesn't seem to be the cause of the GC problem. We are just allocating objects. I think this might be related to #1546170 which is also affecting the devtools test suite. :mccr8 -- do you have any idea what might be going on here?

Flags: needinfo?(continuation)

When you leak JS stuff, as the log looks like it is doing, then the JS engine tends to assert. But yeah, "Assertion failure: m_refCount == 1" also looks like an assertion you'd hit when you leak. It looks like bug 1456013 could be the previous incarnation of this leak, before your patch caused the assertion to change for whatever reason. In that bug, they disabled a test, and in fact this assertion failure seems to have only happened a few times since 5/1.

Flags: needinfo?(continuation)
See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1456013

There are 42 total failures in the last 7 days on windows10-64, windows10-64-ccov, windows10-64-qr and windows10-64-mingwclang all debug builds

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

[task 2019-11-03T07:50:20.238Z] 07:50:20 INFO - TEST-START | browser/base/content/test/siteIdentity/browser_secure_transport_insecure_scheme.js
[task 2019-11-03T07:50:20.239Z] 07:50:20 INFO - GECKO(1908) | --DOCSHELL 0x7f5e1d481800 == 0 [pid = 4632] [id = {26d1813c-0fdb-4687-a86b-354c0d7f62a3}] [url = http://example.com/browser/browser/base/content/test/siteIdentity/test_no_mcb_on_http_site_font2.html]
[task 2019-11-03T07:50:20.308Z] 07:50:20 INFO - GECKO(1908) | --DOMWINDOW == 4 (0x7f5e1d4ab000) [pid = 4632] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:20.310Z] 07:50:20 INFO - GECKO(1908) | --DOMWINDOW == 3 (0x7f5e1dd02f20) [pid = 4632] [serial = 1] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/siteIdentity/test_no_mcb_on_http_site_font2.html]
[task 2019-11-03T07:50:20.310Z] 07:50:20 INFO - GECKO(1908) | --DOMWINDOW == 2 (0x7f5e1e254800) [pid = 4632] [serial = 5] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/siteIdentity/test_no_mcb_on_http_site_font2.html]
[task 2019-11-03T07:50:20.311Z] 07:50:20 INFO - GECKO(1908) | --DOMWINDOW == 1 (0x7f5e1e4e3c00) [pid = 4632] [serial = 4] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/siteIdentity/test_no_mcb_on_http_site_font.html]
[task 2019-11-03T07:50:20.312Z] 07:50:20 INFO - GECKO(1908) | --DOMWINDOW == 0 (0x7f5e1e4e9800) [pid = 4632] [serial = 3] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/siteIdentity/test_no_mcb_on_http_site_img.html]
[task 2019-11-03T07:50:20.353Z] 07:50:20 INFO - GECKO(1908) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp11RlBH.mozrunner/runtests_leaks_tab_pid4659.log
[task 2019-11-03T07:50:20.373Z] 07:50:20 INFO - GECKO(1908) | nsStringStats
[task 2019-11-03T07:50:20.374Z] 07:50:20 INFO - GECKO(1908) | => mAllocCount: 9197
[task 2019-11-03T07:50:20.374Z] 07:50:20 INFO - GECKO(1908) | => mReallocCount: 0
[task 2019-11-03T07:50:20.374Z] 07:50:20 INFO - GECKO(1908) | => mFreeCount: 9197
[task 2019-11-03T07:50:20.375Z] 07:50:20 INFO - GECKO(1908) | => mShareCount: 9622
[task 2019-11-03T07:50:20.375Z] 07:50:20 INFO - GECKO(1908) | => mAdoptCount: 399
[task 2019-11-03T07:50:20.376Z] 07:50:20 INFO - GECKO(1908) | => mAdoptFreeCount: 411
[task 2019-11-03T07:50:20.376Z] 07:50:20 INFO - GECKO(1908) | => Process ID: 4632, Thread ID: 140042648807232
[task 2019-11-03T07:50:20.393Z] 07:50:20 INFO - GECKO(1908) | [Child 4659, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729
[task 2019-11-03T07:50:20.497Z] 07:50:20 INFO - GECKO(1908) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-11-03T07:50:20.630Z] 07:50:20 INFO - GECKO(1908) | [Child 4659, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1787
[task 2019-11-03T07:50:20.633Z] 07:50:20 INFO - GECKO(1908) | ++DOCSHELL 0x7f2cb2582800 == 1 [pid = 4659] [id = {bed284ed-4349-44db-901c-7a346d76658b}]
[task 2019-11-03T07:50:20.674Z] 07:50:20 INFO - GECKO(1908) | ++DOMWINDOW == 1 (0x7f2cb3302f20) [pid = 4659] [serial = 1] [outer = (nil)]
[task 2019-11-03T07:50:20.674Z] 07:50:20 INFO - GECKO(1908) | ++DOMWINDOW == 2 (0x7f2cb2506400) [pid = 4659] [serial = 2] [outer = 0x7f2cb3302f20]
[task 2019-11-03T07:50:20.795Z] 07:50:20 INFO - GECKO(1908) | ++DOMWINDOW == 3 (0x7f2cb350c800) [pid = 4659] [serial = 3] [outer = 0x7f2cb3302f20]
[task 2019-11-03T07:50:20.956Z] 07:50:20 INFO - GECKO(1908) | ++DOMWINDOW == 4 (0x7f2cb36b1400) [pid = 4659] [serial = 4] [outer = 0x7f2cb3302f20]
[task 2019-11-03T07:50:20.964Z] 07:50:20 INFO - GECKO(1908) | [Child 4659, Main Thread] WARNING: Failed to retarget HTML data delivery to the parser thread.: file /builds/worker/workspace/build/src/parser/html/nsHtml5StreamParser.cpp, line 1142
[task 2019-11-03T07:50:21.069Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 4 (0x7f2472c95800) [pid = 2072] [serial = 28] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.089Z] 07:50:21 INFO - GECKO(1908) | --DOCSHELL 0x7f2471c7c800 == 0 [pid = 2072] [id = {7095e4c0-f602-4085-b4a2-cc5b39039b4b}] [url = about:blank]
[task 2019-11-03T07:50:21.125Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 3 (0x7f2472bbb6a0) [pid = 2072] [serial = 29] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.185Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: devtools/client/shared/vendor/react
[task 2019-11-03T07:50:21.189Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.190Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: devtools/client/shared/vendor/react-prop-types
[task 2019-11-03T07:50:21.191Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.192Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: components/JsonPanel
[task 2019-11-03T07:50:21.192Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.200Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: components/TextPanel
[task 2019-11-03T07:50:21.200Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.200Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: components/HeadersPanel
[task 2019-11-03T07:50:21.200Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.200Z] 07:50:21 INFO - GECKO(1908) | JavaScript error: resource://devtools-client-jsonview/lib/require.js, line 170: Error: Script error for: devtools/client/shared/components/tabs/Tabs
[task 2019-11-03T07:50:21.201Z] 07:50:21 INFO - GECKO(1908) | http://requirejs.org/docs/errors.html#scripterror
[task 2019-11-03T07:50:21.285Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] WARNING: Called GetMainThread but there isn't a main thread and we're not the main thread.: file /builds/worker/workspace/build/src/xpcom/threads/nsThreadManager.cpp, line 543
[task 2019-11-03T07:50:21.285Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp, line 241
[task 2019-11-03T07:50:21.286Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] ###!!! ASSERTION: Failed NS_DispatchToMainThread() in shutdown; leaking: 'false', file /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp, line 243
[task 2019-11-03T07:50:21.286Z] 07:50:21 INFO - GECKO(1908) | #01: mozilla::SchedulerGroup::InternalUnlabeledDispatch(mozilla::TaskCategory, already_AddRefed<mozilla::SchedulerGroup::Runnable>&&) [xpcom/threads/SchedulerGroup.cpp:237]
[task 2019-11-03T07:50:21.286Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.286Z] 07:50:21 INFO - GECKO(1908) | #02: mozilla::SchedulerGroup::LabeledDispatch(mozilla::TaskCategory, already_AddRefed<nsIRunnable>&&, mozilla::dom::DocGroup*) [xpcom/threads/SchedulerGroup.cpp:222]
[task 2019-11-03T07:50:21.287Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.287Z] 07:50:21 INFO - GECKO(1908) | #03: mozilla::dom::OffThreadScriptLoaderCallback(JS::OffThreadToken*, void*) [dom/script/ScriptLoader.cpp:2034]
[task 2019-11-03T07:50:21.287Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.288Z] 07:50:21 INFO - GECKO(1908) | #04: js::HelperThread::handleParseWorkload(js::AutoLockHelperThreadState&) [js/src/vm/HelperThreads.cpp:2359]
[task 2019-11-03T07:50:21.289Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.290Z] 07:50:21 INFO - GECKO(1908) | #05: js::HelperThread::threadLoop() [js/src/vm/HelperThreads.cpp:2645]
[task 2019-11-03T07:50:21.291Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.291Z] 07:50:21 INFO - GECKO(1908) | #06: js::detail::ThreadTrampoline<void (&)(void*), js::HelperThread*>::Start(void*) [js/src/threading/Thread.h:200]
[task 2019-11-03T07:50:21.292Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.293Z] 07:50:21 INFO - GECKO(1908) | #07: libpthread.so.0 + 0x76ba
[task 2019-11-03T07:50:21.293Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.295Z] 07:50:21 INFO - GECKO(1908) | #08: libc.so.6 + 0x10741d
[task 2019-11-03T07:50:21.295Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.295Z] 07:50:21 INFO - GECKO(1908) | #09: ??? (???:???)
[task 2019-11-03T07:50:21.296Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] WARNING: Called GetMainThread but there isn't a main thread and we're not the main thread.: file /builds/worker/workspace/build/src/xpcom/threads/nsThreadManager.cpp, line 543
[task 2019-11-03T07:50:21.296Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp, line 241
[task 2019-11-03T07:50:21.296Z] 07:50:21 INFO - GECKO(1908) | [Child 4659, JS Helper] ###!!! ASSERTION: Failed NS_DispatchToMainThread() in shutdown; leaking: 'false', file /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp, line 243
[task 2019-11-03T07:50:21.297Z] 07:50:21 INFO - GECKO(1908) | #01: mozilla::SchedulerGroup::InternalUnlabeledDispatch(mozilla::TaskCategory, already_AddRefed<mozilla::SchedulerGroup::Runnable>&&) [xpcom/threads/SchedulerGroup.cpp:237]
[task 2019-11-03T07:50:21.297Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.298Z] 07:50:21 INFO - GECKO(1908) | #02: mozilla::SchedulerGroup::LabeledDispatch(mozilla::TaskCategory, already_AddRefed<nsIRunnable>&&, mozilla::dom::DocGroup*) [xpcom/threads/SchedulerGroup.cpp:222]
[task 2019-11-03T07:50:21.299Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.299Z] 07:50:21 INFO - GECKO(1908) | #03: mozilla::dom::OffThreadScriptLoaderCallback(JS::OffThreadToken*, void*) [dom/script/ScriptLoader.cpp:2034]
[task 2019-11-03T07:50:21.300Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.300Z] 07:50:21 INFO - GECKO(1908) | #04: js::HelperThread::handleParseWorkload(js::AutoLockHelperThreadState&) [js/src/vm/HelperThreads.cpp:2359]
[task 2019-11-03T07:50:21.301Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.302Z] 07:50:21 INFO - GECKO(1908) | #05: js::HelperThread::threadLoop() [js/src/vm/HelperThreads.cpp:2645]
[task 2019-11-03T07:50:21.302Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.307Z] 07:50:21 INFO - GECKO(1908) | #06: js::detail::ThreadTrampoline<void (&)(void*), js::HelperThread*>::Start(void*) [js/src/threading/Thread.h:200]
[task 2019-11-03T07:50:21.308Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.311Z] 07:50:21 INFO - GECKO(1908) | #07: libpthread.so.0 + 0x76ba
[task 2019-11-03T07:50:21.311Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.312Z] 07:50:21 INFO - GECKO(1908) | #08: libc.so.6 + 0x10741d
[task 2019-11-03T07:50:21.312Z] 07:50:21 INFO -
[task 2019-11-03T07:50:21.313Z] 07:50:21 INFO - GECKO(1908) | #09: ??? (???:???)
[task 2019-11-03T07:50:21.416Z] 07:50:21 INFO - GECKO(1908) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp11RlBH.mozrunner/runtests_leaks_tab_pid4693.log
[task 2019-11-03T07:50:21.452Z] 07:50:21 INFO - GECKO(1908) | [Child 4693, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729
[task 2019-11-03T07:50:21.488Z] 07:50:21 INFO - GECKO(1908) | --DOCSHELL 0x7f2cb2582800 == 0 [pid = 4659] [id = {bed284ed-4349-44db-901c-7a346d76658b}] [url = blob:null/92074c09-a3f6-4b19-81e4-8097ae70d886]
[task 2019-11-03T07:50:21.564Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 3 (0x7f2cb2506400) [pid = 4659] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.565Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 2 (0x7f2cb350c800) [pid = 4659] [serial = 3] [outer = (nil)] [url = https://example.com/browser/browser/base/content/test/siteIdentity/dummy_page.html]
[task 2019-11-03T07:50:21.587Z] 07:50:21 INFO - GECKO(1908) | WARNING: YOU ARE LEAKING THE WORLD (at least one JSRuntime and everything alive inside it, that is) AT JS_ShutDown TIME. FIX THIS!
[task 2019-11-03T07:50:21.587Z] 07:50:21 INFO - GECKO(1908) | Assertion failure: isEmpty() (failing this assertion means this LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/LinkedList.h:433
[task 2019-11-03T07:50:21.651Z] 07:50:21 INFO - GECKO(1908) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-11-03T07:50:21.788Z] 07:50:21 INFO - GECKO(1908) | --DOCSHELL 0x7f5ab8d2a000 == 2 [pid = 2039] [id = {0fbc2962-78d2-42ad-933b-f4a1868a526d}] [url = about:blank]
[task 2019-11-03T07:50:21.795Z] 07:50:21 INFO - GECKO(1908) | [Child 4693, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1787
[task 2019-11-03T07:50:21.811Z] 07:50:21 INFO - GECKO(1908) | ++DOCSHELL 0x7f1fb6981000 == 1 [pid = 4693] [id = {4f842b72-91ed-4624-ab57-bc9451d4ef96}]
[task 2019-11-03T07:50:21.812Z] 07:50:21 INFO - GECKO(1908) | --DOCSHELL 0x7f5ab8d27000 == 1 [pid = 2039] [id = {f3fdaaf4-6a91-4ad9-a577-b8d9bf18117a}] [url = about:blank]
[task 2019-11-03T07:50:21.867Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 8 (0x7f5abc8807a0) [pid = 2039] [serial = 36] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.869Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 7 (0x7f5abc880980) [pid = 2039] [serial = 38] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.870Z] 07:50:21 INFO - GECKO(1908) | --DOMWINDOW == 6 (0x7f5abc8816a0) [pid = 2039] [serial = 40] [outer = (nil)] [url = about:blank]
[task 2019-11-03T07:50:21.871Z] 07:50:21 INFO - GECKO(1908) | ++DOMWINDOW == 1 (0x7f1fb79bdf20) [pid = 4693] [serial = 1] [outer = (nil)]
[task 2019-11-03T07:50:21.872Z] 07:50:21 INFO - GECKO(1908) | ++DOMWINDOW == 2 (0x7f1fb69ab000) [pid = 4693] [serial = 2] [outer = 0x7f1fb79bdf20]
[task 2019-11-03T07:50:22.040Z] 07:50:22 INFO - GECKO(1908) | ++DOMWINDOW == 3 (0x7f1fb77f0c00) [pid = 4693] [serial = 3] [outer = 0x7f1fb79bdf20]
[task 2019-11-03T07:50:22.229Z] 07:50:22 INFO - GECKO(1908) | MEMORY STAT | vsize 3190MB | residentFast 384MB | heapAllocated 138MB
[task 2019-11-03T07:50:22.231Z] 07:50:22 INFO - TEST-OK | browser/base/content/test/siteIdentity/browser_secure_transport_insecure_scheme.js | took 1995ms

Steven, can you assign someone to take a look?

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

Jason, do you have any thoughts of what to do with this? Is this a JavaScript Engine bug?

Flags: needinfo?(sdetar) → needinfo?(jorendorff)

When I looked at this before, the failures were in devtools, and it looked like they were a sign of a leak. Some of these seem to also maybe be the sign of a leak, like the one in comment 31, but the most common variant appears to also include a number of reftest failures:

13:55:20 INFO - REFTEST TEST-UNEXPECTED-FAIL | http://localhost:50112/1572961033320/139/579808-1.html == http://localhost:50112/1572961033320/139/579808-1-ref.html | image comparison, max difference: 255, number of differing pixels: 40000
19382 13:55:42 INFO - REFTEST TEST-UNEXPECTED-FAIL | http://localhost:50112/1572961033386/140/599476.html == http://localhost:50112/1572961033386/140/599476-ref.html | image comparison, max difference: 255, number of differing pixels: 20000
19936 13:56:16 INFO - REFTEST TEST-UNEXPECTED-FAIL | http://localhost:50112/1572961033491/141/632423-1.html == http://localhost:50112/1572961033491/141/632423-1-ref.html | image comparison, max difference: 255, number of differing pixels: 79223

Specifically in those tests.

Then for the actual isEmpty() assertion there's some weirdness going on. Most of them are unsymbolicated, but I found one that was symbolicated:

[task 2019-11-01T10:05:19.222Z] 10:05:19 INFO - Assertion failure: isEmpty() (failing this assertion means this LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/LinkedList.h:433
[task 2019-11-01T10:05:19.223Z] 10:05:19 INFO - #01: RtlActivateActivationContextUnsafeFast[C:\Windows\SYSTEM32\ntdll.dll +0x34053]
[task 2019-11-01T10:05:19.225Z] 10:05:19 INFO - #02: RtlActivateActivationContextUnsafeFast[C:\Windows\SYSTEM32\ntdll.dll +0x3414f]
[task 2019-11-01T10:05:19.225Z] 10:05:19 INFO - #03: LdrShutdownProcess[C:\Windows\SYSTEM32\ntdll.dll +0x409f0]
[task 2019-11-01T10:05:19.226Z] 10:05:19 INFO - #04: RtlExitUserProcess[C:\Windows\SYSTEM32\ntdll.dll +0x408c8]
[task 2019-11-01T10:05:19.226Z] 10:05:19 INFO - #05: FatalExit[C:\Windows\System32\KERNEL32.DLL +0x1b19a]

I guess we're exiting the process and maybe calling the dtors on static variables, and one of them is a linked list?

Flags: needinfo?(jorendorff)

Here's the log that actually has symbols: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=274046464&repo=autoland&lineNumber=31938

Nathan, any ideas?

I guess I'll move this over to XPCOM for the latest rash of problems, but the actual issue is likely to do with whatever is using a linked list, rather than the linked list itself.

Component: JavaScript Engine → XPCOM
Flags: needinfo?(nfroyd)

I suppose LinkedList is in MFBT, not XPCOM.

Component: XPCOM → MFBT

I would expect that the real issue here is a Windows-specific issue related to how we are exiting processes in debug builds, rather than something about this assertion in particular.

INFO - #06: exit[C:\Windows\System32\ucrtbase.dll +0x13828]
INFO - #07: exit[C:\Windows\System32\ucrtbase.dll +0x137db]
INFO - #08: Ordinal0[Z:\task_1572601650\build\application\firefox\plugin-container.exe +0x1443]
INFO - #09: Ordinal0[Z:\task_1572601650\build\application\firefox\plugin-container.exe +0x146b]
INFO - #10: BaseThreadInitThunk[C:\Windows\System32\KERNEL32.DLL +0x13034]
INFO - #11: RtlUserThreadStart[C:\Windows\SYSTEM32\ntdll.dll +0x71461]

It would be nice to know what those Ordinal0 frames are. Unfortunately, the mingw builds don't appear to build crashsymbols (??); the symbols .zip is an empty 22 byte archive. So we have no information on that front. I'm guessing that we're running static destructors (?) and then we're asserting when the linked list is destroyed (?). Unfortunately, there are a number of static linked lists that might be candidates. :(

Flags: needinfo?(nfroyd)

Yeah, I was trying to figure out if you could jam #T into the assertion name, but I didn't see anything easier to do than the MOZ_DECLARE_WEAKREFERENCE_TYPENAME approach. In general, though, I don't think that knowing the name of the class will be too useful. We're always going to leak if we exit immediately, so in debug builds that will always assert. A crude regexp search finds 8 places we have a linked list in a static variable.

Wasn't there something about using _exit() instead of exit() so that we don't run dtors? I don't remember the specifics.

This isEmpty() assertion failure is rather generic, but the two assertion failures from last week are both in js::GlobalHelperThreadState::~GlobalHelperThreadState(), so I'll move this bug to the JavaScript component.

Crash reason: SIGSEGV /SEGV_MAPERR
Crash address: 0x0
Process uptime: not available

Thread 0 (crashed)
0 libxul.so!js::GlobalHelperThreadState::~GlobalHelperThreadState() [HelperThreads.h:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 82 + 0x1e8]
1 libxul.so!JS_ShutDown() [Initialization.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 218 + 0x25]
2 libxul.so!mozilla::ShutdownXPCOM(nsIServiceManager*) [XPCOMInit.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 736 + 0x5]
3 libxul.so!XRE_TermEmbedding() [nsEmbedFunctions.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 225 + 0x7]
4 libxul.so!mozilla::ipc::ScopedXREEmbed::Stop() [ScopedXREEmbed.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 90 + 0x5]
5 libxul.so!XRE_InitChildProcess(int, char**, XREChildData const*) [nsEmbedFunctions.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 765 + 0xe]
6 firefox-bin!content_process_main(mozilla::Bootstrap*, int, char**) [plugin-container.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 56 + 0x11]
7 firefox-bin!main [nsBrowserApp.cpp:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 303 + 0x20]
8 libc-2.27.so + 0x21b97
9 firefox-bin!<name omitted> [UniquePtr.h:6d7fafa57a83a61ea4b4ffa5a6db338738918b35 : 275 + 0x17]

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=292027758&repo=autoland&lineNumber=4916

Priority: P5 → --
Summary: Assertion failure: isEmpty() (failing this assertion means this LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction), at build/src/obj-firefox/dist/include/mozilla/LinkedList.h:433 → Assertion failure: isEmpty() in ~GlobalHelperThreadState (LinkedList's creator is buggy: it should have removed all this list's elements before the list's destruction)

The failure signature here will probably change as a result of https://bugzilla.mozilla.org/show_bug.cgi?id=1661798

Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.