Incorrect execution times for tasks for tasks running in parralel

[dmitry-ryadnenko-izettle]

Hi.

It looks like this plugin measures times between moments of time when task executions end. Not real time it takes to run a task. There is no difference if all tasks are executed one after another, but there is difference if tasks are executed in parallel.

For example, let's say we have tasks A and B. They are executed in parallel. Task A takes 9 seconds to finish, task B takes 10 seconds to finish. Total build time will be 10S for the whole build. Then this plugin will show.

A | 9S | 
B | 1S | 

Expected.

A | 9S  | 
B | 10S | 

This issue makes build time measurements for individual tasks almost unusable in heavily modularized projects where lot of tasks are executed in parallel.

[asarkar]

The plugin should show what in your expected output, not the difference in time between the tasks (I can't imagine how'd that information be useful). If you're seeing something different, please attach a project that can be used to reproduce the issue.

[dmitry-ryadnenko-izettle]

Thank you for the quick response. It wasn't trivial to make a synthetic project that reproduces this but here we go.

MyApplication.zip

./gradlew a b

> Task :lib1:a
A finished

> Task :lib2:a
A finished

> Task :lib1:b
B finished

> Task :lib2:b
B finished
== Build time summary ==
:lib1:a | 4S | 33% | ████
:lib2:a | 1S |  8% | █
:lib1:b | 4S | 33% | ████
:lib2:b | 7S | 58% | ███████

BUILD SUCCESSFUL in 12s
4 actionable tasks: 4 executed

:lib2:a is supposed to be 5S.

Having just two tasks with the same run time which are executed in parallel won't reproduce this. The minimal example I managed to make is four tasks with different run times.

[dmitry-ryadnenko-izettle]

Having four tasks: lib1:a and lib2:a with the same duration and lib1:b and lib2:b with the same duration also won't reproduce this. It's important that the four tasks have different durations.

[asarkar]

@dmitry-ryadnenko-izettle Thanks for the sample app. Since it contains a lot of Android baggage unrelated to the problem at hand, I created a minimal, reproducible project. issue-27.zip

I've made a fix on branch issue-27. Please check out this branch locally and run ./gradlew publishToMavenLocal. Then either use the issue-27 project, or your own Android app with plugin version 3.1.0 to try out the fix; don't forget to configure pluginManagement in settings.gradle as done in the issue-27 project.

[asarkar]

@dmitry-ryadnenko-izettle I'll merge the PR and close this ticket this weekend. If you'd like to test first, please do so by then and provide feedback.

[dmitry-ryadnenko-izettle]

I've tried it locally. Works like a charm, thank you for this!

[dmitry-ryadnenko-izettle]

Another thing to consider is that after this is fixed there will be no way to calculate total build time for the build from the CSV data if we decide to upload that data to some cloud. Before the fix we could've just sum up all the build times for each task and it gave us a pretty correct number for the total build time. Now, when each task execution time is correct the total time I suppose will be much bigger than the real build time.

You can see how it was advised to calculate total build time in the previous version of the plugin in the report.Rmd file https://github.com/passy/build-time-tracker-plugin/blob/master/report.Rmd.

total <- ddply(df, .(date), summarise, milliseconds = sum(milliseconds))

Ain't gonna work no more. Some people may rely on this to work. And we also will need to find some other way to get total build time.

[asarkar]

The build time is tracked separately and not as a sum of all tasks, so there’s no reason for it to be wrong for the plugin when the percentages are calculated. As for yourself, every Gradle build shows the time taken at the end. It is not in the CSV, but it’s there.

[asarkar]

v3.0.1 (not 3.1.0) has been released.