Apollo-android: Response very slow when normalized cache is active

[hameno]

Summary
When using ApolloClient with a normalized cache chain (Memory -> SQLite), response take 40x longer to return (100ms vs 4000ms)
This is measured with enabled logging from OkHttp (response time from server around 400ms) and logging in the stream after rxQuery returns an response for the first time. Response fetcher is set to ApolloResponseFetchers.NETWORK_FIRST to allow cached data for offline case.

Version
2.2.1

Description
When we enabled normalized caching we noticed that responses take 40x longer on average to return data.
Our cache is configured like this:

private fun createDefaultCacheFactory(context: Context): NormalizedCacheFactory<*> = LruNormalizedCacheFactory(
    // 10 MB cache
    EvictionPolicy.builder().maxSizeBytes(10 * 1024 * 1024).build()
).chain(SqlNormalizedCacheFactory(context, name = "catalog"))

It looks like the caching is delaying the emission of the response. Can this be improved? Is there a workaround?

[martinbonnin]

It's something discussed in https://github.com/apollographql/apollo-android/issues/2402. If you don't mind, I'll close this issue and move the discussion over there. Also, do you have a sample response json that we could use for benchmarks? I can always forge one but it's also nice to have real-life examples.

[hameno]

Thanks for the fast response. Unfortunately I cannot provide a JSON, and unfortunately OkHttp just logs "unknown size", but I can tell you the response is quite large. The dependentKeys HashSet has 2551 items.

[martinbonnin]

That's a beefy response :) !

Is it ok for you if I close this one and we move the discussion to #2402?

[hameno]

Yes, is there any workaround known? We are close to a release and this is kind of a blocker for us right now.

[martinbonnin]

https://github.com/apollographql/apollo-android/pull/2412 will improve things. It would be interesting to know how much time that saves in your use case.

[hameno]

I'd be willing to test a SNAPSHOT - could you make one available?

[martinbonnin]

The snapshot is building at https://github.com/apollographql/apollo-android/actions/runs/153870167.

[hameno]

Much better with the latest snapshot, we're down to ~600ms now for this response.

[hameno]

I've profiled a bit more because I notice a lot of GCs during the parsing. It seems as ResponseJsonStreamReader is allocating a lot of objects. I'm gonna dig deeper to see if there is an obvious error or just a lot of data

EDIT: Looks like most are in okio Buffer#readUtf8 - so I guess this is to be expected

[hameno]

Time is now acceptable for us, but it would be great if this could be further improved. The suggestion of a separate (serialized?) caching thread sounds like a good idea to offload this work and reduce delays.

[hameno]

Tests look good here, do you have any timeline on a new release?

[martinbonnin]

It's just done :) https://github.com/apollographql/apollo-android/releases/tag/v2.2.2
Edit: The releases are on jcenter. I'm still struggling with Sonatype so the releases are not on mavenCentral yet but they should be there shortly