Shutdown hang when quitting debug versions of Firefox with at least two tab modal dialogs open and e10s turned on

RESOLVED FIXED in Firefox 59

Status

()

defect
P1
critical
RESOLVED FIXED
2 years ago
Last year

People

(Reporter: whimboo, Assigned: baku)

Tracking

(Depends on 1 bug, {crash, hang})

59 Branch
mozilla60
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox58+ wontfix, firefox59+ fixed, firefox60 fixed)

Details

Attachments

(4 attachments, 1 obsolete attachment)

[Tracking Requested - why for this release]:

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.12; rv:59.0) Gecko/20100101 Firefox/59.0 ID:20171215100105

The following steps are causing a shutdown hang of Firefox, including a crash after 65 seconds as triggered by the background monitor.

Steps:
1. Start a debug version of Firefox
2. Navigate to any page
3. Open Scratchpad
4. Execute: `window.alert('test'); window.alert('test2');`
5. Go to the main menu and select quit from the file menu

The following MOZ_CRASH output can be seen:

Hit MOZ_CRASH(Workers Hanging - A:2|S:0|Q:0-BC:0|WorkerHolderToken-BC:0|WorkerHolderToken) at /builds/worker/workspace/build/src/dom/workers/RuntimeService.cpp:2191
Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=77.7484) [GFX1-]: Receive IPC close with reason=AbnormalShutdown
Hit MOZ_CRASH(Aborting on channel error.) at /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2534
#01: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x6e1034]
#02: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x6b1701]
#03: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x6aea1f]
#04: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x696065]
#05: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x693ac5]
#06: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x6a0bcd]
#07: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/XUL +0x69aafa]
#08: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x393b]
#09: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x3887]
Hit MOZ_CRASH(MachExceptionHandler: Failed to forward to the previous handler!) at /builds/worker/workspace/build/src/js/src/ds/MemoryProtectionExceptionHandler.cpp:639

It looks like something is wrong with DOM workers.
This is also present for Firefox 58 builds. I'm not certain about earlier releases, which might also be affected. But I cannot test it right now. Maybe someone else could have a look at?
Btw. when I disable dom workers via dom.workers.enabled I get a different stack:

Hit MOZ_CRASH(Shutdown too long, probably frozen, causing a crash.) at /builds/worker/workspace/build/src/toolkit/components/terminator/nsTerminator.cpp:160
#01: PR_GetThreadName[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/libnss3.dylib +0x1443a9]
#02: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x393b]
#03: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x3887]
Hit MOZ_CRASH(Aborting on channel error.) at /builds/worker/workspace/build/src/ipc/glue/MessageChannel.cpp:2543
#01: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x6d64e4]
#02: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x6a62d1]
#03: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x6a35ef]
#04: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x68af65]
#05: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x6889c5]
#06: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x694f4d]
#07: nsXPTCStubBase::Stub249()[/Volumes/data/code/gecko/NightlyDebug.app/Contents/MacOS/XUL +0x68f29a]
#08: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x393b]
#09: _pthread_body[/usr/lib/system/libsystem_pthread.dylib +0x3887]

So this might be NSS / NSPR related? Tim, could you have a look? It's at least reproducible on MacOS and Linux.
Flags: needinfo?(ttaubert)
Posted file marionette test
Here a Marionette test which shows this hang during shutdown. To run it save the attachment locally and type `mach marionette test %path_to_file%`.
Btw. the hang is also visible with Firefox 52ESR, and maybe even older releases. But it can be stopped by just disabling e10s.
Summary: Shutdown hang when quitting debug versions of Firefox with at least two tab modal dialogs open → Shutdown hang when quitting debug versions of Firefox with at least two tab modal dialogs open and e10s turned on
Tracking for 58 and 59, though we don't think this is a new regression, maybe we have a chance to fix it for 58 since we have STR now.
On Linux I attached the hanging Firefox process to gdb after the bg monitor crash, and I see the following stack:

(gdb) bt
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007f91a6920dfd in __GI___pthread_mutex_lock (mutex=0x7f918f56a2a0)
    at ../nptl/pthread_mutex_lock.c:80
#2  0x000000000041a542 in mozilla::detail::MutexImpl::lock() ()
#3  0x00007f9195216058 in mozilla::OffTheBooksMutex::Lock() () from /home/henrik/firefox/libxul.so
#4  0x00007f91955fc39a in mozilla::ipc::MessageChannel::Send(IPC::Message*) ()
   from /home/henrik/firefox/libxul.so
#5  0x00007f91958812ce in mozilla::dom::PContentChild::SendAccumulateChildHistograms(nsTArray<mozilla::Telemetry::HistogramAccumulation> const&) () from /home/henrik/firefox/libxul.so
#6  0x00007f9197daa6c5 in mozilla::TelemetryIPCAccumulator::IPCTimerFired(nsITimer*, void*) ()
   from /home/henrik/firefox/libxul.so
#7  0x00007f919522f1f9 in nsTimerImpl::Fire(int) () from /home/henrik/firefox/libxul.so
#8  0x00007f919521e7b3 in nsTimerEvent::Run() () from /home/henrik/firefox/libxul.so
#9  0x00007f9195210e5e in mozilla::SchedulerGroup::Runnable::Run() () from /home/henrik/firefox/libxul.so
#10 0x00007f919522c3f5 in nsThread::ProcessNextEvent(bool, bool*) [clone .part.279] ()
   from /home/henrik/firefox/libxul.so
#11 0x00007f919522d135 in NS_ProcessNextEvent(nsIThread*, bool) () from /home/henrik/firefox/libxul.so
#12 0x00007f919521f57d in nsThreadManager::SpinEventLoopUntil(nsINestedEventLoopCondition*) ()
   from /home/henrik/firefox/libxul.so

Could this maybe even be a problem with Telemetry?
Flags: needinfo?(gfritzsche)
Ok this is indeed Telemetry related! When I set datareporting.policy.dataSubmissionEnabled to False the hang is gone during shutdown.
Component: DOM: Workers → Telemetry
Product: Core → Toolkit
Flags: needinfo?(ttaubert)
Flags: needinfo?(gfritzsche)
Priority: -- → P1
Maybe I was too hasty. I can even reproduce with Telemetry disabled, but only if the one and only page open is about:blank, and no further page load has been executed. This can be done by setting `browser.startup.page=0` and restarting Firefox.

Telemetry might make this problem to only appear more often.
More testing has shown that this should indeed be a DOM worker problem. On Linux I got way more helpful output as on MacOS before:

Hit MOZ_CRASH(Workers Hanging - A:3|S:0|Q:0-BC:0-BC:0|WorkerHolderToken-BC:0|WorkerHolderToken) at /builds/worker/workspace/build/src/dom/workers/RuntimeService.cpp:2197

After attaching to gdb the following stack is reported:

(gdb) bt
#0  __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007f98125fedfd in __GI___pthread_mutex_lock (mutex=0x7f97eb1435e8) at ../nptl/pthread_mutex_lock.c:80
#2  0x000000000041a542 in mozilla::detail::MutexImpl::lock() ()
#3  0x00007f9800cfc058 in mozilla::OffTheBooksMutex::Lock() () from /home/henrik/firefox/libxul.so
#4  0x00007f9802761597 in mozilla::dom::workers::RuntimeService::UnregisterWorker(mozilla::dom::workers::WorkerPrivate*) () from /home/henrik/firefox/libxul.so
#5  0x00007f98027a665a in (anonymous namespace)::TopLevelWorkerFinishedRunnable::Run() ()
   from /home/henrik/firefox/libxul.so
#6  0x00007f9800d06b41 in mozilla::ThrottledEventQueue::Inner::ExecuteRunnable() ()
   from /home/henrik/firefox/libxul.so
#7  0x00007f9800d06be1 in mozilla::ThrottledEventQueue::Inner::Executor::Run() ()
   from /home/henrik/firefox/libxul.so
#8  0x00007f9800d123f5 in nsThread::ProcessNextEvent(bool, bool*) [clone .part.279] ()
   from /home/henrik/firefox/libxul.so
#9  0x00007f9800d13135 in NS_ProcessNextEvent(nsIThread*, bool) () from /home/henrik/firefox/libxul.so
#10 0x00007f980273413c in mozilla::dom::ContentParent::Observe(nsISupports*, char const*, char16_t const*) ()
   from /home/henrik/firefox/libxul.so
#11 0x00007f9800cbf0e1 in nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) ()
   from /home/henrik/firefox/libxul.so
#12 0x00007f9800cbf298 in nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) ()
   from /home/henrik/firefox/libxul.so
#13 0x00007f9803911f88 in nsXREDirProvider::DoShutdown() () from /home/henrik/firefox/libxul.so
#14 0x00007f98039077c0 in ScopedXPCOMStartup::~ScopedXPCOMStartup() () from /home/henrik/firefox/libxul.so
#15 0x00007f9803907808 in mozilla::DefaultDelete<ScopedXPCOMStartup>::operator()(ScopedXPCOMStartup*) const [clone .isra.80] () from /home/henrik/firefox/libxul.so
#16 0x00007f980390e5fe in XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) ()
   from /home/henrik/firefox/libxul.so
#17 0x00007f980390e87b in XRE_main(int, char**, mozilla::BootstrapConfig const&) ()
   from /home/henrik/firefox/libxul.so
#18 0x0000000000406bcd in do_main(int, char**, char**) ()
#19 0x0000000000406474 in main ()

Olli, could you help with this one?
Component: Telemetry → DOM: Workers
Flags: needinfo?(bugs)
Product: Toolkit → Core
Here are the updated steps to reproduce the issue:

Steps:
1. Start a debug version of Firefox
2. Open `about:config` and set `browser.startup.page=0`, and `datareporting.policy.dataSubmissionEnabled=false`
3. Restart Firefox
4. Open Scratchpad
5. Execute: `window.alert('test'); window.alert('test2');`
6. Go to the main menu and select quit from the file menu
Andrea, do you have any time to look at this?  I think you were working on changing our worker shutdown and probably are more familiar with this part.
Flags: needinfo?(bugs) → needinfo?(amarchesini)
Assignee

Updated

2 years ago
Assignee: nobody → amarchesini
Flags: needinfo?(amarchesini)
Comment hidden (obsolete)
Comment hidden (obsolete)
Andrea, have you had a chance to take a look at this bug?

Please be aware that I pushed a workaround with my patch on bug 1403923 for the web-platform tests, which marked the failing tests as timeout for now. With a patch on this bug that has to be reversed.

Thanks
Flags: needinfo?(amarchesini)
No longer blocks: 1431058
:baku, does this still affect 59?
There was no fix provided yet so it still affects nightly and beta.
Assignee

Comment 17

Last year
We cannot fix it for FF58. But definitely for 59. I'm working on it and I'll submit a patch asap.
Flags: needinfo?(amarchesini)
Assignee

Comment 18

Last year
This is a extremely interesting bug. What happens here is this:

What follows is a reverted stack:

#11 0x00007f6276515df5 in ScopedXPCOMStartup::~ScopedXPCOMStartup (this=0xc20cf0, __in_chrg=<optimised out>) at /home/baku/Sources/m/workers/src/toolkit/xre/nsAppRunner.cpp:1504

... here we start the shutting down.


#10 0x00007f6276533668 in nsXREDirProvider::DoShutdown (this=0x7ffd9812aeb0) at /home/baku/Sources/m/workers/src/toolkit/xre/nsXREDirProvider.cpp:1103

... here we are supposed to dispatch the NS_XPCOM_SHUTDOWN_OBSERVER_ID event, but...

#7  0x00007f6273548544 in mozilla::dom::ContentParent::Observe (this=0x374cbd0, aSubject=0x0, aTopic=0x7f627a3cddc0 "profile-before-change", 

... in this profile-before-change, we manage to spin an event loop:

#6  0x00007f627356deba in mozilla::SpinEventLoopUntil<(mozilla::ProcessFailureBehavior)1, mozilla::dom::ContentParent::Observe(nsISupports*, char const*, char16_t const*)::<lambda()> >(<unknown type in /home/baku/Sources/m/workers/build/dist/bin/libxul.so, CU 0x163a657e, DIE 0x166114e5>, nsIThread *) (aPredicate=<unknown type in /home/baku/Sources/m/workers/build/dist/bin/libxul.so, CU 0x163a657e, DIE 0x166114e5>, 
    aThread=0x0) at /home/baku/Sources/m/workers/src/xpcom/threads/nsThreadUtils.h:323

we don't leave this event loop, NS_XPCOM_SHUTDOWN_OBSERVER_ID is not dispatched, and the workers are not terminated.
Assignee

Comment 19

Last year
Something more to share:

the reason why we do crash on debug builds is because pref dom.ipc.tabs.shutdownTimeoutSecs is set to 0. This makes  ContentParent::StartForceKillTimer() to do not start a timer to kill the process and we hang here:

https://dxr.mozilla.org/mozilla-central/source/dom/ipc/ContentParent.cpp#2820

mIPCOpen is true because the actor is still active, and mCalledKillHard is false because we haven't killed the content process.

The problem is now in the content process: why we are not shutting down the ContentChild actor? Still debugging...
Assignee

Comment 20

Last year
Finally I have the complete view of what is going on:

The parent, is waiting for RecvFinishShutdown() after a SendShutdown(). This waiting is done spinning the event loop. In this way workers::RuntimeService cannot receive xpcom-shutdown notification and, after X seconds of hanging, we crash. Node that in debugging mode we don't kill the content process after 5 seconds because of the pref dom.ipc.tabs.shutdownTimeoutSecs.

The content process is showing an alert and this is done spinning the event loop. In ContentChild::RecvShutdown(), we end up here: https://dxr.mozilla.org/mozilla-central/source/dom/ipc/ContentChild.cpp#2974-2987 where, basically, we wait until something happens. But the alert is not closed because of: https://dxr.mozilla.org/mozilla-central/source/toolkit/components/prompts/src/nsPrompter.js#510
Assignee

Comment 21

Last year
Important to note is that ShutdownObserver must be always running because otherwise, if the spin loop is created when shutting down, we are not able to interrupt it.
Attachment #8945859 - Flags: review?(bugs)
Assignee

Comment 22

Last year
A new notification to know when the child is starting the shutting down steps.
Attachment #8945860 - Flags: review?(bugs)
Assignee

Comment 23

Last year
If we like this approach, we should expand the use of Services.tm.spinEventLoopUntilOrShutdown to other components.
Attachment #8945862 - Flags: review?(bugs)
Attachment #8945860 - Flags: review?(bugs) → review+
Comment on attachment 8945860 [details] [diff] [review]
part 2 - content-child-will-shutdown

> ContentChild::RecvShutdown()
> {
>+  nsCOMPtr<nsIObserverService> os = services::GetObserverService();
>+  if (os) {
>+    os->NotifyObservers(static_cast<nsIContentChild*>(this),
>+                          "content-child-will-shutdown", nullptr);
could you align the params.
Comment on attachment 8945859 [details] [diff] [review]
part 1 - nsIThreadManager::spinEventLoopUntilOrShutdown

># HG changeset patch
># User Andrea Marchesini <amarchesini@mozilla.com>
># Parent  32b850fa28ae1c29039cb7ddcdfd71b324762c05
>
>diff --git a/xpcom/threads/nsIThreadManager.idl b/xpcom/threads/nsIThreadManager.idl
>--- a/xpcom/threads/nsIThreadManager.idl
>+++ b/xpcom/threads/nsIThreadManager.idl
>@@ -116,16 +116,25 @@ interface nsIThreadManager : nsISupports
>    * If condition.isDone() throws, this function will throw as well.
>    *
>    * C++ code should not use this function, instead preferring
>    * mozilla::SpinEventLoopUntil.
>    */
>   void spinEventLoopUntil(in nsINestedEventLoopCondition condition);
> 
>   /**
>+   * Similar to the previous method, but the spinning of the event loop
>+   * terminates when the shutting down starts.
This needs to have a comment what notification this is depending on and how this behaves different only
child and parent processes.

>+nsresult
>+nsThreadManager::SpinEventLoopUntilInternal(nsINestedEventLoopCondition* aCondition,
>+                                            bool aCheckingShutdown)
>+{
>   nsCOMPtr<nsINestedEventLoopCondition> condition(aCondition);
>   nsresult rv = NS_OK;
> 
>+  if (aCheckingShutdown && !gShutdownObserver) {
>+    RefPtr<ShutdownObserver> observer;
>+    rv = ShutdownObserver::Create(getter_AddRefs(observer));
>+    if (NS_WARN_IF(NS_FAILED(rv))) {
>+      return rv;
>+    }
So what if we're already shutting down here? This code wouldn't stop spinning.
Perhaps better to create ShutdownObserver eagerly during startup or so?
Attachment #8945859 - Flags: review?(bugs) → review-
Attachment #8945862 - Flags: review?(bugs) → review+
Assignee

Comment 26

Last year
Attachment #8945859 - Attachment is obsolete: true
Attachment #8945997 - Flags: review?(bugs)
Attachment #8945997 - Flags: review?(bugs) → review+

Comment 27

Last year
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/fca93197ead7
Implement nsIThreadManager::spinEventLoopUntilOrShutdown, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/5a098622dab3
"content-child-will-shutdown" notification when the content process starts the shutting down, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/f3e76ecbd9e4
nsPrompter must use nsIThreadManager::spinEventLoopUntilOrShutdown, r=smaug
Andrea, you missed to revert the changes for wdspec tests, which should give a permafail now. See comment 14.
Flags: needinfo?(amarchesini)

Comment 29

Last year
Backout by aiakab@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/90c17c845e06
Backed out 3 changesets for failing Wd on Linux debug at /webdriver/tests/execute_async_script/user_prompts.py
Backed out 3 changesets (bug 1425559) for failing Wd on Linux debug at /webdriver/tests/execute_async_script/user_prompts.py

Backout revision:https://hg.mozilla.org/integration/mozilla-inbound/rev/90c17c845e064847e406f828d402fe88643a2c7b

The push wher it started failing: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=f3e76ecbd9e4422434acc5e25f363d7a35dd942a

Link to the failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=158929340&repo=mozilla-inbound&lineNumber=6499

Part of the log: [task 2018-01-28T11:30:29.824Z] 11:30:29     INFO - STDOUT: :59: AssertionError
6494
[task 2018-01-28T11:30:29.825Z] 11:30:29     INFO - STDOUT: =============================== warnings summary ===============================
6495
[task 2018-01-28T11:30:29.825Z] 11:30:29     INFO - STDOUT: None
6496
[task 2018-01-28T11:30:29.826Z] 11:30:29     INFO - STDOUT:   Module already imported so cannot be rewritten: mozlog
6497
[task 2018-01-28T11:30:29.826Z] 11:30:29     INFO - STDOUT: -- Docs: http://doc.pytest.org/en/latest/warnings.html
6498
[task 2018-01-28T11:30:29.826Z] 11:30:29     INFO - STDOUT: ==================== 7 failed, 1 warnings in 52.57 seconds =====================
6499
[task 2018-01-28T11:30:29.828Z] 11:30:29     INFO - TEST-UNEXPECTED-OK | /webdriver/tests/execute_async_script/user_prompts.py | expected TIMEOUT
6500
[task 2018-01-28T11:30:29.828Z] 11:30:29     INFO - TEST-INFO expected TIMEOUT | took 52618ms
6501
[task 2018-01-28T11:30:29.830Z] 11:30:29  WARNING - u'runner_teardown': ()
6502
[task 2018-01-28T11:30:29.831Z] 11:30:29     INFO - Starting runner
6503
[task 2018-01-28T11:30:29.841Z] 11:30:29     INFO - PID 4708 | 1517139029836	geckodriver	INFO	geckodriver 0.19.1 ( '4fcb41aa9b9b'  '2018-01-28 12:46 +0200')
6504
[task 2018-01-28T11:30:29.841Z] 11:30:29     INFO - PID 4708 | 1517139029839	geckodriver	INFO	Listening on 127.0.0.1:4444
6505
[task 2018-01-28T11:30:30.340Z] 11:30:30     INFO - WebDriver HTTP server listening at http://127.0.0.1:4444/
6506
[task 2018-01-28T11:30:30.341Z] 11:30:30     INFO - TEST-START | /webdriver/tests/execute_script/cyclic.py
6507
[task 2018-01-28T11:30:30.499Z] 11:30:30     INFO - STDOUT: ============================= test session starts ==============================
6508
[task 2018-01-28T11:30:30.500Z] 11:30:30     INFO - STDOUT: platform linux2 -- Python 2.7.12, pytest-unknown, py-1.5.2, pluggy-0.5.3.dev -- /builds/worker/workspace/build/venv/bin/python
6509
[task 2018-01-28T11:30:30.500Z] 11:30:30     INFO - STDOUT: rootdir: /builds/worker/workspace/build, inifile:
6510
[task 2018-01-28T11:30:30.501Z] 11:30:30     INFO - STDOUT: collecting ... 
6511
[task 2018-01-28T11:30:30.509Z] 11:30:30     INFO - STDOUT: collected 4 items
6512
[task 2018-01-28T11:30:30.509Z] 11:30:30     INFO - STDOUT: tests/web-platform/tests/webdriver/tests/execute_script/cyclic.py::test_array 
6513
[task 2018-01-28T11:30:30.517Z] 11:30:30     INFO - PID 4708 | 1517139030507	mozrunner::runner	INFO	Running command: "/builds/worker/workspace/build/application/firefox/firefox" "-marionette" "-profile" "/tmp/rust_mozprofile.SDcor7u95ZzQ"
6514
[task 2018-01-28T11:30:32.426Z] 11:30:32     INFO - PID 4708 | [4720, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /builds/worker/workspace/build/src/extensions/cookie/nsPermissionManager.cpp, line 2909
6515
[task 2018-01-28T11:30:32.575Z] 11:30:32     INFO - PID 4708 | ++DOCSHELL 0xe4b4e800 == 1 [pid = 4720] [id = {4ba0d630-ca5e-49c8-bbab-230e64b3b012}]
6516
[task 2018-01-28T11:30:32.576Z] 11:30:32     INFO - PID 4708 | ++DOMWINDOW == 1 (0xe4b42160) [pid = 4720] [serial = 1] [outer = (nil)]
6517
[task 2018-01-28T11:30:32.576Z] 11:30:32     INFO - PID 4708 | ++DOMWINDOW == 2 (0xe4b51000) [pid = 4720] [serial = 2] [outer = 0xe4b42160]
6518
[task 2018-01-28T11:30:32.806Z] 11:30:32     INFO - PID 4708 | ++DOCSHELL 0xde070c00 == 2 [pid = 4720] [id = {5f363c49-125d-4805-86ff-88351fc7fac8}]
6519
[task 2018-01-28T11:30:32.807Z] 11:30:32     INFO - PID 4708 | ++DOMWINDOW == 3 (0xe4b42940) [pid = 4720] [serial = 3] [outer = (nil)]
6520
[task 2018-01-28T11:30:32.807Z] 11:30:32     INFO - PID 4708 | ++DOMWINDOW == 4 (0xde071400) [pid = 4720] [serial = 4] [outer = 0xe4b42940]
6521
[task 2018-01-28T11:30:32.924Z] 11:30:32     INFO - PID 4708 | [4720, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 330
6522
[task 2018-01-28T11:30:33.005Z] 11:30:33     INFO - PID 4708 | ++DOMWINDOW == 5 (0xde074000) [pid = 4720] [serial = 5] [outer = 0xe4b42160]
6523
[task 2018-01-28T11:30:33.243Z] 11:30:33     INFO - PID 4708 | ++DOCSHELL 0xde07d000 == 3 [pid = 4720] [id = {6519b0ae-0177-40b2-9d22-0b3f956e691f}]
6524
[task 2018-01-28T11:30:33.244Z] 11:30:33     INFO - PID 4708 | ++DOMWINDOW == 6 (0xe4b42ee0) [pid = 4720] [serial = 6] [outer = (nil)]
6525
[task 2018-01-28T11:30:33.784Z] 11:30:33     INFO - PID 4708 | ++DOCSHELL 0xda76e800 == 4 [pid = 4720] [id = {480e8ef7-4aa5-4b23-9668-4d88f3f1cf6a}]
6526
[task 2018-01-28T11:30:33.786Z] 11:30:33     INFO - PID 4708 | ++DOMWINDOW == 7 (0xda58ea60) [pid = 4720] [serial = 7] [outer = (nil)]
6527
[task 2018-01-28T11:30:33.982Z] 11:30:33     INFO - PID 4708 | ++DOMWINDOW == 8 (0xda771400) [pid = 4720] [serial = 8] [outer = 0xda58ea60]
6528
[task 2018-01-28T11:30:34.260Z] 11:30:34     INFO - PID 4708 | ++DOMWINDOW == 9 (0xd8cb9800) [pid = 4720] [serial = 9] [outer = 0xe4b42ee0]
6529
[task 2018-01-28T11:30:34.397Z] 11:30:34     INFO - PID 4708 | [Parent 4720, Main Thread] WARNING: Forced to copy ObserverTable due to nested notifications: file /builds/worker/workspace/build/src/image/ProgressTracker.h, line 87
6530
[task 2018-01-28T11:30:34.438Z] 11:30:34     INFO - PID 4708 | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
6531
[task 2018-01-28T11:30:34.699Z] 11:30:34     INFO - PID 4708 | ++DOCSHELL 0xea2c1400 == 1 [pid = 4767] [id = {20bbf418-7f8f-4503-a963-a48bf10b73c6}]
6532
[task 2018-01-28T11:30:34.722Z] 11:30:34     INFO - PID 4708 | GLib-GIO-Message: Using the 'memory' GSettings backend.  Your settings will not be saved or shared with other applications.
6533
[task 2018-01-28T11:30:34.722Z] 11:30:34     INFO - PID 4708 | [Parent 4720, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /builds/worker/workspace/build/src/netwerk/base/nsChannelClassifier.cpp, line 344
6534
[task 2018-01-28T11:30:34.759Z] 11:30:34     INFO - PID 4708 | ++DOMWINDOW == 1 (0xea363040) [pid = 4767] [serial = 1] [outer = (nil)]
(In reply to Pulsebot from comment #29)
> Backout by aiakab@mozilla.com:
> https://hg.mozilla.org/integration/mozilla-inbound/rev/90c17c845e06
> Backed out 3 changesets for failing Wd on Linux debug at
> /webdriver/tests/execute_async_script/user_prompts.py

The failures were actually unexpected passes of tests that were marked as timeouts, fwiw.
Assignee

Updated

Last year
Flags: needinfo?(amarchesini)

Comment 32

Last year
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/21e24506cb0e
Implement nsIThreadManager::spinEventLoopUntilOrShutdown, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/939a770548c4
"content-child-will-shutdown" notification when the content process starts the shutting down, r=smaug
https://hg.mozilla.org/integration/mozilla-inbound/rev/c68854a72847
nsPrompter must use nsIThreadManager::spinEventLoopUntilOrShutdown, r=smaug
Depends on: 1434950
Andrea, is this safe enough to uplift to beta?
Flags: needinfo?(amarchesini)
Assignee

Comment 35

Last year
Comment on attachment 8945860 [details] [diff] [review]
part 2 - content-child-will-shutdown

Approval Request Comment
[Feature/Bug causing the regression]: nsPrompter.jsm
[User impact if declined]: Firefox can hang during the shutdown
[Is this code covered by automated tests?]: yes
[Has the fix been verified in Nightly?]: yes
[Needs manual test from QE? If yes, steps to reproduce]: if needed, there is a STR. 
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: no
[Why is the change risky/not risky?]: Here we are introducing a new method called: spinEventLoopUntilOrShutdown. In case an alert() is used during the shutdown, the prompt is automatically dismissed.
[String changes made/needed]: none
Flags: needinfo?(amarchesini)
Attachment #8945860 - Flags: approval-mozilla-beta?
Assignee

Comment 36

Last year
Of course the 3 patches must be uplift. Thanks!
Comment on attachment 8945860 [details] [diff] [review]
part 2 - content-child-will-shutdown

Fixing shutdown hangs sounds good to me. 
Should land for beta 10 later this week.
Attachment #8945860 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Attachment #8945997 - Flags: approval-mozilla-beta+
Attachment #8945862 - Flags: approval-mozilla-beta+
Henrik, I just noticed comment 14 about reversing something on a test. I'll comment on that bug too but FYI we are uplifting patches here to beta 59.
Flags: needinfo?(hskupin)
(In reply to Liz Henry (:lizzard) (needinfo? me) from comment #38)
> Henrik, I just noticed comment 14 about reversing something on a test. I'll
> comment on that bug too but FYI we are uplifting patches here to beta 59.

This is already part of the landed patch on central, and now got uplifted as part of https://hg.mozilla.org/releases/mozilla-beta/rev/331bb529635e to mozilla-beta. There is nothing left to do here.
Flags: needinfo?(hskupin)
You need to log in before you can comment on or make changes to this bug.