1498942 - Crash in shutdownhang | NtReadVirtualMemory

Status: RESOLVED FIXED

(Core :: General, defect)

Description

[Trevor Skywalker]

This bug was filed from the Socorro interface and is
report bp-ecd70659-392a-4b1b-9322-c099a0181014.
=============================================================

Top 10 frames of crashing thread:

0 ntdll.dll NtReadVirtualMemory 
1 kernelbase.dll ReadProcessMemory 
2 dbghelp.dll Win32LiveSystemProvider::ReadAllVirtual 
3 dbghelp.dll GenReadTlsDirectory 
4 dbghelp.dll GenAllocateModuleObject 
5 dbghelp.dll GenGetProcessInfo 
6 dbghelp.dll MiniDumpProvideDump 
7 dbghelp.dll MiniDumpWriteDump 
8 xul.dll bool google_breakpad::ExceptionHandler::WriteMinidumpWithExceptionForProcess toolkit/crashreporter/breakpad-client/windows/handler/exception_handler.cc:950
9 xul.dll google_breakpad::ExceptionHandler::WriteMinidumpForChild toolkit/crashreporter/breakpad-client/windows/handler/exception_handler.cc:814

=============================================================

Comment 1

[Trevor Skywalker]

Top Crashers for Firefox 64.0a1

14      1.1% 	-0.64% 	shutdownhang | NtReadVirtualMemory	46 	46 	0 	0 	46 	0 	2015-01-21 


Signature report for shutdownhang | NtReadVirtualMemory

Windows 10 	35 	76.1%
Windows 8.1 	6 	13.0%
Windows 8 	3 	6.5%
Windows 7 	2 	4.3%

Firefox 	64.0a1 	46 	100.0% 	42

amd64 	36 	78.3%
x86 	10 	21.7%

Comment 2

[Andrew Overholt [:overholt]]

How are we tracking these shutdown issues, Jim?

Comment 3

[Jim Mathies [:jimm]]

Looks like this might be related to the extension hang associated with fxmonitor, although those tend to have different signatures.

Comment 4

[Jim Mathies [:jimm]]

(In reply to Andrew Overholt [:overholt] from comment #2)
> How are we tracking these shutdown issues, Jim?

A bunch of metas with thousands of bugs under them. :(

Comment 5

[Itiel]

Just got hit by this crash.
https://crash-stats.mozilla.com/report/index/c20d5c36-83d9-42b5-b1dc-892090181023
Any chance that these signatures:
[@ shutdownhang | NtQueryDirectoryFileEx ]
[@ shutdownhang | NtCreateFile ]
are related? I'm experiencing a rising number of actual shutdown crashes lately.
Nightly has been very sluggish for me in the past month after a certian time of use, and when it gets to that point and I close Nightly, this is the crash I get ~2 minutes after Nightly closed.

Comment 6

[Andrew Overholt [:overholt]]

The crash you reference in comment 5 is when we're trying to write a minidump. Ted, do you have thoughts on why we'd crash there?

Comment 7

[[:philipp]]

shutdownhangs with a similar stack are regressing since 64.0a1 build 20180919003800, where bug 1463048 was landing (and later uplifted to 63).

the issue is spread out over multiple signatures:
https://crash-stats.mozilla.com/search/?proto_signature=~WriteMinidumpWithExceptionForProcess&build_id=%3E%3D20180919003800&date=%3E%3D2018-09-01&_facets=signature&_facets=version&_facets=platform_pretty_version&_facets=useragent_locale&_facets=release_channel&_facets=cpu_arch#facet-signature

Comment 8

[[:philipp]]

this is accounting for 11.4% of browser crashes in 63.0 currently.

Comment 9

[Gabriele Svelto [:gsvelto]]

I've opened a bunch of crashes from the various signatures and they all look like genuine shutdown crashes: what's happening here is that the shutdown hang detector is racing against the timer that force-kills content processes taking too long to shut down. First of all the reason why landing bug 1463048 have caused this to shoot up is that before that bug grabbing minidumps of hung processes during shutdown was borked, so instead of hitting this bug we were hitting that one. With bug 1463048 we now see the real impact of this issue.

So first of all here's the chain of events:

- We commence shutdown by notifying all listeners of the "quit-application" topic [1]

- The shutdown hang detector picks this up and fires its watchdog thread, from now on Firefox has 60s to shutdown, if it doesn't we'll hit a MOZ_CRASH() that kills it for good. Most of the crashes here hit [3] but some hit [4].

- After this initial phase we start closing the content processes via ContentProcess::ShutDownProcess(). This is usually called asynchronously as tabs are closed [5] and later synchronously for processes that still had not tab associated to them [6]. The asynchronous part means we usually start killing more than one process in a short amount of time.

- And here's the issue, when we shut down a process we fire a 5 seconds timer that will kill the process if it hasn't shut down by the time it triggers [7]. This will eventually try to take a minidump of the content process which we assume is hung [8]. What is happening is that we're probably experiencing a slow shutdown, this causes us to kill one content process which in turn causes us to grab a minidump. After the fix for bug 1463048 has landed minidumps are taken synchronously on the main thread so they slow down the shutdown process which most likely has an avalanche effect: more shutdown process timers expire (we fired them all together!) triggering more shutdown process kills and thus more minidumps until the shutdown watchdog kicks in and kills the main process.

As we increase the number of content processes this problem will become more severe so we need to figure out a better way to detect shutdown hangs without *causing* them ourselves. In the short term however increasing both the content shutdown kill timer and the shutdown watchgod timer should give us some breathing room.

[1] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/toolkit/components/startup/nsAppStartup.cpp#468
[2] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/toolkit/components/terminator/nsTerminator.cpp#508
[3] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/toolkit/components/terminator/nsTerminator.cpp#
[4] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/toolkit/components/terminator/nsTerminator.cpp#219
[5] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/dom/ipc/ContentParent.cpp#2051
[6] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/dom/ipc/ContentParent.cpp#1779
[7] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/dom/ipc/ContentParent.cpp#1485
[8] https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/dom/ipc/ContentParent.cpp#3500

Comment 10

[Gabriele Svelto [:gsvelto]]

I've just noticed we have a second shutdown hang detector with similar logic but implemented in JavaScript:

https://searchfox.org/mozilla-central/rev/5b3b6b8fd9f90087f618c20382e631451136ed2b/toolkit/components/asyncshutdown/AsyncShutdown.jsm#930

Since it uses the same timeout as the code in nsTerminator.cpp but starts after it I guess it doesn't trigger often.

Comment 11

[(not currently active) Ted Mielczarek]

(In reply to Gabriele Svelto [:gsvelto] from comment #9)
> - And here's the issue, when we shut down a process we fire a 5 seconds
> timer that will kill the process if it hasn't shut down by the time it
> triggers [7]. This will eventually try to take a minidump of the content
> process which we assume is hung [8]. What is happening is that we're

It sounds like the most straightforward fix here would be to just disable this "content process is hung, so capture a minidump" logic during shutdown. If content processes don't shut down in time we could simply kill them and move on.

Comment 12

[David Durst [:ddurst]]

There's not many people who would take this, so given the crash rate, should we at least have an assignee (which is probably Ted or Gabriele)?

Comment 13

[Gabriele Svelto [:gsvelto]]

Taking this, I want to try a mitigation first then we'll see.

Comment 14

[Andrew Overholt [:overholt]]

Thank you, Gabriele!

Comment 15

[Gabriele Svelto [:gsvelto]]

Attachment: Bug 1498942 - Lengthen timeouts for detecting hung content processes during shutdown

Comment 16

[Gabriele Svelto [:gsvelto]]

This doubles the timeout for killing content processes during shutdown and increases the overall shutdown hang detection timeout by 50%. If this isn't sufficient to reduce the crash rate then we'll have to turn off grabbing minidumps during shutdown.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/11edba6d53bb
Lengthen timeouts for detecting hung content processes during shutdown r=Ehsan

Comment 18

[Gabriele Svelto [:gsvelto]]

Let's leave this open until we're sure we've reduced the crash rate.

Comment 19

[[:philipp]]

can we uplift it to beta though to assess the full impact there there as soon as possbile? (there isn't such a clear crash pattern on nightly)

Comment 20

[Gabriele Svelto [:gsvelto]]

Comment on attachment 9021930 [details]
Bug 1498942 - Lengthen timeouts for detecting hung content processes during shutdown

[Beta/Release Uplift Approval Request]

Feature/Bug causing the regression: Bug 1463048

User impact if declined: Firefox gets stuck during shutdown and crashes after 10 seconds. This is not caused directly by the fix for bug 1463048 but that fix caused the issue to become widespread.

Is this code covered by automated tests?: No

Has the fix been verified in Nightly?: Yes

Needs manual test from QE?: No

If yes, steps to reproduce: 

List of other uplifts needed: None

Risk to taking this patch: Low

Why is the change risky/not risky? (and alternatives if risky): This patch only adjusts a preference to give more time for the content processes to shut down.

String changes made/needed: none

Comment 21

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/11edba6d53bb

Comment 22

[Julien Cristau [:jcristau]]

Comment on attachment 9021930 [details]
Bug 1498942 - Lengthen timeouts for detecting hung content processes during shutdown

ok let's try this on beta, approved for 64.0b8

Comment 23

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/releases/mozilla-beta/rev/0b925d9a30cc

Comment 24

[[:philipp]]

i don't see much of an improvement in the crash pattern in data for 64.0b8. should we look into the other avenue mentioned in comment #16?

in b7 the share of the crashes for this query compared to all browser crashes was 8.7%: 
https://crash-stats.mozilla.com/search/?proto_signature=~WriteMinidumpWithExceptionForProcess&version=64.0b7&process_type=browser&date=%3E%3D2018-09-01

in b8 it's 8.5% so far:
https://crash-stats.mozilla.com/search/?proto_signature=~WriteMinidumpWithExceptionForProcess&version=64.0b8&process_type=browser&date=%3E%3D2018-09-01

Comment 25

[Gabriele Svelto [:gsvelto]]

Yeah, the crash rate keeps ticking up. I'll follow Ted's suggestion in comment 11 to turn this functionality off for the time being. I'll file a bug to reintroduce this at a later point with a mechanism that does not cause this kind of avalanche effects.

Comment 26

[Gabriele Svelto [:gsvelto]]

Attachment: Bug 1498942 - Don't attempt to take minidumps of hung content processes when shutting down

This patch also takes the timeout for killing a content process back to its
original value and removes a related but long unused field.

Comment 27

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c1a4345c8103
Don't attempt to take minidumps of hung content processes when shutting down r=Ehsan

Comment 28

[Razvan Maries]

https://hg.mozilla.org/mozilla-central/rev/c1a4345c8103

Comment 29

[[:philipp]]

hi, could you request uplift to beta again please in order to see how the new approach performs there?

Comment 30

[Pascal Chevrel (relman team) -> :pascalc]

Setting 64 back to affected as the first patch didn't decrease the volume of crashed in beta 8 and we have a second patch we may uplift.

Comment 31

[Gabriele Svelto [:gsvelto]]

There are no more crashes on the nightly channel after the 20181114222927 build so the patch is working as expected.

Comment 32

[Gabriele Svelto [:gsvelto]]

Comment on attachment 9024661 [details]
Bug 1498942 - Don't attempt to take minidumps of hung content processes when shutting down

[Beta/Release Uplift Approval Request]

Feature/Bug causing the regression: Bug 1463048

User impact if declined: Firefox gets stuck during shutdown and crashes after 60 seconds. This is not caused directly by the fix for bug 1463048 but that fix caused the issue to become widespread.

Is this code covered by automated tests?: No

Has the fix been verified in Nightly?: Yes

Needs manual test from QE?: No

If yes, steps to reproduce: 

List of other uplifts needed: None

Risk to taking this patch: Low

Why is the change risky/not risky? (and alternatives if risky): The patch only prevents minidumps from being generated during shutdown and rolls back the previous change which did not prove useful.

String changes made/needed: None

Comment 33

[Julien Cristau [:jcristau]]

Comment on attachment 9024661 [details]
Bug 1498942 - Don't attempt to take minidumps of hung content processes when shutting down

I guess the flip side is that makes it impossible to debug hung content processes?  Anyway, better than making shutdown itself hang.  Approved for 64.0b11

Comment 34

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/be6c9c1f12a7

Comment 35

[[:philipp]]

the crash pattern looks fixed in beta with the latest patch landing in 64.0b11.

Comment 36

[Pascal Chevrel (relman team) -> :pascalc]

Wontfix for 63 since 64 is in two weeks.

Comment 37

[William Lachance (:wlach)]

Resolving this bug seems to have resulted in a huge drop of content shutdown crash submissions (a good thing, if true!), see bug 1515664 for details.