1373671 - AddonManager does not seem emit "onInstallCompleted" message after all installation steps for an addon have completed

Status: RESOLVED INVALID

(Toolkit :: Add-ons Manager, defect)

Description

[Victor Ng [:vng] [:crankycoder]]

The AddonManager does not seem to emit the onInstallEnded message at the right time.

The following code snippet will fail when the uninstall is attempted.  It looks like the order of execution I'm seeing is:

1) addon is installed
2) addon is uninstalled
3) addon manifest file read is attempted 


I think the problem is in `toolkit/mozapps/extensions/internal/XPIInstall.jsm:checkPrompt` as it' fires off an asynchronous function immediately to do things like get the icon - which is in the manifest.

This bug was noticed in https://github.com/mozilla/normandy/pull/778#discussion_r122076191 

'''
async function installAddon(installUrl) {
  const installObj = await AddonManager.getInstallForURL(installUrl, null, "application/x-xpinstall");
  const result = new Promise((resolve, reject) => installObj.addListener({
    onInstallEnded(addonInstall, addon) {
      resolve(addon.id);
    },
    onInstallFailed(addonInstall) {
      reject(`AddonInstall error code: [${addonInstall.error}]`);
    },
    onDownloadFailed() {
      reject(`Download failed: [${installUrl}]`);
    },
  }));
  installObj.install();
  return result;
};


async function uninstallAddon(addonId) {
  const addon = await AddonManager.getAddonByID(addonId);
  if (addon === null) {
    throw new Error(`No addon with ID [${addonId}] found.`);
  }
  addon.uninstall();
  return null;
};

var addonId = await installAddon(xpiUrl);
await uninstallAddon(addonId);
'''

Comment 1

[Andrew Swan [:aswan]]

Can you provide more detail about how this fails?  checkPrompt() doesn't advance the install state machine until the user responds to the install notification.  Its certainly possible that it has a bug but we could use some more detail.
Specifically: what extension were you installing this way and what is the error you saw?

Comment 2

[Victor Ng [:vng] [:crankycoder]]

:aswan I noticed this problem when adding an installAddon() and uninstallAddon() API hook into browser/extensions/shield-recipe-client/lib/NormandyDriver.jsm

The problem shows up only in my tests when I have a dummy webextension that is just a manifest.json file with no actual script code.

The entire webextension code can be found here: https://github.com/mozilla/normandy/blob/master/recipe-client-addon/test/browser/fixtures/addon-fixture/manifest.json

The NormandyDriver is meant to automate the install and uninstall of SHIELD addons, so the testcase was installing and then immediately uninstalling the test fixture addon.

Actual test case is over here: 

https://github.com/mozilla/normandy/blob/113e61b5b6a8cac2e2f6cc2164e0f1e04da3a826/recipe-client-addon/test/browser/browser_NormandyDriver.js#L21

We could only resolve this by adding the call to SimpleTest.executeSoon between the install and uninstall API calls. 

Without the executeSoon() call - I get a stacktrace in my test runs that looks like:


GECKO(29739) | Extension error: Failed to open input source 'jar:file:///var/folders/b3/wz8byszx531_gwwzp7bzx8yw0000gn/T/tmpxd80ip.mozrunner/extensions/[e-mail]!/manifest.json' resource://gre/modules/Extension.jsm:428 :: readJSON/<@resource://gre/modules/Extension.jsm:428:7
GECKO(29739) | readJSON@resource://gre/modules/Extension.jsm:425:12
GECKO(29739) | parseManifest@resource://gre/modules/Extension.jsm:487:7
GECKO(29739) | parseManifest/<@resource://gre/modules/Extension.jsm:867:45
GECKO(29739) | get@resource://gre/modules/ExtensionParent.jsm:1328:25
GECKO(29739) | async*parseManifest@resource://gre/modules/Extension.jsm:866:12
GECKO(29739) | loadManifest@resource://gre/modules/Extension.jsm:537:7
GECKO(29739) | async*loadManifest@resource://gre/modules/Extension.jsm:871:12
GECKO(29739) | _startup@resource://gre/modules/Extension.jsm:1023:42
GECKO(29739) | async*startup@resource://gre/modules/Extension.jsm:999:27
GECKO(29739) | startup@resource://gre/modules/addons/XPIProvider.jsm -> resource://gre/modules/addons/WebExtensionBootstrap.js:29:3
GECKO(29739) | callBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:4449:11
GECKO(29739) | startInstall/<@resource://gre/modules/addons/XPIInstall.jsm:1934:13
GECKO(29739) | async*startInstall@resource://gre/modules/addons/XPIInstall.jsm:1834:6
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:1487:7
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:2178:5
GECKO(29739) | checkForBlockers@resource://gre/modules/addons/XPIInstall.jsm:1792:5
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:1484:7
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:2178:5
GECKO(29739) | checkPrompt/<@resource://gre/modules/addons/XPIInstall.jsm:1767:7
GECKO(29739) | async*checkPrompt@resource://gre/modules/addons/XPIInstall.jsm:1747:6
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:1481:7
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:2178:5
GECKO(29739) | install@resource://gre/modules/addons/XPIInstall.jsm:2701:5
GECKO(29739) | installAddon@resource://shield-recipe-client/lib/NormandyDriver.jsm:175:7

The line that the trace starts at in NormandyDriver.jsm happens when AddonInstall:install() is invoked.

Comment 3

[Andrew Swan [:aswan]]

The issue here is that webextensions are started up asynchronously and if you try to shut down or uninstall one before it has finished starting, bad stuff can happen.
It's tricky to fix since the AddonManager apis (ie, "addon.userDisabled = true/false;" and "addon.uninstall();") are synchronous.

We've mostly just punted on this for now since there are various legacy addons that use these APIs so we can't easily change them.  Once legacy addons are gone, we can actually think about changing this, but it will mean changing those interfaces so they all return Promises (and obviously, enable/disable won't be able to be expressed as setters any more), and then changing all the users of those APIs (of which there are a ridiculously high number)

For the time being, you can use something like this to find out when a webextension has fully started up:
http://searchfox.org/mozilla-central/rev/20d16dadd336e0c6b97e3e19dc4ff907744b5734/toolkit/mozapps/extensions/test/xpcshell/head_addons.js#1069-1080