As part of our regular Gradle build scan investigation we looked at an AndroidX build that should have been largely a 100% remote cache hit. We found that we were in fact hitting the cache as expected (yay!), but the build timeline had a long task that hit the cache and yet was taking way longer than any other task (nay!).
(timeline)
Taking a deeper look, we noticed that this task has a fairly large 60.7MB output, but it is downloading it at a measly 750KBps.
Luckily it was easily reproducible locally. Trying to download the exact same
cache entry using gsutil
directly took <2 seconds, so we clearly had an issue.
Taking a cursory look at a network activity on the machine showed that even
Gradle build cache download takes little time, but the cache entry is not
returned for over a minute after.
Then following profiling that I’ve blogged about before, it was clear that we
were spending all of our time in FileInputStream.read
.
And then it dawned on us, we were not doing any sort of buffering for this!!! A small PR later we went from 82s (750KBps) to 1.7s (36.8MBps) to download the same remote cache entry.
Moral of the story? Always be buffering your input streams! How did I not learn this from I/O profiling earlier this year?