New Errors Logged after Enabling Persistence

[sanaze]

• Operating System version: Multiple
• Browser version: Multiple
• Firebase SDK version: 7.21.1
• Firebase Product: firestore

Describe the problem

This weekend we enabled persistence with tab synchronization on a web app where we did not have persistence enabled before.

After enabling it, a number of new errors started showing up in our production error reporting logs:

Firestore (7.21.1): Failed to obtain primary lease for action 'Release target'.

Firestore (7.21.1): Failed to obtain primary lease for action 'Apply remote event'.

FIRESTORE (7.21.1) INTERNAL ASSERTION FAILED: Unexpected state

Firestore (7.21.1): Detected an update time that is in the future: YYY > ZZZ [where YYY and ZZZ are numeric timestamps]

IndexedDB transaction failed: UnknownError: Internal error opening backing store for indexedDB.open

IndexedDB transaction failed: AbortError: The transaction was aborted, so the request cannot be fulfilled.

These are infrequent but affect multiple users. We haven't observed the errors in our own testing and development. We also didn't receive any bug reports from users that appear to be related to them.

I can't find description on a lot of these, so it is hard to assess their severity. It would be helpful to get additional documentation on them.

Are they something that only affect the newly enabled persistence layer (so the worse case is the app works fine but without persistence)?

[Benny739]

Same here, we're seeing these errors in sentry but it looks like they are not affecting the app.

[schmidt-sebastian]

@sanaze / @Benny739: Thanks for filing this issue.

Firestore (7.21.1): Failed to obtain primary lease for action 'Release target'.
Firestore (7.21.1): Failed to obtain primary lease for action 'Apply remote event'.

Multi-tab elects a primary tab. When the primary tab becomes unresponsive, another tab may take over and "steal" the primary lease. These error messages are likely related to this. The SDK should automatically recover from these errors.

FIRESTORE (7.21.1) INTERNAL ASSERTION FAILED: Unexpected state

I would need a stack trace to figure out what this is. The SDK will not recover from this and will no longer function.

Firestore (7.21.1): Detected an update time that is in the future: YYY > ZZZ [where YYY and ZZZ are numeric timestamps]

This is a strange error that also shouldn't affect the functionality too much, but it means that one tab saw a timestamp in IndexedDb that was newer than the timestamp it got from Date.now(). Are YYY and ZZZ close and reasonable numbers?

IndexedDB transaction failed: UnknownError: Internal error opening backing store for indexedDB.open
IndexedDB transaction failed: AbortError: The transaction was aborted, so the request cannot be fulfilled.

As with the assertion failure, this is something I want to look at. The SDK might go into recovery here, but I would need to see more logs? Do you also happen to know what versions of browsers/operating systems these errors occur on?

[sanaze]

Thank you for the details. Here is some more info as requested.

FIRESTORE (7.21.1) INTERNAL ASSERTION FAILED: Unexpected state

I would need a stack trace to figure out what this is. The SDK will not recover from this and will no longer function.

Error: FIRESTORE (7.21.1) INTERNAL ASSERTION FAILED: Unexpected state
  at y(../node_modules/@firebase/firestore/dist/index.cjs.js:311:1)
  at bs(../node_modules/@firebase/firestore/dist/index.cjs.js:6370:1)
  at enqueue(../node_modules/@firebase/firestore/dist/index.cjs.js:6262:1)
  at ds(../node_modules/@firebase/firestore/dist/index.cjs.js:6235:1)
  at t(../node_modules/@firebase/firestore/dist/index.cjs.js:12082:1)
  at kl(../node_modules/@firebase/firestore/dist/index.cjs.js:15384:1)
  at apply(../node_modules/@firebase/firestore/dist/index.cjs.js:15368:1)
  at r(../node_modules/@sentry/browser/esm/helpers.js:87:1)

Looking more closely at the logs, this assertion error was preceded by the IndexedDB transaction error:

IndexedDbTransactionError: IndexedDB transaction failed: AbortError: The transaction was aborted, so the request cannot be fulfilled.
  at call(../node_modules/@firebase/firestore/dist/index.cjs.js:155:1)
  at new t(../node_modules/@firebase/firestore/dist/index.cjs.js:5784:1)
  at IDBTransaction.transaction.onerror(../node_modules/@firebase/firestore/dist/index.cjs.js:5845:1)

This was one user Chrome 85, Mac OS X 10.15.

Are YYY and ZZZ close and reasonable numbers?

It looks like they are generally very close (1-2 ms) together but one is 350ms apart. Here are some occurrences:

1601315454783 > 1601315454782 Windows
1601312530689 > 1601312530688 Windows
1601312410686 > 1601312410684 Windows
1601321904334 > 1601321903974 Mac

Multiple users. All Chrome 85.

[schmidt-sebastian]

Hm. I am having a bit of trouble figuring out what is going on. The lines in your stacktraces don't map back to the location's in the index.cjs.js file that I am looking at. I need to verify that we never published more than one file that claims that it is version 7.21.1.

But even if I sort this out, I would likely need to know what codepath was hit when the transaction was aborted. If your stacktrace ends at IDBTransaction.transaction.onerror(../node_modules/@firebase/firestore/dist/index.cjs.js:5845:1) I likely need to add more logging and include a better description.

[schmidt-sebastian]

Closing this as I cannot make progress without further information. We can re-open this issue if the debug logging in #3871 provides more insights.