Firestore.terminate hangs, and never calls callback

[sergiocampama]

Description

There are certain scenarios where I'll call Firestore's terminate function, and it will hang, never calling the callback. I haven't been able to create a reproducer, but can consistently get my product's code to get into this state (not shareable for obvious reasons).

This appears to happen when there's an overload of firestore document changes. I am able to see that the com.google.firebase.firestore queue's target queue is com.apple.root.default-qos.overcommit though not sure what this means. It looks like the queue starts with this value set as the target queue, could be a red herring.

Here's a screenshot of the backtrace of where firestore hangs... It looks like it's unable to close the gRPC watch stream for the RemoteStore, stuck on WaitUntilOffQueue.

I'm basically stuck trying to debug this to see where things go wrong and what I can do to avoid this. I'm very unfamiliar with this codebase, so I don't even know what to look for to find where the code is getting stuck. Any help with pointers on where to look or what to check would be very appreciated.

Reproducing the issue

Can't share reproduction steps, as I can't share the relevant code.

Firebase SDK Version

10.22

Xcode Version

15.3

Installation Method

CocoaPods

Firebase Product(s)

Firestore

Targeted Platforms

iOS

Relevant Log Output

There are no relevant logs.

If using Swift Package Manager, the project's Package.resolved

None

If using CocoaPods, the project's Podfile.lock

Can't share

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

[sergiocampama]

Not sure if this is relevant, but I noticed that the tcp connection stops receiving any bytes after this condition is triggered... wondering if there's something here that's triggering some TCP blockage because of the amount of network happening...

[sergiocampama]

I think I have an idea of why it starts happening, but can't yet explain it in code... what happens is that after some event, we'll create some changelog documents on a collection like "/changelog/user_id", which might contain 100s or 1000s of documents created in a very short span of time, but outside of any database transaction, so it looks like it gets 100s of serial updates of 1 document each... for some reason, this seems to lock firestore... if I remove this changelog subscription, I can't reproduce the hang any more

[milaGGL]

Hi @sergiocampama, thank you for filing this issue. Quick question, what were the steps when you produced this issue? Terminating firestore hangs, how is it related to " there's an overload of firestore document changes."? Are you terminating the firestore right after 100 documents mutation?

[sergiocampama]

Through some mechanism, we're creating/modifying 1000s of changelog documents. We have a listener for that collection of changelogs, which is updated 1 at a time, since the changelog documents are created from different cloud functions (they're onModified triggers for another set of documents).

At some point during this listening, it seems firestore locks up and stops receiving any kind of updates. We notice this lack of updates because the UI does not reflect that a document which should have been deleted, is not removed from the screen.

It is at this point that if you call Firestore.terminate, that since it is somehow locked, the terminate's callback won't get called, and it will get stuck on that backtrace shown above.

[milaGGL]

My colleague has pointed out it might be because LevelDbRemoteDocumentCache is creating concurrent tasks. It might have created 1000 tasks in your case, which will definitely overflow the default queue as well as the new threads that created after.

Could you please try changing the LevelDbRemoteDocumentCache::LevelDbRemoteDocumentCache function to use CreateSerial instead, and see it resolves the crash

 executor_ = Executor::CreateSerial("com.google.firebase.firestore.query");

[sergiocampama]

Made the change locally, but it didn't help, still getting stuck. I also replaced the cacheSettings with MemoryCacheSettings(garbageCollectorSettings: MemoryLRUGCSettings()), which bypasses the LevelDB layer, and it's also getting stuck on the same events.

[sergiocampama]

it's not looking like a dispatch issue, more like one of the GrpcStreams is getting blocked

[milaGGL]

Ruling out the persistence, the next suspect is the grpc. In the next ios sdk release we are doing a significant upgrade of the grpc dependency, which may fix the issue. Would you like to try again after the new release? Or, you can try applying #12398 locally to upgrade grpc in advance.

Could you please provide debug log as well? It might give us some clue.

[sergiocampama]

No dice on updated gRPC.

I've enabled logging, and it's a bit massive and contains some sensitive information for a public setting, and I also don't think it provides much value, since there are no errors, just a massive list of watch/unwatch/response logs... I could share it if you start an email thread with me at sergiocampama at gmail dot com...

but I did found this... when the connection seems to hang because of the massive number of document updates, I can still send requests to the backend to listen to new documents (so it's not a dispatch queue issue), but the backend does not reply with a response for the initial document read nor the registered target_id, so it's starting to look like the WatchStream from Firestore's Datastore is getting hung on the backend side (could be head of line blocking on that h2 stream)... if this is indeed a possibility, it seems harder to debug from your side... not sure if I can give you any identifier for the connection so that someone could look more into it...

it would be great if the firestore grpc channel had some sort of ping mechanism to detect that the connection is hanging and to try to force recover it by reregistering the target_ids, so that we don't lose uptime just on that single connection blocking... if not, force closing the watch_stream and write_stream from remote_store would also help so that we can at least recover by letting the user perform the action that would involve firestore's termination

for now we're mitigating by trying to reduce the number of document reads to not trigger this hang, but given we don't have a root cause yet, we fear it might still be triggered in the future.

[sergiocampama]

Actually, looking at the logs for the last response log, I see this just after it:

10.17.0 - [FirebaseFirestore][I-FST000001] GrpcStream('168259010'): operation of type 2 failed
10.17.0 - [FirebaseFirestore][I-FST000001] GrpcStream('168259010'): finishing the underlying call
10.17.0 - [FirebaseFirestore][I-FST000001] GrpcStream('168259010'): fast finishing 1 completion(s)

(we're using 10.22 Firestore but 10.17 FirebaseCore for some reason)