From 361d0d013fa3b054987e6d095243778dc10168e0 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Fri, 23 Dec 2022 13:55:03 -0600 Subject: [PATCH 01/18] Rename Build Caching Leverage to Performance Characteristics --- .../02-validate-local-build-caching-same-location.sh | 7 ++++--- .../03-validate-local-build-caching-different-locations.sh | 7 ++++--- .../gradle/04-validate-remote-build-caching-ci-ci.sh | 7 ++++--- .../gradle/05-validate-remote-build-caching-ci-local.sh | 7 ++++--- components/scripts/lib/info.sh | 2 +- .../maven/01-validate-local-build-caching-same-location.sh | 7 ++++--- .../02-validate-local-build-caching-different-locations.sh | 7 ++++--- .../maven/03-validate-remote-build-caching-ci-ci.sh | 7 ++++--- .../maven/04-validate-remote-build-caching-ci-local.sh | 7 ++++--- 9 files changed, 33 insertions(+), 25 deletions(-) diff --git a/components/scripts/gradle/02-validate-local-build-caching-same-location.sh b/components/scripts/gradle/02-validate-local-build-caching-same-location.sh index a331ce83..e436191e 100755 --- a/components/scripts/gradle/02-validate-local-build-caching-same-location.sh +++ b/components/scripts/gradle/02-validate-local-build-caching-same-location.sh @@ -352,9 +352,10 @@ EOF explain_build_cache_leverage() { local text IFS='' read -r -d '' text < Date: Fri, 23 Dec 2022 13:58:48 -0600 Subject: [PATCH 02/18] Update many function names to use performance characteristics --- .../02-validate-local-build-caching-same-location.sh | 8 ++++---- ...03-validate-local-build-caching-different-locations.sh | 8 ++++---- .../gradle/04-validate-remote-build-caching-ci-ci.sh | 2 +- .../gradle/05-validate-remote-build-caching-ci-local.sh | 2 +- components/scripts/lib/info.sh | 2 +- .../01-validate-local-build-caching-same-location.sh | 8 ++++---- ...02-validate-local-build-caching-different-locations.sh | 8 ++++---- .../maven/03-validate-remote-build-caching-ci-ci.sh | 2 +- .../maven/04-validate-remote-build-caching-ci-local.sh | 2 +- 9 files changed, 21 insertions(+), 21 deletions(-) diff --git a/components/scripts/gradle/02-validate-local-build-caching-same-location.sh b/components/scripts/gradle/02-validate-local-build-caching-same-location.sh index e436191e..bbdbe87a 100755 --- a/components/scripts/gradle/02-validate-local-build-caching-same-location.sh +++ b/components/scripts/gradle/02-validate-local-build-caching-same-location.sh @@ -167,7 +167,7 @@ fetch_build_cache_metrics() { # Overrides info.sh#print_performance_metrics print_performance_metrics() { - print_build_caching_leverage_metrics + print_performance_characteristics } print_quick_links() { @@ -313,7 +313,7 @@ two build scans that were published as part of running the experiment. The build scan of the second build is particularly interesting since this is where you can inspect what tasks were not leveraging the local build cache. -$(explain_build_cache_leverage) +$(explain_performance_characteristics) The ‘Investigation Quick Links’ section below allows quick navigation to the most relevant views in build scans to investigate what tasks were avoided due to @@ -335,7 +335,7 @@ The ‘Summary’ section below captures the configuration of the experiment. No build scans are available for inspection since publishing was disabled for the experiment. -$(explain_build_cache_leverage) +$(explain_performance_characteristics) $(explain_command_to_repeat_experiment) @@ -349,7 +349,7 @@ EOF print_wizard_text "${text}" } -explain_build_cache_leverage() { +explain_performance_characteristics() { local text IFS='' read -r -d '' text < Date: Fri, 23 Dec 2022 15:17:50 -0600 Subject: [PATCH 03/18] Return effective task execution time from API tool --- .../enterprise/api/client/GradleEnterpriseApiClient.java | 6 ++++-- .../enterprise/cli/FetchBuildValidationDataCommand.java | 3 ++- .../src/main/java/com/gradle/enterprise/cli/Fields.java | 1 + .../com/gradle/enterprise/model/BuildValidationData.java | 8 +++++++- 4 files changed, 14 insertions(+), 4 deletions(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java index ff452218..63fdbae0 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java @@ -115,7 +115,8 @@ public BuildValidationData fetchBuildValidationData(String buildScanId) { attributes.getRequestedTasks(), buildOutcomeFrom(attributes), remoteBuildCacheUrlFrom(buildCachePerformance), - summarizeTaskExecutions(buildCachePerformance) + summarizeTaskExecutions(buildCachePerformance), + buildCachePerformance.getEffectiveTaskExecutionTime() ); } if (build.getBuildToolType().equalsIgnoreCase("maven")) { @@ -132,7 +133,8 @@ public BuildValidationData fetchBuildValidationData(String buildScanId) { attributes.getRequestedGoals(), buildOutcomeFrom(attributes), remoteBuildCacheUrlFrom(buildCachePerformance), - summarizeTaskExecutions(buildCachePerformance) + summarizeTaskExecutions(buildCachePerformance), + buildCachePerformance.getEffectiveProjectExecutionTime() ); } throw new UnknownBuildAgentException(baseUrl, buildScanId, build.getBuildToolType()); diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java index a1c0991c..d38603c1 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java @@ -105,7 +105,8 @@ private BuildValidationData fetchBuildScanData(int index, URL buildScanUrl, Cust Collections.emptyList(), "", null, - Collections.emptyMap()); + Collections.emptyMap(), + null); } } diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java index 671d5ece..f7ca017f 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java @@ -30,6 +30,7 @@ public enum Fields { EXECUTED_CACHEABLE_DURATION("Executed cacheable duration", d -> totalDuration(d, "executed_cacheable")), EXECUTED_NOT_CACHEABLE("Executed not cacheable", d -> totalTasks(d, "executed_not_cacheable")), EXECUTED_NOT_CACHEABLE_DURATION("Executed not cacheable duration", d -> totalDuration(d, "executed_not_cacheable")), + EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> toStringSafely(d.getEffectiveTaskExecutionDuration())), ; public final String label; diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java index a269eb07..089e75e8 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java @@ -20,8 +20,9 @@ public class BuildValidationData { private final String buildOutcome; private final URL remoteBuildCacheUrl; private final Map tasksByAvoidanceOutcome; + private final Long effectiveTaskExecutionDuration; - public BuildValidationData(String rootProjectName, String buildScanId, URL gradleEnterpriseServerUrl, String gitUrl, String gitBranch, String gitCommitId, List requestedTasks, String buildOutcome, URL remoteBuildCacheUrl, Map tasksByAvoidanceOutcome) { + public BuildValidationData(String rootProjectName, String buildScanId, URL gradleEnterpriseServerUrl, String gitUrl, String gitBranch, String gitCommitId, List requestedTasks, String buildOutcome, URL remoteBuildCacheUrl, Map tasksByAvoidanceOutcome, Long effectiveTaskExecutionDuration) { this.rootProjectName = rootProjectName; this.buildScanId = buildScanId; this.gradleEnterpriseServerUrl = gradleEnterpriseServerUrl; @@ -32,6 +33,7 @@ public BuildValidationData(String rootProjectName, String buildScanId, URL gradl this.buildOutcome = buildOutcome; this.remoteBuildCacheUrl = remoteBuildCacheUrl; this.tasksByAvoidanceOutcome = tasksByAvoidanceOutcome; + this.effectiveTaskExecutionDuration = effectiveTaskExecutionDuration; } public String getRootProjectName() { @@ -124,4 +126,8 @@ private static boolean isFound(String value) { public Map getTasksByAvoidanceOutcome() { return tasksByAvoidanceOutcome; } + + public Long getEffectiveTaskExecutionDuration() { + return effectiveTaskExecutionDuration; + } } From 4a90d31d9368f5b6a1844569e898c639e72da425 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Fri, 23 Dec 2022 16:29:18 -0600 Subject: [PATCH 04/18] Print realized build time savings in results --- components/scripts/lib/build-scan-parse.sh | 10 +++++- components/scripts/lib/info.sh | 40 ++++++++++++++++++++++ 2 files changed, 49 insertions(+), 1 deletion(-) diff --git a/components/scripts/lib/build-scan-parse.sh b/components/scripts/lib/build-scan-parse.sh index fe04aa57..0852c661 100644 --- a/components/scripts/lib/build-scan-parse.sh +++ b/components/scripts/lib/build-scan-parse.sh @@ -25,6 +25,9 @@ executed_cacheable_duration=() executed_not_cacheable_num_tasks=() executed_not_cacheable_duration=() +# Build duration metrics +effective_task_execution_duration=() + parse_build_scan_csv() { # This isn't the most robust way to read a CSV, # but we control the CSV so we don't have to worry about various CSV edge cases @@ -42,7 +45,7 @@ parse_build_scan_csv() { idx=0 # shellcheck disable=SC2034 # not all scripts use all of the fetched data - while IFS=, read -r field_1 field_2 field_3 field_4 field_5 field_6 field_7 field_8 field_9 field_10 field_11 field_12 field_13 field_14 field_15 field_16 field_17 field_18 field_19; do + while IFS=, read -r field_1 field_2 field_3 field_4 field_5 field_6 field_7 field_8 field_9 field_10 field_11 field_12 field_13 field_14 field_15 field_16 field_17 field_18 field_19 field_20; do if [[ "$header_row_read" == "false" ]]; then header_row_read=true continue; @@ -73,6 +76,11 @@ parse_build_scan_csv() { executed_not_cacheable_num_tasks[idx]="${field_18}" executed_not_cacheable_duration[idx]="${field_19}" + # todo conditional until build-scan-support-tool supports this field + if [[ -n "$field_20" ]]; then + effective_task_execution_duration[idx]="${field_20}" + fi + ((idx++)) done <<< "${build_scan_csv}" } diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 84527fcf..949db0e9 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -142,6 +142,26 @@ print_performance_characteristics() { info "Performance Characteristics" info "----------------------" + print_realized_build_time_savings + + print_build_caching_leverage_metrics + + print_executed_cacheable_tasks_warning +} + +print_realized_build_time_savings() { + local value + value="" + if [[ -n "${effective_task_execution_duration[0]}" && -n "${effective_task_execution_duration[1]}" ]]; then + first_build=$(format_duration "${effective_task_execution_duration[0]}") + second_build=$(format_duration "${effective_task_execution_duration[1]}") + difference=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) + value="From ${first_build} to ${second_build}, saving ${difference} of wall-clock time" + fi + summary_row "Realized build time savings:" "${value}" +} + +print_build_caching_leverage_metrics() { local task_count_padding task_count_padding=$(max_length "${avoided_from_cache_num_tasks[1]}" "${executed_cacheable_num_tasks[1]}" "${executed_not_cacheable_num_tasks[1]}") @@ -173,7 +193,9 @@ print_performance_characteristics() { value="${taskCount} ${BUILD_TOOL_TASK}s, ${executed_not_cacheable_duration[1]} total execution time" fi summary_row "Executed non-cacheable ${BUILD_TOOL_TASK}s:" "${value}" +} +print_executed_cacheable_tasks_warning() { if (( executed_cacheable_num_tasks[1] > 0)); then print_bl warn "Not all cacheable ${BUILD_TOOL_TASK}s' outputs were taken from the build cache in the second build. This reduces the savings in ${BUILD_TOOL_TASK} execution time." @@ -230,3 +252,21 @@ create_receipt_file() { echo "Generated by $(print_version)" } > "${RECEIPT_FILE}" } + +format_duration() { + local duration=$1 + local hours=$((duration/60/60/1000)) + local minutes=$((duration/60/1000%60)) + local seconds=$((duration/1000%60%60)) + local millis=$((duration%1000)) + + if [[ "${hours}" != 0 ]]; then + printf "%dh " "${hours}" + fi + + if [[ "${minutes}" != 0 ]]; then + printf "%dm " "${minutes}" + fi + + printf "%d.%03ds" "${seconds}" "${millis}" +} From 08843d9ed56151abb0649e4deb47b789833dd47a Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 08:37:42 -0600 Subject: [PATCH 05/18] Print performance characteristics header in separate function --- components/scripts/lib/info.sh | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 949db0e9..955a1d2e 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -138,9 +138,7 @@ print_performance_metrics() { } print_performance_characteristics() { - print_bl - info "Performance Characteristics" - info "----------------------" + print_performance_characteristics_header print_realized_build_time_savings @@ -149,6 +147,12 @@ print_performance_characteristics() { print_executed_cacheable_tasks_warning } +print_performance_characteristics_header() { + print_bl + info "Performance Characteristics" + info "----------------------" +} + print_realized_build_time_savings() { local value value="" From 056fafb952cfa4085ff4b046ef599df73f72e147 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 08:43:01 -0600 Subject: [PATCH 06/18] Change printed format of realized build time savings --- components/scripts/lib/info.sh | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 955a1d2e..20f9d2ce 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -157,10 +157,11 @@ print_realized_build_time_savings() { local value value="" if [[ -n "${effective_task_execution_duration[0]}" && -n "${effective_task_execution_duration[1]}" ]]; then - first_build=$(format_duration "${effective_task_execution_duration[0]}") - second_build=$(format_duration "${effective_task_execution_duration[1]}") - difference=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) - value="From ${first_build} to ${second_build}, saving ${difference} of wall-clock time" + local first_build_effective_duration second_build_effective_duration realized_savings + first_build_effective_duration=$(format_duration "${effective_task_execution_duration[0]}") + second_build_effective_duration=$(format_duration "${effective_task_execution_duration[1]}") + realized_savings=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) + value="${realized_savings} wall-clock time (from ${first_build_effective_duration} to ${second_build_effective_duration})" fi summary_row "Realized build time savings:" "${value}" } From 1897984857daa665c7f89ee413e2d1577dcb274f Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 09:45:05 -0600 Subject: [PATCH 07/18] Make static variable final --- .../java/com/gradle/enterprise/model/BuildValidationData.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java index 089e75e8..39f465b2 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java @@ -8,7 +8,7 @@ import java.util.regex.Pattern; public class BuildValidationData { - private static Pattern REMOTE_BUILD_CACHE_SHARD_PATTERN = Pattern.compile(".*/cache/(.+)$"); + private static final Pattern REMOTE_BUILD_CACHE_SHARD_PATTERN = Pattern.compile(".*/cache/(.+)$"); private final String rootProjectName; private final String buildScanId; From c49a38a02452de9a4efc527c3e148ee658236a7a Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 09:51:42 -0600 Subject: [PATCH 08/18] Change data type of effectiveTaskExecutionDuration to Duration --- .../api/client/GradleEnterpriseApiClient.java | 4 ++-- .../cli/FetchBuildValidationDataCommand.java | 3 ++- .../com/gradle/enterprise/cli/Fields.java | 2 +- .../enterprise/model/BuildValidationData.java | 22 +++++++++++++++---- 4 files changed, 23 insertions(+), 8 deletions(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java index 63fdbae0..4aed4471 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/api/client/GradleEnterpriseApiClient.java @@ -116,7 +116,7 @@ public BuildValidationData fetchBuildValidationData(String buildScanId) { buildOutcomeFrom(attributes), remoteBuildCacheUrlFrom(buildCachePerformance), summarizeTaskExecutions(buildCachePerformance), - buildCachePerformance.getEffectiveTaskExecutionTime() + toDuration(buildCachePerformance.getEffectiveTaskExecutionTime()) ); } if (build.getBuildToolType().equalsIgnoreCase("maven")) { @@ -134,7 +134,7 @@ public BuildValidationData fetchBuildValidationData(String buildScanId) { buildOutcomeFrom(attributes), remoteBuildCacheUrlFrom(buildCachePerformance), summarizeTaskExecutions(buildCachePerformance), - buildCachePerformance.getEffectiveProjectExecutionTime() + toDuration(buildCachePerformance.getEffectiveProjectExecutionTime()) ); } throw new UnknownBuildAgentException(baseUrl, buildScanId, build.getBuildToolType()); diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java index d38603c1..f1818dde 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/FetchBuildValidationDataCommand.java @@ -14,6 +14,7 @@ import java.net.MalformedURLException; import java.net.URL; import java.nio.file.Path; +import java.time.Duration; import java.util.ArrayList; import java.util.Collections; import java.util.List; @@ -106,7 +107,7 @@ private BuildValidationData fetchBuildScanData(int index, URL buildScanUrl, Cust "", null, Collections.emptyMap(), - null); + Duration.ZERO); } } diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java index f7ca017f..3f8ce5f3 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java @@ -30,7 +30,7 @@ public enum Fields { EXECUTED_CACHEABLE_DURATION("Executed cacheable duration", d -> totalDuration(d, "executed_cacheable")), EXECUTED_NOT_CACHEABLE("Executed not cacheable", d -> totalTasks(d, "executed_not_cacheable")), EXECUTED_NOT_CACHEABLE_DURATION("Executed not cacheable duration", d -> totalDuration(d, "executed_not_cacheable")), - EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> toStringSafely(d.getEffectiveTaskExecutionDuration())), + EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> String.valueOf(d.getEffectiveTaskExecutionDuration().toMillis())), ; public final String label; diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java index 39f465b2..fd706175 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java @@ -1,7 +1,9 @@ package com.gradle.enterprise.model; +import javax.annotation.Nonnull; import java.net.MalformedURLException; import java.net.URL; +import java.time.Duration; import java.util.List; import java.util.Map; import java.util.regex.Matcher; @@ -20,9 +22,20 @@ public class BuildValidationData { private final String buildOutcome; private final URL remoteBuildCacheUrl; private final Map tasksByAvoidanceOutcome; - private final Long effectiveTaskExecutionDuration; - - public BuildValidationData(String rootProjectName, String buildScanId, URL gradleEnterpriseServerUrl, String gitUrl, String gitBranch, String gitCommitId, List requestedTasks, String buildOutcome, URL remoteBuildCacheUrl, Map tasksByAvoidanceOutcome, Long effectiveTaskExecutionDuration) { + @Nonnull private final Duration effectiveTaskExecutionDuration; + + public BuildValidationData( + String rootProjectName, + String buildScanId, + URL gradleEnterpriseServerUrl, + String gitUrl, + String gitBranch, + String gitCommitId, + List requestedTasks, + String buildOutcome, + URL remoteBuildCacheUrl, + Map tasksByAvoidanceOutcome, + @Nonnull Duration effectiveTaskExecutionDuration) { this.rootProjectName = rootProjectName; this.buildScanId = buildScanId; this.gradleEnterpriseServerUrl = gradleEnterpriseServerUrl; @@ -127,7 +140,8 @@ public Map getTasksByAvoidanceOutcome() { return tasksByAvoidanceOutcome; } - public Long getEffectiveTaskExecutionDuration() { + @Nonnull + public Duration getEffectiveTaskExecutionDuration() { return effectiveTaskExecutionDuration; } } From 30bced9c9aa052e37bedfee9e0dc5ba49cbf5912 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:04:53 -0600 Subject: [PATCH 09/18] Return all durations as milliseconds --- .../java/com/gradle/enterprise/cli/Fields.java | 18 ++---------------- 1 file changed, 2 insertions(+), 16 deletions(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java index 3f8ce5f3..60df975e 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java @@ -5,7 +5,6 @@ import java.time.Duration; import java.util.Arrays; -import java.util.Locale; import java.util.function.Function; import java.util.stream.Stream; @@ -30,7 +29,7 @@ public enum Fields { EXECUTED_CACHEABLE_DURATION("Executed cacheable duration", d -> totalDuration(d, "executed_cacheable")), EXECUTED_NOT_CACHEABLE("Executed not cacheable", d -> totalTasks(d, "executed_not_cacheable")), EXECUTED_NOT_CACHEABLE_DURATION("Executed not cacheable duration", d -> totalDuration(d, "executed_not_cacheable")), - EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> String.valueOf(d.getEffectiveTaskExecutionDuration().toMillis())), + EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> formatDuration(d.getEffectiveTaskExecutionDuration())), ; public final String label; @@ -76,19 +75,6 @@ private static String totalDuration(BuildValidationData data, String avoidanceOu } private static String formatDuration(Duration duration) { - long hours = duration.toHours(); - long minutes = duration.minusHours(hours).toMinutes(); - double seconds = duration.minusHours(hours).minusMinutes(minutes).toMillis() / 1000d; - - StringBuilder s = new StringBuilder(); - if (hours != 0) { - s.append(hours + "h "); - } - if (minutes != 0) { - s.append(minutes + "m "); - } - s.append(String.format(Locale.ROOT, "%.3fs", seconds)); - - return s.toString().trim(); + return String.valueOf(duration.toMillis()); } } From 83dca39a2d33f8d4e945ceb4f7aa34ac16494dad Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:20:00 -0600 Subject: [PATCH 10/18] Format caching leverage metrics as durations --- components/scripts/lib/info.sh | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 20f9d2ce..f76c1df5 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -175,7 +175,7 @@ print_build_caching_leverage_metrics() { if [[ "${avoided_from_cache_num_tasks[1]}" ]]; then local taskCount taskCount="$(printf "%${task_count_padding}s" "${avoided_from_cache_num_tasks[1]}" )" - value="${taskCount} ${BUILD_TOOL_TASK}s, ${avoided_from_cache_avoidance_savings[1]} total saved execution time" + value="${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration avoided_from_cache_avoidance_savings[1]) total saved execution time" fi summary_row "Avoided cacheable ${BUILD_TOOL_TASK}s:" "${value}" @@ -188,14 +188,14 @@ print_build_caching_leverage_metrics() { fi taskCount="$(printf "%${task_count_padding}s" "${executed_cacheable_num_tasks[1]}" )" - value="${summary_color}${taskCount} ${BUILD_TOOL_TASK}s, ${executed_cacheable_duration[1]} total execution time${RESTORE}" + value="${summary_color}${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration executed_cacheable_duration[1]) total execution time${RESTORE}" fi summary_row "Executed cacheable ${BUILD_TOOL_TASK}s:" "${value}" value="" if [[ "${executed_not_cacheable_num_tasks[1]}" ]]; then taskCount="$(printf "%${task_count_padding}s" "${executed_not_cacheable_num_tasks[1]}" )" - value="${taskCount} ${BUILD_TOOL_TASK}s, ${executed_not_cacheable_duration[1]} total execution time" + value="${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration executed_not_cacheable_duration[1]) total execution time" fi summary_row "Executed non-cacheable ${BUILD_TOOL_TASK}s:" "${value}" } From 8786e84f915dc7031902dfc64ef0ecc77f5b718e Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:21:57 -0600 Subject: [PATCH 11/18] Remove nullability annotations --- .../com/gradle/enterprise/model/BuildValidationData.java | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java index fd706175..ebcd51a9 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/model/BuildValidationData.java @@ -1,6 +1,5 @@ package com.gradle.enterprise.model; -import javax.annotation.Nonnull; import java.net.MalformedURLException; import java.net.URL; import java.time.Duration; @@ -22,7 +21,7 @@ public class BuildValidationData { private final String buildOutcome; private final URL remoteBuildCacheUrl; private final Map tasksByAvoidanceOutcome; - @Nonnull private final Duration effectiveTaskExecutionDuration; + private final Duration effectiveTaskExecutionDuration; public BuildValidationData( String rootProjectName, @@ -35,7 +34,7 @@ public BuildValidationData( String buildOutcome, URL remoteBuildCacheUrl, Map tasksByAvoidanceOutcome, - @Nonnull Duration effectiveTaskExecutionDuration) { + Duration effectiveTaskExecutionDuration) { this.rootProjectName = rootProjectName; this.buildScanId = buildScanId; this.gradleEnterpriseServerUrl = gradleEnterpriseServerUrl; @@ -140,7 +139,6 @@ public Map getTasksByAvoidanceOutcome() { return tasksByAvoidanceOutcome; } - @Nonnull public Duration getEffectiveTaskExecutionDuration() { return effectiveTaskExecutionDuration; } From 2a0fcff84c8085126dc7db48c039bc8c66e79531 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:25:38 -0600 Subject: [PATCH 12/18] Change comment wording --- components/scripts/lib/build-scan-parse.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/components/scripts/lib/build-scan-parse.sh b/components/scripts/lib/build-scan-parse.sh index 0852c661..10b63cd2 100644 --- a/components/scripts/lib/build-scan-parse.sh +++ b/components/scripts/lib/build-scan-parse.sh @@ -76,7 +76,7 @@ parse_build_scan_csv() { executed_not_cacheable_num_tasks[idx]="${field_18}" executed_not_cacheable_duration[idx]="${field_19}" - # todo conditional until build-scan-support-tool supports this field + # Conditional because build-scan-support-tool does not yet support this field if [[ -n "$field_20" ]]; then effective_task_execution_duration[idx]="${field_20}" fi From 9bfabd1c3aade22de0444b68c51d641135012f06 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:32:00 -0600 Subject: [PATCH 13/18] Shorten variable names --- components/scripts/lib/info.sh | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index f76c1df5..b464a081 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -157,11 +157,11 @@ print_realized_build_time_savings() { local value value="" if [[ -n "${effective_task_execution_duration[0]}" && -n "${effective_task_execution_duration[1]}" ]]; then - local first_build_effective_duration second_build_effective_duration realized_savings - first_build_effective_duration=$(format_duration "${effective_task_execution_duration[0]}") - second_build_effective_duration=$(format_duration "${effective_task_execution_duration[1]}") + local first_build second_build realized_savings + first_build=$(format_duration "${effective_task_execution_duration[0]}") + second_build=$(format_duration "${effective_task_execution_duration[1]}") realized_savings=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) - value="${realized_savings} wall-clock time (from ${first_build_effective_duration} to ${second_build_effective_duration})" + value="${realized_savings} wall-clock time (from ${first_build} to ${second_build})" fi summary_row "Realized build time savings:" "${value}" } From c4c8ad141765c34b6141cce415e7dec49ebfdf7d Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:36:47 -0600 Subject: [PATCH 14/18] Update changes.md --- release/changes.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/release/changes.md b/release/changes.md index bddc62d8..470100fe 100644 --- a/release/changes.md +++ b/release/changes.md @@ -1 +1 @@ -- [NEW] TBD +- [NEW] Include realized build time savings in experiment summary From 713c5bec17fa7fcdb6cb942e0fd49fd08f8a1bfb Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:42:14 -0600 Subject: [PATCH 15/18] Revert "Format caching leverage metrics as durations" This reverts commit 774b1780fc995776e603448090f6c858b14e63dd. --- components/scripts/lib/info.sh | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index b464a081..34ca4970 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -175,7 +175,7 @@ print_build_caching_leverage_metrics() { if [[ "${avoided_from_cache_num_tasks[1]}" ]]; then local taskCount taskCount="$(printf "%${task_count_padding}s" "${avoided_from_cache_num_tasks[1]}" )" - value="${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration avoided_from_cache_avoidance_savings[1]) total saved execution time" + value="${taskCount} ${BUILD_TOOL_TASK}s, ${avoided_from_cache_avoidance_savings[1]} total saved execution time" fi summary_row "Avoided cacheable ${BUILD_TOOL_TASK}s:" "${value}" @@ -188,14 +188,14 @@ print_build_caching_leverage_metrics() { fi taskCount="$(printf "%${task_count_padding}s" "${executed_cacheable_num_tasks[1]}" )" - value="${summary_color}${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration executed_cacheable_duration[1]) total execution time${RESTORE}" + value="${summary_color}${taskCount} ${BUILD_TOOL_TASK}s, ${executed_cacheable_duration[1]} total execution time${RESTORE}" fi summary_row "Executed cacheable ${BUILD_TOOL_TASK}s:" "${value}" value="" if [[ "${executed_not_cacheable_num_tasks[1]}" ]]; then taskCount="$(printf "%${task_count_padding}s" "${executed_not_cacheable_num_tasks[1]}" )" - value="${taskCount} ${BUILD_TOOL_TASK}s, $(format_duration executed_not_cacheable_duration[1]) total execution time" + value="${taskCount} ${BUILD_TOOL_TASK}s, ${executed_not_cacheable_duration[1]} total execution time" fi summary_row "Executed non-cacheable ${BUILD_TOOL_TASK}s:" "${value}" } From 6b663fdb1522fc67cd3fcfb9e87946764b3dd5b6 Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:42:14 -0600 Subject: [PATCH 16/18] Revert "Return all durations as milliseconds" This reverts commit 7bead5112ec4d02dbac07ea73edfdaa50ec8f507. --- .../java/com/gradle/enterprise/cli/Fields.java | 18 ++++++++++++++++-- 1 file changed, 16 insertions(+), 2 deletions(-) diff --git a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java index 60df975e..3f8ce5f3 100644 --- a/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java +++ b/components/fetch-build-scan-data-cmdline-tool/src/main/java/com/gradle/enterprise/cli/Fields.java @@ -5,6 +5,7 @@ import java.time.Duration; import java.util.Arrays; +import java.util.Locale; import java.util.function.Function; import java.util.stream.Stream; @@ -29,7 +30,7 @@ public enum Fields { EXECUTED_CACHEABLE_DURATION("Executed cacheable duration", d -> totalDuration(d, "executed_cacheable")), EXECUTED_NOT_CACHEABLE("Executed not cacheable", d -> totalTasks(d, "executed_not_cacheable")), EXECUTED_NOT_CACHEABLE_DURATION("Executed not cacheable duration", d -> totalDuration(d, "executed_not_cacheable")), - EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> formatDuration(d.getEffectiveTaskExecutionDuration())), + EFFECTIVE_TASK_EXECUTION_DURATION("Effective task execution duration", d -> String.valueOf(d.getEffectiveTaskExecutionDuration().toMillis())), ; public final String label; @@ -75,6 +76,19 @@ private static String totalDuration(BuildValidationData data, String avoidanceOu } private static String formatDuration(Duration duration) { - return String.valueOf(duration.toMillis()); + long hours = duration.toHours(); + long minutes = duration.minusHours(hours).toMinutes(); + double seconds = duration.minusHours(hours).minusMinutes(minutes).toMillis() / 1000d; + + StringBuilder s = new StringBuilder(); + if (hours != 0) { + s.append(hours + "h "); + } + if (minutes != 0) { + s.append(minutes + "m "); + } + s.append(String.format(Locale.ROOT, "%.3fs", seconds)); + + return s.toString().trim(); } } From c1d8a1a46b4da621797c5f142c13c060456ea4cc Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Wed, 28 Dec 2022 10:59:11 -0600 Subject: [PATCH 17/18] Only print realized build time savings when effective task execution durations exist --- components/scripts/lib/info.sh | 22 ++++++++++++++-------- 1 file changed, 14 insertions(+), 8 deletions(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 34ca4970..58922398 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -154,16 +154,22 @@ print_performance_characteristics_header() { } print_realized_build_time_savings() { - local value - value="" + # Do not print realized build time savings at all if these values do not exist + # This can happen since build-scan-support-tool does not yet support these fields if [[ -n "${effective_task_execution_duration[0]}" && -n "${effective_task_execution_duration[1]}" ]]; then - local first_build second_build realized_savings - first_build=$(format_duration "${effective_task_execution_duration[0]}") - second_build=$(format_duration "${effective_task_execution_duration[1]}") - realized_savings=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) - value="${realized_savings} wall-clock time (from ${first_build} to ${second_build})" + local value + value="" + # Only calculate realized build time savings when these values are non-zero + # These values can be returned as zero when an error occurs processing the Build Scan data + if [[ "${effective_task_execution_duration[0]}" && "${effective_task_execution_duration[1]}" ]]; then + local first_build second_build realized_savings + first_build=$(format_duration "${effective_task_execution_duration[0]}") + second_build=$(format_duration "${effective_task_execution_duration[1]}") + realized_savings=$(format_duration effective_task_execution_duration[0]-effective_task_execution_duration[1]) + value="${realized_savings} wall-clock time (from ${first_build} to ${second_build})" + fi + summary_row "Realized build time savings:" "${value}" fi - summary_row "Realized build time savings:" "${value}" } print_build_caching_leverage_metrics() { From 2933aed2470125296c6a28ddb736e4f405fa612c Mon Sep 17 00:00:00 2001 From: Eric Haag Date: Mon, 6 Mar 2023 10:45:37 -0500 Subject: [PATCH 18/18] Increase number of dashes below Performance Characteristics --- components/scripts/lib/info.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/components/scripts/lib/info.sh b/components/scripts/lib/info.sh index 58922398..b1da332e 100644 --- a/components/scripts/lib/info.sh +++ b/components/scripts/lib/info.sh @@ -150,7 +150,7 @@ print_performance_characteristics() { print_performance_characteristics_header() { print_bl info "Performance Characteristics" - info "----------------------" + info "---------------------------" } print_realized_build_time_savings() {