Open Bug 1581500 Opened 5 months ago Updated 6 days ago

Intermittent GECKO(3943) | Assertion failure: mInFlightProcessId == 0, at /builds/worker/workspace/build/src/docshell/base/CanonicalBrowsingContext.cpp:96

Categories

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

defect

Tracking

()

Fission Milestone M7

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, leave-open, regression, Whiteboard: [comment 23][stockwell disabled])

Attachments

(1 file)

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


[task 2019-09-16T08:36:33.277Z] 08:36:33 INFO - TEST-START | browser/components/urlbar/tests/browser/browser_redirect_error.js
[task 2019-09-16T08:36:33.293Z] 08:36:33 INFO - GECKO(3943) | --DOMWINDOW == 2 (0x7f40d25c6f20) [pid = 5358] [serial = 1] [outer = (nil)] [url = https://example.com/browser/browser/components/urlbar/tests/browser/dummy_page.html]
[task 2019-09-16T08:36:33.293Z] 08:36:33 INFO - GECKO(3943) | --DOMWINDOW == 1 (0x7f40d156ac00) [pid = 5358] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:33.294Z] 08:36:33 INFO - GECKO(3943) | --DOMWINDOW == 0 (0x7f40d1ebf400) [pid = 5358] [serial = 3] [outer = (nil)] [url = https://example.com/browser/browser/components/urlbar/tests/browser/dummy_page.html]
[task 2019-09-16T08:36:33.318Z] 08:36:33 INFO - GECKO(3943) | nsStringStats
[task 2019-09-16T08:36:33.319Z] 08:36:33 INFO - GECKO(3943) | => mAllocCount: 7479
[task 2019-09-16T08:36:33.319Z] 08:36:33 INFO - GECKO(3943) | => mReallocCount: 0
[task 2019-09-16T08:36:33.320Z] 08:36:33 INFO - GECKO(3943) | => mFreeCount: 7479
[task 2019-09-16T08:36:33.320Z] 08:36:33 INFO - GECKO(3943) | => mShareCount: 4757
[task 2019-09-16T08:36:33.320Z] 08:36:33 INFO - GECKO(3943) | => mAdoptCount: 394
[task 2019-09-16T08:36:33.321Z] 08:36:33 INFO - GECKO(3943) | => mAdoptFreeCount: 398
[task 2019-09-16T08:36:33.321Z] 08:36:33 INFO - GECKO(3943) | => Process ID: 5358, Thread ID: 139916818904896
[task 2019-09-16T08:36:33.376Z] 08:36:33 INFO - GECKO(3943) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpQANhnB.mozrunner/runtests_leaks_tab_pid5385.log
[task 2019-09-16T08:36:33.524Z] 08:36:33 INFO - GECKO(3943) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-16T08:36:33.660Z] 08:36:33 INFO - GECKO(3943) | [2019-09-16T08:36:33Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-16T08:36:33.661Z] 08:36:33 INFO - GECKO(3943) | [2019-09-16T08:36:33Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-16T08:36:33.681Z] 08:36:33 INFO - GECKO(3943) | ++DOCSHELL 0x7fc735db4000 == 1 [pid = 5385] [id = {bd441287-4046-46a1-a0c3-387e05a1286c}]
[task 2019-09-16T08:36:33.742Z] 08:36:33 INFO - GECKO(3943) | ++DOMWINDOW == 1 (0x7fc736dc0f20) [pid = 5385] [serial = 1] [outer = (nil)]
[task 2019-09-16T08:36:33.742Z] 08:36:33 INFO - GECKO(3943) | ++DOMWINDOW == 2 (0x7fc735d3a800) [pid = 5385] [serial = 2] [outer = 0x7fc736dc0f20]
[task 2019-09-16T08:36:34.186Z] 08:36:34 INFO - GECKO(3943) | [Child 5385, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 2125
[task 2019-09-16T08:36:34.254Z] 08:36:34 INFO - GECKO(3943) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpQANhnB.mozrunner/runtests_leaks_tab_pid5407.log
[task 2019-09-16T08:36:34.456Z] 08:36:34 INFO - GECKO(3943) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-16T08:36:34.557Z] 08:36:34 INFO - GECKO(3943) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-09-16T08:36:34.636Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 10 (0x7f02196b1400) [pid = 4016] [serial = 21] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.636Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 9 (0x7f02196af400) [pid = 4016] [serial = 27] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.637Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 8 (0x7f02196ad400) [pid = 4016] [serial = 24] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.637Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 7 (0x7f021aedcc00) [pid = 4016] [serial = 22] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.637Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 6 (0x7f021b3ac800) [pid = 4016] [serial = 19] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.653Z] 08:36:34 INFO - GECKO(3943) | --DOCSHELL 0x7fc735db4000 == 0 [pid = 5385] [id = {bd441287-4046-46a1-a0c3-387e05a1286c}] [url = about:blank]
[task 2019-09-16T08:36:34.718Z] 08:36:34 INFO - GECKO(3943) | [2019-09-16T08:36:34Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-16T08:36:34.720Z] 08:36:34 INFO - GECKO(3943) | [2019-09-16T08:36:34Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-16T08:36:34.736Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 1 (0x7fc736dc0f20) [pid = 5385] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.738Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 0 (0x7fc735d3a800) [pid = 5385] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.739Z] 08:36:34 INFO - GECKO(3943) | ++DOCSHELL 0x7faba5cb7000 == 1 [pid = 5407] [id = {84b81c52-f69e-4a41-8235-729f1edef0b2}]
[task 2019-09-16T08:36:34.778Z] 08:36:34 INFO - GECKO(3943) | [Child 5385, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3361
[task 2019-09-16T08:36:34.850Z] 08:36:34 INFO - GECKO(3943) | nsStringStats
[task 2019-09-16T08:36:34.851Z] 08:36:34 INFO - GECKO(3943) | => mAllocCount: 7045
[task 2019-09-16T08:36:34.852Z] 08:36:34 INFO - GECKO(3943) | => mReallocCount: 0
[task 2019-09-16T08:36:34.852Z] 08:36:34 INFO - GECKO(3943) | => mFreeCount: 7045
[task 2019-09-16T08:36:34.853Z] 08:36:34 INFO - GECKO(3943) | => mShareCount: 4376
[task 2019-09-16T08:36:34.854Z] 08:36:34 INFO - GECKO(3943) | => mAdoptCount: 392
[task 2019-09-16T08:36:34.855Z] 08:36:34 INFO - GECKO(3943) | => mAdoptFreeCount: 396
[task 2019-09-16T08:36:34.856Z] 08:36:34 INFO - GECKO(3943) | => Process ID: 5385, Thread ID: 140494030202688
[task 2019-09-16T08:36:34.856Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 8 (0x7f2f6665c800) [pid = 4204] [serial = 41] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:34.870Z] 08:36:34 INFO - GECKO(3943) | --DOCSHELL 0x7fd461676000 == 20 [pid = 3943] [id = {ed52f80c-a521-4136-916f-b8920c3f3963}] [url = chrome://browser/content/browser.xhtml]
[task 2019-09-16T08:36:34.871Z] 08:36:34 INFO - GECKO(3943) | --DOCSHELL 0x7fd461774000 == 19 [pid = 3943] [id = {8096759e-084f-4708-ba90-5277ae956f87}] [url = chrome://browser/content/browser.xhtml]
[task 2019-09-16T08:36:34.872Z] 08:36:34 INFO - GECKO(3943) | --DOCSHELL 0x7fd46168d000 == 18 [pid = 3943] [id = {9aadd9c1-66ca-4078-8789-87c5b160746f}] [url = chrome://browser/content/browser.xhtml]
[task 2019-09-16T08:36:34.880Z] 08:36:34 INFO - GECKO(3943) | ++DOMWINDOW == 1 (0x7faba6cc4f20) [pid = 5407] [serial = 1] [outer = (nil)]
[task 2019-09-16T08:36:34.881Z] 08:36:34 INFO - GECKO(3943) | ++DOMWINDOW == 2 (0x7faba5c6a800) [pid = 5407] [serial = 2] [outer = 0x7faba6cc4f20]
[task 2019-09-16T08:36:34.948Z] 08:36:34 INFO - GECKO(3943) | --DOCSHELL 0x7fd466487000 == 17 [pid = 3943] [id = {445cfaa3-b127-456f-bc19-8842347f7115}] [url = about:blank]
[task 2019-09-16T08:36:34.963Z] 08:36:34 INFO - GECKO(3943) | --DOMWINDOW == 5 (0x7f021ae3bd40) [pid = 4016] [serial = 23] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:35.040Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 7 (0x7f2f69749020) [pid = 4204] [serial = 43] [outer = (nil)] [url = about:privatebrowsing]
[task 2019-09-16T08:36:35.040Z] 08:36:35 INFO - GECKO(3943) | --DOCSHELL 0x7f2f67709800 == 1 [pid = 4204] [id = {596064c0-c4e2-4b13-8323-6337a27a3261}] [url = about:privatebrowsing]
[task 2019-09-16T08:36:35.040Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 6 (0x7f2f69749200) [pid = 4204] [serial = 40] [outer = (nil)] [url = data:text/html,Hello]
[task 2019-09-16T08:36:35.067Z] 08:36:35 INFO - GECKO(3943) | ++DOMWINDOW == 3 (0x7faba6c0c400) [pid = 5407] [serial = 3] [outer = 0x7faba6cc4f20]
[task 2019-09-16T08:36:35.289Z] 08:36:35 INFO - GECKO(3943) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpQANhnB.mozrunner/runtests_leaks_tab_pid5429.log
[task 2019-09-16T08:36:35.437Z] 08:36:35 INFO - GECKO(3943) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-09-16T08:36:35.586Z] 08:36:35 INFO - GECKO(3943) | [2019-09-16T08:36:35Z WARN audio_thread_priority::rt_linux] Could not make thread real-time.
[task 2019-09-16T08:36:35.588Z] 08:36:35 INFO - GECKO(3943) | [2019-09-16T08:36:35Z WARN audioipc_client] Could not promote audio threads to real-time during initialization.
[task 2019-09-16T08:36:35.603Z] 08:36:35 INFO - GECKO(3943) | ++DOCSHELL 0x7fd531fb7000 == 1 [pid = 5429] [id = {69f7b932-db79-4376-9110-a4cf4ef8d644}]
[task 2019-09-16T08:36:35.660Z] 08:36:35 INFO - GECKO(3943) | ++DOMWINDOW == 1 (0x7fd532fdcf20) [pid = 5429] [serial = 1] [outer = (nil)]
[task 2019-09-16T08:36:35.660Z] 08:36:35 INFO - GECKO(3943) | ++DOMWINDOW == 2 (0x7fd531f6a800) [pid = 5429] [serial = 2] [outer = 0x7fd532fdcf20]
[task 2019-09-16T08:36:35.836Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 7 (0x7f91e7476c00) [pid = 4127] [serial = 140] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:35.837Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 6 (0x7f91e827e000) [pid = 4127] [serial = 136] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:35.852Z] 08:36:35 INFO - GECKO(3943) | --DOCSHELL 0x7f91e7cbf800 == 1 [pid = 4127] [id = {2050dbdd-2f42-4552-b9a9-905dedffde61}] [url = about:blank]
[task 2019-09-16T08:36:35.916Z] 08:36:35 INFO - GECKO(3943) | --DOCSHELL 0x7f91e74c4000 == 0 [pid = 4127] [id = {f5bb1d90-21aa-40a5-bdb0-f16a1d0b15a0}] [url = about:privatebrowsing]
[task 2019-09-16T08:36:35.916Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 5 (0x7f91e7c7e200) [pid = 4127] [serial = 137] [outer = (nil)] [url = about:blank]
[task 2019-09-16T08:36:35.916Z] 08:36:35 INFO - GECKO(3943) | --DOMWINDOW == 4 (0x7f91e7c7e020) [pid = 4127] [serial = 139] [outer = (nil)] [url = about:privatebrowsing]
[task 2019-09-16T08:36:36.234Z] 08:36:36 INFO - GECKO(3943) | [Child 5429, Main Thread] WARNING: CompleteRedirectSetup failed, HttpChannelChild already open?: file /builds/worker/workspace/build/src/netwerk/protocol/http/HttpChannelChild.cpp, line 2125
[task 2019-09-16T08:36:36.263Z] 08:36:36 INFO - GECKO(3943) | Assertion failure: mInFlightProcessId == 0, at /builds/worker/workspace/build/src/docshell/base/CanonicalBrowsingContext.cpp:96
[task 2019-09-16T08:36:36.263Z] 08:36:36 INFO - GECKO(3943) | #01: nsFrameLoader::SkipBrowsingContextDetach() [mfbt/RefPtr.h:91]
[task 2019-09-16T08:36:36.263Z] 08:36:36 INFO -
[task 2019-09-16T08:36:36.266Z] 08:36:36 INFO - GECKO(3943) | #02: nsFrameLoaderOwner::ChangeRemoteness(mozilla::dom::RemotenessOptions const&, mozilla::ErrorResult&) [dom/base/nsFrameLoaderOwner.cpp:76]
[task 2019-09-16T08:36:36.267Z] 08:36:36 INFO -
[task 2019-09-16T08:36:36.268Z] 08:36:36 INFO - GECKO(3943) | #03: mozilla::dom::XULFrameElement_Binding::changeRemoteness(JSContext*, JS::Handle<JSObject*>, mozilla::dom::XULFrameElement*, JSJitMethodCallArgs const&) [s3:gecko-generated-sources:acd92d7ef4b03943f432a062fc850e214066862f6e0e626e7aa72b419f598676a04e3953ef1946e9dbf06f1d60b00196ad9a69d0250cc2a7bb6bdbaf68826dfe/dom/bindings/XULFrameElementBinding.cpp::427]
[task 2019-09-16T08:36:36.268Z] 08:36:36 INFO -
[task 2019-09-16T08:36:36.268Z] 08:36:36 INFO - GECKO(3943) | #04: 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:3170]
[task 2019-09-16T08:36:36.268Z] 08:36:36 INFO -
[task 2019-09-16T08:36:36.269Z] 08:36:36 INFO - GECKO(3943) | #05: ??? (???:???)
[task 2019-09-16T08:36:36.270Z] 08:36:36 INFO - GECKO(3943) | [Child 5407, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/workspace/build/src/image/imgRequestProxy.cpp, line 931
[task 2019-09-16T08:36:36.270Z] 08:36:36 INFO - GECKO(3943) | [Child 5407, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/workspace/build/src/image/imgRequestProxy.cpp, line 931
[task 2019-09-16T08:36:36.286Z] 08:36:36 INFO - GECKO(3943) | ExceptionHandler::GenerateDump cloned child 5453
[task 2019-09-16T08:36:36.286Z] 08:36:36 INFO - GECKO(3943) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-09-16T08:36:36.286Z] 08:36:36 INFO - GECKO(3943) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-09-16T08:36:36.442Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.442Z] 08:36:36 INFO - GECKO(3943) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-09-16T08:36:36.442Z] 08:36:36 INFO - GECKO(3943) | [Child 4204, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-09-16T08:36:36.442Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.447Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | [Child 4016, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-09-16T08:36:36.448Z] 08:36:36 INFO - GECKO(3943) | [Child 3993, Chrome_ChildThread] WARNING: pipe error (3): Connection reset by peer: file /builds/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 358
[task 2019-09-16T08:36:36.449Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.449Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.449Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.449Z] 08:36:36 INFO - GECKO(3943) | Exiting due to channel error.
[task 2019-09-16T08:36:36.496Z] 08:36:36 INFO - TEST-INFO | Main app process: exit 11
[task 2019-09-16T08:36:36.496Z] 08:36:36 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2019-09-16T08:36:36.497Z] 08:36:36 INFO - Buffered messages logged at 08:36:35
[task 2019-09-16T08:36:36.497Z] 08:36:36 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_redirect_error.js | There is a new tab. -
[task 2019-09-16T08:36:36.503Z] 08:36:36 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_redirect_error.js | onLocationChange catches only redirected URI. -
[task 2019-09-16T08:36:36.504Z] 08:36:36 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_redirect_error.js | This is a background tab. -
[task 2019-09-16T08:36:36.504Z] 08:36:36 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_redirect_error.js | The content area is redirected. aIsSelectedTab:false -
[task 2019-09-16T08:36:36.505Z] 08:36:36 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_redirect_error.js | The URL bar shows the content URI. aIsSelectedTab:false -
[task 2019-09-16T08:36:36.505Z] 08:36:36 INFO - Buffered messages finished

Tentatively moving all bugs whose summaries mention "Fission" (or other Fission-related keywords) but are not assigned to a Fission Milestone to the "?" triage milestone.

This will generate a lot of bugmail, so you can filter your bugmail for the following UUID and delete them en masse:

0ee3c76a-bc79-4eb2-8d12-05dc0b68e732

Fission Milestone: --- → ?
Fission Milestone: ? → M4.1

In the last 7 days, there have been 63 failures on linux64 platform, debug build type.

An example of a recent log file:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=277875305&repo=mozilla-central&lineNumber=21977

And the relevant part of the log:
[task 2019-11-24T10:27:54.532Z] 10:27:54 INFO - TEST-START | browser/base/content/test/tabs/browser_new_tab_in_privilegedabout_process_pref.js

[task 2019-11-24T10:28:08.787Z] 10:28:08 INFO - GECKO(5390) | ++DOMWINDOW == 12 (0x7ff426acc400) [pid = 5880] [serial = 39] [outer = 0x7ff426a256a0]
[task 2019-11-24T10:28:09.004Z] 10:28:09 INFO - GECKO(5390) | ++DOMWINDOW == 13 (0x7ff4261d6800) [pid = 5880] [serial = 40] [outer = 0x7ff426a256a0]
[task 2019-11-24T10:28:09.089Z] 10:28:09 INFO - GECKO(5390) | Assertion failure: mInFlightProcessId == 0, at /builds/worker/workspace/build/src/docshell/base/CanonicalBrowsingContext.cpp:101
[task 2019-11-24T10:28:09.090Z] 10:28:09 INFO - GECKO(5390) | #01: nsFrameLoader::SkipBrowsingContextDetach() [mfbt/RefPtr.h:91]
[task 2019-11-24T10:28:09.090Z] 10:28:09 INFO -
[task 2019-11-24T10:28:09.091Z] 10:28:09 INFO - GECKO(5390) | #02: nsFrameLoaderOwner::ChangeRemotenessCommon(bool, nsTSubstring<char16_t> const&, std::function<void ()>&, mozilla::ErrorResult&) [dom/base/nsFrameLoaderOwner.cpp:0]
[task 2019-11-24T10:28:09.092Z] 10:28:09 INFO -
[task 2019-11-24T10:28:09.092Z] 10:28:09 INFO - GECKO(5390) | #03: nsFrameLoaderOwner::ChangeRemoteness(mozilla::dom::RemotenessOptions const&, mozilla::ErrorResult&) [dom/base/nsFrameLoaderOwner.cpp:196]
[task 2019-11-24T10:28:09.093Z] 10:28:09 INFO -
[task 2019-11-24T10:28:09.093Z] 10:28:09 INFO - GECKO(5390) | #04: mozilla::dom::XULFrameElement_Binding::changeRemoteness(JSContext*, JS::Handle<JSObject*>, mozilla::dom::XULFrameElement*, JSJitMethodCallArgs const&) [s3:gecko-generated-sources:e0f03af0718f8c4036f7abdd4d52699f90e3261f9f3e3503ff4d96ec144b84bdbbca56de7943672a10ad99a39492068b6c6a56f269abddadb6c99ad2c1550263/dom/bindings/XULFrameElementBinding.cpp::427]
[task 2019-11-24T10:28:09.094Z] 10:28:09 INFO -
[task 2019-11-24T10:28:09.095Z] 10:28:09 INFO - GECKO(5390) | #05: 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-11-24T10:28:09.095Z] 10:28:09 INFO -
[task 2019-11-24T10:28:09.096Z] 10:28:09 INFO - GECKO(5390) | #06: ??? (???:???)
[task 2019-11-24T10:28:09.109Z] 10:28:09 INFO - GECKO(5390) | ExceptionHandler::GenerateDump cloned child 6075
[task 2019-11-24T10:28:09.110Z] 10:28:09 INFO - GECKO(5390) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-11-24T10:28:09.110Z] 10:28:09 INFO - GECKO(5390) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-11-24T10:28:09.291Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.291Z] 10:28:09 INFO - GECKO(5390) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-11-24T10:28:09.291Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.291Z] 10:28:09 INFO - GECKO(5390) | [RDD 5770, Main Thread] WARNING: Shutting down RDD process early due to a crash!: file /builds/worker/workspace/build/src/dom/media/ipc/RDDParent.cpp, line 207
[task 2019-11-24T10:28:09.291Z] 10:28:09 INFO - GECKO(5390) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-11-24T10:28:09.293Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.294Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.297Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.298Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.299Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.300Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.301Z] 10:28:09 INFO - GECKO(5390) | Exiting due to channel error.
[task 2019-11-24T10:28:09.341Z] 10:28:09 INFO - TEST-INFO | Main app process: exit 11
[task 2019-11-24T10:28:09.342Z] 10:28:09 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite

Neha, as you are the triage owner of this component, could you please take a look at this?
Thank you!

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

Olli is this a regression of bug 1595900 ?

Flags: needinfo?(bugs)

No. Nothing in m-c should even use that code yet.

Flags: needinfo?(bugs)

Aryx can you provide some input here?

History looks like this in the last 30 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-10-28&endday=2019-11-27&tree=trunk&bug=1581500 spiking since the 18th

This moves chunks so retriggering is difficult, hg history doesn't show history from the 17/18 , all failures are on fission.

Flags: needinfo?(aryx.bugmail)

Removing my NI since Matt is correctly already NI'ed here.

Flags: needinfo?(nkochar)
Priority: P5 → P3

Here is a pernosco trace for a run under fission.

https://pernos.co/debug/tiebh-uXnWsUX058HOGavg/index.html

I'm not sure why this got worse recently.

The issue is that we're getting multiple process switch requests from the front-end in quick succession, and this assert explicitly fails for that case.

Comment here documents the issue: https://searchfox.org/mozilla-central/diff/e561c0f595f61c671aa61ed5a944c3edc6e9ba1d/dom/base/nsFrameLoader.cpp#3429

We probably need epochs, an array of 'in flight id's, or just to not crash and always ignore messages from the wrong owner.

Flags: needinfo?(matt.woodrow)
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][comment 23]
Assignee: nobody → aciure
Attachment #9112894 - Attachment description: Bug 1581500 - disable browser_new_tab_in_privilegedabout_process_pref.js for frequent failures. r=gbrown,jmaher → Bug 1581500 - disable browser_new_tab_in_privilegedabout_process_pref.js for frequent failures. r=jmaher
Attachment #9112894 - Attachment description: Bug 1581500 - disable browser_new_tab_in_privilegedabout_process_pref.js for frequent failures. r=jmaher → Bug 1581500 - disable browser_new_tab_in_privilegedabout_process_pref.js for frequent failures. r=#intermittent-reviewers
Pushed by aciure@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/cc3156b5e7e8
disable browser_new_tab_in_privilegedabout_process_pref.js for frequent failures. r=jmaher

The patch seems to have fixed this.

Whiteboard: [comment 23][stockwell disable-recommended] → [comment 23]

This is now failing under browser_redirect_error.js: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=279606559&repo=autoland&lineNumber=12413

[task 2019-12-04T17:58:55.202Z] 17:58:55 INFO - TEST-START | browser/components/urlbar/tests/browser/browser_redirect_error.js
[task 2019-12-04T17:58:55.270Z] 17:58:55 INFO - GECKO(2603) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpKaFdP9.mozrunner/runtests_leaks_tab_pid4784.log
[task 2019-12-04T17:58:55.292Z] 17:58:55 INFO - GECKO(2603) | [Child 4784, 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-12-04T17:58:55.435Z] 17:58:55 INFO - GECKO(2603) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-12-04T17:58:55.597Z] 17:58:55 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1798
[task 2019-12-04T17:58:55.619Z] 17:58:55 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f3b9ded0800 == 1 [pid = 4784] [id = {62acbe78-57b9-4b76-8869-007e5aea7d6f}]
[task 2019-12-04T17:58:55.680Z] 17:58:55 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f3b9ede0f20) [pid = 4784] [serial = 1] [outer = (nil)]
[task 2019-12-04T17:58:55.684Z] 17:58:55 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2019-12-04T17:58:55.684Z] 17:58:55 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f3b9dd16c00) [pid = 4784] [serial = 2] [outer = 0x7f3b9ede0f20]
[task 2019-12-04T17:58:55.885Z] 17:58:55 INFO - [2582, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 173
[task 2019-12-04T17:58:56.094Z] 17:58:56 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-04T17:58:56.110Z] 17:58:56 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-04T17:58:56.110Z] 17:58:56 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 575
[task 2019-12-04T17:58:56.166Z] 17:58:56 INFO - GECKO(2603) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpKaFdP9.mozrunner/runtests_leaks_tab_pid4805.log
[task 2019-12-04T17:58:56.190Z] 17:58:56 INFO - GECKO(2603) | [Child 4805, 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-12-04T17:58:56.306Z] 17:58:56 INFO - GECKO(2603) | [Parent 2603, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-12-04T17:58:56.307Z] 17:58:56 INFO - GECKO(2603) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-12-04T17:58:56.483Z] 17:58:56 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f3b9ded0800 == 0 [pid = 4784] [id = {62acbe78-57b9-4b76-8869-007e5aea7d6f}] [url = about:blank]
[task 2019-12-04T17:58:56.579Z] 17:58:56 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f3b9ede0f20) [pid = 4784] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2019-12-04T17:58:56.581Z] 17:58:56 INFO - GECKO(2603) | [Child 4784: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f3b9dd16c00) [pid = 4784] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2019-12-04T17:58:56.596Z] 17:58:56 INFO - GECKO(2603) | [Child 4805, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1798
[task 2019-12-04T17:58:56.612Z] 17:58:56 INFO - GECKO(2603) | [Child 4805: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f699a7d2800 == 1 [pid = 4805] [id = {62acbe78-57b9-4b76-8869-007e5aea7d6f}]
[task 2019-12-04T17:58:56.651Z] 17:58:56 INFO - GECKO(2603) | [Child 4784, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3361

[task 2019-12-04T17:58:57.536Z] 17:58:57 INFO - GECKO(2603) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2019-12-04T17:58:57.712Z] 17:58:57 INFO - GECKO(2603) | [Child 4827, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1798
[task 2019-12-04T17:58:57.728Z] 17:58:57 INFO - GECKO(2603) | [Child 4827: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f4f3e1d1800 == 1 [pid = 4827] [id = {62acbe78-57b9-4b76-8869-007e5aea7d6f}]
[task 2019-12-04T17:58:57.789Z] 17:58:57 INFO - GECKO(2603) | [Child 4827: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f4f3f0edf20) [pid = 4827] [serial = 1] [outer = (nil)]
[task 2019-12-04T17:58:57.790Z] 17:58:57 INFO - GECKO(2603) | [Child 4827, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2019-12-04T17:58:57.790Z] 17:58:57 INFO - GECKO(2603) | [Child 4827: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f4f3f03e800) [pid = 4827] [serial = 2] [outer = 0x7f4f3f0edf20]
[task 2019-12-04T17:58:58.381Z] 17:58:58 INFO - GECKO(2603) | [Child 4827, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-04T17:58:58.389Z] 17:58:58 INFO - GECKO(2603) | Assertion failure: mInFlightProcessId == 0, at /builds/worker/workspace/build/src/docshell/base/CanonicalBrowsingContext.cpp:101
[task 2019-12-04T17:58:58.391Z] 17:58:58 INFO - GECKO(2603) | #01: nsFrameLoader::SkipBrowsingContextDetach() [mfbt/RefPtr.h:91]
[task 2019-12-04T17:58:58.391Z] 17:58:58 INFO -
[task 2019-12-04T17:58:58.392Z] 17:58:58 INFO - GECKO(2603) | #02: nsFrameLoaderOwner::ChangeRemotenessCommon(bool, nsTSubstring<char16_t> const&, std::function<void ()>&, mozilla::ErrorResult&) [dom/base/nsFrameLoaderOwner.cpp:0]
[task 2019-12-04T17:58:58.392Z] 17:58:58 INFO -
[task 2019-12-04T17:58:58.393Z] 17:58:58 INFO - GECKO(2603) | #03: nsFrameLoaderOwner::ChangeRemoteness(mozilla::dom::RemotenessOptions const&, mozilla::ErrorResult&) [dom/base/nsFrameLoaderOwner.cpp:196]
[task 2019-12-04T17:58:58.393Z] 17:58:58 INFO -
[task 2019-12-04T17:58:58.394Z] 17:58:58 INFO - GECKO(2603) | #04: mozilla::dom::XULFrameElement_Binding::changeRemoteness(JSContext*, JS::Handle<JSObject*>, mozilla::dom::XULFrameElement*, JSJitMethodCallArgs const&) [s3:gecko-generated-sources:e0f03af0718f8c4036f7abdd4d52699f90e3261f9f3e3503ff4d96ec144b84bdbbca56de7943672a10ad99a39492068b6c6a56f269abddadb6c99ad2c1550263/dom/bindings/XULFrameElementBinding.cpp::427]
[task 2019-12-04T17:58:58.395Z] 17:58:58 INFO -
[task 2019-12-04T17:58:58.396Z] 17:58:58 INFO - GECKO(2603) | #05: 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-12-04T17:58:58.396Z] 17:58:58 INFO -
[task 2019-12-04T17:58:58.397Z] 17:58:58 INFO - GECKO(2603) | #06: ??? (???:???)
[task 2019-12-04T17:58:58.397Z] 17:58:58 INFO - GECKO(2603) | [Child 4827, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannelChild, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannelChild.cpp, line 63
[task 2019-12-04T17:58:58.398Z] 17:58:58 INFO - GECKO(2603) | [Child 4827, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 575
[task 2019-12-04T17:58:58.414Z] 17:58:58 INFO - GECKO(2603) | ExceptionHandler::GenerateDump cloned child 4850
[task 2019-12-04T17:58:58.415Z] 17:58:58 INFO - GECKO(2603) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-12-04T17:58:58.415Z] 17:58:58 INFO - GECKO(2603) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-12-04T17:58:58.416Z] 17:58:58 INFO - GECKO(2603) | [Child 4805, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/workspace/build/src/image/imgRequestProxy.cpp, line 931
[task 2019-12-04T17:58:58.417Z] 17:58:58 INFO - GECKO(2603) | [Child 4805, Main Thread] WARNING: NS_ENSURE_TRUE(GetOwner() && !mCanceled) failed: file /builds/worker/workspace/build/src/image/imgRequestProxy.cpp, line 931
[task 2019-12-04T17:58:58.556Z] 17:58:58 INFO - GECKO(2603) | [Child 2680: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (0x7f51965cb400) [pid = 2680] [serial = 20] [outer = (nil)] [url = about:blank]
[task 2019-12-04T17:58:58.556Z] 17:58:58 INFO - GECKO(2603) | [Child 2680: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (0x7f5196334000) [pid = 2680] [serial = 24] [outer = (nil)] [url = about:blank]
[task 2019-12-04T17:58:58.556Z] 17:58:58 INFO - GECKO(2603) | [Child 2680: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f5196366000 == 1 [pid = 2680] [id = {0574f8eb-656c-42fe-8773-5f7d5ee38fc1}] [url = about:blank]
[task 2019-12-04T17:58:58.637Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.637Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.641Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.642Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.644Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.644Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.645Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.646Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.648Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.649Z] 17:58:58 INFO - GECKO(2603) | Exiting due to channel error.
[task 2019-12-04T17:58:58.728Z] 17:58:58 INFO - TEST-INFO | Main app process: exit 11
[task 2019-12-04T17:58:58.728Z] 17:58:58 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite

Whiteboard: [comment 23][stockwell disable-recommended] → [comment 23]
Depends on: 1583254

Does this intermittent test failure need to block Fission? This test is disabled for all debug linux64 platforms, not Fission specifically:

https://searchfox.org/mozilla-central/rev/fca0be7e2cf2f922c9b927423ce28e8a04b3fd90/browser/base/content/test/tabs/browser.ini#71-72

Fission Milestone: M4.1 → ?
Whiteboard: [comment 23] → [comment 23][stockwell disabled]

needinfo'ing kmag. He doesn't want to remove this assertion because it still finds some real bugs.

Nika thinks we should fix this before Fission MVP.

Tracking for Fission riding the trains to Beta (M7)

Fission Milestone: ? → M7
Flags: needinfo?(kmaglione+bmo)
You need to log in before you can comment on or make changes to this bug.