1473837 - Firefox can not remove the extension XPI from OS temporary folder

Status: VERIFIED FIXED

(Toolkit :: Add-ons Manager, defect, P2)

Description

[CoolCmd]

User Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0
Build ID: 20180621125625

Steps to reproduce:

install the extension, for example: https://addons.mozilla.org/en-US/firefox/addon/twitch_5/



Actual results:

open the browser console. it contains:

1530867882557	addons.xpi	WARN	 Failed to remove temporary file D:\Temp\tmp-y3n.xpi for addon https://addons.mozilla.org/firefox/downloads/file/1004981/alternate_player_for_twitchtv_twitch_5-2018.7.3-an+fx.xpi: [Exception... "Component returned failure code: 0x80520015 (NS_ERROR_FILE_ACCESS_DENIED) [nsIFile.remove]"  nsresult: "0x80520015 (NS_ERROR_FILE_ACCESS_DENIED)"  location: "JS frame :: resource://gre/modules/addons/XPIInstall.jsm :: removeTemporaryFile :: line 1729"  data: no] Stack trace: removeTemporaryFile()@resource://gre/modules/addons/XPIInstall.jsm:1729
startInstall/<()@resource://gre/modules/addons/XPIInstall.jsm:2061

restart the browser. the file D:\Temp\tmp-y3n.xpi is still exists.

this also happens on extension update. my temporary folder holds tens of temporary XPIs.



Expected results:

after installation, temporary files should be deleted.

Comment 1

[CoolCmd]

the folder has permission for delete files for all users on my computer.

Comment 2

[David Durst [:ddurst]]

Do you have an active backup program or virus scanner that has a lock on this file?

Comment 3

[CoolCmd]

none of these programs is installed

Comment 4

[David Durst [:ddurst]]

Can we please see if we can reproduce this? It's the only report, and it sounds OS-related, but this is the first step.

Comment 5

[CoolCmd]

actually 2 reports. user of my webextension sent me console screenshot with the identical error.

Comment 6

[Vlad Jiman]

The issue is reproducible by installing the extension from the example having the console open: 

(WARN	Failed to remove temporary file C:\Users\VLAD~1.JIM\AppData\Local\Temp\tmp-mtl.xpi for addon https://addons.mozilla.org/firefox/downloads/file/1022106)

The file is still present after restarting the browser.

Reproduced using Firefox 63.0a1 (20180723220051), Firefox 61.0.1 (20180704003137) and Firefox 62.0b9 (20180713213322) running on Win 10 x64.

Comment 7

[Luca Greco [:rpl] [:luca] [:lgreco]]

I just tried to reproduce this on a recent Nightly running on Windows 10 and dig into it a bit more, and this seems to be reproducible consistently. 
As we suspected it is not an issue specific to a particular extension xpi file, I've been able to reproduce the same issue by installing any other extensions from AMO.

The NS_ERROR_FILE_ACCESS_DENIED error seems to be raised because the file is still open, and it seems that it is kept open by Firefox itself (I briefly verified it by using ProcessExplorer, https://docs.microsoft.com/en-us/sysinternals/downloads/process-explorer, and also by trying to remove the file as a user from the file browser, which fails until that Firefox instance is not running anymore). 

In my opinion, we are currently keeping the file open because we open the archive file to retrieve the addon metadata (which are then used in the install doorhanger):

- https://searchfox.org/mozilla-central/search?q=loadManifest%28this.file%29&path=toolkit%2Fmozapps%2Fextensions

and so, to "free" this open file, it seems that we should be sure to "flush the jar cache" for this file at least right before we try to remove it here:

- https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/toolkit/mozapps/extensions/internal/XPIInstall.jsm#1499

(e.g. using `Services.obs.notifyObservers(this.file, "flush-cache-entry");` or the `flushJarCache` helper function already defined in 'XPIInstall.jsm')

Flushing the jar cache is something that we already do in many cases for the exact same reason (Windows raised the Ns_ERROR_FILE_ACCESS_DENIED otherwise), https://searchfox.org/mozilla-central/search?q=flushJarCache(&case=false&regexp=false&path=, but apparently we are not currently flushing the jar cache for this file.

Comment 8

[Andrew Swan [:aswan]]

We do flush the jar cache from here:
https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/toolkit/mozapps/extensions/internal/XPIInstall.jsm#1575

However, I guess we're flushing it too early since we build a jar: url for the icon to use in the install dialog which re-opens the file.  Ugh.  Perhaps for the purpose of the AddonInstall object we should read the icon into a blob or even a data url?

Comment 9

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to Andrew Swan [:aswan] from comment #8)
> We do flush the jar cache from here:
> https://searchfox.org/mozilla-central/rev/
> d47c829065767b6f36d29303d650bffb7c4f94a3/toolkit/mozapps/extensions/internal/
> XPIInstall.jsm#1575
> 
> However, I guess we're flushing it too early since we build a jar: url for
> the icon to use in the install dialog which re-opens the file.  Ugh. 
> Perhaps for the purpose of the AddonInstall object we should read the icon
> into a blob or even a data url?

Yep, it looks like it, we are re-opening the jar file from getIcon [1] which is called in the checkPrompt [2].

Turning the icon into a blob or data url from inside getIcon sounds like a good idea, because we could make getIcon responsible to flush the jar cache right after it has retrieved and converted the icon. 

[1]: https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/toolkit/mozapps/extensions/internal/XPIInstall.jsm#1606-1616
[2]: https://searchfox.org/mozilla-central/rev/d47c829065767b6f36d29303d650bffb7c4f94a3/toolkit/mozapps/extensions/internal/XPIInstall.jsm#1631

Comment 10

[Andrew Swan [:aswan]]

I was thinking we would read it in loadManifest() and keep the current flush logic.  I'm working under the premise that flushing the jar cache is expensive and we should avoid doing it too often, which is oral tradition rather than something I have specific numbers or documentation to back up...

Comment 11

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: Bug 1473837 - AddonInstall should flush the jar cache for the temporary xpi file before trying to remove it.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c4f020146cf8
AddonInstall should flush the jar cache for the temporary xpi file before trying to remove it. r=kmag

Comment 13

[Alexandru Michis [:malexandru]]

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

Comment 14

[Alex Cornestean]

Verified the fix using the latest Nightly (70.0a1/20190821215524) under Windows 10 Pro 64-bit and macOS High Sierra 10.13.6.

The warning message is no longer displayed in the browser console and the temporary XPI is deleted from the temp folder immediately after the extension is installed in the browser, thus confirming the fix.

Comment 15

[Luca Greco [:rpl] [:luca] [:lgreco]]

Comment on attachment 9084271 [details]
Bug 1473837 - AddonInstall should flush the jar cache for the temporary xpi file before trying to remove it.

Beta/Release Uplift Approval Request

• User impact if declined: Firefox doesn't remove the temporary xpi files related to the extensions installed by the user. These temporary files cannot even be removed manually by the user while the Firefox instance that has created them is still running.
• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: Same steps used to verify the fix on Nightly (as described by the reporter in comment 0).
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): One line change (which just makes sure that the jar cache for the temporary xpi file is flushed right before trying to remove it).
• String changes made/needed:

Comment 16

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9084271 [details]
Bug 1473837 - AddonInstall should flush the jar cache for the temporary xpi file before trying to remove it.

Simple fix to allow temporary XPIs to be removed. Approved for 69.0b16.

Comment 17

[Arthur Iakab [arthur_iakab]]

https://hg.mozilla.org/releases/mozilla-beta/rev/14b258057e34

Comment 18

[Alex Cornestean]

Verified the fix using the latest Beta (69.0b16/20190822210915) under Windows 10 Pro 64-bit and macOS High Sierra 10.13.6.

The warning message is no longer displayed in the browser console and the temporary XPI is deleted from the temp folder immediately after the extension is installed in the browser, thus confirming the fix.

Comment 21

[Serhiy]

I'm still seeing fresh tmp-*.xpi files in temp that are not being deleted on Linux in fresh versions: it's at least 75 through 76.0.1 but I have the folder in tmpfs so it's possible it never stopped. Should I reopen this report or start a new one?

Comment 22

[Alex Cornestean]

Hello,

I’ve rechecked the issue and when installing add-ons from AMO, all tmp-*.xpis are properly deleted from the generic temp folders upon the install completing, no errors being shown in the browser console either. I’ve rechecked on the latest Nightly (78.0a1/20200518214824), Beta (77.0b7/20200515125749) and Release (76.0.1/20200507114007) under Windows 10 Pro 64-bit, macOS Catalina 10.15 and Ubuntu 16.04.

In what concerns the tmpfs file system on Linux, it is beyond my technical knowledge and could not check there.

However, while investigating the current issue, I’ve come across a bug which might explain the behavior you have encountered (i.e tmp-*.xpi files not being deleted from temp folders). Please see https://bugzilla.mozilla.org/show_bug.cgi?id=1639163 for further details.

Comment 23

[Serhiy]

Thank you! I forgot to specify that it happens on add-on upgrades. I don't think tmpfs is the reason, I cannot imagine how that would affect things. I guess #1639163 covers this issue too anyway.

Comment 24

[Alex Cornestean]

Hi Сергій,

I just checked what you said about add-on upgrades and still cannot reproduce the issue.

I attempted to reproduce on the latest Nightly, Beta and Release on Windows 10 Pro 64-bit and Ubuntu 16.04 LTS with uBlock Origin, Ghostery and Decentraleyes.

Indeed a tmp-*.xpi file is created as soon as the add-on update process begins, but it’s deleted once the add-on is updated.

Note: After installing an older version of the mentioned add-ons, I’ve manually checked for add-on updates via “Check for Updates” from the cog wheel menu.

Comment 25

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to Сергій from comment #23)

Thank you! I forgot to specify that it happens on add-on upgrades. I don't think tmpfs is the reason, I cannot imagine how that would affect things. I guess #1639163 covers this issue too anyway.

I'm wondering if the tmp-*.xpi files not being removed may be related to "postponed addon upgrades".

would you mind to try to reproduce the issue and then collect and send me a small sample of the tmp-*.xpi files?

I'd like to double-check if it may be the same underlying issue that the patch attached to Bug 1495021 is meant to fix.

Comment 26

[Serhiy]

Yes, I have two files currently, 2.8MiB each. Sending them to your e-mail. Unless you meant changing some settings and then waiting for them to appear.

Comment 27

[Serhiy]

GMail didn't like it at all. Any other way I can send them or can I just open them and give you some short text info?

Comment 28

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to Сергій from comment #27)

GMail didn't like it at all. Any other way I can send them or can I just open them and give you some short text info?

Send me just the manifest.json files, that may be enough to let me identify which extensions the xpi files are related to.

Thanks a lot!

Comment 29

[Serhiy]

Sent them, it's uBlock Origin 1.27.2 and 1.27.0

Comment 30

[Luca Greco [:rpl] [:luca] [:lgreco]]

Thanks for collecting and sending the manifest files to me.

Yeah, both the xpi files are related to "uBlock origin", and so I can now confirm that the issue you are experiencing is related to the "postponed add-on upgrades" as I was initially assuming (uBlock origin is one of the few extension that is using a post-poned upgrade, and so it is triggering this issue).

The issue with the temporary file should be fixed by the patch attached to Bug 1495021, while a more visible feedback (and fix) for the postponed upgrades is going to be part of Bug 1627495.

You can follow those two bugs to be notified by bugzilla once we will land the patch to fix them.

Thanks again for your help on investigating this.