wasyl
09/08/2020, 10:30 AMwasyl
09/08/2020, 10:30 AMwasyl
09/08/2020, 10:39 AMsam
09/08/2020, 5:05 PMsam
09/08/2020, 5:05 PMwasyl
09/09/2020, 6:46 AM./gradlew someProject:test
wasyl
09/09/2020, 10:38 AMwasyl
09/09/2020, 10:38 AMtestFinished
listener, figuring out failures:wasyl
09/09/2020, 10:39 AMdescribe
blocks side by sidewasyl
09/09/2020, 10:40 AMbigDataClass.toString()
because now with forAll
we still need to differentiate nested nested tests and it’s the easiest way)wasyl
09/09/2020, 10:51 AM./gradle someModule:test --tests "that.test.class"
) but still takes 30 seconds when running all tests in module (before optimizing it took 60 seconds, so still a win)wasyl
09/09/2020, 10:55 AMisAnscestorOf
is a massive hot stop and it’s relatively inefficient under some circumstances. In my case I suspect it’s just deeply nested tests + instance-per-leaf mode + somewhat long descriptions. All in findChildFailure()
wasyl
09/09/2020, 11:00 AMJUnitTestEngineListener
is the same for all tests in Gradle run, it’d also explain the continuous drop in performance, as from what I see all results are appended to a single mutable list, and after each test all the results are filtered againwasyl
09/09/2020, 11:12 AMDescription#id()
is a pretty low-hanging fruit?wasyl
09/09/2020, 11:32 AMwasyl
09/09/2020, 11:34 AMsam
09/09/2020, 12:23 PMwasyl
09/09/2020, 12:24 PMsam
09/09/2020, 12:24 PMsam
09/09/2020, 12:24 PMsam
09/09/2020, 12:24 PMwasyl
09/09/2020, 12:25 PMDescription#id
is created 200k times over the course of tests run, even though at the end there’s only 411 live instances of it, so perhaps the caching might still make sensewasyl
09/09/2020, 12:25 PMsam
09/09/2020, 12:25 PMsam
09/09/2020, 12:26 PMsam
09/09/2020, 12:26 PMsam
09/09/2020, 12:26 PMwasyl
09/09/2020, 12:27 PMsam
09/09/2020, 12:28 PMsam
09/09/2020, 12:28 PMwasyl
09/09/2020, 12:28 PMwasyl
09/09/2020, 12:29 PMstartup profiler
and manually modify jvmargs for the test task such that it attaches and samples from the startsam
09/09/2020, 12:30 PMwasyl
09/09/2020, 1:07 PMforall
blocks I seem to also lose a bit of time in isOnPath
btwwasyl
09/09/2020, 1:09 PMid
calculation though, but it seems that the regex patter is created every time?wasyl
09/09/2020, 1:09 PMcompile
is quite heavy so I suppose it could be cached as wellwasyl
09/09/2020, 1:23 PMRegex.replace
in the id()
calculation, but I don’t see how to optimise it 🤔sam
09/09/2020, 7:12 PMwasyl
09/09/2020, 8:27 PMsam
09/09/2020, 8:27 PMsam
09/10/2020, 6:58 AMwasyl
09/10/2020, 9:06 AMwasyl
09/10/2020, 9:08 AMwasyl
09/10/2020, 9:36 AMsourceRef()
call. I’ll try to get some more information about the specifics though, but I suspect it’s something about the stacktrace being massive 😉wasyl
09/10/2020, 9:56 AMThrowable.getStackTrace() -> getOurStackTrace() -> getStackTraceElement
, which happens for every test. If the SourceRef
data is not needed always, perhaps the stacktrace could be retrieved lazily — creating Throwable()
is relatively cheap so it could be stored, and stacktrace could be only calculated when neededwasyl
09/10/2020, 10:22 AMclass Sample: DescribeSpec() {
describe("root") {
it("1") { println("Done") }
it("2") { println("Done") }
it("3") { println("Done") }
...
it("300") { println("Done") }
}
}
runs pretty long as well, and spends most of the time in sourceRef()
. Why I experience this is just because we have 4 nested forall
blocks, and couple assertions on each step, and it adds up to roughly 200-300 assertions. It’s still not that much for a unit test which uses forAll
or generators thoughsam
09/10/2020, 10:40 PMreevn
09/11/2020, 9:20 AMsam
09/12/2020, 6:38 PMsam
09/12/2020, 6:39 PMwasyl
09/13/2020, 1:39 PMStackWalker
could be used? Anyway if it’s a significant bottleneck for someone, one workaround is to use -XX:MaxJavaStackTraceDepth=10
(10 seems to work with current Kotest), assuming there’s no need for full stacktraces elsewhere. This seems to speed up the tests for which the sourceRef
is costly (as its performance degrades with the tests depth, it might not be an issue for everyone. I observe noticeable impact with ~400 levels deep stacks, and it seems like using forall
results in a bit deeper stacktraces?).
Thanks for looking into it, Sam!sam
09/13/2020, 2:27 PMwasyl
09/14/2020, 7:14 AMsam
09/14/2020, 8:22 AMsam
09/14/2020, 8:28 AMsam
09/14/2020, 9:13 AM4.3.0.678-SNAPSHOT
and then add a module kotest-framework-jdk9
to your build, that should trigger the usage of stack walker. Would be interesting to see how much quicker it is for you.wasyl
09/14/2020, 9:50 AMwasyl
09/14/2020, 9:52 AMsam
09/14/2020, 9:53 AMsam
09/14/2020, 9:53 AMwasyl
09/14/2020, 10:15 AMwasyl
09/14/2020, 10:16 AMsam
09/14/2020, 10:26 AMwasyl
09/14/2020, 10:28 AMsam
09/14/2020, 10:29 AMsam
09/14/2020, 10:29 AMwasyl
09/14/2020, 10:29 AMsam
09/14/2020, 10:32 AMwasyl
09/14/2020, 10:32 AMsam
09/14/2020, 10:32 AM4.3.0.679-SNAPSHOT
and then try setting the system property
kotest.framework.sourceref.disable=true
wasyl
09/14/2020, 10:33 AMsam
09/14/2020, 10:33 AMtasks.named<Test>("test") {
useJUnitPlatform()
systemProperty("kotest.framework.sourceref.disable", "true")
}
sam
09/14/2020, 10:34 AMwasyl
09/14/2020, 11:50 AMsam
09/14/2020, 11:53 AM