Closed Bug 1404105 Opened 7 years ago Closed 7 years ago

Crash in AsyncShutdownTimeout | Places Clients shutdown | sanitize.js: Sanitize,sanitize.js: Sanitize on shutdown

Categories

(Core :: Storage: Quota Manager, defect, P1)

defect

Tracking

()

RESOLVED FIXED
mozilla58
Tracking Status
firefox-esr52 57+ fixed
firefox56 + fixed
firefox57 blocking fixed
firefox58 --- fixed

People

(Reporter: lizzard, Assigned: baku)

References

Details

(Keywords: crash, regression)

Crash Data

Attachments

(2 files)

This bug was filed from the Socorro interface and is 
report bp-151af9d2-018a-44aa-8a9d-041920170928.
=============================================================

We have a fair amount of crashes showing up in the very early 56.0 release results, with similar signatures to this one. It seems unclear if it's something that we think is significantly affecting users.
Bill, Blake, can you take a closer look?
Flags: needinfo?(wmccloskey)
Flags: needinfo?(mrbkap)
Bug 1047098 made this clean up more data stores. I could believe that might end up causing more hangs in this code, particularly if a use had "clear on exit" set but this data wasn't being cleared before, so there was a lot accumulated.
I'm also having this issue with the final release of Firefox 56 that was released to the public. 

https://crash-stats.mozilla.com/report/index/eacf36dc-5a7e-4541-ac9f-4285b1170928

https://crash-stats.mozilla.com/report/index/42321009-7ce6-4bc0-aa8b-fbe771170928

Two Firefox processes never shutdown/get removed from the task manager after closing Firefox. The following launch, Firefox warns that a Firefox is still running and ask to close the hung Firefox process to start a new session. The Firefox has crashed window also randomly shows up to fill a crash report. 


The issue does NOT occur with Firefox 56 b12.
Crash Signature: [@ AsyncShutdownTimeout | Places Clients shutdown | sanitize.js: Sanitize,sanitize.js: Sanitize on shutdown] → [@ AsyncShutdownTimeout | Places Clients shutdown | sanitize.js: Sanitize,sanitize.js: Sanitize on shutdown] [@ AsyncShutdownTimeout | Places Clients shutdown | sanitize.js: Sanitize] [@ AsyncShutdownTimeout | Places Clients shutdown | sanitize.js: Sani…
I'm probably not going to be terribly useful here. It looks like it might be worth adding additional info to the shutdown blocker so we can get more insight into exactly where we're taking too long in shutdown, but beyond that I'm not too sure.
Flags: needinfo?(mrbkap)
Blocks: 1047098
Keywords: regression
OS: Windows 10 → All
Hardware: Unspecified → All
The vast majority of these reports, when using an aggregate on Async Shutdown Timeout shows: "offlineApps":"blocking" in the metadata

So practically sanitize is blocked on trying to cleanup offlineApps: http://searchfox.org/mozilla-central/rev/e62604a97286f49993eb29c493672c17c7398da9/browser/base/content/sanitize.js#289

Based on the pushlog, the following changes happened in sanitize.js and are in 56

Andrea Marchesini - Bug 1402270 - Sanitizer and BrowsingData should delete QuotaManager storages using the origin directly and not the origin as pattern, r=janv
Andrea Marchesini - Bug 1047098 - "Clear Recent History" must clean up all the ServiceWorkers, r=bkelly
Marco Castelluccio - Bug 1357517 - Remove or delay Preferences.jsm usage from some browser/base/content/* files. r=Gijs
Florian Quèze - Bug 1368456 

I can probably exclude the last 2, so the remaining possible candidate is one of the 2 patches involved sanitization of QuotaManager or ServiceWorkers.
Flags: needinfo?(bkelly)
Flags: needinfo?(amarchesini)
ah, quota manager is only in 58, so it must be Bug 1047098
an affected user at https://support.mozilla.org/en-US/questions/1178358#answer-1013700 is reporting that if he's manually trying to clear offline-site-data during the session, that process is still not finished after letting it sit for 30 minutes... does that make sense?
I defer to Andrea and Jan here.
Flags: needinfo?(bkelly)
(In reply to [:philipp] from comment #8)
> an affected user at
> https://support.mozilla.org/en-US/questions/1178358#answer-1013700 is
> reporting that if he's manually trying to clear offline-site-data during the
> session, that process is still not finished after letting it sit for 30
> minutes... does that make sense?

It's possible, it shows that there's a bug and sometimes the promise is never resolved.
I'm getting crashes now, always, on shutdown.  I was using beta 56 to avoid this problem in FF55.  But, beta upgraded to 57 and now half plugins don't work in 57.  But, after going to stable 56, this started happening on my "other" system connected with the same FF account.  The saga of this problem, which was diagnosed, but never actually resolved, is documented in Bug 1397163.

I'm here because the these crashes, the only crashes I've had with 56, show some match with this bug.
Here are the crash IDs:
bp-c54b576b-5ec0-4f16-be73-16e5f0171005
bp-3f39c1b2-aabc-4f9c-8791-a4d170171004
bp-bfd90b01-faab-4849-a671-e23380171004
(In reply to Marco Bonardo [::mak] from comment #10)
> (In reply to [:philipp] from comment #8)
> > an affected user at
> > https://support.mozilla.org/en-US/questions/1178358#answer-1013700 is
> > reporting that if he's manually trying to clear offline-site-data during the
> > session, that process is still not finished after letting it sit for 30
> > minutes... does that make sense?
> 
> It's possible, it shows that there's a bug and sometimes the promise is
> never resolved.

This might be a regression of bug 1047098, but I was not able to reproduce using mozregression. Maybe I missed some steps?
(In reply to sjw from comment #14)
> This might be a regression of bug 1047098, but I was not able to reproduce
> using mozregression. Maybe I missed some steps?

It could be due to some specific detail of your original profile.
(In reply to Tascorla from comment #4)
> I'm also having this issue with the final release of Firefox 56 that was
> released to the public. 
> 
> https://crash-stats.mozilla.com/report/index/eacf36dc-5a7e-4541-ac9f-
> 4285b1170928
> 
> https://crash-stats.mozilla.com/report/index/42321009-7ce6-4bc0-aa8b-
> fbe771170928
> 
> Two Firefox processes never shutdown/get removed from the task manager after
> closing Firefox. The following launch, Firefox warns that a Firefox is still
> running and ask to close the hung Firefox process to start a new session.
> The Firefox has crashed window also randomly shows up to fill a crash
> report. 
> 
> 
> The issue does NOT occur with Firefox 56 b12.

For what it's worth, I fixed the issue by creating a new profile and porting all my extension/bookmarks and saved passwords to that new profile.
(In reply to Marco Bonardo [::mak] from comment #13)
> This bug has nothing to do with bookmarks, as well as your crash ids, if you
> have a separate problem with bookmarks, please file a separate bug for it.

I'm sorry, I don't understand.  The crashes have the same signature as this bug.  Are you saying that is an error on the part of the crash reporting system?  That could be, but your comment is unclear.  It's clear you don't think this bug report is related to bookmark problems.  Okay.  But, it's not clear if you are saying my crashes have nothing to do with bookmarks or if are you saying my crashes are not related to this bug report, even though they share the same signature.
Your crashes are related to this bug, but there's no relation with your bookmarks issues.
Tracking for 57 as well, since right now that this is the top browser crash on Beta 6: https://crash-stats.mozilla.com/topcrashers/?product=Firefox&version=57.0b6&days=7
I really don't know anything about this code. It seems like we should needinfo Jan as well as baku though. Jan, can you look into this? It seems like a regression from bug 1047098.
Flags: needinfo?(wmccloskey) → needinfo?(jvarga)
Jan and baku are talking about how to fix this. I'll give it to Jan for now.
Assignee: nobody → jvarga
Component: DOM: Content Processes → DOM: Quota Manager
Priority: -- → P1
Adding some comments from the crashes in case it helps:

* keep on getting crash messages when Firefox isnt even open. 
* Firefox stays in Memory even after closing. Help!!!! 
* simple opened it after installed and then closed it, upon closing it crashed 
* Firefox keeps deleting history on exit regadless of settings. 
* FF does not close when I exit. I keep getting this message saying it crashed. What the heck is wrong????????????
* keeps crashing when I exit 
* Whenever i close firefox it automatically deletes my history when i open firefox back up and i have it set it to remember history
Ubuntu 16.04.3 LTS

Updated 57.0b7 to 57.0b8 earlier and it did not restart.
The crash reporter came up, but I did not submit that report.
Started 57.0 and the update to 57.0b8 applied.
Since my 57.0 Beta didn't crash on shutdown using a test profile, I tried a refresh.
Firefox crashed on shutdown and didn't reopen. I did submit that crash report.
Started it again and the refresh hadn't applied.
Ended the process using System Monitor to avoid creating another crash report.

Very happy using Nightly.
Ritu, we may want to count this as a 57 blocking issue given the high number of user complaints.
I would also consider it a possible dot release driver for 56.
Flags: needinfo?(rkothari)
Sure. Let's tracking this as a 57 blocker.
Flags: needinfo?(rkothari)
Janv, it seems that the promise is not resolved.  I can add a timeout in order to mitigate this issue but probably we should check what's happening here on a QuotaManager-side.
Flags: needinfo?(amarchesini)
baku, which promise is not resolved ?
Quota manager doesn't use async shutdown, it has its own profile-before-change-qm listener.
Flags: needinfo?(jvarga)
https://dxr.mozilla.org/mozilla-central/source/browser/base/content/sanitize.js#315-318 :

                promises.push(new Promise(r => {                                          
                  let req = quotaManagerService.clearStoragesForPrincipal(principal, null, false);
                  req.callback = () => { r(); };                                                  
                }));
I found a possible problem in JS, but I'm not sure if that fixes this bug.
baku is working on a patch and I will review it.
Attached patch quota.patchSplinter Review
Assignee: jvarga → amarchesini
Attachment #8918802 - Flags: review?(jvarga)
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

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

::: browser/base/content/sanitize.js
@@ +309,5 @@
>          await new Promise(resolve => {
>            quotaManagerService.getUsage(request => {
> +            if (request.resultCode != Cr.NS_OK) {
> +              // We are probably shutting down. We don't want to propagate the
> +              // error, rejecting the promise.

Not sure, why we may fail here, but for now the comment is ok.
Attachment #8918802 - Flags: review?(jvarga) → review+
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b767da767ec5
Sanitize.js must check if QuotaManager returns an error before continuing with cleaning data, r=janv
One possible explanation for the failing getUsage() would be that a user runs "profile from future".
(In reply to Jan Varga [:janv] from comment #33)
> One possible explanation for the failing getUsage() would be that a user
> runs "profile from future".

I think that matches my case.  I had problems with FF 55, and I tried 56 Beta channel, which was working much better.  But, then 57 came to the beta channel and half my plugins broke.  So, I went back to the release channel.  So, my profile experienced 57 briefly.  Does that fit?  Am I being helpful?
(In reply to Porcelain Mouse from comment #34)
> (In reply to Jan Varga [:janv] from comment #33)
> > One possible explanation for the failing getUsage() would be that a user
> > runs "profile from future".
> 
> I think that matches my case.  I had problems with FF 55, and I tried 56
> Beta channel, which was working much better.  But, then 57 came to the beta
> channel and half my plugins broke.  So, I went back to the release channel. 
> So, my profile experienced 57 briefly.  Does that fit?  Am I being helpful?

Yes, there was a storage version bump between FF 56 and 57.
Thanks, it was really helpful.
But why was Nightly also crashing?(In reply to Jan Varga [:janv] from comment #33)
> One possible explanation for the failing getUsage() would be that a user
> runs "profile from future".

But why was Nightly also crashing?
It sounds to me like we have some profile storage schema mismatch going on in nightly as well.  For example, see bug 1409115.
Note, in FF57 we began preventing a lot of service worker call sites when nsContentUtils::StorageAllowed() returns eDeny.  Is there any correlation with cookie policy and the issues here?
(In reply to Ben Kelly [:bkelly] from comment #38)
> Note, in FF57 we began preventing a lot of service worker call sites when
> nsContentUtils::StorageAllowed() returns eDeny.  Is there any correlation
> with cookie policy and the issues here?

I don't think so.
https://hg.mozilla.org/mozilla-central/rev/b767da767ec5
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
Please request uplift to beta when you get a chance.
Flags: needinfo?(amarchesini)
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

Approval Request Comment
[Feature/Bug causing the regression]:Bug 1402270 
[User impact if declined]: FF can freeze on shutdown.
[Is this code covered by automated tests?]: no
[Has the fix been verified in Nightly?]: manually yes.
[Needs manual test from QE? If yes, steps to reproduce]: no
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: low.
[Why is the change risky/not risky?]: It's just a resultCode check before processing the array of origins
[String changes made/needed]: none
Flags: needinfo?(amarchesini)
Attachment #8918802 - Flags: approval-mozilla-beta?
(In reply to Ben Kelly [:bkelly] from comment #37)
> It sounds to me like we have some profile storage schema mismatch going on
> in nightly as well.  For example, see bug 1409115.

I've re-audited known schema versions via the searchfox links at the bottom of https://public.etherpad-mozilla.org/p/quota-manager-schema-change-log and nothing has changed since 57.  I've also added the PushDB (unchanged since 47/43 depending on platform) for completeness given my interest in Push for the ghost window bug.
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

This is a top crasher on 57, Beta57+
Attachment #8918802 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Will ride the train with 57 as it is not a new crash
It was a last minute regression in 56 and should go in 52.5 if 1402270 does.
Since this fixed the crashes in 57 beta 10, can you request uplift to m-r if it will apply correctly? Thanks.
Flags: needinfo?(amarchesini)
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

Approval Request Comment
[Feature/Bug causing the regression]:Bug 1402270 
[User impact if declined]: FF can freeze on shutdown.
[Is this code covered by automated tests?]: no
[Has the fix been verified in Nightly?]: manually yes.
[Needs manual test from QE? If yes, steps to reproduce]: no
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: low.
[Why is the change risky/not risky?]: It's just a resultCode check before processing the array of origins
[String changes made/needed]: none
Flags: needinfo?(amarchesini)
Attachment #8918802 - Flags: approval-mozilla-release?
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

Fix for a top crash that seems to have a big impact on users on release.
Attachment #8918802 - Flags: approval-mozilla-release? → approval-mozilla-release+
How could bug 1402270 be the cause of the regression when it only landed in 58?
Flags: needinfo?(amarchesini)
This doesn't graft to m-r. AFAICT, it depends on code which landed in bug 1333050 (which wasn't uplifted to 56). Is there an alternate patch required?
We sorted it out over IRC. Only the sanitize.js change is needed on m-r, and that one grafts cleanly.
Flags: needinfo?(amarchesini)
Please nominate this for ESR52 approval.
Flags: needinfo?(amarchesini)
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

[Approval Request Comment]
User impact if declined: When QuotaManager data is deleted, the status of the operation is not checked and we end up triggering a JS error. This blocks the shutting down of firefox and triggers a crash. This patch fixes this issue.
Fix Landed on Version: 56
Risk to taking this patch (and alternatives if risky): low. The patch just checks the status of the operation before continuing.
String or UUID changes made by this patch: none.
Flags: needinfo?(amarchesini)
Attachment #8918802 - Flags: approval-mozilla-esr52?
Comment on attachment 8918802 [details] [diff] [review]
quota.patch

Fix for shutdown crash, also needed for bug 1047098.
Attachment #8918802 - Flags: approval-mozilla-esr52? → approval-mozilla-esr52+
Blocks: 1415342
See Also: → 1725820
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: