Andreas Tolfsen ❲:ato❳ Reporter
	Description • 6 years ago

When Marionette quits Firefox in [1] the following gets printed to
stdout since very recently:

>  0:13.41 pid:7871 1518011089031	addons.xpi	WARN	Exception running bootstrap method shutdown on activity-stream@mozilla.org: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://activity-stream/lib/SnippetsFeed.jsm :: uninit :: line 123"  data: no] Stack trace: uninit()@resource://activity-stream/lib/SnippetsFeed.jsm:123 < onAction()@resource://activity-stream/lib/SnippetsFeed.jsm:139 < _middleware/</<()@resource://activity-stream/lib/Store.jsm:49 < Store/this[method]()@resource://activity-stream/lib/Store.jsm:28 < uninit()@resource://activity-stream/lib/Store.jsm:151 < uninit()@resource://activity-stream/lib/ActivityStream.jsm:275 < uninit()@resource://gre/modules/addons/XPIProvider.jsm -> file:///home/ato/src/gecko/obj-x86_64-pc-linux-gnu/dist/bin/browser/features/activity-stream@mozilla.org/bootstrap.js:79 < shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> file:///home/ato/src/gecko/obj-x86_64-pc-linux-gnu/dist/bin/browser/features/activity-stream@mozilla.org/bootstrap.js:199 < callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:4415 < observe()@resource://gre/modules/addons/XPIProvider.jsm:2273 < GeckoDriver.prototype.quit()@driver.js:3268

If we make the Log.jsm stack actually readable:

> uninit()@resource://activity-stream/lib/SnippetsFeed.jsm:123
> onAction()@resource://activity-stream/lib/SnippetsFeed.jsm:139
> _middleware/</<()@resource://activity-stream/lib/Store.jsm:49
> Store/this[method]()@resource://activity-stream/lib/Store.jsm:28
> uninit()@resource://activity-stream/lib/Store.jsm:151
> uninit()@resource://activity-stream/lib/ActivityStream.jsm:275
> uninit()@resource://gre/modules/addons/XPIProvider.jsm -> file:///home/ato/src/gecko/obj-x86_64-pc-linux-gnu/dist/bin/browser/features/activity-stream@mozilla.org/bootstrap.js:79
> shutdown()@resource://gre/modules/addons/XPIProvider.jsm -> file:///home/ato/src/gecko/obj-x86_64-pc-linux-gnu/dist/bin/browser/features/activity-stream@mozilla.org/bootstrap.js:199
> callBootstrapMethod()@resource://gre/modules/addons/XPIProvider.jsm:4415
> observe()@resource://gre/modules/addons/XPIProvider.jsm:2273
> GeckoDriver.prototype.quit()@driver.js:3268

Marionette typically uses the eForceQuit bitmask.

I don’t want to inhibit activity stream from logging useful things,
but it seems like the logging repository for addons.xpi is always
turned on?  Is this intentional?

  [1] https://searchfox.org/mozilla-central/rev/84cea84b12145d752e50ddca6be5462c38510e35/testing/marionette/driver.js#3266

	Ed Lee :Mardak Assignee
	Comment 1 • 6 years ago

I would think this is caused by removeObserver being called before `async init` actually adds the observer because it's still waiting for other async stuff:

https://searchfox.org/mozilla-central/rev/a70da6775d5341a9cca86bf1572a5e3534909153/browser/extensions/activity-stream/lib/SnippetsFeed.jsm#170-185

	Andreas Tolfsen ❲:ato❳ Reporter
	Comment 2 • 6 years ago

(In reply to Ed Lee :Mardak from comment #1)

> I would think this is caused by removeObserver being called before
> `async init` actually adds the observer because it's still waiting
> for other async stuff:

I can confirm this is the case.  Adding an entry guard like in the
attached diff fixes the problem.

	Ed Lee :Mardak Assignee
	Comment 5 • 6 years ago

https://github.com/mozilla/activity-stream/commit/526161e6db57e46a3f9b9a25830466e953c95c43

	Ed Lee :Mardak Assignee
	Comment 6 • 6 years ago

https://hg.mozilla.org/mozilla-central/rev/5dc20e8d5f71