firebase / firebase-js-sdk

Firebase Javascript SDK
https://firebase.google.com/docs/web/setup
Other
4.75k stars 872 forks source link

INTERNAL ASSERTION FAILED: Unexpected state, occurs in Browser #7161

Closed michaelAtCoalesce closed 6 months ago

michaelAtCoalesce commented 1 year ago
Error: Error: FIRESTORE (9.12.1) INTERNAL ASSERTION FAILED: Unexpected state STACK: ../../../node_modules/@firebase/firestore/dist/index.esm2017.js:(k:139 
../../../node_modules/@firebase/firestore/dist/index.esm2017.js:(value:17048 
../../../node_modules/@firebase/firestore/dist/index.esm2017.js:(enqueueAndForgetEvenWhileRestricted:16963 
../../../node_modules/@firebase/firestore/dist/index.esm2017.js:(Wc:16947 
../../../node_modules/@firebase/firestore/dist/index.esm2017
google-oss-bot commented 1 year ago

I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, thank you for reporting this issue.

Since it is hard to repro, we might have to reply on debug log to provide us with some insights. Could you please enable logging with firebase.firestore.setLogLevel('debug') , and have one of your users capture the log output from the console when they notice this error? Please make sure you have redacted any sensitive information from the log before sharing it here.

Also, would it be possible to check if this problem is only happening with Firefox?

dconeybe commented 1 year ago

[possible relevant context] This issue arose from discussing https://github.com/firebase/firebase-js-sdk/issues/6931 with the OP.

milaGGL commented 1 year ago
  • Firebase SDK version: "firebase": "^9.17.1",

One thing tho, the Firestore version in the error message is 9.12.1, different from the firebase version that you mentioned. It might worth checking out.

michaelAtCoalesce commented 1 year ago

thanks @milaGGL - i would definitely trust the number coming from the log message ;)

one question about the debug log level` - is this something that could be turned on all the time? we dont have a good recreatable test case, so we'd have to crank the debug logging level up all the time in order to capture it the next time it happens. looking at our logs, it happens a handful of times a week.

alternatively, we are happy to accept a patched version with appropriate logs, or updating to a version of firestore with more targeted telemetry for when this happens.

we definitely would like to work with you however possible to get logs to rectify this issue.

milaGGL commented 1 year ago

@michaelAtCoalesce, yes, you can enable debug-level logging for the Firestore JavaScript SDK all the time, but this might generate a large amount of log output, so it is better to disable it once we locate the root cause of the error.

Taking one step further, the stack trace indicate that the exception is occurring during a call to enqueueAndForgetEvenWhileRestricted(), a method that is called in exactly 2 places: terminate() and clearIndexedDbPersistence(). Are these functions called in your app?

If yes, I would suggest enable debug logging before each of these method calls and disable it after awaiting the promise that they return, to reduce the log output volume. Something like this:

setLogLevel('debug');
await terminate(db);
setLogLevel('silent');

Regarding the terminate() function, are you running terminate() in response to the user closing the web page or navigating away? It is possible that the call to terminate() is getting interrupted by the web page being unloaded.

google-oss-bot commented 1 year ago

Hey @michaelAtCoalesce. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

michaelAtCoalesce commented 1 year ago

more updates @milaGGL

we do not directly call those functions in our codebase.

looking at our user logs, you can see that we are also getting the following error message around the same time FirebaseError: Failed to obtain exclusive access to the persistence layer. To allow shared access, multi-tab synchronization has to be enabled in all tabs. If you are using experimentalForceOwningTab:true, make sure that only one tab has persistence enabled at any given time.

image

as well as this log sometimes [2023-04-06T14:31:01.545Z] @firebase/firestore: Firestore (9.12.1): FirebaseError: [code=resource-exhausted]: Too many outstanding requests.

is any of that interesting?

michaelAtCoalesce commented 1 year ago

@milaGGL any ideas on next steps? we are recreating this at the rate of a few times a week so we'd be happy to try specific builds or logs.

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, would it be possible to provide a bug reproduction code by reducing the unrelated code and narrowing down the cope?

Is this only happening in Firefox, or all browsers?

Have you used enableIndexedDbPersistence in your code? If yes, what it looks like? We should be able to resolve the "Failed to obtain exclusive access to the persistence layer." error by using enableMultiTabIndexedDbPersistence()

Please enable debug-level logging, hopefully, it should be able to tell us more about what causes this error.

n0land0 commented 1 year ago

Hey @milaGGL, chiming in here for @michaelAtCoalesce on some of these questions. We received at least 7 fresh instances of this error over the weekend so some more data points to consult.

Is this only happening in Firefox, or all browsers?

It's happening for some of our Chrome users as well.

Have you used enableIndexedDbPersistence in your code?

We don't call that function in our codebase, no.


One new clue we received in these fresh incidents is an Error enabling FB persistence cache: attempting to stringify object w/ constructor: n; {"code":"failed-precondition","name":"FirebaseError”}. For the 2 incidents in which we received this log, it occured 10-20 minutes before the main FIRESTORE (9.12.1) INTERNAL ASSERTION FAILED: Unexpected state exception. Hope this provides some insight

michaelAtCoalesce commented 1 year ago

@milaGGL do you have any guidance based on @n0land0's comments above? should we attempt to turn on debug logging all the time (are there performance implications with doing this?). we don't have a recreatable test case or a function call that seems to trigger this assertion.

we are starting to hit this multiple times a day, so we'd be happy to take a patched version of the SDK that gives more information on the assert.

milaGGL commented 1 year ago

@michaelAtCoalesce, @n0land0, the message INTERNAL ASSERTION FAILED: Unexpected state is the default message when the fail() function is called without a parameter: https://github.com/firebase/firebase-js-sdk/blob/480d7d560b6a3006d6dc8e141288177cb82f42bc/packages/firestore/src/util/assert.ts#L30-L30 So it is possible that your errors have completely different root causes. In order to properly debug the issue, it would be helpful to have a full stack of error messages.

@michaelAtCoalesce, based on the error message you shared: FirebaseError: Failed to obtain exclusive access to the persistence layer...., it seems like you may have used enableIndexedDbPersistence. Could you please double check this?

Enable debug-level logging would definitely have some performance overhead, but it should be be barely noticeable. And without a reproducible code, this is our alternative option to gather info for debugging.

@n0land0, I am curious if the message string Error enabling FB persistence cache: is added by your application. The message {"code":"failed-precondition","name":"FirebaseError”} suggests that a failed-precondition error occurred while enabling persistence. Could you please share more info about your code?

michaelAtCoalesce commented 1 year ago

@milaGGL we call enablePersistence(). i do not see a call to enableIndexedDbPersistence. empirically, we are seeing this occur more frequently since starting to call the function enablePersistence()

milaGGL commented 1 year ago

@michaelAtCoalesce, yes, enablePersistence in compact layer is the same as enableIndexedDbPersistence. Please try enableMultiTabIndexedDbPersistence(), and see if this error message is gone: FirebaseError: Failed to obtain exclusive access to the persistence layer. To allow shared access, multi-tab synchronization has to be enabled in all tabs. If you are using experimentalForceOwningTab:true, make sure that only one tab has persistence enabled at any given time.

n0land0 commented 1 year ago

@milaGGL we don't seem to have solved the issue by using enableMultiTabIndexedDbPersistence. I've been able to grab a CSV sample of firestore debug log output surrounding some recent incidents, happy to email someone there who's willing to take a look

michaelAtCoalesce commented 1 year ago

@milaGGL can you email me at michael.xu coalesce.io with your email so we can send you logs?

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, please feel free to send me the logs via milamamat@google.com.

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, just writing to confirm that I have received your log info, and looking into it.

michaelAtCoalesce commented 1 year ago

thanks! @milaGGL

michaelAtCoalesce commented 1 year ago

hi mila - any updates?

michaelAtCoalesce commented 1 year ago

hi - we need to elevate the priority of this ticket. we have done as specified, to send over logs as requested - and our customers are seeing crashes due to this - but we have not heard anything about any progress for the past week.

can someone on the google side comment on this?

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, unfortunately, I am unable to identify the underlying cause of the problem based on the provided debug log. The error messages are removed during our build process, making it difficult to pinpoint the exact location of the issue in the code. https://github.com/firebase/firebase-js-sdk/blob/480d7d560b6a3006d6dc8e141288177cb82f42bc/packages/firestore/src/util/assert.ts#L24

The best course of action now is to use a custom build. Are you open to using a custom build for your application? If so, we can work together to preserve the error messages or use a debug build instead.

michaelAtCoalesce commented 1 year ago

OK - understandable - can you mail me at michael . xu @ coalesce.io and let's figure out how to get the custom build going. we can recreate this in our test environment... (it takes a day or two) - but we can temporarily change the build.

milaGGL commented 1 year ago

Hi @michaelAtCoalesce. A branch called origin/dconeybe/FirestoreNoLogStrip has been created to keep the error messages in build.

Please see the steps to make a custom build for your test app:

#  Clone the web SDK 
git clone https://github.com/firebase/firebase-js-sdk.git
cd firebase-js-sdk

# Checkout the modified branch and build
git checkout origin/dconeybe/FirestoreNoLogStrip
npm install -g yarn
yarn
yarn build

# Create a .tgz file for Firestore
cd packages/firestore
yarn pack

# Cd to your project directory containing package.json and install the package
npm install <path_to_tgz_file_created_by_yarn_pack>

If you encounter any issues while creating the custom build, please let us know.

n0land0 commented 1 year ago

Hi @milaGGL ,

We've gone through the steps provided (with debug logging turned on as well). Is there any way for us to confirm that the custom build is doing what we expect, specific logs etc.?

So far the logs pretty much resemble what we've been seeing in our normal build with debug logging on. From your comments it does sound like the custom build might only show differences when errors occur, but we'd like to confirm as best as possible that our build is as expected before we deploy & let it sit for a few days.

milaGGL commented 1 year ago

Hi @n0land0, We only removed the code that strips off the error messages, so the only way to see if the custom build is in use is that there are more logs with extended details.

milaGGL commented 1 year ago

Hi @n0land0, are you able to use the custom build in the testing environment? Is the bug reproducible?

n0land0 commented 1 year ago

Hi @milaGGL, thanks for checking in - our test environment using the custom build will be getting much heavier usage next week, so we're hopeful that at that point we'll see repros with useful stack traces & will be able to share.

milaGGL commented 1 year ago

Hi @n0land0, I am unable to locate the root cause based on the CSV file. However, there are 2 things caught my eyes:

  1. I noticed that the app has enabled experimentalAutoDetectLongPolling, and sometimes it is jumping back and forth between "there is a proxy", "there is no proxy":
    
    [2023-05-25T15:19:16.046Z] @firebase/firestore: Firestore (9.22.0): WebChannelConnection RPC 'Listen' stream 0x653ddba4 detected buffering proxy

[2023-05-25T15:19:16.074Z] @firebase/firestore: Firestore (9.22.0): WebChannelConnection RPC 'Listen' stream 0x653ddba4 detected no buffering proxy


Could you please help check what is your network condition by running this debug page:  https://debug-my.firebaseapp.com/ . And, can you try to use `experimentalForceLongPolling` instead to see if it helps with the webchannel connection?

2. There are multiple lines that recording  `SQL compilation error:syntax error line 6 at position 1 unexpected`.  There were similar issue report that caused by casing in SQL: https://github.com/firebase/firebase-js-sdk/issues/4451#issuecomment-1041917569. 
Are you using SQL? If yes, could you please double check the SQL syntaxes?
michaelAtCoalesce commented 1 year ago

hi @milaGGL ,

1) we do not set experimentalAutoDetectLongPolling anywhere in our codebase.

2) we do not have any usages of capital ASC or DESC in our codebase

can you revisit your build and add more instrumentation so that when it happens again you have the appropriate logging? our app is being used by customers - we cannot realistically ask them to visit https://debug-my.firebaseapp.com whenever they hit this crash

we are happy to try builds and recreate the issue, but the most immediate effect is if you could add more instrumentation so that when the error occurs again, you have the right information to understand what is happening.

i'm happy to jump on a call - but we are not doing anything unique with our initialization. the only thing i see is that after we initialize firebase in the browser we immediately call setPersistence().

milaGGL commented 1 year ago

Hi @michaelAtCoalesce, while re-reading the email with stack trace, I realized that you are using firestore-compat, not the firestore. Please correct me if I am wrong.

../node_modules/@firebase/firestore-compat/node_modules/@firebase/firestore/dist/index.esm2017.js:197:16:null
../node_modules/@firebase/firestore-compat/node_modules/@firebase/firestore/dist/index.esm2017.js:18139:19:O ...

If you are indeed using firestore-compat, with the previous build steps, the app high likely is still using the public build. I am so sorry for the confusion and inconvenience.

Could you please retry this steps for custom build?

#  Clone the web SDK 
git clone https://github.com/firebase/firebase-js-sdk.git
cd firebase-js-sdk

# Checkout the modified branch and build
git checkout origin/dconeybe/FirestoreNoLogStrip
npm install -g yarn
yarn
yarn build

# Create a .tgz file for Firestore
cd packages/firestore
yarn pack

// Pack firestore-compat as well
# Create a .tgz file for Firestore-compat
cd packages/firestore-compat
yarn pack

# Cd to your project directory containing package.json and install both packages above
npm install <path_to_tgz_file_for_firestore>
npm install <path_to_tgz_file__for_firestore_compat>
milaGGL commented 11 months ago

Hi @n0land0 and @michaelAtCoalesce,

I understand the frustration and sincerely apologize for this inconvenience. My team acknowledges that this is a tricky issue, as it is hard to reproduce and hard to debug due to its potential multiple causes. I want to assure you that we are actively investigating this issue. But, being honest, this is not something we can fix quickly or quite possibly at all.

Unfortunately, we do not have a quick workaround to fix the problem as the root cause may differ. Some bugs that can cause this error message are identified, but I believe your issue is different: https://github.com/firebase/firebase-js-sdk/issues/4451#issuecomment-1147623949

Do please try to disable enablePersistence() in the testing environment, at least we would be able to rule out a possible cause if it is not.

The stack traces you provided still contain minified information, which makes it difficult to pinpoint the exact source of the problem. These unexpectedly minified stack traces are due to a bug in Firestore's source map generation, a bug whose fix was merged today: https://github.com/firebase/firebase-js-sdk/pull/7382. So to find the root cause, we unfortunately need to ask you to rebuild your app (again) with a version of Firestore that includes this fix. The fix will be included in the release planned for late July 2023. But the "FirestoreNoLogStrip" branch mentioned above has been updated to include it.

Once again, I apologize for the inconvenience and hope you understand.

milaGGL commented 11 months ago

Hi @n0land0 and @michaelAtCoalesce, today's release of v10.0.0 contains the source map fixes. As long as the app is build against v10.0.0, we should be able to use the stack traces to figure out the line of code which caused the error.

michaelAtCoalesce commented 10 months ago

Hi Mila, We have not seen the issue since disabling the call to enablePersistence(), we are going to turn it back on with the build and see if it triggers.

milaGGL commented 10 months ago

@michaelAtCoalesce That is a great news! Thank you for letting me know.

If the bug get triggered by enablePersistence(), we should be able to narrow down the cause to persistence, and by isolating unrelated code, we might be able to replicate it for further investigation!

maccman commented 10 months ago

We are also seeing a huge number of unexpected state errors.

CleanShot 2023-07-17 at 09 29 33@2x

We are on Firebase 9.23.0.

Here is our config: https://gist.github.com/maccman/eef600c92126597394a2180e04ed0728

michaelAtCoalesce commented 10 months ago

@maccman are you using local persistence?

milaGGL commented 10 months ago

Hi @maccman, would it be possible to upgrade your firestore version to the newest one(release of v10.0.0), and turn on the debug level logging as suggested here: https://github.com/firebase/firebase-js-sdk/issues/7161#issuecomment-1489524711?

ralphcode commented 10 months ago

FYI, we've struggled with these errors generated on both SDK v8 & v9. We could reliably replicate by enabling persistence and putting a basic Capacitor app into the background/foreground repeatedly every ~5 seconds on iOS.

We upgraded to v10 last week and have not seen this (or similar broken persistence) errors since 👍

Thanks all!

vojto commented 9 months ago

Hi @maccman, would it be possible to upgrade your firestore version to the newest one(release of v10.0.0), and turn on the debug level logging as suggested here: #7161 (comment)?

Hey, I'm working with @maccman. We've been on v10 for a few weeks now, and still seeing these issues for about 3% of our users.

I'll try to turn on the logging and capture more data for you.

milaGGL commented 9 months ago

Hi @vojto, thank you for letting me know. Please feel free to send me the logs via milamamat@google.com and remember to scratch out confidential information if there is any.

milaGGL commented 7 months ago

Hi @vojto, just want to follow up on the status of this issue, and see you were able to get the debug logs.

vojto commented 7 months ago

Hi @vojto, just want to follow up on the status of this issue, and see you were able to get the debug logs.

Thanks - we haven't been able to capture the logs yet, but have the code in place - will try to get something useful in the comings weeks.

milaGGL commented 7 months ago

Sounds good. Thank you for letting me know.

google-oss-bot commented 6 months ago

Hey @michaelAtCoalesce. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

google-oss-bot commented 6 months ago

Since there haven't been any recent updates here, I am going to close this issue.

@michaelAtCoalesce if you're still experiencing this problem and want to continue the discussion just leave a comment here and we are happy to re-open this.