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

[LanderBeeuwsaert]

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/

[google-oss-bot]

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

[dconeybe]

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

[LanderBeeuwsaert]

@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)

[MarkChrisLevy]

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.

[dconeybe]

@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?

[MarkChrisLevy]

@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?

[dconeybe]

@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.

[TimmNL]

I think this could be the same type of issue that is discussed over here #8383 and here #8250. @dconeybe maybe you can use those log files?

[dconeybe]

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.

[LanderBeeuwsaert]

@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?

[dconeybe]

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.

[LanderBeeuwsaert]

@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.