firebase/firestore: getting internal error from AsyncQueue

[mgenov]

Version Information

• Firebase Component: Firestore
• Component version: 18.2.0
• Affected Android Versions: 4.2.2, 5.1.1

Description

It happens rarely and this is the stack trace from crashlytics:

Fatal Exception: java.lang.RuntimeException: Internal error in Firestore (18.2.0).
       at com.google.firebase.firestore.util.AsyncQueue.lambda$panic$5(com.google.firebase:firebase-firestore@@18.2.0:379)
       at com.google.firebase.firestore.util.AsyncQueue$$Lambda$5.run(com.google.firebase:firebase-firestore@@18.2.0)
       at android.os.Handler.handleCallback(Handler.java:739)
       at android.os.Handler.dispatchMessage(Handler.java:95)
       at android.os.Looper.loop(Looper.java:135)
       at android.app.ActivityThread.main(ActivityThread.java:5254)
       at java.lang.reflect.Method.invoke(Method.java)
       at java.lang.reflect.Method.invoke(Method.java:372)
       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:902)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:697)

Caused by android.database.CursorWindowAllocationException: Cursor window allocation of 2048 kb failed. 
       at android.database.CursorWindow.<init>(CursorWindow.java:108)
       at android.database.AbstractWindowedCursor.clearOrCreateWindow(AbstractWindowedCursor.java:198)
       at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:139)
       at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:133)
       at android.database.AbstractCursor.moveToPosition(AbstractCursor.java:197)
       at android.database.AbstractCursor.moveToNext(AbstractCursor.java:245)
       at com.google.firebase.firestore.local.SQLitePersistence$Query.forEach(com.google.firebase:firebase-firestore@@18.2.0:430)
       at com.google.firebase.firestore.local.SQLiteRemoteDocumentCache.getAll(com.google.firebase:firebase-firestore@@18.2.0:98)
       at com.google.firebase.firestore.local.LocalStore.lambda$applyRemoteEvent$5(com.google.firebase:firebase-firestore@@18.2.0:385)
       at com.google.firebase.firestore.local.LocalStore$$Lambda$6.get(com.google.firebase:firebase-firestore@@18.2.0)
       at com.google.firebase.firestore.local.SQLitePersistence.runTransaction(com.google.firebase:firebase-firestore@@18.2.0:195)
       at com.google.firebase.firestore.local.LocalStore.applyRemoteEvent(com.google.firebase:firebase-firestore@@18.2.0:328)
       at com.google.firebase.firestore.core.SyncEngine.handleRemoteEvent(com.google.firebase:firebase-firestore@@18.2.0:327)
       at com.google.firebase.firestore.core.FirestoreClient.handleRemoteEvent(com.google.firebase:firebase-firestore@@18.2.0:260)
       at com.google.firebase.firestore.remote.RemoteStore.raiseWatchSnapshot(com.google.firebase:firebase-firestore@@18.2.0:545)
       at com.google.firebase.firestore.remote.RemoteStore.handleWatchChange(com.google.firebase:firebase-firestore@@18.2.0:454)
       at com.google.firebase.firestore.remote.RemoteStore.access$100(com.google.firebase:firebase-firestore@@18.2.0:53)
       at com.google.firebase.firestore.remote.RemoteStore$1.onWatchChange(com.google.firebase:firebase-firestore@@18.2.0:176)
       at com.google.firebase.firestore.remote.WatchStream.onNext(com.google.firebase:firebase-firestore@@18.2.0:109)
       at com.google.firebase.firestore.remote.WatchStream.onNext(com.google.firebase:firebase-firestore@@18.2.0:39)
       at com.google.firebase.firestore.remote.AbstractStream$StreamObserver.lambda$onNext$1(com.google.firebase:firebase-firestore@@18.2.0:119)
       at com.google.firebase.firestore.remote.AbstractStream$StreamObserver$$Lambda$2.run(com.google.firebase:firebase-firestore@@18.2.0)
       at com.google.firebase.firestore.remote.AbstractStream$CloseGuardedRunner.run(com.google.firebase:firebase-firestore@@18.2.0:67)
       at com.google.firebase.firestore.remote.AbstractStream$StreamObserver.onNext(com.google.firebase:firebase-firestore@@18.2.0:110)
       at com.google.firebase.firestore.util.FirestoreChannel$1.onMessage(com.google.firebase:firebase-firestore@@18.2.0:150)
       at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33)
       at io.grpc.ForwardingClientCallListener.onMessage(ForwardingClientCallListener.java:33)
       at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1MessagesAvailable.runInContext(ClientCallImpl.java:519)
       at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
       at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
       at java.util.concurrent.FutureTask.run(FutureTask.java:237)
       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:152)
       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:265)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at com.google.firebase.firestore.util.AsyncQueue$DelayedStartFactory.run(com.google.firebase:firebase-firestore@@18.2.0:205)
       at java.lang.Thread.run(Thread.java:818)

Steps to reproduce:

It's caused during fetching from firestore. As this thread says: https://stackoverflow.com/questions/11340257/sqlite-android-database-cursor-window-allocation-of-2048-kb-failed

it may be caused due Cursor leak in the code.

[wilhuff]

We're pretty careful about not leaking cursors. In this particular case we're using forEach to iterate over the complete result set and it already uses the suggested pattern.

I've added code to our integration tests in #386 to detect whether or not we're leaking and I'm not seeing any failures. I don't think leaked cursors are the issue.

Even though we're not leaking cursors, it is possible that other leaks are causing us to be unable to perform this allocation. If you profile memory usage in your app, are you otherwise leak free?

I've seen elsewhere that this can happen if memory is otherwise scarce. Is there a pattern to the devices on which you're seeing this error? For example, are they older devices with less RAM? A possible resolution there is to disable persistence if there's not enough RAM available. We'd need more data to support this hypothesis though.

[mgenov]

I'm not sure that it's related to memory usage. Here are the device details from the crash:

My app is using react-native (react-native-firebase respectively as lib) and most of the code is JS code. The issue may be caused and by react-native-firebase but I'm not at 100% sure about that.

[mgenov]

This is the data in crashlytics:

[var-const]

SQLite has some limitations on the maximum number of elements in a query, so one possibility is that the issue may be triggered by a database with a very large number of documents. I will test out this hypothesis and post an update here.

[var-const]

Update: I couldn't reproduce the issue. I tried reading a collection with ~10K documents, as well as a 100MB collection, neither of those led to "cursor window allocation" problem in SQLite.