Screenshots fails to load

[past]

I got this on Windows with the latest Nightly and the system add-on from the tree (not test pilot):

12:26:28.333 DOMException [InvalidStateError: "A mutation operation was attempted on a database that did not allow mutations."
code: 11
nsresult: 0x80660006
location: resource://gre/modules/IndexedDB.jsm:294] bootstrap.js:100

This was the only related error message and it seems to have broken the initialization of every other add-on I have except for test pilot itself. This is just a theory however, as I see that the error was caught in bootstrap.js.

[past]

I should add that this only happened once. Following sessions started normally, exhibiting issue #2902.

[jaredhirsch]

Looking at the version of screenshots in the tree, line 100 corresponds to an error handler for webextension startup:

https://dxr.mozilla.org/mozilla-central/source/browser/extensions/screenshots/bootstrap.js#100

[jaredhirsch]

I've seen this as well in some profiles I've used in recent Nightly. I'm not sure what can be done for this case: it looks like the webextension startup promise fails due to an uncaught error emitted by the webextension framework code, related to a breaking change in indexeddb.

Maybe we should wontfix this?

[johngruen]

@6a68 should we point someone from add-ons at this bug as as courtesy?

[ianb]

It's happening a lot to me in development, which maybe we could ignore, but I think @past is describing it happening in Nightly, which we can't ignore.

[ianb]

Opened as Bug 1368831

[jaredhirsch]

I think we might be able to work around this by doing

// inside handleStartup
webextension.startup()
  .catch(() => { // deal with error })
  .then(() => { // finish init })

[ianb]

I'm pretty sure that the .then() clause not being called isn't what is causing the problem. The button, for instance, is simply part of the startup call, and it doesn't show up in this case. So the add-on is really just broken.

I think we should be careful about shipping #2934 (fixing migration) in case it triggers this bug. We should be sure to get SoftVision to exercise it some. It seems like it works okay, and I could do some more testing, but I think we need to be extra careful.

[jaredhirsch]

Interesting. Kris was saying that the addon really does start up, but this error is thrown. So, I was thinking we could startup(), catch any errors, discard it if it's this one, then continue on to re-fetch a webextension pointer, and finally wire up the message handler (the api.browser.runtime.onMessage.addListener(handleMessage) line from inside the then() function).

I'll spend a little more time poking at the state in the debugger when this error is thrown and see if I can find a tidy workaround.

[jaredhirsch]

I added some logging inside the bootstrap start method, and it looks like the error isn't thrown until we call the webextension object's startup() method. I suspect we could wrap the startup() call in a try/catch/finally, and finish init inside the finally clause. However, this is hard to test, because affected profiles seem to be fixed after 1-2 restarts.

The upstream bug related to this issue (https://bugzilla.mozilla.org/show_bug.cgi?id=1364768) looks like it's close to being fixed, so this may turn out to be a one day only Nightly bug.

Next, I'm going to try to find reliable steps to generate a busted profile.

[jaredhirsch]

work-in-progress STR:

• create a profile on dev edition
  • that is, delete Profile/ from the screenshots directory, then run ./bin/run-addon to create a new profile
• open the profile in dev edition
  • on mac, ./bin/run-addon --bootstrap --binary /Applications/FirefoxDevEdition
• open the profile in nightly once or twice

The IndexedDB error message seems to always appear when the profile is opened in Nightly, but the webextension only sometimes fails to load--sometimes the button appears, sometimes it doesn't.

When the button does not appear, an additional error (TypeError: api is undefined) is thrown at the next line in the start method. When startup fails, it seems like the promise is resolving, not rejecting, and yet the api object isn't getting passed to the next promise in the chain.

Hopefully this bug will not be reproducible in tomorrow's Nightly. In case it is, the following snippet can be run once inside the browser devtools scratchpad (the webext has to be manually shut down to do this more than once)

/*
 * This is a JavaScript Scratchpad.
 *
 * Enter some JavaScript, then Right Click or choose from the Execute Menu:
 * 1. Run to evaluate the selected text (Cmd-R),
 * 2. Inspect to bring up an Object Inspector on the result (Cmd-I), or,
 * 3. Display to insert the result in a comment after the selection. (Cmd-L)
 */
Cu.import("resource://gre/modules/XPCOMUtils.jsm");
XPCOMUtils.defineLazyModuleGetter(this, "LegacyExtensionsUtils",
                                  "resource://gre/modules/LegacyExtensionsUtils.jsm");
webext = LegacyExtensionsUtils.getEmbeddedExtensionFor({
  id: "screenshots@mozilla.org",
  resourceURI: Services.io.newURI("file:///Users/jhirsch/codez/github/mozilla-services-screenshots/Profile/extensions/screenshots@mozilla.org/")
})
webext.startup()
    .then((api) => {
      console.log('about to call api.browser.runtime.onMessage.addListener');
      api.browser.runtime.onMessage.addListener(function handleMessage() {});
      console.log('just called api.browser.runtime.onMessage.addListener');
    }).catch((err) => { console.error(err) })

[jaredhirsch]

Just unintentionally confirmed that this bug still affects today's Nightly: while hacking on the DOM text capture bug, when I did ./bin/run-addon --bootstrap -s screenshots.firefox.com, screenshots did not load, and I observed the IndexedDB error again.

I captured the entire startup log from the browser toolbox console in a gist for debugging: https://gist.github.com/6a68/0df2e221d3647b306eadf50b24aa1395

[jaredhirsch]

OK, good news here:

First, if I create a new profile in dev edition, then start today's Nightly, I don't see the IndexedDB error. This bug might be resolved for certain upgrade cases.

Second, I have one test profile that was previously broken that is still broken, meaning I see the IndexedDB error on startup in today's Nightly. It turns out that I can open the Scratchpad, fetch the webextension from LegacyExtensionsUtils, and its started flag is set to false; if I call webext.startup(), it then initializes correctly, and the button appears. No IndexedDB errors.

I suspect that we could wrap the entire startup function in a try/catch, and just call the function a second time if it fails the first time.

[ianb]

Ah, I tried doing a retry myself, to no positive effect, but I think you are resetting started in addition

[jaredhirsch]

@kmaglione Hey, any idea if we can work around the indexeddb issue from within the screenshots code? This is a weird one to reproduce, but seems to be a fatal error when it occurs.

[jaredhirsch]

Looks likethe error message is slightly different when Screenshots fails to load vs when it loads successfully:

Error thrown, but Screenshots loads:

Error thrown, Screenshots does not load:

That extra error message corresponds to @past's bug report, and seems to suggest something additional is going wrong at the C++ level in certain situations.

[jaredhirsch]

Looking at the terminal that launched firefox, there's extremely verbose logging of the two error messages - the DOMException and the apparently non-fatal InvalidStateError: https://gist.github.com/6a68/0a0a6168986765224d3ad154916c6cd6

Not sure what to do next. Might ask for help in #fx-team.

I have one profile that was broken two days ago that I've saved; I'm able to consistently repro the fatal error by copying it into the Profile directory inside the Screenshots repo.

Aside from that profile, though, I haven't been able to repro this by creating a profile in dev edition, then reopening it in Nightly.

[jaredhirsch]

Asked kris if he had any guesses about the DOMException in #teamaddons, his response: "Not off hand. In any case, that code is going away in the next day or two."

I think this may have just been a temporary Nightly bug, might be time to remove the firefox-55 label.

[jaredhirsch]

@ianb mentioned he's able to trigger this via the migration flow, but I've been unable to reproduce this bug by migrating from either nightly + page shot or dev edition + page shot, to nightly with screenshots enabled.

@SoftVision-CosminMuntean, could you try to find steps to reproduce this IndexedDB bug, either by migrating from page shot to screenshots, or by creating a profile in dev edition, then upgrading to nightly?

[ianb]

Here's my reproduction:

1. Open Firefox with ./bin/run-addon --setup-profile
2. Go to https://testpilot.firefox.com/experiments/page-shot and install Page Shot
3. Quit Firefox
4. Start Firefox again with ./bin/run-addon --bootstrap
5. Observe. I get an IndexedDB error pretty consistently, though it is not always fatal.

In the fatal cases the error is reported in our bootstrap.js. In the not-fatal cases the error is reported, but coming from an (unknown) source.

[jaredhirsch]

@ianb Oh, so you're opening Nightly (with Screenshots enabled by default), then installing Page Shot, then restarting? Does that track with any real-world scenario that we're planning to support?

[ianb]

@6a68 This situation is not very likely with a lot going on there with various things in different locations overwriting each other. But if this reproduces very infrequently to some people (with simpler steps), it might be good to make the code resilient to this error, and treat it as a bonus that we have a somewhat reliable reproduction.

[jaredhirsch]

Cool, I'll also see if I can repro from old nightly + page shot to new nightly.

Note also that kris thought that https://bugzilla.mozilla.org/show_bug.cgi?id=1364768 would fix the indexeddb error, but those patches haven't yet landed.

[jaredhirsch]

TL;DR: I'm not sure we can do anything about this bug, short of waiting for the upstream bug to be fixed. Installing or removing addons seems to be broken by the IndexedDB breakage, and Screenshots updates are addon updates.

More details:

I've tried following @ianb's repro steps, adding console.logs and try/catch blocks inside bootstrap.js, but the local copy of screenshots doesn't seem to get successfully installed when this error occurs.

If I create a local build of Firefox that includes a version of screenshots with some extra try/catches and logging, then run through the repro steps, screenshots does start ok - which doesn't track with the original bug description - and page shot isn't disabled or removed. Ignoring the Telemetry errors in this screenshot, note that the IndexedDB error is thrown just after bootstrap.js receives the removeOldAddon message:

It seems like Nightly throws the IndexedDB error when it tries to add or remove addons. Since Screenshots is a system addon, I think Nightly tries and fails to install an updated version when it upgrades.

[ncalexan]

I saw this immediately after updating to Firefox Nightly 55.0a1 (2017-06-01) (64-bit) on Mac OS X.

[SoftVision-CosminMuntean]

I have managed to reproduce an IndexDB error, but is from a unknown source. Here are the STR:

[Prerequisites]:

• Have an old Night build (eg: the build from 2017-05-30) and create a new profile.

[Steps to reproduce]:

1. Start the old Nightly build with the profile from prerequisites.
2. Update the Nightly build to the latest version.
3. After the browser is restarted open the browser console (CTRL+SHIFT+J).
4. Observe the errors from browser console.

[Expected results]:

• No errors are displayed in browser console.

[Actual results]:

• A "InvalidStateError:..." is displayed.

• Here is a screen recording of the issue: https://goo.gl/Qulsk6

• Here is a screenshot with browser console errors:
  

[ianb]

@ncalexan : did you have Page Shot installed previously? There seems to be fatal and non-fatal IndexedDB errors, and the fatal errors seem to be related to the Page Shot migration, but we aren't sure.

[ncalexan]

@ncalexan : did you have Page Shot installed previously? There seems to be fatal and non-fatal IndexedDB errors, and the fatal errors seem to be related to the Page Shot migration, but we aren't sure.

I think I did turn it on initially, but I really can't recall. I cannot say I definitely did not, so I can't rule out this (known) situation.

[jaredhirsch]

@SoftVision-CosminMuntean Thanks for the STR. When you reproduce that error message, does Screenshots work? Do other installed addons initialize correctly? The IndexedDB error alone is sometimes fatal, sometimes not. The DOMException version seems to be consistently fatal, so I'd suspect your error message is non-fatal (meaning, Screenshots does work, despite the error message). (See this comment earlier in the bug for the two slightly different error messages.)

Note that the original description has all addon initialization breaking once that message is observed.

[jaredhirsch]

According to kris, the likely source of the fatal startup error bug was fixed in bug 1368152, which landed a few days ago.

If it's possible to reproduce the fatal, breaking-the-world DOM Exception error, we should reach out to the addons folks right away.

If an IndexedDB error is shown in the console, but Screenshots works, let's take the firefox-55 blocker tag off this bug and throw it in the Stretch milestone.

[SoftVision-CosminMuntean]

@6a68 After I reproduce the error, Screenshots works as expected. Also, the other installed add-ons are not affected. It seems that this IndexedDB error that I can reproduce is not fatal.

Unfortunately, I haven't managed to reproduce the original description when the IndexedDB error is fatal and all add-ons are affected.

[jaredhirsch]

I haven't managed to reproduce the original description when the IndexedDB error is fatal and all add-ons are affected

\o/

[ianb]

I see the errors in the console, but they don't keep Screenshots from starting. I did notice #3007 during the reproduction, but it's not related to this error.

Closing. I believe no one should see this on Nightly now, as the add-on fix is released and there wasn't any Screenshots fix. If someone sees it again please reopen.