Skip to content

Commit

Permalink
Add BuildExecutionListener
Browse files Browse the repository at this point in the history
  • Loading branch information
klu2 authored May 17, 2022
1 parent 606acb9 commit 2436c8b
Show file tree
Hide file tree
Showing 3 changed files with 172 additions and 0 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import io.cloudflight.gradle.autoconfigure.report.ReportConfigurePlugin
import io.cloudflight.gradle.autoconfigure.kotlin.KotlinConfigurePlugin
import io.cloudflight.gradle.autoconfigure.kotlin.KotlinConfigurePluginExtension
import io.cloudflight.gradle.autoconfigure.kotlin.isKotlinProject
import io.cloudflight.gradle.autoconfigure.util.BuildExecutionTimeListener
import io.cloudflight.gradle.autoconfigure.util.isServerProject
import io.cloudflight.license.gradle.LicensePlugin
import org.gradle.api.GradleException
Expand All @@ -20,6 +21,12 @@ class AutoConfigureGradlePlugin : Plugin<Project> {
override fun apply(target: Project) {
if (target != target.rootProject) throw GradleException("'autoconfigure-gradle' plugin can only be applied to the root project.")

if (!target.gradle.startParameter.isParallelProjectExecutionEnabled) {
target.gradle.addListener( BuildExecutionTimeListener())
} else {
target.logger.info("Parallel builds are enabled. Build Execution Times are not calculated as this is not yet supported")
}

val autoConfigure = target.extensions.create(EXTENSION_NAME, AutoConfigureExtension::class)
with(autoConfigure.java) {
languageVersion.convention(JAVA_LANGUAGE_VERSION)
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,164 @@
package io.cloudflight.gradle.autoconfigure.util

import org.gradle.BuildListener
import org.gradle.BuildResult
import org.gradle.api.Task
import org.gradle.api.execution.TaskExecutionListener
import org.gradle.api.initialization.Settings
import org.gradle.api.invocation.Gradle
import org.gradle.api.logging.Logging
import org.gradle.api.tasks.TaskState
import java.util.*
import java.util.concurrent.TimeUnit

/**
* TODO find alternative solution that does not use deprecated code as soon as https://github.com/gradle/gradle/issues/20151 is solved
*/
class BuildExecutionTimeListener : TaskExecutionListener, BuildListener {

companion object {
private val LOG = Logging.getLogger(BuildExecutionTimeListener::class.java)

private const val MIN_TIME_FOR_LOG = 100
private const val MAX_LENGTH_FOR_TIME_STRING = 27
private const val MIN_GAP_BETWEEN_TEXT_AND_TIME = 2
}

private val taskStack = Stack<String>()
private val executionTimes = mutableMapOf<String, Long>()
private var lastTaskStartTime: Long = 0

override fun beforeExecute(task: Task) {
taskStack.push(task.path)
lastTaskStartTime = System.currentTimeMillis()
}

override fun afterExecute(task: Task, state: TaskState) {
val latestTask = taskStack.peek()
if (task.path != latestTask) {
LOG.debug("We have $latestTask on the peek of the stack, but we were closing ${task.path}. Build Execution Times will be wrong")
} else {
val lastTask = taskStack.pop()
executionTimes[lastTask] = System.currentTimeMillis() - lastTaskStartTime
}
if (!taskStack.empty()) {
// we have other tasks still on the stack that will be executed probably now
lastTaskStartTime = System.currentTimeMillis()
}
}


override fun buildFinished(result: BuildResult) {
if (executionTimes.isEmpty()) {
return
}
val timesPerModule = mutableMapOf<String, Long>()
val timesPerTask = mutableMapOf<String, Long>()

val sum = executionTimes.values.sum()

if (sum == 0L) {
return
}

val allTasks = StringBuilder()
allTasks.append("All tasks that take longer than $MIN_TIME_FOR_LOG ms").append(System.lineSeparator())
val maxTaskPathLength = getMaxKeyLength(executionTimes)
addHeader(allTasks, maxTaskPathLength)
executionTimes.toSortedMap().forEach {
val taskPath = it.key
val time = it.value

val lastColon = taskPath.lastIndexOf(':')
val taskName = taskPath.substring(lastColon + 1)
if (!timesPerTask.containsKey(taskName)) {
timesPerTask.put(taskName, time)
} else {
timesPerTask.put(taskName, time + timesPerTask.getValue(taskName))
}

val module = taskPath.substring(0, lastColon)
if (!timesPerModule.containsKey(module)) {
timesPerModule.put(module, time)
} else {
timesPerModule.put(module, time + timesPerModule.getValue(module))
}
if (time >= MIN_TIME_FOR_LOG) {
addEntry(allTasks, taskPath, maxTaskPathLength, time, sum)
}
}

val modules = StringBuilder()
modules.append("Grouped by module").append(System.lineSeparator())
val maxModulePathLength = getMaxKeyLength(timesPerModule)
addHeader(modules, maxModulePathLength)
timesPerModule.entries.sortedBy { it.value }.reversed().forEach {
val modulePath = it.key
val time = it.value
addEntry(modules, if (modulePath.isBlank()) "<<root>>" else modulePath, maxModulePathLength, time, sum)

}

val tasks = StringBuilder()
tasks.append("Grouped by task").append(System.lineSeparator())
val maxTaskNameLength = getMaxKeyLength(timesPerTask)
addHeader(tasks, maxTaskNameLength)
timesPerTask.entries.sortedBy { it.value }.reversed().forEach {
val taskName = it.key
val time = it.value
addEntry(tasks, taskName, maxTaskNameLength, time, sum)
}

LOG.quiet(
"""
BUILD EXECUTION TIMES
=====================
Total: ${format(sum)}
${modules}
${tasks}
${allTasks}
"""
)
}


private fun addHeader(tasks: StringBuilder, maxTaskNameLength: Int): StringBuilder {
return tasks.append("-".repeat(maxTaskNameLength + MIN_GAP_BETWEEN_TEXT_AND_TIME + MAX_LENGTH_FOR_TIME_STRING))
.append(System.lineSeparator())
}

private fun addEntry(builder: StringBuilder, entry: String, maxEntryLength: Int, time: Long, sum: Long) {
val timeString = createTimeString(time, sum)
builder.append(entry)
.append(" ".repeat(Math.max(1, maxEntryLength + MIN_GAP_BETWEEN_TEXT_AND_TIME - entry.length)))
.append(" ".repeat(Math.max(1, MAX_LENGTH_FOR_TIME_STRING - timeString.length)))
.append(timeString).append(System.lineSeparator())
}

private fun createTimeString(time: Long, sum: Long): String {
return time.toString() + " ms" + " (" + (Math.round(time / sum.toDouble() * 100)).toString()
.padStart(3, ' ') + "%)"
}

private fun format(millis: Long): String {
return String.format(
"%dm %ds",
TimeUnit.MILLISECONDS.toMinutes(millis),
TimeUnit.MILLISECONDS.toSeconds(millis) -
TimeUnit.MINUTES.toSeconds(TimeUnit.MILLISECONDS.toMinutes(millis))
)
}

private fun getMaxKeyLength(map: Map<String, Long>): Int {
if (map.isEmpty()) {
return 0
} else {
return map.keys.toSortedSet(compareBy { it.length }).first().length
}
}

override fun settingsEvaluated(settings: Settings) {}
override fun projectsLoaded(gradle: Gradle) {}
override fun projectsEvaluated(gradle: Gradle) {}
}
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,7 @@ class AutoconfigureGradlePluginTest {

assertThat(noPluginAppliedOutput).doesNotContain(JavaConfigurePlugin::class.simpleName)
assertThat(javaModuleOutput).contains(JavaConfigurePlugin::class.simpleName)
assertThat(result.normalizedOutput).contains("BUILD EXECUTION TIMES")
}

companion object {
Expand Down

0 comments on commit 2436c8b

Please sign in to comment.