https://kotlinlang.org logo
Title
s

Seb Jachec

06/13/2022, 3:57 PM
Hi, we’re seeing cache-only queries on both Android & iOS being unexpectedly very slow, but I’m not really sure where to go with debugging / optimising performance. Hoping someone has some pointers – not sure if we’re running into an Apollo limitation or just missing something basic around Kotlin flows! (sorry for the large message 😅) On iPhone 13 Pro w/ latest iOS, I measured ~500-600ms to perform a cache-only query for our items (just via naive
print
statements before/after
query.execute()
) shortly after app launch. From inspecting the SQL DB, I’d guess this query reads ~2,000 SQL records worth of data. We’re using Apollo’s in-memory cache (10MB limit), chained with the SQL normalized disk cache, in a KMM app. Inspecting the cache seems easy on Android, from where I can see our disk cache DB file is ~1.1MB, with ~2150 records in total during an average flow through our app (launch app, query for account, query user’s paginated items). Each ‘item’ has ~15 immediate fields, most of which are nested fragments/objects. We’re creating a
flow { .. }
, and using
withContext(Dispatchers.Main) { .. }
inside this to execute the Apollo query for items and receive the response (we later perform some other operations within that flow, after emitting the queried cache-only items). Downstream shared view models collect via
IO
(Android)/`Default` Dispatcher (iOS), and further downstream, platform view models collect from shared view models on the main dispatcher/thread to present UI.
b

bod

06/13/2022, 4:05 PM
Hi! 👋 Is the ~500-600ms time with the chained cache, and is it consistent? If the same query is slow the first time but not the second time that would point to the SQL cache.
(also, not related to the performance issues, but there is a
ApolloCall.toFlow()
method that already returns a Flow - this may be simpler than calling
execute()
inside a
flow {...}
)
also, just to confirm, are you using 3.x?
s

Seb Jachec

06/13/2022, 4:14 PM
Hi! Yes, 500-600ms is with the chained caches, and it’s very much consistent for subsequent identical queries. We’re using Apollo 3.3.0
🙏 1
b

bod

06/13/2022, 4:16 PM
interesting
That seems very high to me indeed especially for the in-memory cache.
however it's kind of hard to gauge what's "normal" or not 🙂 Would you be able to create a repro project?
s

Seb Jachec

06/13/2022, 4:37 PM
It might be a bit tricky, but I’ll see what I can do tomorrow morning!
🙏 1
I thought I’d try using a free/open GraphQL API (AniList) in a new project setup as similarly to ours as possible, fetching a similar number of fragments/fields in the main paginated query. Our API is behind authentication and a bit hard to extract. The amount of data is much higher – on-disk cache DB file is ~4.3MB Android, ~16k records (so ~4x disk size, ~7x record count) – however much that’s actually relevant to the in-memory cache. But, the cache-only read time is only ~138ms 🤔
b

bod

06/14/2022, 10:14 AM
damn 😅 more data but faster 🤔
s

Seb Jachec

06/14/2022, 3:23 PM
Switched back to our actual app to try and narrow things down. Copied over Apollo’s internal `MemoryCacheFactory`/`MemoryCache`/`LruCache` implementations to add some logging, that seems to take ~30ms to load the records for the particular cache-only query. The
cacheInfo
on Apollo’s actual response still reports 500-600ms (from
cacheEndMillis - cacheStartMillis
), so my next guess is the conversion from cached records into actual objects is taking a while
b

bod

06/14/2022, 3:35 PM
The conversion involves instantiating Data classes and using the generated parsers to "populate" them with the data from the Maps in the cache.
👌 1
thank you for digging into this by the way! 🙏
s

Seb Jachec

06/14/2022, 4:20 PM
Do you know if there’s a way I could stop Apollo from re-generating the generated response adapters each time I build, so that I could make changes / add logging to them? I thought maybe just disabling the
generateServiceApolloSources
Gradle task might work, but it looks like that’s doing a bit more as my sync/build breaks entirely
b

bod

06/14/2022, 4:28 PM
good question! Wondering if you could just copy the generated files to your sources and temporarily comment out the Apollo plugin?
s

Seb Jachec

06/14/2022, 4:56 PM
Brilliant, that works thanks! Investigation to be continued.. 😅
:android-wave: 1
w

wasyl

06/14/2022, 8:06 PM
I wonder if you would see the same results on regular JVM, for example in a unit test. If yes, it’d be relatively easy to attach some profiling tool and actually see which methods take the most time
1
m

mbonnin

06/17/2022, 9:45 AM
@Seb Jachec did you end up finding anything? One thing that comes to mind is if you're using the
responseBased
codegen, it can generate a non-trivial amount of bytecode. Maybe simply loading these classes is what is taking the ~500ms? (although it should be faster on subsequent calls)
s

Seb Jachec

06/17/2022, 10:31 AM
Sorry for the radio silence! Wanted to come back with some more conclusive results 😅. I’ve finally been able to account for all of the time that Apollo reports in its
cacheInfo
(
cacheEndMillis - cacheStartMillis
) — ~75% of that 500-600ms in our app is being spent just loading records from the in-memory cache, ~15% is taken by the response adapters (mis-measured the time before). We’ve got custom
CacheKeyResolver
and
CacheKeyGenerator
implementations which I think might be detrimental to the specific query we’re trying to improve. We are indeed using
responseBased
codegen too though. Taken a brief break from this, will revisit next week!
🙏 1
m

mbonnin

06/17/2022, 10:40 AM
Thanks for the update! 500ms for in-memory is a loooong time. I'd be curious if using
operationBased
changes anything. We should certainly work on baseline benchmarks on our side too to have a comparison point
s

Seb Jachec

06/20/2022, 11:23 AM
operationBased
seems to be nearly the same as
responseBased
for our use-case (no significant difference). I’m looking at the just-added
@typePolicy(embeddedFields:)
now, as it could be potentially useful to cut down on the sheer number of cache records. With a few types extended, I’m so far running into
JsonDataException: Expected BEGIN_OBJECT but was NULL at path…
, although inspecting the normalised SQL DB on-disk it looks like a much tidier representation. Probably user error (and not something I can give helpful debug info for if not), so there’s more to work out yet!
b

bod

06/20/2022, 11:29 AM
Woops, this issue with
embeddedFields
was found Friday - the fix is on another branch that is not merged yet
s

Seb Jachec

06/20/2022, 11:30 AM
Ooh awesome, okay!
No urgency from me, but out of interest do you think it’s likely that branch would be merged into
main
in the next few days or weeks?
b

bod

06/20/2022, 11:39 AM
the plan is that this should go in version 3.4.0 so maybe not next few days but next few weeks yes 🙂 This release will focus on cache improvements.
m

mbonnin

06/20/2022, 12:02 PM
@Seb Jachec you can always build locally, it's usually a matter of
./gradlew publishToMavenLocal
and adding
mavenLocal()
to your repos
But we could as well very much merge this PR @bod?
b

bod

06/20/2022, 12:05 PM
well this one hasn't been reviewed 😅 But we could merge the fix independently 🙂
m

mbonnin

06/20/2022, 12:08 PM
Yeaaa, that's on me but I don't want to be the bottleneck there. Tests are and there are no API changes so it's all good for me
I just approved 🙂
b

bod

06/20/2022, 12:14 PM
all right it should be merged to main soon (waiting for CI to be sure 🙂)
:loading: 1
s

Seb Jachec

06/20/2022, 12:19 PM
Ah, thanks! 😄 I didn’t know about building locally @mbonnin – that’s good to know for the future
b

bod

06/20/2022, 1:12 PM
this is merged now!
❤️ 1
1
m

mbonnin

06/20/2022, 1:13 PM
Will be in the SNAPSHOTS in ~40min :loading:
Sometimes I envy our JS colleagues 🙃
😅 2
s

Seb Jachec

06/21/2022, 1:34 PM
We’ve experimented with
@typePolicy(keyFields:,embeddedFields:)
in various configurations and found we basically have a trade-off between embedding fields (reducing cache record count, increasing read speed) and being able to query for individual objects later on. In the most extreme case, embedding our entire paginated query and all its objects/fields such that there’s a single cache record (instead of ~500) gives us a 110ms cache-only query, instead of ~350ms on Android, but obviously that would then lose the benefit of getting a cache hit when querying for a single item, and we might overwrite the entire cache record for any mutations. The schema we’re querying against looks something like this:
type PageInfo {
	# Omitted for brevity
}

type ItemConnection {
	edges: [ItemEdge!]!
	pageInfo: PageInfo
}

type ItemEdge {
	id: ID!
	node: Item!
}

type Item {
	id: ID!
	title: String!
	start: DateTimeInfo
	end: DateTimeInfo
	# ... ~10 other fields, mostly objects, omitted for brevity
}
Would you have any recommendations here as to how we could get the best of both worlds, i.e. storing cache keys for each edge, but also embedding for speedy paginated queries?
m

mbonnin

06/21/2022, 1:36 PM
This is all using only in-memory cache, right?
w

wasyl

06/21/2022, 1:37 PM
I’d hope it’s possible to do some optimizations in Apollo in the first place, before having to adjust queries. Perhaps there’s some place to trade off memory for speed in how the cache is accessed
:plus-one: 1
m

mbonnin

06/21/2022, 1:39 PM
To answer the question, I don't really have strong recommendations at this point. I'd love to get this as a benchmark in the repo though and use it as a starting point for future optimization work
s

Seb Jachec

06/21/2022, 1:41 PM
The numbers and benchmarking we’ve been doing has just been using in-memory cache alone, yep
m

mbonnin

06/21/2022, 1:48 PM
Any chance you can share the schema, typical query and response json? I can work on putting that in the repo, maybe even make in run in a device farm somewhere so that we can track the evolution of the numbers as we make changes
s

Seb Jachec

06/21/2022, 2:13 PM
Absolutely, happy to! I’ll just get hold of these and send them over
:thank-you: 1
I’ve zipped up our schema, relevant queries (and fragments), and an actual response JSON file (formatted). Let me know if there’s any more info I can give, feel free to simplify any of this if need be too
🙏 1
m

mbonnin

06/21/2022, 4:19 PM
Thank you 💙! Is it ok to include this in the apollo-kotlin Github repository?
s

Seb Jachec

06/21/2022, 4:19 PM
Yes!
💙 1
m

mbonnin

06/21/2022, 7:10 PM
Early benchmark is there: https://github.com/apollographql/apollo-kotlin/blob/add-benchmarks/benchmark/src/androidTest/java/com/apollographql/apollo3/benchmark/Calendar.kt I still need to iron out everything and double check everything tomorrow but early numbers are ~74ms for reading from cache the 635KB json. Not really sure if it's good or bad but that's at least something
s

Seb Jachec

06/22/2022, 1:34 PM
Interesting! That’s similar to what we’re seeing for that amount of data on Android, but iOS is still 2x–3x the time. (Our interim app change has been to decrease the amount of data we’re fetching, to about the amount in the response I sent over, which reduced the time on both platforms)
m

mbonnin

06/22/2022, 1:56 PM
Double checking: iOS is Kotlin multiplatform too, right? Not
apollo-ios
?
s

Seb Jachec

06/22/2022, 1:58 PM
Yep! Kotlin multiplatform
👍 1