From 161d8d1cea8059b837d7cfc05ec019d767168877 Mon Sep 17 00:00:00 2001 From: "nataliya.valtman" Date: Fri, 18 Nov 2022 12:31:23 +0100 Subject: [PATCH] KT-54959 Add worker execution time to task action execution time --- .../report/metrics/BuildMetricsReporter.kt | 1 + .../metrics/BuildMetricsReporterImpl.kt | 9 ++ .../report/metrics/BuildPerformanceMetric.kt | 51 +++++---- .../kotlin/build/report/metrics/BuildTime.kt | 108 +++++++++--------- .../kotlin/build/report/metrics/BuildTimes.kt | 2 - .../metrics/DoNothingBuildMetricsReporter.kt | 3 + .../GradleCompilerRunnerWithWorkers.kt | 2 + .../GradleKotlinCompilerRunner.kt | 2 + .../GradleKotlinCompilerWork.kt | 4 + .../gradle/report/BuildReportsService.kt | 12 +- .../report/PlainTextBuildReportWriter.kt | 4 +- .../kotlin/gradle/report/reportDataUtil.kt | 81 ++++++++++--- .../jetbrains/kotlin/gradle/tasks/Tasks.kt | 3 +- 13 files changed, 187 insertions(+), 95 deletions(-) diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporter.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporter.kt index 5c5142905f2..0034bccecc6 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporter.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporter.kt @@ -12,6 +12,7 @@ interface BuildMetricsReporter { fun addTimeMetricMs(time: BuildTime, durationMs: Long) = addTimeMetricNs(time, durationMs * 1_000_000) fun addMetric(metric: BuildPerformanceMetric, value: Long) + fun addTimeMetric(metric: BuildPerformanceMetric) fun addAttribute(attribute: BuildAttribute) diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporterImpl.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporterImpl.kt index f7f2dcf5276..5de3a45e37f 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporterImpl.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildMetricsReporterImpl.kt @@ -38,6 +38,15 @@ class BuildMetricsReporterImpl : BuildMetricsReporter, Serializable { myBuildMetrics.add(metric, value) } + override fun addTimeMetric(metric: BuildPerformanceMetric) { + when (metric.type) { + ValueType.NANOSECONDS -> myBuildMetrics.add(metric, System.nanoTime()) + ValueType.MILLISECONDS -> myBuildMetrics.add(metric, System.currentTimeMillis()) + else -> error("Unable to add time metric for '${metric.type}' type") + } + + } + override fun addAttribute(attribute: BuildAttribute) { myBuildAttributes.add(attribute) } diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildPerformanceMetric.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildPerformanceMetric.kt index 80ddbb935d3..d9f10713880 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildPerformanceMetric.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildPerformanceMetric.kt @@ -8,30 +8,37 @@ package org.jetbrains.kotlin.build.report.metrics import java.io.Serializable @Suppress("Reformat") -enum class BuildPerformanceMetric(val parent: BuildPerformanceMetric? = null, val readableString: String, val type: SizeMetricType) : Serializable { - CACHE_DIRECTORY_SIZE(readableString = "Total size of the cache directory", type = SizeMetricType.BYTES), - LOOKUP_SIZE(CACHE_DIRECTORY_SIZE, "Lookups size", type = SizeMetricType.BYTES), - SNAPSHOT_SIZE(CACHE_DIRECTORY_SIZE, "ABI snapshot size", type = SizeMetricType.BYTES), +enum class BuildPerformanceMetric(val parent: BuildPerformanceMetric? = null, val readableString: String, val type: ValueType) : Serializable { + CACHE_DIRECTORY_SIZE(readableString = "Total size of the cache directory", type = ValueType.BYTES), + LOOKUP_SIZE(CACHE_DIRECTORY_SIZE, "Lookups size", type = ValueType.BYTES), + SNAPSHOT_SIZE(CACHE_DIRECTORY_SIZE, "ABI snapshot size", type = ValueType.BYTES), - BUNDLE_SIZE(readableString = "Total size of the final bundle", type = SizeMetricType.BYTES), + BUNDLE_SIZE(readableString = "Total size of the final bundle", type = ValueType.BYTES), - COMPILE_ITERATION(parent = null, "Total compiler iteration", type = SizeMetricType.NUMBER), + COMPILE_ITERATION(parent = null, "Total compiler iteration", type = ValueType.NUMBER), // Metrics for the `kotlin.incremental.useClasspathSnapshot` feature - CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT(parent = null, "Number of times 'ClasspathEntrySnapshotTransform' ran", type = SizeMetricType.NUMBER), - JAR_CLASSPATH_ENTRY_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of jar classpath entry", type = SizeMetricType.BYTES), - JAR_CLASSPATH_ENTRY_SNAPSHOT_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of jar classpath entry's snapshot", type = SizeMetricType.BYTES), - DIRECTORY_CLASSPATH_ENTRY_SNAPSHOT_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of directory classpath entry's snapshot", type = SizeMetricType.BYTES), - COMPUTE_CLASSPATH_CHANGES_EXECUTION_COUNT(parent = null, "Number of times classpath changes are computed", type = SizeMetricType.NUMBER), - SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT(parent = null, "Number of times classpath snapshot is shrunk and saved after compilation", type = SizeMetricType.NUMBER), - CLASSPATH_ENTRY_COUNT(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of classpath entries", type = SizeMetricType.NUMBER), - CLASSPATH_SNAPSHOT_SIZE(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Size of classpath snapshot", type = SizeMetricType.BYTES), - SHRUNK_CLASSPATH_SNAPSHOT_SIZE(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Size of shrunk classpath snapshot", type = SizeMetricType.BYTES), - LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT(parent = null, "Number of times classpath snapshot is loaded", type = SizeMetricType.NUMBER), - LOAD_CLASSPATH_ENTRY_SNAPSHOT_CACHE_HITS(parent = LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of cache hits when loading classpath entry snapshots", type = SizeMetricType.NUMBER), - LOAD_CLASSPATH_ENTRY_SNAPSHOT_CACHE_MISSES(parent = LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of cache misses when loading classpath entry snapshots", type = SizeMetricType.NUMBER), - ; + CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT(parent = null, "Number of times 'ClasspathEntrySnapshotTransform' ran", type = ValueType.NUMBER), + JAR_CLASSPATH_ENTRY_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of jar classpath entry", type = ValueType.BYTES), + JAR_CLASSPATH_ENTRY_SNAPSHOT_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of jar classpath entry's snapshot", type = ValueType.BYTES), + DIRECTORY_CLASSPATH_ENTRY_SNAPSHOT_SIZE(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM_EXECUTION_COUNT, "Size of directory classpath entry's snapshot", type = ValueType.BYTES), + COMPUTE_CLASSPATH_CHANGES_EXECUTION_COUNT(parent = null, "Number of times classpath changes are computed", type = ValueType.NUMBER), + SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT(parent = null, "Number of times classpath snapshot is shrunk and saved after compilation", type = ValueType.NUMBER), + CLASSPATH_ENTRY_COUNT(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of classpath entries", type = ValueType.NUMBER), + CLASSPATH_SNAPSHOT_SIZE(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Size of classpath snapshot", type = ValueType.BYTES), + SHRUNK_CLASSPATH_SNAPSHOT_SIZE(parent = SHRINK_AND_SAVE_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Size of shrunk classpath snapshot", type = ValueType.BYTES), + LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT(parent = null, "Number of times classpath snapshot is loaded", type = ValueType.NUMBER), + LOAD_CLASSPATH_ENTRY_SNAPSHOT_CACHE_HITS(parent = LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of cache hits when loading classpath entry snapshots", type = ValueType.NUMBER), + LOAD_CLASSPATH_ENTRY_SNAPSHOT_CACHE_MISSES(parent = LOAD_CLASSPATH_SNAPSHOT_EXECUTION_COUNT, "Number of cache misses when loading classpath entry snapshots", type = ValueType.NUMBER), + //exact time + START_TASK_ACTION_EXECUTION(readableString = "Start time of task action", type = ValueType.MILLISECONDS), + CALL_KOTLIN_DAEMON(readableString = "Finish gradle part of task execution", type = ValueType.NANOSECONDS), + CALL_WORKER(readableString = "Worker submit time", type = ValueType.NANOSECONDS), + START_WORKER_EXECUTION(readableString = "Start time of werker execution", type = ValueType.NANOSECONDS), + START_KOTLIN_DAEMON_EXECUTION(readableString = "Start time of kotlin daemon task execution", type = ValueType.NANOSECONDS), + FINISH_KOTLIN_DAEMON_EXECUTION(readableString = "Finish kotlin daemon execution", type = ValueType.MILLISECONDS), + ; companion object { const val serialVersionUID = 0L @@ -41,7 +48,9 @@ enum class BuildPerformanceMetric(val parent: BuildPerformanceMetric? = null, va } } -enum class SizeMetricType { +enum class ValueType { BYTES, - NUMBER + NUMBER, + NANOSECONDS, + MILLISECONDS, } diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTime.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTime.kt index 8e712c85aec..13741d26024 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTime.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTime.kt @@ -10,58 +10,63 @@ import java.io.Serializable @Suppress("Reformat") enum class BuildTime(val parent: BuildTime? = null, val readableString: String) : Serializable { GRADLE_TASK(readableString = "Total Gradle task time"), + GRADLE_TASK_PREPARATION(readableString = "Spent time before task action"), GRADLE_TASK_ACTION(readableString = "Task action"), - CLEAR_OUTPUT(GRADLE_TASK_ACTION, "Clear output"), - BACKUP_OUTPUT(GRADLE_TASK_ACTION, "Backup output"), - RESTORE_OUTPUT_FROM_BACKUP(GRADLE_TASK_ACTION, "Restore output"), - CONNECT_TO_DAEMON(GRADLE_TASK_ACTION, "Connect to Kotlin daemon"), - CLEAR_JAR_CACHE(GRADLE_TASK_ACTION, "Clear jar cache"), - CALCULATE_OUTPUT_SIZE(GRADLE_TASK_ACTION, "Calculate output size"), - RUN_COMPILATION(GRADLE_TASK_ACTION, "Run compilation"), - NON_INCREMENTAL_COMPILATION_IN_PROCESS(RUN_COMPILATION, "Non incremental inprocess compilation"), - NON_INCREMENTAL_COMPILATION_OUT_OF_PROCESS(RUN_COMPILATION, "Non incremental out of process compilation"), - NON_INCREMENTAL_COMPILATION_DAEMON(RUN_COMPILATION, "Non incremental compilation in daemon"), - INCREMENTAL_COMPILATION_DAEMON(RUN_COMPILATION, "Incremental compilation in daemon"), - STORE_BUILD_INFO(INCREMENTAL_COMPILATION_DAEMON, "Store build info"), - JAR_SNAPSHOT(INCREMENTAL_COMPILATION_DAEMON, "ABI JAR Snapshot support"), - SET_UP_ABI_SNAPSHOTS(JAR_SNAPSHOT, "Set up ABI snapshot"), - IC_ANALYZE_JAR_FILES(JAR_SNAPSHOT, "Analyze jar files"), - IC_CALCULATE_INITIAL_DIRTY_SET(INCREMENTAL_COMPILATION_DAEMON, "Calculate initial dirty sources set"), //TODO - COMPUTE_CLASSPATH_CHANGES(IC_CALCULATE_INITIAL_DIRTY_SET, "Compute classpath changes"), - LOAD_CURRENT_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Load current classpath snapshot"), - REMOVE_DUPLICATE_CLASSES(LOAD_CURRENT_CLASSPATH_SNAPSHOT, "Remove duplicate classes"), - SHRINK_CURRENT_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Shrink current classpath snapshot"), - GET_LOOKUP_SYMBOLS(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Get lookup symbols"), - FIND_REFERENCED_CLASSES(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Find referenced classes"), - FIND_TRANSITIVELY_REFERENCED_CLASSES(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Find transitively referenced classes"), - LOAD_SHRUNK_PREVIOUS_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Load shrunk previous classpath snapshot"), - COMPUTE_CHANGED_AND_IMPACTED_SET(COMPUTE_CLASSPATH_CHANGES, "Compute changed and impacted set"), - COMPUTE_CLASS_CHANGES(COMPUTE_CHANGED_AND_IMPACTED_SET, "Compute class changes"), - COMPUTE_KOTLIN_CLASS_CHANGES(COMPUTE_CLASS_CHANGES, "Compute Kotlin class changes"), - COMPUTE_JAVA_CLASS_CHANGES(COMPUTE_CLASS_CHANGES, "Compute Java class changes"), - COMPUTE_IMPACTED_SET(COMPUTE_CHANGED_AND_IMPACTED_SET, "Compute impacted set"), - IC_ANALYZE_CHANGES_IN_DEPENDENCIES(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze dependency changes"), - IC_FIND_HISTORY_FILES(IC_ANALYZE_CHANGES_IN_DEPENDENCIES, "Find history files"), - IC_ANALYZE_HISTORY_FILES(IC_ANALYZE_CHANGES_IN_DEPENDENCIES, "Analyze history files"), - IC_ANALYZE_CHANGES_IN_JAVA_SOURCES(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze Java file changes"), - IC_ANALYZE_CHANGES_IN_ANDROID_LAYOUTS(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze Android layouts"), - IC_DETECT_REMOVED_CLASSES(IC_CALCULATE_INITIAL_DIRTY_SET, "Detect removed classes"), - CLEAR_OUTPUT_ON_REBUILD(INCREMENTAL_COMPILATION_DAEMON, "Clear outputs on rebuild"), - IC_UPDATE_CACHES(INCREMENTAL_COMPILATION_DAEMON, "Update caches"), - COMPILATION_ROUND(INCREMENTAL_COMPILATION_DAEMON, "Sources compilation round"), - IC_WRITE_HISTORY_FILE(INCREMENTAL_COMPILATION_DAEMON, "Write history file"), - SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION(INCREMENTAL_COMPILATION_DAEMON, "Shrink and save current classpath snapshot after compilation"), - INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Shrink current classpath snapshot incrementally"), - INCREMENTAL_LOAD_CURRENT_CLASSPATH_SNAPSHOT(INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load current classpath snapshot"), - INCREMENTAL_LOAD_SHRUNK_CURRENT_CLASSPATH_SNAPSHOT_AGAINST_PREVIOUS_LOOKUPS(INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load shrunk current classpath snapshot against previous lookups"), - NON_INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Shrink current classpath snapshot non-incrementally"), - NON_INCREMENTAL_LOAD_CURRENT_CLASSPATH_SNAPSHOT(NON_INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load current classpath snapshot"), - SAVE_SHRUNK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Save shrunk current classpath snapshot"), - COMPILER_PERFORMANCE(readableString = "Compiler time"), - COMPILER_INITIALIZATION(COMPILER_PERFORMANCE, "Compiler initialization time"), - CODE_ANALYSIS(COMPILER_PERFORMANCE, "Compiler code analysis"), - CODE_GENERATION(COMPILER_PERFORMANCE, "Compiler code generation"), - CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM(parent = null, "Classpath entry snapshot transform"), + OUT_OF_WORKER_TASK_ACTION(GRADLE_TASK_ACTION, "Task action before worker execution"), + BACKUP_OUTPUT(OUT_OF_WORKER_TASK_ACTION, "Backup output"), + RUN_WORKER_DELAY(readableString = "Start gradle worker"), + RUN_COMPILATION_IN_WORKER(GRADLE_TASK_ACTION, "Run compilation in Gradle worker"), + CLEAR_JAR_CACHE(RUN_COMPILATION_IN_WORKER, "Clear jar cache"), + CLEAR_OUTPUT(RUN_COMPILATION_IN_WORKER, "Clear output"), + RESTORE_OUTPUT_FROM_BACKUP(RUN_COMPILATION_IN_WORKER, "Restore output"), + CONNECT_TO_DAEMON(RUN_COMPILATION_IN_WORKER, "Connect to Kotlin daemon"), + CALCULATE_OUTPUT_SIZE(RUN_COMPILATION_IN_WORKER, "Calculate output size"), + RUN_COMPILATION(RUN_COMPILATION_IN_WORKER, "Run compilation"), + NON_INCREMENTAL_COMPILATION_IN_PROCESS(RUN_COMPILATION, "Non incremental inprocess compilation"), + NON_INCREMENTAL_COMPILATION_OUT_OF_PROCESS(RUN_COMPILATION, "Non incremental out of process compilation"), + NON_INCREMENTAL_COMPILATION_DAEMON(RUN_COMPILATION, "Non incremental compilation in daemon"), + INCREMENTAL_COMPILATION_DAEMON(RUN_COMPILATION, "Incremental compilation in daemon"), + STORE_BUILD_INFO(INCREMENTAL_COMPILATION_DAEMON, "Store build info"), + JAR_SNAPSHOT(INCREMENTAL_COMPILATION_DAEMON, "ABI JAR Snapshot support"), + SET_UP_ABI_SNAPSHOTS(JAR_SNAPSHOT, "Set up ABI snapshot"), + IC_ANALYZE_JAR_FILES(JAR_SNAPSHOT, "Analyze jar files"), + IC_CALCULATE_INITIAL_DIRTY_SET(INCREMENTAL_COMPILATION_DAEMON, "Calculate initial dirty sources set"), //TODO + COMPUTE_CLASSPATH_CHANGES(IC_CALCULATE_INITIAL_DIRTY_SET, "Compute classpath changes"), + LOAD_CURRENT_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Load current classpath snapshot"), + REMOVE_DUPLICATE_CLASSES(LOAD_CURRENT_CLASSPATH_SNAPSHOT, "Remove duplicate classes"), + SHRINK_CURRENT_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Shrink current classpath snapshot"), + GET_LOOKUP_SYMBOLS(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Get lookup symbols"), + FIND_REFERENCED_CLASSES(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Find referenced classes"), + FIND_TRANSITIVELY_REFERENCED_CLASSES(SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Find transitively referenced classes"), + LOAD_SHRUNK_PREVIOUS_CLASSPATH_SNAPSHOT(COMPUTE_CLASSPATH_CHANGES, "Load shrunk previous classpath snapshot"), + COMPUTE_CHANGED_AND_IMPACTED_SET(COMPUTE_CLASSPATH_CHANGES, "Compute changed and impacted set"), + COMPUTE_CLASS_CHANGES(COMPUTE_CHANGED_AND_IMPACTED_SET, "Compute class changes"), + COMPUTE_KOTLIN_CLASS_CHANGES(COMPUTE_CLASS_CHANGES, "Compute Kotlin class changes"), + COMPUTE_JAVA_CLASS_CHANGES(COMPUTE_CLASS_CHANGES, "Compute Java class changes"), + COMPUTE_IMPACTED_SET(COMPUTE_CHANGED_AND_IMPACTED_SET, "Compute impacted set"), + IC_ANALYZE_CHANGES_IN_DEPENDENCIES(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze dependency changes"), + IC_FIND_HISTORY_FILES(IC_ANALYZE_CHANGES_IN_DEPENDENCIES, "Find history files"), + IC_ANALYZE_HISTORY_FILES(IC_ANALYZE_CHANGES_IN_DEPENDENCIES, "Analyze history files"), + IC_ANALYZE_CHANGES_IN_JAVA_SOURCES(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze Java file changes"), + IC_ANALYZE_CHANGES_IN_ANDROID_LAYOUTS(IC_CALCULATE_INITIAL_DIRTY_SET, "Analyze Android layouts"), + IC_DETECT_REMOVED_CLASSES(IC_CALCULATE_INITIAL_DIRTY_SET, "Detect removed classes"), + CLEAR_OUTPUT_ON_REBUILD(INCREMENTAL_COMPILATION_DAEMON, "Clear outputs on rebuild"), + IC_UPDATE_CACHES(INCREMENTAL_COMPILATION_DAEMON, "Update caches"), + COMPILATION_ROUND(INCREMENTAL_COMPILATION_DAEMON, "Sources compilation round"), + COMPILER_PERFORMANCE(COMPILATION_ROUND, readableString = "Compiler time"), + COMPILER_INITIALIZATION(COMPILER_PERFORMANCE, "Compiler initialization time"), + CODE_ANALYSIS(COMPILER_PERFORMANCE, "Compiler code analysis"), + CODE_GENERATION(COMPILER_PERFORMANCE, "Compiler code generation"), + IC_WRITE_HISTORY_FILE(INCREMENTAL_COMPILATION_DAEMON, "Write history file"), + SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION(INCREMENTAL_COMPILATION_DAEMON, "Shrink and save current classpath snapshot after compilation"), + INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Shrink current classpath snapshot incrementally"), + INCREMENTAL_LOAD_CURRENT_CLASSPATH_SNAPSHOT(INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load current classpath snapshot"), + INCREMENTAL_LOAD_SHRUNK_CURRENT_CLASSPATH_SNAPSHOT_AGAINST_PREVIOUS_LOOKUPS(INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load shrunk current classpath snapshot against previous lookups"), + NON_INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Shrink current classpath snapshot non-incrementally"), + NON_INCREMENTAL_LOAD_CURRENT_CLASSPATH_SNAPSHOT(NON_INCREMENTAL_SHRINK_CURRENT_CLASSPATH_SNAPSHOT, "Load current classpath snapshot"), + SAVE_SHRUNK_CURRENT_CLASSPATH_SNAPSHOT(SHRINK_AND_SAVE_CURRENT_CLASSPATH_SNAPSHOT_AFTER_COMPILATION, "Save shrunk current classpath snapshot"), + TASK_FINISH_LISTENER_NOTIFICATION(readableString = "Task finish event notification"), + CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM(readableString = "Classpath entry snapshot transform"), LOAD_CLASSES(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM, "Load classes"), SNAPSHOT_CLASSES(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM, "Snapshot classes"), READ_CLASSES_BASIC_INFO(parent = SNAPSHOT_CLASSES, "Read basic information about classes"), @@ -69,6 +74,7 @@ enum class BuildTime(val parent: BuildTime? = null, val readableString: String) SNAPSHOT_KOTLIN_CLASSES(parent = SNAPSHOT_CLASSES, "Snapshot Kotlin classes"), SNAPSHOT_JAVA_CLASSES(parent = SNAPSHOT_CLASSES, "Snapshot Java classes"), SAVE_CLASSPATH_ENTRY_SNAPSHOT(parent = CLASSPATH_ENTRY_SNAPSHOT_TRANSFORM, "Save classpath entry snapshot"), + ; companion object { diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTimes.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTimes.kt index 5b5368d7808..f769e892fce 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTimes.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/BuildTimes.kt @@ -23,8 +23,6 @@ class BuildTimes : Serializable { fun addTimeMs(buildTime: BuildTime, timeMs: Long) = addTimeNs(buildTime, timeMs * 1_000_000) - fun asMapNs(): Map = buildTimesNs - fun asMapMs(): Map = buildTimesNs.mapValues { it.value / 1_000_000 } companion object { diff --git a/build-common/src/org/jetbrains/kotlin/build/report/metrics/DoNothingBuildMetricsReporter.kt b/build-common/src/org/jetbrains/kotlin/build/report/metrics/DoNothingBuildMetricsReporter.kt index 6764c1f0a9a..390be0d99e7 100644 --- a/build-common/src/org/jetbrains/kotlin/build/report/metrics/DoNothingBuildMetricsReporter.kt +++ b/build-common/src/org/jetbrains/kotlin/build/report/metrics/DoNothingBuildMetricsReporter.kt @@ -18,6 +18,9 @@ object DoNothingBuildMetricsReporter : BuildMetricsReporter { override fun addMetric(metric: BuildPerformanceMetric, value: Long) { } + override fun addTimeMetric(metric: BuildPerformanceMetric) { + } + override fun addAttribute(attribute: BuildAttribute) { } diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleCompilerRunnerWithWorkers.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleCompilerRunnerWithWorkers.kt index 0b20e4bf331..d007676be23 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleCompilerRunnerWithWorkers.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleCompilerRunnerWithWorkers.kt @@ -15,6 +15,7 @@ import org.gradle.workers.WorkParameters import org.gradle.workers.WorkQueue import org.gradle.workers.WorkerExecutor import org.jetbrains.kotlin.build.report.metrics.BuildMetricsReporter +import org.jetbrains.kotlin.build.report.metrics.BuildPerformanceMetric import org.jetbrains.kotlin.build.report.metrics.BuildTime import org.jetbrains.kotlin.build.report.metrics.measure import org.jetbrains.kotlin.gradle.tasks.* @@ -36,6 +37,7 @@ internal class GradleCompilerRunnerWithWorkers( taskOutputsBackup: TaskOutputsBackup? ): WorkQueue { + buildMetrics.addTimeMetric(BuildPerformanceMetric.CALL_WORKER) val workQueue = workerExecutor.noIsolation() workQueue.submit(GradleKotlinCompilerWorkAction::class.java) { params -> params.compilerWorkArguments.set(workArgs) diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerRunner.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerRunner.kt index f3977a854cd..b7abb85de61 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerRunner.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerRunner.kt @@ -12,6 +12,7 @@ import org.gradle.api.tasks.bundling.AbstractArchiveTask import org.gradle.jvm.tasks.Jar import org.gradle.workers.WorkQueue import org.jetbrains.kotlin.build.report.metrics.BuildMetricsReporter +import org.jetbrains.kotlin.build.report.metrics.BuildPerformanceMetric import org.jetbrains.kotlin.build.report.metrics.BuildTime import org.jetbrains.kotlin.build.report.metrics.measure import org.jetbrains.kotlin.cli.common.arguments.* @@ -220,6 +221,7 @@ internal open class GradleCompilerRunner( taskOutputsBackup: TaskOutputsBackup? ): WorkQueue? { try { + buildMetrics.addTimeMetric(BuildPerformanceMetric.CALL_WORKER) val kotlinCompilerRunnable = GradleKotlinCompilerWork(workArgs) kotlinCompilerRunnable.run() } catch (e: FailedCompilationException) { diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerWork.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerWork.kt index 4e18ecd8d31..ebf6466b6f8 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerWork.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/compilerRunner/GradleKotlinCompilerWork.kt @@ -124,6 +124,8 @@ internal class GradleKotlinCompilerWork @Inject constructor( get() = incrementalCompilationEnvironment != null override fun run() { + metrics.addTimeMetric(BuildPerformanceMetric.START_WORKER_EXECUTION) + metrics.startMeasure(BuildTime.RUN_COMPILATION_IN_WORKER) try { val gradlePrintingMessageCollector = GradlePrintingMessageCollector(log, allWarningsAsErrors) val gradleMessageCollector = GradleErrorMessageCollector(gradlePrintingMessageCollector, kotlinPluginVersion = kotlinPluginVersion) @@ -141,6 +143,7 @@ internal class GradleKotlinCompilerWork @Inject constructor( withAbiSnapshot = incrementalCompilationEnvironment?.withAbiSnapshot, withArtifactTransform = incrementalCompilationEnvironment?.classpathChanges is ClasspathChanges.ClasspathSnapshotEnabled ) + metrics.endMeasure(BuildTime.RUN_COMPILATION_IN_WORKER) val result = TaskExecutionResult(buildMetrics = metrics.getMetrics(), icLogLines = icLogLines, taskInfo = taskInfo) TaskExecutionResults[taskPath] = result } @@ -297,6 +300,7 @@ internal class GradleKotlinCompilerWork @Inject constructor( log.info("Options for KOTLIN DAEMON: $compilationOptions") val servicesFacade = GradleIncrementalCompilerServicesFacadeImpl(log, bufferingMessageCollector) val compilationResults = GradleCompilationResults(log, projectRootFile) + metrics.addTimeMetric(BuildPerformanceMetric.CALL_KOTLIN_DAEMON) return metrics.measure(BuildTime.RUN_COMPILATION) { daemon.compile(sessionId, compilerArgs, compilationOptions, servicesFacade, compilationResults) }.also { diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/BuildReportsService.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/BuildReportsService.kt index e0d07d968e4..31bbc1c9060 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/BuildReportsService.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/BuildReportsService.kt @@ -17,7 +17,7 @@ import org.gradle.api.services.BuildServiceParameters import org.gradle.tooling.events.FinishEvent import org.gradle.tooling.events.OperationCompletionListener import org.gradle.tooling.events.task.TaskFinishEvent -import org.jetbrains.kotlin.build.report.metrics.SizeMetricType +import org.jetbrains.kotlin.build.report.metrics.ValueType import org.jetbrains.kotlin.gradle.plugin.BuildEventsListenerRegistryHolder import org.jetbrains.kotlin.gradle.plugin.getKotlinPluginVersion import org.jetbrains.kotlin.gradle.plugin.stat.BuildFinishStatisticsData @@ -121,7 +121,7 @@ abstract class BuildReportsService : BuildService "${key.readableString}: ${value}ms" } //sometimes it is better to have separate variable to be able debug val perfData = data.performanceMetrics.map { (key, value) -> when (key.type) { - SizeMetricType.BYTES -> "${key.readableString}: ${formatSize(value)}" + ValueType.BYTES -> "${key.readableString}: ${formatSize(value)}" + ValueType.MILLISECONDS -> DATE_FORMATTER.format(value) else -> "${key.readableString}: $value}" } } timeData.union(perfData).joinTo(readableString, ",", "Performance: [", "]") - return splitStringIfNeed(readableString.toString(), lengthLimit) + return splitStringIfNeed(readableString.toString(), CUSTOM_VALUE_LENGTH_LIMIT) } private fun splitStringIfNeed(str: String, lengthLimit: Int): List { @@ -287,7 +288,8 @@ abstract class BuildReportsService : BuildService p.println("${sizeMetric.readableString}: ${formatSize(value)}") - SizeMetricType.NUMBER -> p.println("${sizeMetric.readableString}: $value") + ValueType.BYTES -> p.println("${sizeMetric.readableString}: ${formatSize(value)}") + ValueType.NUMBER -> p.println("${sizeMetric.readableString}: $value") } repeat(indentLevel) { p.popIndent() } } diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/reportDataUtil.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/reportDataUtil.kt index 193d5874b56..fe3a3354f61 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/reportDataUtil.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/report/reportDataUtil.kt @@ -9,7 +9,7 @@ import org.gradle.tooling.events.task.TaskFailureResult import org.gradle.tooling.events.task.TaskFinishEvent import org.gradle.tooling.events.task.TaskSkippedResult import org.gradle.tooling.events.task.TaskSuccessResult -import org.jetbrains.kotlin.build.report.metrics.BuildMetrics +import org.jetbrains.kotlin.build.report.metrics.* import org.jetbrains.kotlin.gradle.plugin.internal.state.TaskExecutionResults import org.jetbrains.kotlin.gradle.plugin.stat.CompileStatisticsData import org.jetbrains.kotlin.gradle.plugin.stat.StatTag @@ -18,6 +18,7 @@ import org.jetbrains.kotlin.incremental.ChangedFiles import org.jetbrains.kotlin.utils.addToStdlib.ifTrue import java.lang.management.ManagementFactory import java.util.ArrayList +import java.util.concurrent.TimeUnit private fun availableForStat(taskPath: String): Boolean { @@ -51,10 +52,13 @@ internal fun prepareData( if (!availableForStat(taskPath)) { return null } - val buildMetrics = buildOperationRecords.firstOrNull { it.path == taskPath }?.buildMetrics val taskExecutionResult = TaskExecutionResults[taskPath] - val buildTimesMs = buildMetrics?.buildTimes?.asMapMs()?.filterValues { value -> value != 0L } ?: emptyMap() - val perfData = buildMetrics?.buildPerformanceMetrics?.asMap()?.filterValues { value -> value != 0L } ?: emptyMap() + val buildMetrics = buildOperationRecords.firstOrNull { it.path == taskPath }?.buildMetrics + + val performanceMetrics = collectBuildPerformanceMetrics(taskExecutionResult, buildMetrics) + val buildTimesMetrics = collectBuildMetrics(taskExecutionResult, buildMetrics, performanceMetrics, result.startTime, System.currentTimeMillis()) + val buildAttributes = collectBuildAttributes(taskExecutionResult, buildMetrics) + val changes = when (val changedFiles = taskExecutionResult?.taskInfo?.changedFiles) { is ChangedFiles.Known -> changedFiles.modified.map { it.absolutePath } + changedFiles.removed.map { it.absolutePath } else -> emptyList() @@ -63,14 +67,13 @@ internal fun prepareData( durationMs = durationMs, taskResult = taskResult.name, label = label, - buildTimesMetrics = buildTimesMs, - performanceMetrics = perfData, + buildTimesMetrics = buildTimesMetrics, + performanceMetrics = performanceMetrics, projectName = projectName, taskName = taskPath, changes = changes, - tags = parseTags(taskExecutionResult, buildMetrics, additionalTags).map { it.name }, - nonIncrementalAttributes = buildMetrics?.buildAttributes?.asMap()?.filter { it.value > 0 }?.keys - ?: emptySet(), + tags = collectTags(taskExecutionResult, buildMetrics, additionalTags).map { it.name }, + nonIncrementalAttributes = collectBuildAttributes(taskExecutionResult, buildMetrics), hostName = BuildReportsService.hostName, kotlinVersion = kotlinVersion, buildUuid = uuid, @@ -79,9 +82,61 @@ internal fun prepareData( ) } -private fun parseTags(taskExecutionResult: TaskExecutionResult?, buildMetrics: BuildMetrics?, additionalTags: List): List { - val tags = parseTags(taskExecutionResult, additionalTags) - val nonIncrementalAttributes = buildMetrics?.buildAttributes?.asMap() ?: emptyMap() +private fun collectBuildAttributes(taskExecutionResult: TaskExecutionResult?, buildMetrics: BuildMetrics?): Set { + val attributes = HashSet() + buildMetrics?.buildAttributes?.asMap()?.filter { it.value > 0 }?.keys?.also { attributes.addAll(it) } + taskExecutionResult?.buildMetrics?.buildAttributes?.asMap()?.filter { it.value > 0 }?.keys?.also { attributes.addAll(it) } + return attributes +} + + +private fun collectBuildPerformanceMetrics( + taskExecutionResult: TaskExecutionResult?, + buildMetrics: BuildMetrics?, +): Map { + val taskBuildPerformanceMetrics = HashMap() + taskExecutionResult?.buildMetrics?.buildPerformanceMetrics?.asMap()?.let { taskBuildPerformanceMetrics.putAll(it) } + buildMetrics?.buildPerformanceMetrics?.asMap()?.let { taskBuildPerformanceMetrics.putAll(it) } + taskBuildPerformanceMetrics.filterValues { value -> value != 0L } + return taskBuildPerformanceMetrics +} +private fun collectBuildMetrics( + taskExecutionResult: TaskExecutionResult?, + buildMetrics: BuildMetrics?, + performanceMetrics: Map, + gradleTaskStartTime: Long? = null, + taskFinishEventTime: Long? = null, +): Map { + val taskBuildMetrics = HashMap() + taskExecutionResult?.buildMetrics?.buildTimes?.asMapMs()?.let { taskBuildMetrics.putAll(it) } + buildMetrics?.buildTimes?.asMapMs()?.let { taskBuildMetrics.putAll(it) } + gradleTaskStartTime?.let { startTime -> + performanceMetrics[BuildPerformanceMetric.START_TASK_ACTION_EXECUTION]?.let { actionStartTime -> + taskBuildMetrics.put(BuildTime.GRADLE_TASK_PREPARATION, actionStartTime - startTime) + } + } + taskFinishEventTime?.let { listenerNotificationTime -> + performanceMetrics[BuildPerformanceMetric.FINISH_KOTLIN_DAEMON_EXECUTION]?.let { daemonFinishTime -> + taskBuildMetrics.put(BuildTime.TASK_FINISH_LISTENER_NOTIFICATION, listenerNotificationTime - daemonFinishTime) + } + } + performanceMetrics[BuildPerformanceMetric.CALL_WORKER]?.let { callWorkerTime -> + performanceMetrics[BuildPerformanceMetric.START_WORKER_EXECUTION]?.let { startWorkerExecutionTime -> + taskBuildMetrics.put(BuildTime.RUN_WORKER_DELAY, TimeUnit.NANOSECONDS.toMillis(startWorkerExecutionTime - callWorkerTime)) + } + + } + taskBuildMetrics.filterValues { value -> value != 0L } + return taskBuildMetrics +} + +private fun collectTags( + taskExecutionResult: TaskExecutionResult?, + buildMetrics: BuildMetrics?, + additionalTags: List +): List { + val tags = collectTags(taskExecutionResult, additionalTags) + val nonIncrementalAttributes = collectBuildAttributes(taskExecutionResult, buildMetrics) if (nonIncrementalAttributes.isEmpty()) { tags.add(StatTag.INCREMENTAL) } else { @@ -90,7 +145,7 @@ private fun parseTags(taskExecutionResult: TaskExecutionResult?, buildMetrics: B return tags } -private fun parseTags( +private fun collectTags( taskExecutionResult: TaskExecutionResult?, additionalTags: List, ): MutableList{ diff --git a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/tasks/Tasks.kt b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/tasks/Tasks.kt index e6aa2e3619d..bdf2b6c23d9 100644 --- a/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/tasks/Tasks.kt +++ b/libraries/tools/kotlin-gradle-plugin/src/common/kotlin/org/jetbrains/kotlin/gradle/tasks/Tasks.kt @@ -388,7 +388,8 @@ abstract class AbstractKotlinCompile @Inject constr @TaskAction fun execute(inputChanges: InputChanges) { val buildMetrics = metrics.get() - buildMetrics.measure(BuildTime.GRADLE_TASK_ACTION) { + buildMetrics.addTimeMetric(BuildPerformanceMetric.START_TASK_ACTION_EXECUTION) + buildMetrics.measure(BuildTime.OUT_OF_WORKER_TASK_ACTION) { KotlinBuildStatsService.applyIfInitialised { if (name.contains("Test")) it.report(BooleanMetrics.TESTS_EXECUTED, true)