1163937 - Downloads are not cleared from about:downloads when "Clear on exit" is used

Status: VERIFIED FIXED

(Firefox for Android Graveyard :: Download Manager, defect)

Description

[Flaviu Cos]

Environment: 
Device: Asus Transformer Tab (Android 4.2.1);
Build: Nightly 41.0a1 (2015-05-12);

Steps to reproduce:
1. Launch Fennec;
2. Download some files (e.g.: 1.usa.gov/deeXKM);
3. Go to Settings -> Privacy -> Clear on exit;
4. Check "Downloads" and tap Set;
5. Tap Options and select "Quit" from the menu;
6. Relaunch Fennec and go to about: downloads.

Expected result:
The downloaded files are deleted from device and from about:downloads.

Actual result:
The files are deleted from device but they still appear in about:downloads.

Comment 1

[:Margaret Leibovic]

I thought this would have been fixed with bug 1114506.

I also thought there was another bug where we were talking about how Downloads.jsm didn't flush changes to disk immediately, which sounds like it would result in this behavior. I thought we fixed that, but I can't find a bug number.

Comment 2

[Flaviu Cos]

There is bug 1141550 which is fixed up to Fennec 39.
Fennec 40 and 41 are affected so I logged this new bug.

Comment 3

[Flaviu Cos]

Regression window:

Last good build: 2015-05-01;
First bad build: 2015-05-02;

Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=7723b15ea695&tochange=1e8d30cb367e

Comment 4

[Richard Newman [:rnewman]]

FTR, I disagree with the expected behavior: I'd expect about:downloads to be cleared and the files to *not* be removed without additional prompting. So we currently do the opposite!

Comment 5

[:Margaret Leibovic]

I was able to reproduce this locally, but when I added dump statements in Sanitizer.jsm, it didn't reproduce :/

Paolo, it seems like our fix for bug 1141550 didn't actually work properly (or somehow regressed). Do you know if anything has changed recently with the AsyncShutdown logic we added?

Comment 6

[:Margaret Leibovic]

(In reply to Flaviu Cos, QA [:flaviu] from comment #3)
> Regression window:
> 
> Last good build: 2015-05-01;
> First bad build: 2015-05-02;
> 
> Pushlog:
> http://hg.mozilla.org/mozilla-central/
> pushloghtml?fromchange=7723b15ea695&tochange=1e8d30cb367e

I'm having a tough time finding anything that might be relevant in this regression range :(

Comment 7

[Flaviu Cos]

(In reply to :Margaret Leibovic from comment #6)
> 
> I'm having a tough time finding anything that might be relevant in this
> regression range :(

Inbound regression window:

Last good revision: 4103078c32e5
First bad revision: 67cb93edea83
Pushlog:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=4103078c32e5&tochange=67cb93edea83

Comment 8

[:Paolo Amadini]

(In reply to :Margaret Leibovic from comment #5)
> Paolo, it seems like our fix for bug 1141550 didn't actually work properly
> (or somehow regressed). Do you know if anything has changed recently with
> the AsyncShutdown logic we added?

No, I don't know of anything that may have changed there. Maybe now we exit the process or are killed earlier for some reason?

(In reply to :Margaret Leibovic from comment #6)
> I'm having a tough time finding anything that might be relevant in this
> regression range :(

Same for me. If the failure is intermittent, it might be difficult to identify the actual regression range.

Comment 9

[Robert (rrayborn, he/him)]

I'm seeing some complaints of this issue on Input for 38:
https://input.mozilla.org/en-US/dashboard/response/5389394
https://input.mozilla.org/en-US/dashboard/response/5385399
https://input.mozilla.org/en-US/dashboard/response/5377310
https://input.mozilla.org/en-US/dashboard/response/5369834

Comment 10

[:Margaret Leibovic]

I can reproduce this pretty reliably... I added some logging, and I found that we're even removing the file properly, yet somehow the change to the download list isn't persisting.

Looking back at the patch from bug 1141550, I'm worried that maybe AsyncShutdown doesn't work properly on Fennec... we definitely don't follow the normal shutdown steps that desktop Firefox follows (we live with a "we might be killed at any time" type of mentality). I will dig into this a bit more to see what I can find, but maybe we should see if there's a way to just brute force "write this to disk" from the call we make in Sanitizer.jsm.

Comment 11

[:Margaret Leibovic]

Yoric, can you help me understand how AsyncShutdown works? Is it expected to work properly on Android?

For a bit of context, the Android app lifecycle is different than desktop, and we can expect to be killed at any time, so we usually can't depend on code being run at shutdown. However, we created this "Clear on exit" setting that allows you to clear certain types of data on exit when you explicitly quit the app. This is the code we run when you select a "Quit" menu item:
http://hg.mozilla.org/mozilla-central/annotate/291614a686f1/mobile/android/chrome/content/browser.js#l1358

The issue we're having in this bug (and that we tried to address in bug 1141550) is that that after we remove a download from the list, that change is not persisted to disk before the app totally shuts down. Is there some piece of logic we're missing to make sure the AsyncShutdown blocker works properly?

Or alternately, Paolo, is there a way we can just change the downloads API to force this write after removing the download?

Comment 12

[David Teller [:Yoric] - still alive but not very active]

AsyncShutdown probably doesn't work on Android. If there is a notification you send when shutting down, I could add it to AsyncShutdown, though.

Comment 13

[David Teller [:Yoric] - still alive but not very active]

Let me rephrase: AsyncShutdown *phases* probably don't work on Android, as they are hard-wired to specific phases of the shutdown sequence. But we can add phases hard-wired to the Android shutdown sequence if there is one.

Comment 14

[:Margaret Leibovic]

(In reply to David Rajchenbach-Teller [:Yoric] (away June 22 - July 7th, use "needinfo") from comment #13)
> Let me rephrase: AsyncShutdown *phases* probably don't work on Android, as
> they are hard-wired to specific phases of the shutdown sequence. But we can
> add phases hard-wired to the Android shutdown sequence if there is one.

Looking through our "quit" logic, I see that after we call this sanitize method, we call window.close() to actually quit the app. Is there something that AsyncShutdown listens for during that window.close() sequence? I can also add a notification to that logic that says "hey, we're quitting now", if that helps AysncShutdown do the right thing.

However, I'm not actually clear on what our self-destruct sequence is following that window.close() call... I'd want to make sure we don't kill the app before we're done doing our shutdown logic. snorp, do you know how this works?

Comment 15

[James Willcox (:snorp) ([e-mail]) (he/him)]

(In reply to :Margaret Leibovic from comment #14)
> (In reply to David Rajchenbach-Teller [:Yoric] (away June 22 - July 7th, use
> "needinfo") from comment #13)
> > Let me rephrase: AsyncShutdown *phases* probably don't work on Android, as
> > they are hard-wired to specific phases of the shutdown sequence. But we can
> > add phases hard-wired to the Android shutdown sequence if there is one.
> 
> Looking through our "quit" logic, I see that after we call this sanitize
> method, we call window.close() to actually quit the app. Is there something
> that AsyncShutdown listens for during that window.close() sequence? I can
> also add a notification to that logic that says "hey, we're quitting now",
> if that helps AysncShutdown do the right thing.
> 
> However, I'm not actually clear on what our self-destruct sequence is
> following that window.close() call... I'd want to make sure we don't kill
> the app before we're done doing our shutdown logic. snorp, do you know how
> this works?

Closing the last window should initiate the normal gecko shutdown sequence. Gecko will then exit the main loop. We then set the GeckoExited launch state on the Java side and dispatch the Gecko:Exited message[0]

AFAICT, any special shutdown magic we have in Gecko should work if we explicitly 'quit'. If we are killed by the OS, though, it obviously won't.

[0] https://dxr.mozilla.org/mozilla-central/source/mobile/android/base/GeckoThread.java?from=GeckoThread.java&case=true#191

Comment 16

[:Paolo Amadini]

I realized I have an old needinfo request on this bug, but it looks like ensuring the AsyncShutdown phase works on Android is the way to go here.

Comment 17

[:Margaret Leibovic]

Gah, I've been really bad at following up on this bug. snorp, do you have anyone on your team who could help with this? I know your team has been looking into startup improvements, so maybe you would also be interested in a shutdown fix :)

Comment 18

[James Willcox (:snorp) ([e-mail]) (he/him)]

Yup, Dylan can look into it.

Comment 19

[Dylan Roeh (:droeh) (he/him)]

Attachment: Incomplete patch

snorp, can you take a look at this?

Comment 20

[James Willcox (:snorp) ([e-mail]) (he/him)]

Comment on attachment 8645083 [details] [diff] [review]
Incomplete patch

One problem I see is that Downloads.getList() returns a Promise. So you need to use yield or .then() on it to get the actual list.

Comment 21

[Dylan Roeh (:droeh) (he/him)]

Attachment: Proposed patch

This adds a function called forceSave to DownloadIntegration, which is called by Sanitizer to ensure that the removed downloads don't persist. The problem seems to have been that blocking on finalization of a DeferredTask (in DownloadAutoSaveView) does not ensure the task actually gets completed.

Comment 22

[James Willcox (:snorp) ([e-mail]) (he/him)]

Comment on attachment 8645940 [details] [diff] [review]
Proposed patch

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

Looks good to me! Let's have a front-end person go over this just to make sure.

Comment 23

[:Paolo Amadini]

(In reply to Dylan Roeh (:droeh) from comment #21)
> The
> problem seems to have been that blocking on finalization of a DeferredTask
> (in DownloadAutoSaveView) does not ensure the task actually gets completed.

Hm, this should not happen - if it does, it's probably a bug that we should investigate and solve now rather than working around it.

Also, if it's AsyncShutdown that does not work reliably here, nothing ensures this patch will be 100% reliable, since that's the same mechanism that blocks the shutdown in the sanitizer itself.

Comment 24

[:Paolo Amadini]

Comment on attachment 8645940 [details] [diff] [review]
Proposed patch

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

Thanks for working on this! I have a few comments as it's still unclear to me what exactly isn't working at present.

::: mobile/android/chrome/content/browser.js
@@ +1622,5 @@
>            promises.push(Sanitizer.clearItem(key));
>        }
>      }
>  
> +    AsyncShutdown.profileBeforeChange.addBlocker("Sanitizer: Sanitizing profile", Promise.all(promises));

I think addBlocker expects to be called once per component rather than once per invocation - it might leak memory at each call otherwise.

::: mobile/android/modules/Sanitizer.jsm
@@ +203,5 @@
>        clear: Task.async(function* () {
>          let list = yield Downloads.getList(Downloads.ALL);
>          let downloads = yield list.getAll();
>  
> +        var i = 1;

Leftover?

@@ +220,5 @@
>              // Ensure that the download is stopped and no partial data is kept.
>              // This works even if the download state has changed meanwhile.  We
>              // don't need to wait for the procedure to be complete before
>              // processing the other downloads in the list.
> +            yield download.finalize(true).then(() => null, Cu.reportError);

I believe the comment is still true, we don't need to wait for the procedure to be complete before processing the other downloads in the list.

In fact this patch changed a few things, do we need all of them to solve the issue? Ideally for example we'd not serialize the file removals, we should start them at once and only wait for all of them to complete (that should be handled by the OS.File shutdown blocker already).

Comment 25

[:Paolo Amadini]

Hm, is it possible that the profile-before-change notification fires before the sanitize method had a chance to invoke all the DownloadList.remove calls (that enqueue the JSON file save)?

Comment 26

[Dylan Roeh (:droeh) (he/him)]

Paolo,

Yeah, a couple of leftovers are in that patch that I overlooked, I'll clean those out tomorrow morning.

The reason I yielded for download.finalize was that I didn't see any guarantee that they would actually be finalized before Fennec quits otherwise; I know they don't have to be serialized. I could perhaps do something like build a list of promises from the finalize calls and then yield Promise.all(promises) at the end of the task instead.

How do you recommend handling adding the AsyncShutdown blocker in browser.js if the way I'm doing it will cause a memory leak? I think it's necessary there, but I'll double-check tomorrow to be sure.

I don't think it's possible that the profile-before-change notification fires before the DownloadList.remove calls have all been made -- if this was the case, I don't see how my fix would work. It reaches the DownloadIntegration.forceSave call before the profile-before-change notification fires as best I can tell.

Comment 27

[Dylan Roeh (:droeh) (he/him)]

I have a thought on a possible source of the race condition happening here:

DownloadAutoSaveView._writer.finalize could be called before the DownloadList.remove calls in Sanitizer are made, and once DownloadAutoSaveView._writer is finalized, it can't be re-armed, so the DownloadAutoSaveView.onDownloadRemoved calls triggered by DownloadList.remove are effectively noops. 

Good news: This would explain why my patch (particularly the addition of forceSave to DownloadIntegration) works: because forceSave doesn't rely on DownloadAutoSaveView, and instead directly saves the DownloadStore.

Bad news: This wouldn't explain (as far as I can tell) why changing kSaveDelayMs to 0 also fixes the bug, which is what motivated me to write my patch in the first place. I'll test this more tomorrow, but if anyone has an idea on why setting the delay to 0 would change this behavior I'd be interested to hear.

Comment 28

[Dylan Roeh (:droeh) (he/him)]

Attachment: Proposed patch (updated)

Updated the previous patch to clear out some leftover code and made some changes Paolo suggested.

Comment 29

[:Paolo Amadini]

This solution looks fine to me, though I wonder if there's a better way.

David, can AsyncShutdown handle dependencies between components, like Sanitizer has to be finalized before Downloads is finalized?

Comment 30

[:Paolo Amadini]

(In reply to Dylan Roeh (:droeh) from comment #26)
> How do you recommend handling adding the AsyncShutdown blocker in browser.js
> if the way I'm doing it will cause a memory leak? I think it's necessary
> there, but I'll double-check tomorrow to be sure.

The simplest way may be to implement the automatic sanitization on shutdown as an AsyncShutdown blocker task itself, registered once on startup.

> It reaches the
> DownloadIntegration.forceSave call before the profile-before-change
> notification fires as best I can tell.

Can you add logging to verify? (Note that you want to know when the notification is fired more than when it's handled.)

Comment 31

[:Paolo Amadini]

(In reply to Dylan Roeh (:droeh) from comment #27)
> I have a thought on a possible source of the race condition happening here:
> 
> DownloadAutoSaveView._writer.finalize could be called before the
> DownloadList.remove calls in Sanitizer are made, and once
> DownloadAutoSaveView._writer is finalized, it can't be re-armed, so the
> DownloadAutoSaveView.onDownloadRemoved calls triggered by
> DownloadList.remove are effectively noops. 

Looks likely!

> Bad news: This wouldn't explain (as far as I can tell) why changing
> kSaveDelayMs to 0 also fixes the bug, which is what motivated me to write my
> patch in the first place. I'll test this more tomorrow, but if anyone has an
> idea on why setting the delay to 0 would change this behavior I'd be
> interested to hear.

Maybe that's just timing - other tasks are triggered that block shutdown in the meantime. If you have more than a few downloads, they may have trouble finalizing in this case as well.

Comment 32

[David Teller [:Yoric] - still alive but not very active]

(In reply to :Paolo Amadini from comment #29)
> This solution looks fine to me, though I wonder if there's a better way.
> 
> David, can AsyncShutdown handle dependencies between components, like
> Sanitizer has to be finalized before Downloads is finalized?

Yes, that should fit nicely within the scope of AsyncShutdown.
1/ Create a AsyncShutdown barrier in Downloads;
2/ Instead of finalizing Downloads immediately, have shutdown wait for all blockers of the barrier to be lifted (that's a one-liner);
3/ Expose the barrier client in the API of Downloads;
4/ Tweak Sanitize to register its shutdown as a blocker of that barrier.

Just please don't do 4/ before I have landed bug 1089695, I have sufficient difficulties landing it as is :)

Comment 33

[:Paolo Amadini]

(In reply to David Rajchenbach-Teller [:Yoric] (use "needinfo") from comment #32)
> 4/ Tweak Sanitize to register its shutdown as a blocker of that barrier.
> 
> Just please don't do 4/ before I have landed bug 1089695, I have sufficient
> difficulties landing it as is :)

This is the Android sanitizer, it looks like it's separate from the code you're touching so we should be good to go on that side.

One possible complication is that it appears we should load Downloads.jsm to register the barrier, so we may lose the advantages of the lazy loading of the module. But this may not be a big issue after all.

Comment 34

[:Margaret Leibovic]

Comment on attachment 8646561 [details] [diff] [review]
Proposed patch (updated)

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

If Paolo and Yoric approve, then this looks fine to me. Thanks for picking this up!

Comment 35

[Dylan Roeh (:droeh) (he/him)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=eb5cd71a0122

Comment 36

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/c3438863c173

Comment 37

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/integration/fx-team/rev/c3438863c173

Comment 38

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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

Comment 39

[Flaviu Cos]

Verified as fixed in build 43.0a1 2015-08-21;
Device: Motorola Razr (Android 4.4.4).

Comment 40

[Dylan Roeh (:droeh) (he/him)]

Comment on attachment 8646561 [details] [diff] [review]
Proposed patch (updated)

Approval Request Comment
[Feature/regressing bug #]: 1001309
[User impact if declined]: Downloads may fail to be cleared from about:downloads when they are set to be cleared on exit.
[Describe test coverage new/current, TreeHerder]: https://treeherder.mozilla.org/#/jobs?repo=try&revision=eb5cd71a0122
[Risks and why]: No apparent risks; just adds code to ensure that changes made to downloads during sanitizing persist.
[String/UUID change made/needed]: N/A

Comment 41

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8646561 [details] [diff] [review]
Proposed patch (updated)

This patch has been in Nightly for a week, and the fix has been verified. Seems safe to uplift to Aurora and Beta.

Comment 42

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/6714dfb68afb

Comment 43

[Ryan VanderMeulen [:RyanVM]]

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

Comment 44

[:Paolo Amadini]

Thanks for fixing this! I'll file a follow-up, low priority bug to rework this using a proper AsyncShutdown flow. It's possible that by the time we do that, we'll even have better AsyncShutdown mechanisms in place.

Comment 45

[Flaviu Cos]

Verified as fixed in builds:
- 41 Beta 6;
- 42.0a2 2015-09-01;
Device: Motorola Razr (Android 4.4.4).