[Bug] Using Firestore's offline persistence on certain Android devices causes the app to force close.

[baba-s]

[REQUIRED] Please fill in the following fields:

• Unity editor version: 2022.3.20f1
• Firebase Unity SDK version: 11.6.0
• Source you installed the SDK: Unity Package Manager
• Problematic Firebase Component: Firestore
• Other Firebase Components in use: None
• Additional SDKs you are using: None
• Platform you are using the Unity editor on: Mac
• Platform you are targeting: Android
• Scripting Runtime: IL2CPP

[REQUIRED] Please describe the issue here:

* Tinno - FIH Foxconn
    * M10
* Innovatech - Unisoc
    * T30
* Worldchip - Windriver
    * P25_T_ROW
    * P25_T_EEA
    * P80T_ROW
* Deejoy - FIH Foxconn
    * Kids_10
    * PlimPad_P3_Pro

On the above Android device, calling FirebaseFirestore.Collection, then closing the app, then starting the app again and calling FirebaseFirestore.Collection, the following error occurs and the app is forced to close.

FATAL EXCEPTION: main
Process: com.XXXX.YYYY, PID: 9713
java.lang.RuntimeException: Internal error in Cloud Firestore (24.8.1).
	at com.google.firebase.firestore.util.AsyncQueue.lambda$panic$3(AsyncQueue.java:545)
	at com.google.firebase.firestore.util.AsyncQueue$$ExternalSyntheticLambda3.run(Unknown Source:2)
	at android.os.Handler.handleCallback(Handler.java:938)
	at android.os.Handler.dispatchMessage(Handler.java:99)
	at android.os.Looper.loopOnce(Looper.java:201)
	at android.os.Looper.loop(Looper.java:288)
	at android.app.ActivityThread.main(ActivityThread.java:7876)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1182)
Caused by: java.lang.RuntimeException: android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)
	at com.google.firebase.firestore.util.AsyncQueue$SynchronizedShutdownAwareExecutor.lambda$executeAndReportResult$1(AsyncQueue.java:333)
	at com.google.firebase.firestore.util.AsyncQueue$SynchronizedShutdownAwareExecutor$$ExternalSyntheticLambda0.run(Unknown Source:4)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
	at java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at com.google.firebase.firestore.util.AsyncQueue$SynchronizedShutdownAwareExecutor$DelayedStartFactory.run(AsyncQueue.java:235)
	at java.lang.Thread.run(Thread.java:1012)
Caused by: android.database.sqlite.SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)
	at android.database.sqlite.SQLiteConnection.nativeExecute(Native Method)
	at android.database.sqlite.SQLiteConnection.execute(SQLiteConnection.java:709)
	at android.database.sqlite.SQLiteSession.beginTransactionUnchecked(SQLiteSession.java:325)
	at android.database.sqlite.SQLiteSession.beginTransaction(SQLiteSession.java:300)
	at android.database.sqlite.SQLiteDatabase.beginTransaction(SQLiteDatabase.java:624)
	at android.database.sqlite.SQLiteDatabase.beginTransactionWithListener(SQLiteDatabase.java:587)
	at com.google.firebase.firestore.local.SQLitePersistence.runTransaction(SQLitePersistence.java:211)
	at com.google.firebase.firestore.local.SQLiteOverlayMigrationManager.buildOverlays(SQLiteOverlayMigrationManager.java:46)
	at com.google.firebase.firestore.local.SQLiteOverlayMigrationManager.run(SQLiteOverlayMigrationManager.java:42)
	at com.google.firebase.firestore.local.LocalStore.start(LocalStore.java:182)
	at com.google.firebase.firestore.core.ComponentProvider.initialize(ComponentProvider.java:156)
	at com.google.firebase.firestore.core.FirestoreClient.initialize(FirestoreClient.java:296)
	at com.google.firebase.firestore.core.FirestoreClient.lambda$new$0$com-google-firebase-firestore-core-FirestoreClient(FirestoreClient.java:114)
	at com.google.firebase.firestore.core.FirestoreClient$$ExternalSyntheticLambda1.run(Unknown Source:8)
	at com.google.firebase.firestore.util.AsyncQueue.lambda$enqueue$2(AsyncQueue.java:444)
	at com.google.firebase.firestore.util.AsyncQueue$$ExternalSyntheticLambda6.call(Unknown Source:2)
	at com.google.firebase.firestore.util.AsyncQueue$SynchronizedShutdownAwareExecutor.lambda$executeAndReportResult$1(AsyncQueue.java:330)
	... 8 more

Firestore offline data persistence behavior not available on the aforementioned Android devices.

Steps to reproduce:

1. Add a Firebase project to be able to use "Cloud Firestore".
2. Create a new Unity project, set "Package Name" and add "google-services.json".
3. Add the following Firebase SDKs from the Unity Package Manager.
   • com.google.external-dependency-manager-1.2.177.tgz
   • com.google.firebase.app-11.6.0.tgz
   • com.google.firebase.firestore-11.6.0.tgz
4. Add the following script to your Unity project and attach it to the game objects in your scene.

   using System.Threading.Tasks;
   using Firebase;
   using Firebase.Firestore;
   using UnityEngine;
   
   internal sealed class Example : MonoBehaviour
   {
       private async Task Start()
       {
           await FirebaseApp.CheckAndFixDependenciesAsync();
           var firebaseFirestore = FirebaseFirestore.DefaultInstance;
           firebaseFirestore.Collection( "hoge" );
       }
   }

5. Build the application to the aforementioned Android device.
6. When the call to firebaseFirestore.Collection is complete, exit the application.
7. Start the app and wait for the firebaseFirestore.Collection call to complete.
8. An error occurs and the application is forcefully terminated (100%).

Supplement

• Forced termination does not occur on any device other than the aforementioned Android devices.
• If PersistenceEnabled is set to false as follows, no forced termination occurs.

  using System.Threading.Tasks;
  using Firebase;
  using Firebase.Firestore;
  using UnityEngine;
  
  internal sealed class Example : MonoBehaviour
  {
      private async Task Start()
      {
          await FirebaseApp.CheckAndFixDependenciesAsync();
          var firebaseFirestore = FirebaseFirestore.DefaultInstance;
          firebaseFirestore.Settings.PersistenceEnabled = false;
          firebaseFirestore.Collection( "hoge" );
      }
  }

[dconeybe]

Unfortunately, Firestore has had ongoing issues with SQLiteDatabaseLockedException exceptions being thrown in Android that we have not been able to fully understand, reproduce, or resolve. Here are some examples: https://github.com/search?q=repo%3Afirebase%2Ffirebase-android-sdk+SQLiteDatabaseLockedException&type=issues

Since it sounds like you can consistently reproduce this issue, could you do the following to assist with our investigation:

1. Set FirebaseFirestore.LogLevel = LogLevel.Debug as early as possible in your application.
2. Reproduce the crash.
3. Capture the Android logcat log.
4. Post the captured logcat log to https://gist.github.com/ and include the link to the gist in a comment on this issue.

The logcat log with debug logging enabled will provide a great deal of information to help focus the investigation.

Thank you for reporting this issue.

[baba-s]

Thanks for the reply!

1. Set FirebaseFirestore.LogLevel = LogLevel.Debug as early as possible in your application.

using System.Threading.Tasks;
using Firebase;
using Firebase.Firestore;
using UnityEngine;

internal sealed class Example : MonoBehaviour
{
    private async Task Start()
    {
        await FirebaseApp.CheckAndFixDependenciesAsync();
        FirebaseFirestore.LogLevel = LogLevel.Debug; // Add
        var firebaseFirestore = FirebaseFirestore.DefaultInstance;
        firebaseFirestore.Collection( "hoge" );
    }
}

I have changed the script as above.

2. Reproduce the crash.
3. Capture the Android logcat log.
4. Post the captured logcat log to https://gist.github.com/ and include the link to the gist in a comment on this issue.

The Android logcat log of the crash is attached below.

https://gist.github.com/baba-s/d8fb4309fcdaa73b51e80ea6798ecdad

Also, if firebaseFirestore.Collection is called when the app is first launched, it will not crash, so the log of that call is also attached below.

https://gist.github.com/baba-s/4faedc5796397b1d553782173986fe1f

Since it sounds like you can consistently reproduce this issue

Yes, I have the following android device that can reproduce the crash 100%.

Amazon: https://amzn.asia/d/3z6UZR6

I hope this helps.

[dconeybe]

Thanks for the logs! It looks like you've gone through the trouble to capture the exact logs output by your application. I'm actually interested in the entire device logs, even though they will be noisy. I'm especially interested if the "successful" launch of your application has the same linux PID as the instance that encounters the exception and, if not, if there is some overlap of their lifetimes.

If possible, could you redo this experiment with some modifications to the steps:

1. From your computer, run adb logcat -c to clear the logcat logs.
2. Run adb logcat -c again (sometimes the first run doesn't actually clear the logs 🤷)
3. Run adb logcat >capture.logcat.txt and let it continue running.
4. Launch your application successfully.
5. Launch your application again, in the way that reproduces the crash.
6. Press CTRL+C on your computer to end the logcat capture started in step 3.
7. Upload capture.logcat.txt to a GitHub Gist.

It would also be interesting to see a screen recording of the Android device of you following the reproduction steps above. To do that, follow these steps:

1. From your computer, run adb shell screenrecord --bugreport /data/local/tmp/screenrecord.mp4
2. Follow the steps in the previous paragraph to capture the logcat.
3. Press CTRL+C on your computer to end the screen recording.
4. Run adb pull /data/local/tmp/screenrecord.mp4 to copy the video from the Android device to your computer.
5. Upload the video screenrecord.mp4 to the Internet somewhere and attach a link to it (you may be able to drag-and-drop it into this GitHub issue comment).

If you could do one or both of these it could help a lot. Thanks!

[baba-s]

Hi, I have taken the following steps to log based on the instructions you gave me. 🙇

1. Run adb logcat -c.
2. Run adb logcat -c again.
3. Run adb logcat >capture.logcat.txt and let it continue running.
4. Install the .apk on my Android device and launch it.
5. Restart the application after the call to FirebaseFirestore.Collection is complete.
   • Per line 557 of capture.logcat.txt.
6. Exit logcat with Ctrl + C after application crash.
   • Per line 1455 of capture.logcat.txt.

capture.logcat.txt: https://gist.github.com/baba-s/e22368eb79c182457e999ffafc8b6a87

Screen recording is also attached.

00:04 Install the .apk on my Android device and launch it.
00:33 The application is terminated because the call to FirebaseFirestore.Collection is complete.
00:38 Restart application.
00:53 Crash.

screenrecord.mp4

[dconeybe]

@baba-s Thank you for the logs and screen recording!

I have a couple of questions:

1. Did your application call FirebaseFirestore.LogLevel = LogLevel.Debug? If not, could you re-capture the logcat with debug logging enabled? I ask because I'm not seeing the logs that I expected to see from Firestore in the logcat. There is no need to recapture the screen recording. Nevermind, I see the debug logs now.
2. Are you comfortable providing me with the app you use to reproduce the crash? If so, I could try and reproduce it for myself, which would expedite any investigation.

Thank you.

[dconeybe]

Actually, I see the debug logs. Please ignore my question 1 from the previous comment.

[dconeybe]

After doing some searching, my hypothesis that the sqlite database is still opened by the old linux process is plausible (Googlers see yaqs/210491605533065216). Apparently, Android's "ActivityManager" can incorrectly think that the linux process for a service/activity is dead (when in fact it is not yet dead) and launch a new linux process to host the service/activity. If the old process has the sqlite database opened and the new process attempts to open it then the "SQLiteDatabaseLockedException: database is locked (code 5 SQLITE_BUSY)" exception could occur. The only fix that I can think of is to add some retries if SQLiteDatabaseLockedException occurs. I'll discuss with the team.

[baba-s]

Are you comfortable providing me with the app you use to reproduce the crash?

Hi, I have sent the .apk to your email.
The title of the email is "[GitHub Issue] .apk to reproduce Firestore crashes.". 🙇

[baba-s]

my hypothesis that the sqlite database is still opened by the old linux process is plausible

I was thinking the same thing as you.
However, the cause may possibly be different, as the crash occurs even after rebooting the Android device. 🤔

• If Android device is rebooted: crash
• If .apk was overwritten and installed: no crash on first boot

I suspect that the crash occurs at the point where localStore.start() is called in the initialize method of the ComponentProvider class.

https://github.com/firebase/firebase-android-sdk/blob/master/firebase-firestore/src/main/java/com/google/firebase/firestore/core/ComponentProvider.java#L156

Supplement

• If PersistenceEnabled is false, localStore.start() will probably not be called and will not crash.
• Changing the call to firebaseFirestore.Collection to firebaseFirestore.DisableNetworkAsync also causes a crash.

  using System.Threading.Tasks;
  using Firebase;
  using Firebase.Firestore;
  using UnityEngine;
  
  internal sealed class Example : MonoBehaviour
  {
      private async Task Start()
      {
          await FirebaseApp.CheckAndFixDependenciesAsync();
          FirebaseFirestore.LogLevel = LogLevel.Debug;
          var firebaseFirestore = FirebaseFirestore.DefaultInstance;
          await firebaseFirestore.DisableNetworkAsync(); // Changed
      }
  }

I'll discuss with the team.

Thank you!