Specs duration reported by Knapsack are always shorter than specs duration reported by RSpec
Extracted from https://gitlab.com/gitlab-org/gitlab-ce/issues/31465#note_28372282
That's probably because RSpec basically:
- Sets the start time when the suite starts: https://github.com/rspec/rspec-core/blob/d729301ca8c2fa61839562de9de570abce04ab7b/lib/rspec/core/reporter.rb#L87
- Compute the total time at the end: https://github.com/rspec/rspec-core/blob/d729301ca8c2fa61839562de9de570abce04ab7b/lib/rspec/core/reporter.rb#L198
So RSpec reports the wall-clock duration.
Knapsack, on the other hand compute each example's timing:
- Starts a time before each example: https://github.com/ArturT/knapsack/blob/567b12e481c43e85871a39afa7d8bf4836059ed8/lib/knapsack/adapters/rspec_adapter.rb#L17
- Stops the time after each example: https://github.com/ArturT/knapsack/blob/567b12e481c43e85871a39afa7d8bf4836059ed8/lib/knapsack/adapters/rspec_adapter.rb#L21
So Knapsack reports the sum of all the examples individual wall-clock time, which makes sense since it's goal is to balance examples between nodes.
In most cases the differences between the two duration reports is about 1 minute, which is ok, but in some cases, the difference is 8 minutes or even 17 minutes.
Part of the difference in timings can probably be explained by context setup (i.e. before(:context)
) duration and example switching duration (i.e. the time RSpec takes between the end of an example and the start of a new example, excluding the context setup duration).
The problem is, since Knapsack doesn't take in account the context setup duration (since it reports example durations only), it can happen that it reports a spec file to run in X seconds
while in reality it has a heavy context setup that runs in Y seconds
so the real duration of the file is more X + Y seconds
...
I'm not 100% sure of this theory at the moment, but I have the feeling this could explain why our specs are not balance perfectly...