Closed Bug 1474557 Opened 6 years ago Closed 6 years ago

Prevent ExtensionStorageIDB and child/ext-storage.js from caching a stale or rejected selectBackend promise

Categories

(WebExtensions :: Storage, defect, P1)

Product:
WebExtensions
Component:
Storage
Version:
62 Branch
Type:
defect

Tracking

(firefox-esr52 unaffected, firefox-esr60 unaffected, firefox61 unaffected, firefox62 verified, firefox63 verified)

Status:
VERIFIED FIXED
Milestone:
mozilla63
Tracking Flags:
Tracking Status
firefox-esr52 --- unaffected
firefox-esr60 --- unaffected
firefox61 --- unaffected
firefox62 --- verified
firefox63 --- verified

People

(Reporter: rpl, Assigned: rpl)

References

Details

(Keywords: regression)

Attachments

(5 files, 1 obsolete file)

Bug 1474557 - Prevent ExtensionStorageIDB and child/ext-storage from caching a stale or rejected selectBackend promise.
59 bytes, text/x-review-board-request
mixedpuppy
: review+
lizzard
: approval-mozilla-beta+
Details
Bug 1474557 - Clear the dbPromise cached by ext-storage when IndexedDB raises an exception while opening the db.
59 bytes, text/x-review-board-request
mixedpuppy
: review+
lizzard
: approval-mozilla-beta+
Details
storage-local-stale-promises.xpi
5.96 KB, application/x-xpinstall
Details
Bug1474557.png
297.91 KB, image/png
Details
Bug1474557.png
70.72 KB, image/png
Details 
Last week I've been chasing this issue, I notice it while I was looking into the issue described in Bug 1406181 comment 317.

If an extension context calls a storage.local API method and then it is immediately destroyed while the call is still waiting for the main process to reply, then the promise returned by context.childManager.callParentAsyncFunction may never be resolved (because it is a Promise object created from a context that has been nuked and so that Promise object becomes a dead wrapper).
I have been able to reproduce it from an automated test case, and I also verified how easily a user may experience this issue while using a real webextension on a promise that uses the JSONFile backend:

To trigger this issue with Adblock Plus, it seems that Firefox has to starts with a session to restore after a previous crash (for me it has been enough to kill the Firefox process instead of exiting Firefox cleanly), and then open the Adblock Plus options page to check that the none of the saved options seem to have been loaded. 

The issue is triggered by Adblock plus because of a storage.local.get API method called from a context that is immediately destroyed (call is coming from its polyfill.js source file, which uses that API call to detect if the promised APIs are available).

On Adblock Plus, the issues seems to be more easily triggered when e10s mode is disabled (but with the automated test case I verified that it is a scenario that can be triggered in both e10s and non-e10s mode).

The issue is not that visible because it doesn't log any error, but the issue can be easily verified by opening the Addon Debugging window on the extension and verifying that (after triggering the issue) the promises returned from any browser.storage.local API calls are not resolved anymore (and that is the reason why the options page is not able to load the save options anymore).
Assignee: nobody → lgreco
Blocks: 1406181, 1470213
Status: NEW → ASSIGNED
status-firefox62: --- → affected
status-firefox63: --- → affected
Priority: -- → P1
Attachment #8990953 - Flags: review?(mixedpuppy)
Blocks: 1474562
Comment on attachment 8990981 [details]
Bug 1474557 - Fix storage.local JSONFile backend unable to store data successfully from a destroying context.

This is an additional small set of changes (applied on top of the other patch in this mozreview request) which fix the issue described in Bug 1406181 comment 37.

With the change applied by Bug 1406181, even when the storage.local IDB backend has not been turned on, the first storage.local API call will have to call the parent process twice (one to ask for the selected backend, and migrate the data to the new backend if enabled, and then a second one to send the data to be stored to the main process if the enabled backend is the JSONFile one).  

I've added it as a separate patch because I wanted to ask you on it an initial feedback first, because:

it should be enough to fix that regression when the storage.local backend is the JSONFile one, but it doesn't yet fix it when the IndexedDB backend is enabled (it currently still need to ask to the main process to migrate the data if needed).

Nevertheless this is still a regression in behavior for Firefox 62, where the JSONFile backend is still the enabled one, and so it seems worth to double-check with you if we want to fix that regression on the JSONFile backend even if the new IDB backend is not yet fixed (and we still need to evaluate if and how to fix it for the new backend).

Let me know what do you think about it.
Attachment #8990981 - Flags: feedback?(mixedpuppy)
Comment on attachment 8990953 [details]
Bug 1474557 - Prevent ExtensionStorageIDB and child/ext-storage from caching a stale or rejected selectBackend promise.

https://reviewboard.mozilla.org/r/255940/#review262832

::: toolkit/components/extensions/ExtensionStorageIDB.jsm:394
(Diff revision 1)
> -        })();
> -      } else {
> +          }
> +
> +          // Cache the result using a promise object that is not tied to the current extension context,
> +          // because we are caching it for the entire life of the extension in the current process (and
> +          // the promise returned by context.childManager.callParentAsyncFunction would become a dead
> +          // object when the context.cloneScope has been destroyed).

maybe some tweaks on this comment as we discussed on irc
Attachment #8990953 - Flags: review?(mixedpuppy) → review+
Attachment #8990981 - Flags: feedback?(mixedpuppy)
Comment on attachment 8990981 [details]
Bug 1474557 - Fix storage.local JSONFile backend unable to store data successfully from a destroying context.

https://reviewboard.mozilla.org/r/255990/#review262848

::: toolkit/components/extensions/ExtensionStorageIDB.jsm:416
(Diff revision 2)
>  
>            return result;
>          });
>        }
>  
>        // If migrating to the IDB backend is not enabled by the preference, then we

comment is no longer entirely correct

::: toolkit/components/extensions/ExtensionStorageIDB.jsm:418
(Diff revision 2)
>        if (!this.isBackendEnabled) {
> -        return Promise.resolve({backendEnabled: false});
> +        promise = Promise.resolve({backendEnabled: false});
> +        this.selectedBackendPromises.set(extension, promise);
> +        return promise;

Since the blocks are very similar...consider moving this block up and doing something like:

if (!backendenabled) {
  if (childmanager) {
    callParentAsyncFunction
  }
  promise = Promise.resolve({backendEnabled: false});
  this.selectedBackendPromises.set(extension, promise);
  return promise
}

if (childmanager)
  ...
Attachment #8990981 - Flags: feedback?(mixedpuppy) → feedback+
Attachment #8990981 - Flags: review?(mixedpuppy)
Comment on attachment 8991621 [details]
Bug 1474557 - Clear the dbPromise cached by ext-storage when IndexedDB raises an exception while opening the db.

https://reviewboard.mozilla.org/r/256540/#review263412

This is moved here from bug 1470213 where I already r+'d.
Attachment #8991621 - Flags: review?(mixedpuppy) → review+
Blocks: 1475306
Comment on attachment 8990981 [details]
Bug 1474557 - Fix storage.local JSONFile backend unable to store data successfully from a destroying context.

https://reviewboard.mozilla.org/r/255990/#review263688

::: toolkit/components/extensions/ExtensionStorageIDB.jsm:371
(Diff revision 4)
>      if (!this.selectedBackendPromises.has(extension)) {
>        let promise;
>  
> +      // If the IDB backend is not enabled by the preference, then we
> +      // don't need to migrate any data and the new backend is not enabled.
> +      if (!this.isBackendEnabled) {
> +        if (context.childManager) {
> +          // Ensure that the `isBackendEnabled` lazy preference getter is also initialized
> +          // in the main process with the same value cached in the child process.
> +          context.childManager.callParentAsyncFunction(
> +            "storage.local.IDBBackend.isBackendEnabled", []
> +          );
> +        }
> +
> +        // Resolve immediately, so that the storage.local.set has a chance to be completed even
> +        // when called from a context that is destroyed immediately after a storage.local.set
> +        // API call.
> +        promise = Promise.resolve({backendEnabled: false});
> +        this.selectedBackendPromises.set(extension, promise);
> +        return promise;
> +      }
> +

The last revision the !this.isBackendEnabled happened after the block it is in now, so my requested change might be a little incorrect.  It seems like moving this up to its own block just before the selectedBackendPromises if statement would result in the prior behavior being handled.
Attachment #8990981 - Flags: review?(mixedpuppy)
Comment on attachment 8990981 [details]
Bug 1474557 - Fix storage.local JSONFile backend unable to store data successfully from a destroying context.

https://reviewboard.mozilla.org/r/255990/#review263688

> The last revision the !this.isBackendEnabled happened after the block it is in now, so my requested change might be a little incorrect.  It seems like moving this up to its own block just before the selectedBackendPromises if statement would result in the prior behavior being handled.

As we discussed over vidyo, I'm still not happy about how this patch is trying to solve this issue (the scenario where "the first storage.local call for an extension is a storage.local.set coming from a context that is being destroyed", e.g. an extension popup).

Like it is right now (as well as its previous versions), I'm pretty sure that it is breaking the part of this method that makes sure that the "main process" propagates the same selected backend to all the extension contexts related to the same extension (which may run in the different processes, e.g. the extension and the content child processes) for the entire life of the extension (regardless of any changes to the `extensions.webextensions.ExtensionStorageIDB.enabled` preference that may be happening while that extension is still running).

And, as mentioned in comment 4, this patch does not even solve the same issue when the IndexedDB backend is selected. 

I'm going to drop this patch from this mozreview request in the meantime, I've some other ideas that may fit better, but I think that it would be better to handle them separately and land the fixes for the "caching of stale and rejected promises" issues first.
Attachment #8990981 - Attachment is obsolete: true
Attachment #8990981 - Flags: review?(mixedpuppy)
Pushed by luca.greco@alcacoop.it:
https://hg.mozilla.org/integration/autoland/rev/18c5ad6ddb9e
Prevent ExtensionStorageIDB and child/ext-storage from caching a stale or rejected selectBackend promise. r=mixedpuppy
https://hg.mozilla.org/integration/autoland/rev/d2b1558a677c
Clear the dbPromise cached by ext-storage when IndexedDB raises an exception while opening the db. r=mixedpuppy
https://hg.mozilla.org/mozilla-central/rev/18c5ad6ddb9e
https://hg.mozilla.org/mozilla-central/rev/d2b1558a677c
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
status-firefox63: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla63
The attached xpi contains a small test extension that can be used to more easily trigger the issue on an affected and a fixed builds, and verify that it has been fixed in a recent nightly build and that can be still reproduced on an affected one (e.g. an older nightly and beta).

STR:
- start Firefox and install the attached test extension temporarily
- open the browser console and clear the messages already logged
- open the browserAction popup and press the "storage.local.get and close" button
  (the popup should close itself)
- open the browserAction popup again and press the "storage.local.get and wait" button

Expected behavior (and actual behavior) on the fixed version:
- a "CALLING storage.local.get and wait for its result" message should have been logged in the browser console
- a "RESOLVED storage.local.get" message should have been logged in the browser console right after the previous one

Actual behavior on the non-fixed version:
- a "CALLING storage.local.get and wait for its result" message should have been logged in the console
- no "RESOLVED storage.local.get" message is actually logged
- pressing again the "storage.local.get and wait" button logs the "CALLING ...." message, but the "RESOLVED ..." message is never logged
Flags: qe-verify+
Attached image Bug1474557.png — 
I was able to reproduce this issue with OOP set to false on Firefox 62.0b9 (20180713213322) under Win 7 64-bit and Mac OS X 10.13.3.

This issue is verified as fixed on Firefox 63.0a1 (20180716221418) under Win 7 64-bit and Mac OS X 10.13.3.

Please see the attached screenshot.
Status: RESOLVED → VERIFIED
status-firefox63: fixed → verified
Flags: qe-verify+
Comment on attachment 8990953 [details]
Bug 1474557 - Prevent ExtensionStorageIDB and child/ext-storage from caching a stale or rejected selectBackend promise.

Approval Request Comment
[Feature/Bug causing the regression]:
Bug 1406181

[User impact if declined]:
Extensions that trigger the issue are not able to retrieve or set data from the storage.local API (and the promises returned by the storage.local API are never resolved).

The issue can be triggered by an extension (even if the new storage.local IndexedDB preference is not enabled),
by calling a storage.local API methods from a destroying context (e.g. an extension popup that is closed right
after calling the storage.local API). 

Some popular extensions seem to be able to trigger the issue, e.g. AdBlock Plus can trigger this issue when Firefox is started with a session to restore (and when triggered the extension is not able to load the filters and the other options that are stored into the storage.local).

[Is this code covered by automated tests?]:
Yes

[Has the fix been verified in Nightly?]:
Yes

[Needs manual test from QE? If yes, steps to reproduce]: 
Yes, same STR used to verify the issue on Nightly (Comment 26)

[List of other uplifts needed for the feature/fix]:
None

[Is the change risky?]:
Low

[Why is the change risky/not risky?]:
The change is limited to the storage.local API internals, and so it can't introduce regression on the other extensions API or to the other Firefox features, and the API and the fixes applied have automated tests to prevent the other expected behaviors from regress.

[String changes made/needed]:
None
Attachment #8990953 - Flags: approval-mozilla-beta?
Comment on attachment 8991621 [details]
Bug 1474557 - Clear the dbPromise cached by ext-storage when IndexedDB raises an exception while opening the db.

See Comment 28.
Attachment #8991621 - Flags: approval-mozilla-beta?
Comment on attachment 8990953 [details]
Bug 1474557 - Prevent ExtensionStorageIDB and child/ext-storage from caching a stale or rejected selectBackend promise.

Fix for regression in 62, verified in nightly, let's take this for beta 62. 
Thanks for the new test.
Attachment #8990953 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Attachment #8991621 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Attached image Bug1474557.png — 
This issue is verified as fixed on Firefox 62.0b10 (20180719140244) under Win 7 64-bit and Mac OS X 10.13.3.

Please see the attached screenshot.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: