Closed Bug 1244118 Opened 4 years ago Closed 4 years ago

slow-shutdown, process cleanup takes a long period in task manager

Categories

(Core :: Graphics, defect)

46 Branch
Unspecified
Windows 7
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla47
Tracking Status
firefox45 --- unaffected
firefox46 + fixed
firefox47 + fixed

People

(Reporter: alice0775, Assigned: mtseng)

References

Details

(Keywords: perf, regression, reproducible)

Attachments

(3 files, 1 obsolete file)

Build Identifier:
https://hg.mozilla.org/mozilla-central/rev/0ecd7d72f232304da046b352c457e039e35ceed7
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:47.0) Gecko/20100101 Firefox/47.0 ID:20160128030208

When I close browser after normal browsing, process cleanup takes a long period in task manager.

Reproducible: sometimes

Steps To Reproduce:
at least the following STR cause the problem in 50% probability.

1. Start Aurora with new profile and close Aurora.
2. Start Nightly with the profile. When "Default Browser" dialog pops up, choose [Not now].
3. Restore Previous Session from history menu.
4. Open url[1] in new tab (i.e., paste the url[1] in locationbar and then press Alt+Enter.
   [1] https://addons.mozilla.org/en-US/firefox/?utm_source=snippet&utm_medium=snippet&utm_campaign=addons
5. Close Nightly.
6. Repeat from step 1, if any.

Actual Results:
Process cleanup takes a long period in task manager.
In this case, about:telemetry "Simple Measurements" shows 'shutdownDuration 28233'.
Usually shutdownDuration is ~1000.

Expected Results:
It should be few seconds
Another Steps To Reproduce:
The following STR also cause the problem in almost 100% probability.

1. Start Nightly with new profile and close Nightly.
2. Start Nightly with the profile. When "Default Browser" dialog pops up, choose [Not now].
3. Open url[1] in new tab (i.e., paste the url[1] in locationbar and then press Alt+Enter.
   [1] https://addons.mozilla.org/en-US/firefox/?utm_source=snippet&utm_medium=snippet&utm_campaign=addons
4. Close Nightly.
5. Repeat from step 1, if any.
[Tracking Requested - why for this release]: shutdown hang


Regression window (using STR in Comment 1):
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=d244738428700a2f8d85b17161c42a0444af6ca0&tochange=c347dd2df979ab54dd05370c6a1f548f0c2b4aeb

Suspect: Bug 1172796 , Bug 1215438 , Bug 1215005


And I confirmed that Aurora46.0a2 is also affected.
Component: General → Graphics
Flags: needinfo?(seth)
Flags: needinfo?(roc)
Flags: needinfo?(mtseng)
Flags: needinfo?(bugs)
Flags: needinfo?(bas)
Keywords: regression
OS: Unspecified → Windows 7
Product: Firefox → Core
Version: Trunk → 46 Branch
Attached file about:support
Morris, could you investigate this.

So far I haven't managed to reproduce on Linux. The only case I've see a bit longer shutdown was when the newly created profile ended up trying to look for a new update I think.
Flags: needinfo?(bugs)
(In reply to Olli Pettay [:smaug] from comment #4)
> Morris, could you investigate this.
> 
> So far I haven't managed to reproduce on Linux. The only case I've see a bit
> longer shutdown was when the newly created profile ended up trying to look
> for a new update I think.
Sure.
Assignee: nobody → mtseng
Flags: needinfo?(seth)
Flags: needinfo?(roc)
Flags: needinfo?(mtseng)
Flags: needinfo?(bas)
(In reply to Olli Pettay [:smaug] from comment #4)
> Morris, could you investigate this.
> 
> So far I haven't managed to reproduce on Linux. The only case I've see a bit
> longer shutdown was when the newly created profile ended up trying to look
> for a new update I think.

Even if I disable auto update, the long hang occurs.
Keywords: perf
I can reproduce with STR described on comment 1 on my local build. Keep investigating it.
The root cause is:

[1] set idle thread timeout to 30 seconds. So when ShutdownXPCOM() shuts all threads in [2], it will wait this idle thread timeout. I think we should call ThreadPool::Shutdown() before [2].

[1]: https://dxr.mozilla.org/mozilla-central/source/dom/base/ImageEncoder.cpp?from=ImageEncoder.cpp#511
[2]: https://dxr.mozilla.org/mozilla-central/source/xpcom/build/XPCOMInit.cpp#879
In my case this happened to me at work after +-8 hours open almost every day(i´m using 30/12/2015 nightly build -32bits noE10).

Sometimes i had to kill the process.

After testing for a while, closing nightly using the menu command, this situation doesn´t happen.
Duplicate of this bug: 1234531
There's some debug log output over in bug 1234531 that might be useful.
(In reply to Morris Tseng [:mtseng] from comment #9)
> Created attachment 8714670 [details] [diff] [review]
> Shutdown threadpool when xpcom-shutdown-threads happened.

I can confirm this patch fixes the problem.
Comment on attachment 8714670 [details] [diff] [review]
Shutdown threadpool when xpcom-shutdown-threads happened.

Review of attachment 8714670 [details] [diff] [review]:
-----------------------------------------------------------------

::: dom/base/ImageEncoder.cpp
@@ +522,5 @@
> +    nsCOMPtr<nsIObserverService> os = mozilla::services::GetObserverService();
> +    NS_ASSERTION(os, "do_GetService failed");
> +    os->AddObserver(new EncoderThreadPoolTerminator(),
> +                    "xpcom-shutdown-threads",
> +                    false);

You need to make sure you're doing this all on the main thread; getting the observer service and manipulating it is not safe to do on a non-main thread.
Attached image example dialog
this is the dialog you get when you try to open the browser. Selecting "Close Firefox" doesn't seem to do anything.
Attachment #8714670 - Attachment is obsolete: true
Attachment #8714670 - Flags: review?(seth)
Comment on attachment 8719362 [details] [diff] [review]
Shutdown threadpool when xpcom-shutdown-threads happened v2.

Approval Request Comment
[Feature/regressing bug #]: 1172796
[User impact if declined]: Firefox may freeze 30 seconds when shutdown.
[Describe test coverage new/current, TreeHerder]: Tested locally.
[Risks and why]: Low risk, only call ThreadPool::Shutdown during shutdown process.
[String/UUID change made/needed]: n/a
Attachment #8719362 - Flags: approval-mozilla-aurora?
https://hg.mozilla.org/mozilla-central/rev/de3cd971372c
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla47
Duplicate of this bug: 1244696
Tracking since this is a recent regression.
Comment on attachment 8719362 [details] [diff] [review]
Shutdown threadpool when xpcom-shutdown-threads happened v2.

Fix for recent shutdown hang regression. 
Please uplift to aurora.
Attachment #8719362 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Please land the patch to aurora. Thanks.
Keywords: checkin-needed
This significantly improves the very long shutdown times I've been seeing for a while. Even with this patch, shutdown under OS X still takes 2-5s longer than before the changeset containing Bug 1172796, Bug 1215438, and Bug 1215005. Is this expected? Should I file a separate issue for this?
You need to log in before you can comment on or make changes to this bug.