firebase-js-sdk icon indicating copy to clipboard operation
firebase-js-sdk copied to clipboard

failure when logging out: "1 errors occurred during unsubscription:1) Error: FIRESTORE (11.4.0) INTERNAL ASSERTION FAILED: Unexpected state"

Open LanderBeeuwsaert opened this issue 8 months ago • 18 comments

Operating System

Apple & Windows, Chrome & Edge

Environment (if applicable)

Chrome versions 111 => 133 - Edge version 134

Firebase SDK Version

11.3.1 and 11.4.0

Firebase SDK Product(s)

Analytics, Firestore

Project Tooling

We have an angular + angularFire + firebase web application.

Detailed Problem Description

Since upgrading from firebase-js-sdk v10 to v11 (now 11.4.0) we see that clients have the following error when logging out: "1 errors occurred during unsubscription:1) Error: FIRESTORE (11.4.0) INTERNAL ASSERTION FAILED: Unexpected state"

Steps and code to reproduce issue

You can find the application here: https://www.acro-companion.com/

LanderBeeuwsaert avatar Mar 20 '25 20:03 LanderBeeuwsaert

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

google-oss-bot avatar Mar 20 '25 20:03 google-oss-bot

Could you please enable Firestore debug logging (by calling setLogLevel('debug')), reproduce the issue, and provide the logs?

dconeybe avatar Mar 21 '25 00:03 dconeybe

@dconeybe unfortunately not. We see this happening in our error logging that our users have this in our production environment approximately one time every ?4? days on a userbase of +- 2000 users per day. But we can't enable debugging logging for all our users in production (and would not even be able to get that logging if the issue would occur)

LanderBeeuwsaert avatar Mar 21 '25 11:03 LanderBeeuwsaert

I have a similar problem, I can reproduce it in my app, however not able to reproduce in test repo. I will try to describe what I see:

  • User is logged in
  • Lots of snapshot listeners are running
  • User uses the app and on some page error is thrown: TypeError: Cannot use 'in' operator to search for 'nullValue' in null - obvious mistake, input data is not validated and instead of an array null is passed to in operator
  • Every other new query/listener or any operation on firestore is not possible and INTERNAL ASSERTION FAILED: Unexpected state is thrown
  • Stack trace of the error
    • fail
    • verifyNotFailed
    • enqueue
    • enqueueAndForget

Firestore configured to use MemoryPersistance. After the "in" error, debug outputs only WebChannelConnection RPC logs, nothing else. The message "1 errors occured during unsubscription" was shown few times just after Unexpected state error, but I wasn't able to reproduce it every single time.

Hope that helps.

MarkChrisLevy avatar Mar 21 '25 20:03 MarkChrisLevy

@MarkChrisLevy Looking in the source code of Firestore, there are 6 places that are obvious that they could cause a TypeError: Cannot use 'in' operator to search for 'nullValue' in null error:

[firebase-js-sdk/packages/firestore/src] $ grep -r "'nullValue' in"
model/values.ts:  if ('nullValue' in value) {
model/values.ts:  if ('nullValue' in value) {
model/values.ts:  return !!value && 'nullValue' in value;
model/values.ts:  if ('nullValue' in value) {
model/values.ts:  if ('nullValue' in value) {
index/firestore_index_value_writer.ts:    if ('nullValue' in indexValue) {

It is plausible that if one of these lines were to cause the noted TypeError then the unsubscribe error could result. However, I really need some logs or a reproducible scenario to dig in further.

@MarkChrisLevy Are you able to reproduce the TypeError with Firestore debug logging enabled, and provide the log?

dconeybe avatar Mar 25 '25 19:03 dconeybe

@dconeybe It is not about the nullValue error, it is about the status of the firestore instance after this error (but very likely after other errors) - as you can see in the stack trace I sent, verifyNotFailed() will return that the firestore is in failed state and so any further queries/operations will raise Unexpected state error, there is no way to "unfail" firestore and use it in future. As I stated, debug logs after Unexpected state error was only about RPC, of course there was a huge number of log entries before the nullValue error, because of lots of queries/listeners were working.

The obvious question is why Firestore goes into "failure" mode and cannot reset/restore?

MarkChrisLevy avatar Mar 27 '25 19:03 MarkChrisLevy

@MarkChrisLevy the reason I'm latching on to this "nullValue" error is that it seems to be reproducible on your end. I am unable to investigate the "1 errors occurred during unsubscription" error without either (a) full debug logs or (b) a reproducible scenario. So if you are able to reproduce the "1 errors occurred during unsubscription" via this "nullValue" error then I'm quite interested to learn about it so that I can reproduce it for myself and investigate. If you are not seeing the "1 errors occurred during unsubscription" error then please open a new issue in the github issue tracker for your specific issue, as this issue is specifically pertaining to that "unsubscription" error.

dconeybe avatar Mar 27 '25 20:03 dconeybe

I think this could be the same type of issue that is discussed over here https://github.com/firebase/firebase-js-sdk/issues/8383 and here https://github.com/firebase/firebase-js-sdk/issues/8250. @dconeybe maybe you can use those log files?

TimmNL avatar Apr 01 '25 07:04 TimmNL

For this issue I'm specifically looking into the "1 errors occurred during unsubscription" error message. Unfortunately, the "INTERNAL ASSERTION FAILED: Unexpected state" error message is super generic and occurs for a myriad of reasons. As a result, those other logs are not necessarily helpful.

For anyone that is observing the "1 errors occurred during unsubscription" error, please enable Firestore debug logging by calling setLogLevel('debug') and capture the logs that show this error. Even better would be a reproducible scenario. Without one of these two pieces of information there is not much that I can do unfortunately.

dconeybe avatar Apr 01 '25 15:04 dconeybe

@dconeybe "Unfortunately, the "INTERNAL ASSERTION FAILED: Unexpected state" error message is super generic and occurs for a myriad of reasons. As a result, those other logs are not necessarily helpful." => wouldn't it be an improvement that in the firebase-js-sdk code, the error message becomes more useful and helps pinpoint the cause better?

LanderBeeuwsaert avatar Apr 01 '25 15:04 LanderBeeuwsaert

wouldn't it be an improvement that in the firebase-js-sdk code, the error message becomes more useful and helps pinpoint the cause better?

Yes, that is an excellent point. It is indeed a deficiency in the SDK. A long time ago we chose to strip out the error messages because they contributing significantly to the bundle sizes of the compiled JavaScript, a major concern for a lot of users. Internally, we have an open issue, b/302682954, to go back and make things better. Unfortunately, priority has been given to other projects since then but I hope we will get back to address this particular issue some day. I can't make any specific commitments in that regard though. For now, we're stuck in a situation where we need some logs and/or a reproducible scenario to investigate this issue.

dconeybe avatar Apr 01 '25 15:04 dconeybe

@dconeybe Thank you for the clarification. Unfortunately as I explained in a previous comment, from our side we can't provide the logs and/or reproducible scenario because this is only happening in production without a clear reproducable path. So fingers crossed that somebody else will I would think.

LanderBeeuwsaert avatar Apr 01 '25 16:04 LanderBeeuwsaert

@LanderBeeuwsaert Just wanted to let you know that my colleague @MarkDuckworth has merged https://github.com/firebase/firebase-js-sdk/pull/8313 which adds useful information to these "Unexpected state" errors. His work on that PR was motivated specifically by your use case and hopes that we can get to the bottom of the issues you are seeing. This PR will be included in the next SDK release which is planned to be in about 2 weeks (near the end of April 2025). Please provide updated logs, or even just the error message with the extra information that it will contain once the release goes out.

dconeybe avatar Apr 14 '25 17:04 dconeybe

@dconeybe @MarkDuckworth greatly appreciated! I've marked 2 weeks from now in my calendar to see for upgrading. I'll indeed update this issue afterwards. We had a few occurrences this weekend again so I'm quite sure we'll be able to give you an update.

LanderBeeuwsaert avatar Apr 14 '25 18:04 LanderBeeuwsaert

Hi @dconeybe, we see these errors regularly in our production app, and we have upgraded to Firestore 11.6.1 to get error reports that include the additional logging. For us, the error is always the following:

FIRESTORE (11.6.1) INTERNAL ASSERTION FAILED: Unexpected state (ID: b815) CONTEXT: {"ec":"Error: FIRESTORE (11.6.1) INTERNAL ASSERTION FAILED: Unexpected state (ID: ca9) CONTEXT: {\"Fe\":-1}

or sometimes just this, which is the same as the context of the above error anyway:

FIRESTORE (11.6.1) INTERNAL ASSERTION FAILED: Unexpected state (ID: ca9) CONTEXT: {"Fe":-1}

duncannz avatar May 20 '25 23:05 duncannz

@duncannz you posted this comment in multiple issues. But I've replied in https://github.com/firebase/firebase-js-sdk/issues/8250#issuecomment-2896090592

MarkDuckworth avatar May 21 '25 00:05 MarkDuckworth

@LanderBeeuwsaert, if you're able to upgrade to 11.6.1 or later and post the full "unexpected state" error(s) from that version, that will help us better understand the root cause of the error. Thanks!

MarkDuckworth avatar May 21 '25 00:05 MarkDuckworth

@MarkDuckworth yes thank you, we're on 11.6.1 since some time already but we haven't had the issue anymore. I can close this if you prefer and I'll open another ticket once it resurfaces.

LanderBeeuwsaert avatar May 21 '25 06:05 LanderBeeuwsaert