React-native-firebase: Slow Query Response in Offline Mode

[zihandev]

Hello,
Firestore offline Queries are taking too much time, around 8-12 seconds even for small queries and small database. The first query response is quick, but the subsequent same query responses are extremely slow. I'm using Android with react-native and @react-native-firebase/firestore": "6.2.0"

Regards,
Zihan

[Ehesp]

How big is the dataset? We don't really do anything other than forward query requests on and send them back so I have a feeling this may be an SDK issue.

[ziban]

I am experiencing this issue too. I recently upgraded from v5 to v6 and the calls to Firestore in v6 are very slow. A user upgraded to the app version using v6 and called me almost immediately complaining about the slowness. A collection with about 50 documents can take anywhere from 10 - 55 seconds.

[mikehardy]

@ziban note that documents is not the unit of measure that is important here, I think the appropriate unit of measure is maybe documents for the actual query to run, but for this issue it might be "size of result set" - are the documents large (indicating a serialization/bridge issue?). Basically - there's a real need to tease apart the components of performance to see where the problem is. If you could use a profiler that would help

[ziban]

@mikehardy I did some testing
I did some estimations on the time it takes to make some firebase calls between v5 and v6 using console.time on an emulator(Android Nexus 5 Api 22).

Call 1.

Collections/documents/A

Where A has the following structure

    { 
           field1: string, 
           field2: string, 
           field3: string, 
           field4: string, 
           field5: string, 
     }  

The number of document always retrieved was 1/ A will always be a single object.
First invocation (initial call):
V6:
Time ranged from ~4000ms to ~15000ms
V5:
Time ranged from ~3000ms to 12000ms
Subsequent calls:
V5 && v6:
Time ranged from ~400ms to ~10000ms

Call 2

Collections/documents/B

Where B contains multiple entries each having the following structure :

    mainField: { 
             field1: string, 
             field2: string, 
             field3: string, 
             field4: string, 
             field5: string, 
        }

The number of entries was ~1700. I did not apply any queries.
First invocation (initial call):
V6:
Time was approximately ~13000ms
V5:
Time was approximately ~11000ms
Subsequent calls:
V6:
Time was approximately ~7000ms - ~10, 000ms
V5:
Time was approximately ~1800ms – ~4000ms

Call 3:

Collections/documents/C

Where C contains multiple entries each having the following structure :
mainField: stringified_object
where the stringified_object had this structure

{ 
field1: string, 
field2: string
field3: string }

The number of entries was ~10000(This was the biggest). I did not apply any queries.
First invocation (initial call):
V6:
Time was approximately ~5000 – 8000ms
V5:
Time was approximately ~10000ms
Subsequent calls:
v6:
Time was approximately ~1000ms - ~3000ms.
V5:
Time was approximately ~500ms - ~3000ms.

Call 4:

Collections/documents/D

Where D contains multiple entries each having the following structure :

mainField: { 
     field1: { 
         innerField : { 
              properties……
             }
         },
    field2: { 
             innerField : { 
                   properties……
                    }
             },
       field3: { 
            innerField : { 
                 properties……
           }
       },
     field4: string, 
     field5: string, 
}

The number of entries was ~2000. I applied a query filtering on two fields which are indexed
First invocation (initial call):
V6:
Time was approximately ~80000ms
V5:
Time was approximately ~3000ms
Subsequent calls:
V6:
Time was approximately ~50, 000 – ~70,000ms
V5:
Time was approximately ~1500ms – ~3000ms

Even though this is not the best data, I think it shows that there is a performance degradation that warrants some investigations.

[mikehardy]

That last one is very interesting. You mention counts, but don't mention sizes. What are the sizes of these objects, and does the performance vary between v5/v6 with different sizes but same counts? In order to test this and really identify it we may need a script that reproducibly creates a test data set inside firebase so we can tune the test data itself and we know that we have a reproducible test and aren't chasing phantoms

Are you creating this test data in live environment or did you generate it specifically for this test? If you did generate, could you share the test data generator?

[ziban]

I am using the data from a live environment but I can write a script that generates almost similar data. The only variable was rn firebase v6 and v5. I can estimate each object to be between 50 - 200 bytes on average. The last one(call 4) is the largest object.

But I think there is no need even for a complex data set. I think all this can be reproduced using a simple data sets -> Documents with flat objects, objects within objects, arrays, objects in arrays, etc. In fact, I suspect that the performance hit in call 4 is caused by queries.

[mikehardy]

I'm inclined to agree with you, I think you're right, but in my experience performance tuning everything (including generation of the test set) has to be fully automated - even production of the results report, or it's horribly inefficient + does not get a solution

[ziban]

Let me get started on writing a simple script that can generate almost similar data. I'll probably not be done till the end of the week but I will circle back here once I am done and we can move on from there. How does that sound?

[mikehardy]

Sounds like how we find the real source of the problem (that is to say, sounds fantastic!)

[ziban]

@mikehardy You can check here https://github.com/ziban/rn-firebase-perf-data-generator for a small project that generates the data I described above. I wrote it in a hurry so there might be errors here and there but it should work. I've not had the time to create a sample RN project to test this.

[mikehardy]

@Ehesp / @Salakar (But specifically Eliot - I know you looked into firestore perf before) - we have a test data generator now thanks to @ziban along with some results above that should help finally isolate where the bottleneck is without a lot of time wasted not controlling for data. The index.js in that project let's you control how many of each level of a tree to make, and while it isn't parameterized (to possible change how big each node is) it would be easy to change. Combine that with a driver that creates the data then times queries and the full perf-testing rig exists

[Ehesp]

I'll get this looked into - what's really odd is at the time we did some benchmark testing against v5 and it was quicker in all cases.

Thanks for the info though @ziban, will help massively.

[Ehesp]

Ok so there could be a "quick fix" for this, however we need to be careful.

Generally we try to perform all logic on a different thread to the UI, so you don't get UI jank when something is happening on the device (e.g. converting a load of query results into a React Native friendly format). We do this with Tasks, and use an Executor: https://github.com/invertase/react-native-firebase/blob/f57d69d4bf6c100e45e00f755c405e3acf7d3b46/packages/firestore/android/src/reactnative/java/io/invertase/firebase/firestore/ReactNativeFirebaseFirestoreCollectionModule.java#L162

If you actually look at the implementation of this: https://github.com/invertase/react-native-firebase/blob/f57d69d4bf6c100e45e00f755c405e3acf7d3b46/packages/app/android/src/reactnative/java/io/invertase/firebase/common/ReactNativeFirebaseModule.java#L76

It's a single threaded executor... now, this will literally queue operations up using a single thread. If something else is happening internally, it'll have to wait.

What we could do instead is use a cached thread pool. I'd guess that helps performance, but we need to make sure all the tests are passing because it can introduce some odd async type bugs.

[mikehardy]

Nice, then can spread across all cores on the device and map reduce haha - I kid, but having a thread pool should not be too big of a change - good idea

[mikehardy]

This assumes of course that profiling shows that's the bottleneck (fully optimized code blocked by something) as opposed to something terrible in the single thread...

[ziban]

Curios here -> If this was the case then, wouldn't it mean that query calls would be slow inconsistently ie if call A then B would be different from B then A(depending on which one is faster)? Or calls would be slow over time as the build-up occurred? Also, what would be the difference between v5 and v6?

[mikehardy]

@ziban I lean towards your "that probably won't help" stance, but using your test generator and a harness before any effort would focus the effort on what would work. Might be more threads, but probably it's just something obvious a profiler would show. I'd love to do it myself but have not had time yet and likely won't for quite a while unless it hits me personally, sorry

[Ehesp]

Part of the issue with firestore is how the data has to be iterated to convert it to a readable data structure on both sides. Generally with a large payload this can take some time, and will lock up the thread.

I'm not 100% sure, but it should help. I've got @russellwheatley tasked with digging into this one!

[ziban]

@russellwheatley did you ever find anything?

[russellwheatley]

Hey @ziban, I haven't been able to solve this problem as yet. I didn't find any performance difference between using a single thread and a cached thread pool as noted above. I think that makes sense anyway because the benefits would probably be seen in an app being utilised fully (and single thread queued up) as opposed to the Firestore queries I was executing in isolation of any other tasks.

I'm currently working on this in my own time whilst having a couple of other tasks ahead of it so I haven't been able to give it my full attention yet. But it is on my radar so bear with me :)

I do appreciate the data generator you made which I did use myself!

[ziban]

I can try to help. Is there any documentation/tips on how I can get started contributing(e.g looking into such a problem in rn-firebase)? I.e something a bit more technical. Or will I have just dig deep into code and figure it out as I go?

[russellwheatley]

We have a contributing guide here:https://github.com/invertase/react-native-firebase/blob/master/CONTRIBUTING.md. In terms of the technical aspect, I'm afraid there is no document that will help you (at least, not to my knowledge). It is a case of digging into the code and getting your hands dirty.

As a breadcrumb, my next line of inquiry is to look at how we map data and send it across the bridge to native side: https://github.com/invertase/react-native-firebase/blob/master/packages/firestore/lib/utils/typemap.js
We could potentially look at using buffers or something along those lines to improve performance.

Silly question, but just to clarify, you did run these tests in isolation: https://github.com/invertase/react-native-firebase/issues/3491#issuecomment-631068209?

[mikehardy]

Yeah - I just got going again for a PR and the "tests" module in the monorepo gets you set up to execute everything on iOS and Android, then you can make a performance test that is 'describe.only('test name', () => etc etc` and with the .only bit it will only run that each time. Then you can make a performance test inside the test harness that already exists if that's useful

[ziban]

@russellwheatley no, that was from a running app(running in an emulator). Each call was made on a different page so that's as isolated as it got.

[ziban]

As a breadcrumb, my next line of inquiry is to look at how we map data and send it across the bridge to native side: https://github.com/invertase/react-native-firebase/blob/master/packages/firestore/lib/utils/typemap.js
I have a feeling that this is probably where the problem lies because data that is "stringified" was way faster even though it was the largest.

[ziban]

I spent some time today doing a bit of digging found that most of the time is spent @ this call. https://github.com/invertase/react-native-firebase/blob/master/packages/firestore/lib/FirestoreQuery.js#L169 (Might mean the problem is on the other side of the bridge? ). I set a simple timer before the function call and after the function call and that's where the most time was spent(e.g of out 4200ms, 4100ms was spent here). I measured calls in typemap && it came to about 80ms to 100ms.

[mikehardy]

@ziban
Good work zeroing in on it - you are definitely on the native side now, or perhaps just in between them, in this method https://github.com/invertase/react-native-firebase/blob/a6dc460955bf5d92490cb8b285b4f68e9c10b832/packages/firestore/android/src/reactnative/java/io/invertase/firebase/firestore/ReactNativeFirebaseFirestoreCollectionModule.java#L118

I think if you run the app from AndroidStudio you can fairly easily do some CPU profiling. I find these areas of AndroidStudio a little intimidating because I don't use them often but every time I try I'm able to see what I want without much fuss, you might give it a shot? https://developer.android.com/studio/profile/cpu-profiler

[ziban]

@mikehardy I've timed that function call and it comes to about 2seconds. I cannot account for the other 4 - 6 seconds. Maybe its the bridge? This is the first time I am working on the native side so chances are I am missing something. Edit: Retimed the function and this is where most of the time is spent.

[mikehardy]

what did the profiler say?

[ziban]

I can share some screenshots: It does not show individual functions though

]()

[ziban]

[ziban]

@mikehardy A correction: retimed the function again and most of the time is spent there. I do not know if the profiler info helps much? :(

@ReactMethod
  public void collectionGet(
    String appName,
    String path,
    String type,
    ReadableArray filters,
    ReadableArray orders,
    ReadableMap options,
    ReadableMap getOptions,
    Promise promise
  ) {
    /* Debug.startMethodTracing("collectionGet"); */
    long startTime = System.currentTimeMillis();
    Log.d("StartTime", Long.toString(startTime));
    FirebaseFirestore firebaseFirestore = getFirestoreForApp(appName);
    ReactNativeFirebaseFirestoreQuery query = new ReactNativeFirebaseFirestoreQuery(
      getQueryForFirestore(firebaseFirestore, path, type),
      filters,
      orders,
      options
    );

    Source source;

    if (getOptions != null && getOptions.hasKey("source")) {
      String optionsSource = getOptions.getString("source");
      if ("server".equals(optionsSource)) {
        source = Source.SERVER;
      } else if ("cache".equals(optionsSource)) {
        source = Source.CACHE;
      } else {
        source = Source.DEFAULT;
      }
    } else {
      source = Source.DEFAULT;
    }

    Task<WritableMap> writableMapTask = query.get(getExecutor(), source)
      .addOnCompleteListener(task -> {
        if (task.isSuccessful()) {
          /* Debug.stopMethodTracing(); */
          long endTime = System.currentTimeMillis();
          Log.d("End", Long.toString(endTime));
          Log.d("Diff", Long.toString(endTime - startTime));
          promise.resolve(task.getResult());
        } else {
          rejectPromiseFirestoreException(promise, task.getException());
        }
      });

[mikehardy]

That looks like it's parked in OkHTTP network code a lot. I would want to expand the stack trace on the dominant method and see who is calling it. Is there some socket buffer size misconfiguration somewhere so it's round-tripping on the network and getting awful throughput? Or is it looping one item at a time instead of batching at the logic level (if that's even possible?)?

[ziban]

I had the react-native js debugger open. Look at the 10.0.2.2:8081 next to it -> It's calls to the debugger.

[mikehardy]

Oh my. Never debug a performance problem while using the react-native debugger. It executes your JS code in the browser, did you know that? Not on the device. No statements about or measurements of performance are valid when it's going through the debugger

[ziban]

Didn't know that. Always thought it was some socket communication i.e just passing messages across. Thanks

[mikehardy]

I didn't know it either until I started maintaining react-native-device-info and thought I was being clever using "synchronous native methods" to make APIs available for people in non-async way, and found out the hard way that doesn't work on the debugger because (mind-blowingly, to me) it runs the whole bundle in browser. Learn something every day

[emersiljr]

I'm having the same problem. My RN project with FB v5 is fast, but in v6 it was very slow. Curious is that only on Android, because on iOS is good.

[ziban]

@emersiljr, some things you can do in the meantime:
-> Try to do some local caching if you can afford it. The first call might be slow but you can create the illusion that the latter calls are fast.
-> check if you have firebase calls within firebase calls.. Try to break the calls to be independent/eliminate some calls/cache repeated results.

I looked into this problem for a while and it seems that the library spends a considerable amount of time processing the data on the android before sending it over the bridge. I suspect that the problem might lie in firebase android sdk but I am not sure what exactly is(probably they might have removed something that cached calls/results on their side). Sadly, I've not had the time recently to look into this more.

[Marvin90]

i fixed it with firestore().disableNetwork() and NetInfo:

    NetInfo.fetch().then((state) => {
      if (state.isConnected) {
        firestore().enableNetwork();
      } else {
        firestore().disableNetwork();
      }
    });

[mikehardy]

Fascinating, this sounds like it might be an upstream issue for offline vs online, unrelated to the "gets slower with different data issue", has anyone checked in firebase-android-sdk or firebase-ios-sdk to see if they are tracking something similar or can reproduce with just the native APIs from those SDKs?

[julitroalves]

i fixed it with firestore().disableNetwork() and NetInfo:

    NetInfo.fetch().then((state) => {
      if (state.isConnected) {
        firestore().enableNetwork();
      } else {
        firestore().disableNetwork();
      }
    });

Thanks, help me a lot!

[dackers86]

Closing as the above solution appears to solve the problem