Severe slowdown in CI build when using SBT 2

Question
1

I’m cutting over Kinetic Merge to use SBT 2.x because Scala Steward is nagging me.

I’ve got to the point where both the local and Github CI builds pass, but the Github CI build has a catastrophic slowdown - it takes around 4.5 hours to complete compared to the relatively snappy 20 minutes or so for the mainline build to complete, using SBT 1.x.

These timings vary, but stay in the same ballpark - tens of minutes for SBT 1.x and several hours for SBT 2.x.

I tried a commit on the SBT 2.x branch that reverts to SBT 1.x but keeps as much of the other changes in build.sbt etc on that branch as possible to try to isolate what is causing the slowdown - now the build is back to sensible times again, seeing ~20 minutes when using 1.x.

I’ve tried reading the documentation and also giving Jules a whirl to see if it could brute-force its way to a solution, but to no avail.

The commit going back to SBT 1 from SBT 2 is minimal: Sbt 2 cutover by sageserpent-open · Pull Request #412 · sageserpent-open/kineticMerge · GitHub, the only big difference is the disabling of caching on a task definition whose task isn’t used in the CI build for the SBT 2.x version.

The local build times on my development machine don’t show this kind of slowdown, in fact SBT 2.x seems to be quicker, even when I’m running sbt testFull to ensure all tests are re-run.

The GitHub action uses ubuntu-latest, so I expect to have 16Gb of RAM available at a stretch. The tests do have memory spikes, but not that high.

One hopeful sign - Americium has also been cut over to use SBT 2.x, and that doesn’t exhibit the same slowdown in its CI build - and this uses a very similar build setup to Kinetic Merge, actually a little more complex as it does multiple builds for Scala 2.13/3. So perhaps there is just an odd test somewhere that pushes things over the edge?

​​I’m still digging away, but if this rings any bells, do share your ideas…

​

2

@eed3si9n Quick question for you while I flail around: does SBT 2 do anything to mock / substitute or adjust the system clock, or intercept calls to Instant.now? I ask because there is a passage in the Book of SBT (Caching - The Book of sbt):

As a mental model of the build as a pure function, build engineers sometimes use the term hermetic build, which is a build that takes place in a shipping container in a desert with no clocks or the Internet. If we can produce a JAR file from that state, then the JAR file should be safe to be shared by any machine. Why did I mention the clock? It’s because a JAR file could capture the timestamp, and thus produce slightly different JARs each time. To avoid this, hermetic build tools overwrite the timestamp to a fixed date 2010-01-01 regardless of when the build took place.

I have tests that run on a time budget, so perhaps they are being affected by this (if there is any such effect in the first place). I have also noticed some weirdness in the time increments used by progress reporters when tests are running in CI - negative increments - so I’d like to either include or eliminate this off the list of suspects.

3

I did make some progress, in that some of the property-based tests were writing to stdout with println or whatever rather than logging, as as the test cases number in the hundreds to thousands, this was severely overloading SBT 2 (SBT 1 is fine with this).

Removing these println etc resulted in a definite speedup, as long as some other tests were still disabled; those ones don’t output to stdout at all, but do generate a pile of logging entries.

Moving on to those other tests, I tried various experiments with disabling log buffering, forcing the SUT logging (as opposed to SBT itself) to just ERROR via Logback configuration and disabling caching.

I also replaced the timing strategy used by one of the remaining problem tests with a fixed count in case there was some influence by the hermetic build system.

None of these bring the test times anywhere near SBT 1, although disabling log buffering had a definite effect, bringing the test time down by roughly 50% overall - but don’t read too much into this, as the builds in question have some tests disabled still.

I did try

Test / outputStrategy := Some(
      OutputStrategy.CustomOutput(
        OutputStream.nullOutputStream
      )
    )

, as something of that ilk works for Americium, but this if anything makes it worse for the Kinetic Merge build.

Local builds work just fine with SBT 2, though.

Given that CI builds with the full test suite are taking from 5 to 6 hours (assuming they aren’t automatically cancelled by GitHub), it isn’t really practicable to continue with this.

1 Like
4

did you figure it out? my guess it’s because of this [2.x] build products shouldn't be moved around · Issue #9569 · sbt/sbt · GitHub

5

Unfortunately, no I didn’t - it still remains a mystery to me. :person_shrugging:

I haven’t looked in the last couple of weeks, but from what I recall, this severe slowdown was only a problem on GitHub CI builds; local ones on OS/X work fine.

Furthermore, Americium seems to build OK via SBT 2 for its GitHub CI build. Only Kinetic Merge seems to be affected. I did try to minimise / workaround the problem, but haven’t yet found a smoking gun or fix.

I’m currently holding off merging the SBT 2 cutover in both projects, and am waiting to see if anyone else experiences similar issues or has advice - I’m OK with SBT 1.x for the foreseeable future, this was only a case of diligently trying to keep up with the ecosystem changes; there are other things that need more attention right now.

Doubtless I’ll come back and revisit this once things have settled down…

1 Like