A friend of mine, Kyle Lehman at Comcast, recently sent me this message:
Hey Tony, I just noticed the dependency-analysis plugin is almost doubling our config time (adding ~3sec). Didn't see any open issues that would potentially be related to this. Should I open one up or do you think we might be doing something funky in our config or is this just a fact of life?
😱
I asked him to create an issue,1 but undercut my own process by immediately following up and also asking if he could provide a profile. I've had success in the past optimizing my code with the use of profiles, and find them to be invaluable tools.
Synopsis
In this post, we'll see that optimizing build performance is often not a straight path, but a winding journey. We'll observe some Gradle worst practices, see how we can replace them with best practices, and with CPU profiles and build scans as our guides. You will learn how to create a CPU profile of your build process (it's quite easy!) and learn a bit about interpreting them.
Starting with a build scan
Kyle started by providing me a build scan, from which I have excerpted this:
Yeah, that looks pretty bad. I would not be happy to be working on a project where configuration time had a floor of three seconds.
While the build scan was sufficient to show that something was going on, it didn't provide enough detail to understand what that something was. What was taking all that time? And why were those tasks being created? I thought I used task configuration avoidance exclusively....
Narrator: he didn't.
You see, my plugin works by registering tasks for each variant of an Android project,2 and then also registering an aggregating task that combines all the variant-specific data into a single coherent whole. That holistic information is then the basis of the holistic "advice" it provides to users. And here's where it gets interesting. When I originally wrote the aggregating code, I was focused on getting it to work, and also apparently suffered a mild stroke?, because I completely ignored best practices and had done this:
val adviceTasks = tasks.withType<AdviceTask>()
val dependencyOutputs = mutableListOf<RegularFileProperty>()
adviceTasks.all {
dependencyOutputs.add(adviceReport)
}
val aggregateAdviceTask =
tasks.register<AdviceSubprojectAggregationTask>("aggregateAdvice") {
// a ListProperty<RegularFileProperty>
dependencyAdvice.set(dependencyOutputs)
}
😱
For anyone who may not yet have gone through their ritual Gradle hazing, the issue here is tasks.withType<AdviceTask>().all { ... }, which eagerly realizes all tasks of type AdviceTask, defeating configuration avoidance.
I actually didn't notice this immediately after speaking with Kyle. At that point, I was waiting on the CPU profile he had promised, and so was working on something totally unrelated. But I had his issue in the back of my mind, tickling my neurons. When I stumbled across that snippet above, and finally saw what I had done (and then wept), I fixed it like so:
val aggregateAdviceTask
= tasks.register<AdviceSubprojectAggregationTask>("aggregateAdvice")
val adviceTask = ...
aggregateAdviceTask.configure {
// a ListProperty<RegularFile>
dependencyAdvice.add(adviceTask.map { it.adviceReport })
}
(The commit is available here.)
The difference is that I register the aggregating task immediately, without a configuration block. Then I configure it piecemeal, each time I add a "sub," or variant-specific, task. Because I have a thorough end-to-end test suite, I was able to verify I didn't break anything by just running all the tests ✅
I published that version of the plugin and told Kyle about it.
He responded that it didn't resolve his problem.
Interesting! My plugin is no longer eagerly realizing all of its tasks, but it still takes three seconds to configure. Kyle and I then briefly debated the value of task configuration avoidance,3 but that's neither here nor there. It was clear we had to go deeper. I asked again for a CPU profile.
Continuing with a CPU profile
The profile had a story to tell. I'll focus on one section of it (keep reading for instructions on how to create your own profile):
AndroidAppAnalyzer is the code responsible for analyzing a com.android.application project. And it is responsible for 50% of CPU usage! From the profile, I could tell it was due to registerClassAnalysisTask(), which in turn required some — apparently — quite expensive computation. Here's the code in question:
val javaVariantFiles = androidSourceSets.flatMapToSet { sourceSet ->
project.files(sourceSet.javaDirectories)
.asFileTree
.files
.toVariantFiles(sourceSet.name)
}
This code does the following:
- Iterates over the Android source sets (a
Set<SourceProvider>) for the given variant - Gets the Java directories for each source set
- Converts each directory into a
FileTree(which points to files instead of directories) - Gets that file tree as a
Set<File> - Converts those into a custom data class called
VariantFile, defined below.
/**
* Associates a [variant] ("main", "debug", "release", ...) with a
* [filePath] (to a file such as Java, Kotlin, or XML).
*/
data class VariantFile(
val variant: String,
val filePath: String
)
(This is part of what enables the plugin to provide variant-specific advice for Android projects.)
The final two steps (.files and .toVariantFiles()) were the expensive bits, at 35% and 10% of the total cost, respectively.
I was able to find a solution to this problem by adding a new task that did this work (pushing the work out of configuration and into a cacheable task), and making that new task's output an input to my now much-cheaper-to-configure ClassListAnalysisTask. Here's the commit that does it.
And here's the new CPU profile:
From 50% of total CPU time to under 7%! Not bad. Configuration time also went down from over six seconds to just over three seconds. (Well, not all their build's problems were from my plugin!)
Interlude
While I was working on adapting my configuration-time code to instead work during task execution, Kyle continued to investigate with the help of build scans. He noticed this:
This is from a custom script, appcenter.gradle, which configures publishing for one of their apps. By itself, it takes over 1s to apply, but it's also triggering the eager realization of a lot of tasks, including all those from my plugin — which explains why my earlier fix didn't help, and reinforcing the value of continuing to work on improving my plugin's configuration performance per se.
When Kyle simply commented out that script as an experiment, he next saw this:
Proving that his script was the proximal cause. Care to guess what that script was doing? If you can't bare to wait, keep reading:
project.afterEvaluate {
project.tasks.all { task ->
There's that damn all again, ruining everything. So I guess task configuration avoidance isn't a waste after all.4
Using Gradle-Profiler to profile a build
First, please refer to Benchmarking builds with Gradle-Profiler for instructions on how to install gradle-profiler. If you already have this installed, please ensure you have it up to date.
Now without further ado, here is how you can profile your build's configuration phase:
$ gradle-profiler —profile async-profiler --project-dir <root-dir-of-build> help
Note the use of the task help here. This task is very fast and just prints some basic help text to console. help therefore often serves as a useful proxy for configuration time. Once it finishes, it will produce output in the working directory under profile-out-N, where N is a 1-based index. Within that directory, you will find a flamegraph, an icicle graph, and related files.
Enjoy!
Endnotes
1 Just realized he never did. Tsk tsk. up
2 For JVM projects, it also looks at "all the variants," which in practice is just "main." up
3 At, like, an ontological level. up
4 But what does it mean? up
Top comments (3)
@autonomousapps that is a decent article love it :) Always struggled with Gradle, and still kinda there :P Any advice about how to grow as a Gradle expert? (I suppose cramming through their docs site and playing with open-source plugins). Maybe, you have some extra good resource on your mind ;)
Anyway, great article!!!
I learned more working on this plugin than any other way. I also read the docs like they're a book.
So:
@autonomousapps I think the command for profiling should be "--profile" not "—profile" right?