Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Secrets of the Build Scan Plugin - Virtual Android Makers 2020

Secrets of the Build Scan Plugin - Virtual Android Makers 2020

Build scans provide some very useful information about Gradle Builds. Build time, configuration time, task execution time. Scans even show garbage collection time, time spent downloading dependencies, time spent in annotation processors? What can you do with all this data?

In this talk I'll share how to surface actionable information from your Gradle build immediately to developers without using the build scan plugin or Gradle Enterprise.

Presented at Virtual Android Makers https://androidmakers.fr/schedule/2020-04-20?sessionId=172401
https://www.youtube.com/watch?v=lgaqS0pmUzk

Nelson Osacky

April 20, 2020
Tweet

More Decks by Nelson Osacky

Other Decks in Programming

Transcript

  1. Me • Previously at Square in SF on Square Register

    and Build Tools • Currently Working at SoundCloud in Berlin
  2. Me • Je parle francais ! • J'ai étudié à

    l’Université de Technologie de Compiègne
  3. Me • Maintainer of some Gradle Plugins: • Fladle -

    Plugin for Firebase Test Lab https://github.com/runningcode/ fladle • Delect - Plugin for Dagger Reflect https://github.com/soundcloud/ delect • Gradle Doctor - https://github.com/runningcode/gradle-doctor
  4. BUILD SUCCESSFUL in 14s 1 actionable task: 1 executed Publishing

    build scan... http://gradle-enterprise.dev.s-cloud.net:81/s/4ctreiklpx5da
  5. 2 x 6GB Daemon + 4GB AS = 16GB We

    all have 16GB MacBooks What about other apps? Web browser?
  6. no 2638 0,0 0,8 12502224 128092 ?? Ss 11:21am 3:25.62

    /Library/Java/ JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home/bin/java -Xmx6g -Dfile.encoding=UTF-8 - Duser.country=DE -Duser.language=de -Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/ cfmwm155h49vnt3hynmlrsdst/gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1485 0,0 15,3 12706900 2574060 ?? Ss 11:10am 13:34.74 /Users/no/Library/ Application Support/JetBrains/Toolbox/apps/AndroidStudio/ch-0/192.6186006/Android Studio.app/Contents/ jre/jdk/Contents/Home/bin/java -Xmx6g -Dfile.encoding=UTF-8 -Duser.country=DE -Duser.language=de - Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/cfmwm155h49vnt3hynmlrsdst/ gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1315 0,0 0,7 10615736 122396 ?? Ss 11:07am 1:39.22 /Library/Java/ JavaVirtualMachines/jdk-12.0.1.jdk/Contents/Home/bin/java --add-opens java.base/java.util=ALL-UNNAMED -- add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.lang.invoke=ALL-UNNAMED --add-opens java.prefs/java.util.prefs=ALL-UNNAMED -Dfile.encoding=UTF-8 -Duser.country=DE -Duser.language=de - Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/cfmwm155h49vnt3hynmlrsdst/ gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1207 0,0 0,7 10274128 125368 ?? Ss 11:06am 1:55.71 /Library/Java/ JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home/bin/java -Dfile.encoding=UTF-8 -Duser.country=DE - Duser.language=de -Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.0.1-all/ 99d3u8wxs16ndehh90lbbir67/gradle-6.0.1/lib/gradle-launcher-6.0.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.0.1 no 6366 0,0 0,0 4267972 680 s003 R+ 1:20pm 0:00.00 grep GradleDaemon
  7. no 2638 0,0 0,8 12502224 128092 ?? Ss 11:21am 3:25.62

    /Library/Java/ JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home/bin/java -Xmx6g -Dfile.encoding=UTF-8 - Duser.country=DE -Duser.language=de -Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/ cfmwm155h49vnt3hynmlrsdst/gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1485 0,0 15,3 12706900 2574060 ?? Ss 11:10am 13:34.74 /Users/no/Library/ Application Support/JetBrains/Toolbox/apps/AndroidStudio/ch-0/192.6186006/Android Studio.app/Contents/ jre/jdk/Contents/Home/bin/java -Xmx6g -Dfile.encoding=UTF-8 -Duser.country=DE -Duser.language=de - Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/cfmwm155h49vnt3hynmlrsdst/ gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1315 0,0 0,7 10615736 122396 ?? Ss 11:07am 1:39.22 /Library/Java/ JavaVirtualMachines/jdk-12.0.1.jdk/Contents/Home/bin/java --add-opens java.base/java.util=ALL-UNNAMED -- add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.lang.invoke=ALL-UNNAMED --add-opens java.prefs/java.util.prefs=ALL-UNNAMED -Dfile.encoding=UTF-8 -Duser.country=DE -Duser.language=de - Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.1.1-all/cfmwm155h49vnt3hynmlrsdst/ gradle-6.1.1/lib/gradle-launcher-6.1.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.1.1 no 1207 0,0 0,7 10274128 125368 ?? Ss 11:06am 1:55.71 /Library/Java/ JavaVirtualMachines/jdk1.8.0_181.jdk/Contents/Home/bin/java -Dfile.encoding=UTF-8 -Duser.country=DE - Duser.language=de -Duser.variant -cp /Users/no/.gradle/wrapper/dists/gradle-6.0.1-all/ 99d3u8wxs16ndehh90lbbir67/gradle-6.0.1/lib/gradle-launcher-6.0.1.jar org.gradle.launcher.daemon.bootstrap.GradleDaemon 6.0.1 no 6366 0,0 0,0 4267972 680 s003 R+ 1:20pm 0:00.00 grep GradleDaemon
  8. Gradle Time! • Samples can be placed in any build.gradle.kts

    file • Can also be placed in build.gradle with minor modifications • Can also be placed in buildSrc • In Gradle Doctor it is packaged inside the plugin
  9. • Run command ps command • Check if more than

    one daemon • Display warning
  10. valacommanda=aarrayOf("/bin/bash", "-c", "ps aux | grep GradleDaemon | wc -l")

    valbprocessb=bRuntime.getRuntime().exec(command) build.gradle.kts
  11. valacommanda=aarrayOf("/bin/bash", "-c", "ps aux | grep GradleDaemon | wc -l")

    valbprocessb=bRuntime.getRuntime().exec(command) if (process.waitFor() != 0) {a throw RuntimeException(process.errorStream.readToString()) }a build.gradle.kts
  12. valacommanda=aarrayOf("/bin/bash", "-c", "ps aux | grep GradleDaemon | wc -l")

    valbprocessb=bRuntime.getRuntime().exec(command) if (process.waitFor() != 0) {a throw RuntimeException(process.errorStream.readToString()) }a process.inputStream.readBytes().toString().trim().toInt() - 1 build.gradle.kts
  13. valacommanda=aarrayOf("/bin/bash", "-c", "ps aux | grep GradleDaemon | wc -l")

    valbprocessb=bRuntime.getRuntime().exec(command) if (process.waitFor() != 0) {a throw RuntimeException(process.errorStream.readToString()) }a valcnumDaemons = process.inputStream.readBytes().toString().trim().toInt() - 1 build.gradle.kts
  14. valacommanda=aarrayOf("/bin/bash", "-c", "ps aux | grep GradleDaemon | wc -l")

    valbprocessb=bRuntime.getRuntime().exec(command) if (process.waitFor() != 0) {a throw RuntimeException(process.errorStream.readToString()) }a valcnumDaemons = process.inputStream.readBytes().toString().trim().toInt() - 1 if (numDaemons > 1) {b throw GradleException("$numDaemons active. This may indicate a mismatched JAVA_HOME.") }b build.gradle.kts
  15. But… • Throws exception when running two different Gradle Projects

    • Throws exceptions for build.gradle.kts spawning extra Gradle Daemons • Throws exceptions when running tests using the GradleRunner
  16. val environmentJavaHomea=bSystem.getenv("JAVA_HOME") val gradleJavaHomec=dJvm.current().javaHome ifa(environmentJavaHomea==bnull) {a throwaGradleException("JAVA_HOME isn't set.") }a

    if (gradleJavaHome.toPath().toRealPath() != File(environmentJavaHome).toPath().toRealPath()) {b throw GradleException("JAVA_HOME doesn't match Gradle's Java") }b Follow symlinks! Thanks Eugen Martynov!
  17. val environmentJavaHomea=bSystem.getenv("JAVA_HOME") val gradleJavaHomec=dJvm.current().javaHome ifa(environmentJavaHomea==bnull) {a throwaGradleException("JAVA_HOME isn't set.") }a

    if (gradleJavaHome.toPath().toRealPath() != File(environmentJavaHome).toPath().toRealPath()) {b throw GradleException("JAVA_HOME doesn't match Gradle's Java") }b Follow symlinks! Thanks Eugen Martynov!
  18. gradle.addBuildListener(object : BuildListener { override fun settingsEvaluated(settings: Settings) { }

    overrideafunabuildFinished(result:aBuildResult)a{ } override fun projectsLoaded(gradle: Gradle) { } override fun buildStarted(gradle: Gradle) { } override fun projectsEvaluated(gradle: Gradle) { } }) build.gradle.kts
  19. To see more detail about a task, run gradlew help

    --task <task> For troubleshooting, visit https://help.gradle.org Build took 288ms BUILD SUCCESSFUL in 1s 1 actionable task: 1 executed
  20. /** * Returns a list of {@link GarbageCollectorMXBean} objects *

    in the Java virtual machine. * The Java virtual machine may have one or more * {@code GarbageCollectorMXBean} objects. * It may add or remove {@code GarbageCollectorMXBean} * during execution. * * @return a list of {@code GarbageCollectorMXBean} objects. * */ public static List<GarbageCollectorMXBean> getGarbageCollectorMXBeans() { return getPlatformMXBeans(GarbageCollectorMXBean.class); }
  21. val start = System.currentTimeMillis() valastartGCTimea=aManagementFactory.getGarbageCollectorMXBeans() .sumBya{ait.collectionTime.toInt()a} gradle.buildFinished { val end

    = System.currentTimeMillis() val endGCTime = ManagementFactory.getGarbageCollectorMXBeans() .sumBy { it.collectionTime.toInt() } val duration = end - start val gcTime = endGCTime - startGCTime println("Build took $duration ms") println("Spent $gcTime ms garbage collecting") println("${gcTime * 1.0f / duration} % garbage collecting") }
  22. Build took 1257 ms Spent 17 ms garbage collecting 0.013524264

    % garbage collecting BUILD SUCCESSFUL in 2s
  23. =============================== Gradle Doctor Prescriptions ============================================ | This build spent 96%

    garbage collecting. | | If this is the first build with this Daemon, it likely means that this build needs more heap space. | | Otherwise, if this is happening after several builds it could indicate a memory leak. | | For a quick fix, restart this Gradle daemon. ./gradlew --stop | ========================================================================================================
  24. /** * An internal interface for Gradle that exposed objects

    and concepts that * are not intended for public consumption. */ @UsedByScanPlugin public interface GradleInternal extends Gradle, PluginAwareInternal { @UsedByScanPlugin ServiceRegistry getServices(); }
  25. /** * A read-only registry of services. May or may

    not be immutable. */ public interface ServiceRegistry extends ServiceLookup { /** * Locates the service of the given type. * * @param serviceType The service type. * @param <T> The service type. * @return The service instance. Never returns null. * @throws UnknownServiceException When there is no service of the given type available. * @throws ServiceLookupException On failure to lookup the specified service. */ @UsedByScanPlugin <T> T get(Class<T> serviceType) throws UnknownServiceException, ServiceLookupException; }
  26. /** * Manages listeners of build operations. * * There

    is one global listener for the life of the build runtime. * Listeners must be sure to remove themselves if they want to only listen for a single build. * */ public interface BuildOperationListenerManager { void addListener(BuildOperationListener listener); void removeListener(BuildOperationListener listener); BuildOperationListener getBroadcaster(); }
  27. val gradleInternal = (gradle as GradleInternal) val manager = gradleInternal.services[BuildOperationListenerManager::class.java]

    manager.addListener(object : BuildOperationListener { override fun progress(operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { } override fun finished(buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } })
  28. manager.addListener(object : BuildOperationListener { override fun progress(operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent)

    { } override fun finished(buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } }) Memory Leak!
  29. /** * Manages listeners of build operations. * * There

    is one global listener for the life of the build runtime. * Listeners must be sure to remove themselves if they want to only listen for a single build. * */ public interface BuildOperationListenerManager { void addListener(BuildOperationListener listener); void removeListener(BuildOperationListener listener); BuildOperationListener getBroadcaster(); }
  30. There is one global listener for the life of the

    build runtime. Listeners must be sure to remove themselves if they want to only listen for a single build.
  31. There is one global listener for the life of the

    build runtime. Listeners must be sure to remove themselves if they want to only listen for a single build.
  32. manager.addListener(object : BuildOperationListener { override fun progress(operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent)

    { } override fun finished(buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } })
  33. val listener = object : BuildOperationListener { override fun progress(operationIdentifier:

    OperationIdentifier, progressEvent: OperationProgressEvent) { } override fun finished(buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } }
  34. val listener = object : BuildOperationListener { override fun progress(operationIdentifier:

    OperationIdentifier, progressEvent: OperationProgressEvent) { } overrideafunafinished(buildOperation:aBuildOperationDescriptor,afinishEvent: OperationFinishEvent)a{ } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } } manager.addListener(listener) gradle.buildFinished { manager.removeListener(listener) } ☺
  35. @NotUsedByScanPlugin("used to report annotation processor execution times to TAPI progress

    listeners") public class CompileJavaBuildOperationType implements BuildOperationType { public interface Result { /** * Returns details about the used annotation processors, if available. * * <p>Details are only available if an instrumented compiler was used. * * @return details about used annotation processors; {@code null} if unknown. */ @Nullable List<AnnotationProcessorDetails> getAnnotationProcessorDetails(); /** * Details about an annotation processor used during compilation. */ interface AnnotationProcessorDetails { /** * Returns the fully-qualified class name of this annotation processor. */ String getClassName(); /** * Returns the total execution time of this annotation processor. */ long getExecutionTimeInMillis(); } } }
  36. var daggerTime = 0L val listener = object : BuildOperationListener

    { override fun finished( buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { val result = finishEvent.result ifa(result is CompileJavaBuildOperationType.Result)a{ result.annotationProcessorDetails!!.forEacha{ if (it.className.contains("dagger"))a{ daggerTime += it.executionTimeInMillis } } } } }
  37. var daggerTime = 0L val listener = object : BuildOperationListener

    { override fun finished( buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { val result = finishEvent.result ifa(result is CompileJavaBuildOperationType.Result)a{ result.annotationProcessorDetails!!.forEacha{ if (it.className.contains("dagger"))a{ daggerTime += it.executionTimeInMillis } } } } }
  38. var daggerTime = 0L val listener = object : BuildOperationListener

    { override fun finished( buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { val result = finishEvent.result if (result is CompileJavaBuildOperationType.Result) { result.annotationProcessorDetails!!.forEacha{ if (it.className.contains("dagger"))a{ daggerTime += it.executionTimeInMillis } } } } }
  39. var daggerTime = 0L val listener = object : BuildOperationListener

    { override fun finished( buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { val result = finishEvent.result if (result is CompileJavaBuildOperationType.Result) { result.annotationProcessorDetails!!.forEacha{ if (it.className.contains("dagger"))a{ daggerTime += it.executionTimeInMillis } } } } } gradle.buildFinished { manager.removeListener(listener) println("This build spent $daggerTime in Dagger annotation processors") }
  40. var daggerTime = 0L val listener = object : BuildOperationListener

    { override fun finished( buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { val result = finishEvent.result if (result is CompileJavaBuildOperationType.Result) { result.annotationProcessorDetails!!.forEacha{ if (it.className.contains("dagger"))a{ daggerTime += it.executionTimeInMillis } } } } } gradle.buildFinished { println("This build spent $daggerTime in Dagger annotation processors") }
  41. • Only measures annotationProcessor • annotationProcessor is part of JavaCompileTask

    and owned by Gradle • KAPT is not measured. It is owned by JetBrains • There is no public api
  42. :libs:periodicjobs:bundleLibResDebug UP-TO-DATE :libs:periodicjobs:bundleLibRuntimeDebug UP-TO-DATE :listenerapp:devdrawer:javaPreCompileDebug :listenerapp:devdrawer:compileDebugJavaWithJavac w: [kapt] Annotation processor

    stats: w: [kapt] dagger.internal.codegen.ComponentProcessor: total: 1808 ms, init: 488 ms, 3 round(s): 1162 ms, 157 ms, 1 ms w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms w: [kapt] com.soundcloud.lightcycle.LightCycleProcessor: total: 11 ms, init: 1 ms, 3 round(s): 10 ms, 0 ms, 0 ms :features:onboarding:compileDebugKotlin :features:onboarding:javaPreCompileDebug :features:onboarding:compileDebugJavaWithJavac
  43. val listener = object : BuildOperationListener { override fun progress(operationIdentifier:

    OperationIdentifier, progressEvent: OperationProgressEvent) { } override fun finished(buildOperation: BuildOperationDescriptor, finishEvent: OperationFinishEvent) { } override fun started(buildOperation: BuildOperationDescriptor, startEvent: OperationStartEvent) { } }
  44. val listener = object : BuildOperationListener { override fun progress(

    operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { } }
  45. overrideafunaprogress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log = progressEvent.details

    if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  46. overrideafunaprogress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log = progressEvent.details

    if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  47. overrideafunaprogress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log = progressEvent.details

    if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  48. overrideafunaprogress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log = progressEvent.details

    if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  49. overrideafunaprogress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log = progressEvent.details

    if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  50. override fun progress( operationIdentifier: OperationIdentifier, progressEvent: OperationProgressEvent) { val log

    = progressEvent.details if (log is LogEventBuildOperationProgressDetails) { if (log.message.contains("kapt") && log.message.contains("dagger")) { daggerTime += "\\d+".toRegex().find(log.message)!!.groups[0]!!.value.toInt() } } } gradle.buildFinished { println("This build spent $daggerTime in Dagger annotation processors") } w: [kapt] dagger.android.processor.AndroidProcessor: total: 1367 ms, init: 29 ms, 3 round(s): 1333 ms, 5 ms, 0 ms
  51. 68.5s average of 5 builds without Gradle Doctor 70.1s average

    of 5 builds with Gradle Doctor std deviation = 10.5 seconds Profiler results show no significant difference
  52. ====================== Gradle Doctor Prescriptions ====================== | Detected a slow download

    speed downloading from Build Cache. | | 4.28 MB downloaded in 53.43 s | | Total speed from cache = 0.08 MB/s | =========================================================================
  53. ========= Remote Build Cache Benchmark Report ======== Executed tasks created

    compressed artifacts of size 159,93 MB Total Task execution time was 208,85 s In order for a remote build cache to save you time, you would need an internet connection to your node of at least 0,77 MB/s. ======================================================
  54. • Ensure JAVA_HOME matches • Warn on excessive Garbage collection

    • Warn if spending too much time with Dagger • Warn on slow build cache connection speed • Benchmark Remote Build cache