I m porting some unit tests from Kotest 4 6 to Kotest 5 3 an

Question

I m porting some unit tests from Kotest 4 6 to Kotest 5 3 and I ve discovered that one of my tests is taking a hugely longer time to run with the new kotest i e from 1 5 seconds with kotest <http 4 to|4 6 to> 90 seconds with kotest 5 3 on my test AWS host Any idea what could be causing this

Jonathan Lennox · Answer

Oddly this only happens if it s part of my whole unit test if I run it individually with `mvn Dtest=TccGeneratorNodeTest test` it takes only 1 5 seconds again

Jonathan Lennox · Answer

So maybe something else in the test suite is interfering

Jonathan Lennox · Answer

The one notable change I had to do for the port to kotest 5 3 was to add `suspend` to the declarations of the test s `beforeSpec` methods

Jonathan Lennox · Answer

The test is available at <https github com JonathanLennox jitsi media transform blob bump kotlin src test kotlin org jitsi nlj transform node incoming TccGeneratorNodeTest kt|https github com JonathanLennox jitsi media transform blob bump kotlin src test n org jitsi nlj transform node incoming TccGeneratorNodeTest kt> if that s helpful to anyone

Jonathan Lennox · Answer

The other odd thing is that this problem only occurs on a Linux box on my x64 Mac it doesn t happen

sam · Answer

Linux box here running the suite INFO Tests run 9 Failures 0 Errors 0 Skipped 0 Time elapsed 0 687 s in org jitsi nlj transform node incoming TccGeneratorNodeTest INFO Running org jitsi nlj util TimeExpiringCacheTest

sam · Answer

0 6 seconds for that test

Jonathan Lennox · Answer

Huh even weirder Which JVM

Jonathan Lennox · Answer

And this was with the version of the PR that used the 5 3 0 test suite

Jonathan Lennox · Answer

To be clear the one that misbehaved was <https github com jitsi jitsi media transform commit 19ff911f4183f35e7f070dc6c157974e8c07b377>

sam · Answer

Ok I was on master Switching to your `bump kotlin` branch ``` INFO INFO T E S T S INFO WARNING Corrupted STDOUT by directly writing to native stream in forked JVM 1 See FAQ web page and the dump file home sam development workspace jitsi media transform target surefire reports 2022 05 29T09 26 30 623 jvmRun1 dumpstream INFO INFO Results INFO INFO Tests run 0 Failures 0 Errors 0 Skipped 0 INFO INFO INFO BUILD FAILURE INFO INFO Total time 29 472 s INFO Finished at 2022 05 29T09 26 32 05 00 INFO ERROR Failed to execute goal org apache maven plugins maven surefire plugin 2 22 0 test default test on project jitsi media transform There are test failures ERROR ERROR Please refer to home sam development workspace jitsi media transform target surefire reports for the individual test results ERROR Please refer to dump files if any exist date jvmRun N dump date dumpstream and date jvmRun N dumpstream ERROR There was an error in the forked process ERROR io kotlintest specs ShouldSpec ERROR org apache maven surefire booter SurefireBooterForkException There was an error in the forked process ERROR io kotlintest specs ShouldSpec ERROR at org apache maven plugin surefire booterclient ForkStarter fork ForkStarter java 658 ERROR at org apache maven plugin surefire booterclient ForkStarter fork ForkStarter java 533 ERROR at org apache maven plugin surefire booterclient ForkStarter run ForkStarter java 278 ERROR at org apache maven plugin surefire booterclient ForkStarter run ForkStarter java 244 ERROR at org apache maven plugin surefire AbstractSurefireMojo executeProvider AbstractSurefireMojo java 1194 ERROR at org apache maven plugin surefire AbstractSurefireMojo executeAfterPreconditionsChecked AbstractSurefireMojo java 1022 ERROR at org apache maven plugin surefire AbstractSurefireMojo execute AbstractSurefireMojo java 868 ERROR at org apache maven plugin DefaultBuildPluginManager executeMojo DefaultBuildPluginManager java 137 ```

Jonathan Lennox · Answer

Just to confirm this is the tag which has the ktor 5 build right I rolled the bump kotlin branch back to ktor 4 so I could merge it

sam · Answer

I just looked at the PR branch

Jonathan Lennox · Answer

I now have a bump kotlin ktor5 branch so as to avoid confusion

Jonathan Lennox · Answer

sam · Answer

ok let me try that

Jonathan Lennox · Answer

What JVM version are you using

sam · Answer

openjdk 11 0 12 2021 07 20 OpenJDK Runtime Environment 18 9 build 11 0 12+7 OpenJDK 64 Bit Server VM 18 9 build 11 0 12+7 mixed mode

sam · Answer

same fork error on your new branch btw

Jonathan Lennox · Answer

Hm that s what I have too

Jonathan Lennox · Answer

Two other notable things we have GitHub integration tests for these PR and when this PR ran there the testing took six hours and then was killed by GitHub

Jonathan Lennox · Answer

Which is much worse than my AWS instance so there s something variable here

sam · Answer

I ll try removing some tests until it at least passes

sam · Answer

something is odd in your project as it just killed my intellij

Jonathan Lennox · Answer

Huh

Jonathan Lennox · Answer

When you ran the tests

sam · Answer

just trying to parse out a file

sam · Answer

might just be a weird one off

sam · Answer

I don t know if this is contribuing to your issues ``` WARNING Corrupted STDOUT by directly writing to native stream in forked JVM 1 See FAQ web page and the dump file home sam development workspace jitsi media transform target surefire reports 2022 05 29T09 46 40 841 jvmRun1 dumpstream```

Jonathan Lennox · Answer

That s not happening for me so something s different there too

sam · Answer

do you have a custom stdout logger

Jonathan Lennox · Answer

I don t think so what s the message in the dumpstream

sam · Answer

it just passed so now I don t have it

sam · Answer

let me start adding things back in

sam · Answer

did you explicitly enable kotest logging btw

Jonathan Lennox · Answer

No

sam · Answer

ok that s a bug unless I have it enabled on my system as an env var

Jonathan Lennox · Answer

Well I didn t write the original kotest here I m just porting it to kotest 5 but I don t think so

sam · Answer

a bug in kotest to be clear

sam · Answer

ok never mind I have it enabled KOTEST DEBUG=true

Jonathan Lennox · Answer

I wonder if it s outputting something in the forked process

sam · Answer

I wasn t doing maven clean test before

sam · Answer

just maven test

sam · Answer

so it s possible those errors were from the other branch man facepalming skin tone 2

sam · Answer

``` INFO Tests run 116 Failures 0 Errors 0 Skipped 0 INFO INFO INFO BUILD SUCCESS INFO INFO Total time 01 11 min INFO Finished at 2022 05 29T09 56 17 05 00 INFO ```

sam · Answer

that s for everything but your tcc test

Jonathan Lennox · Answer

Ok this is interesting I tried adding an ` lt argLine gt Xmx1G lt argLine gt ` to the maven surefire plugin configuration and the tests now seem to take much longer on my Mac I suspect something s leaking memory and if JVM s heap is too small the GC starts thrashing

sam · Answer

you could fire up the tests and launch visualvm

sam · Answer

attach it to the test jvm and see what gc is doign

sam · Answer

ok with all tests enabled ``` INFO Tests run 125 Failures 0 Errors 0 Skipped 0 INFO INFO INFO BUILD SUCCESS INFO INFO Total time 01 04 min INFO Finished at 2022 05 29T09 57 46 05 00 INFO ```

sam · Answer

I have an i9 16 core with 32gb btw

Jonathan Lennox · Answer

Yeah this would explain why it s been fine on my Mac it s got 32G too

sam · Answer

when I run stuff on GHA I always bump the VM to 3gb

sam · Answer

It s gradle but I do this ```GRADLE OPTS Dorg gradle configureondemand=false Dorg gradle parallel=false Dkotlin incremental=false Dorg gradle jvmargs= Xmx3g XX MaxPermSize=2048m XX +HeapDumpOnOutOfMemoryError Dfile encoding=UTF 8 ```

Jonathan Lennox · Answer

I ll see if I can give the visualVm a try later

Jonathan Lennox · Answer

Have to run now Thank you

Jonathan Lennox · Answer

Okay some experimentation shows it definitely has to do with heap size When I set heap size to ` lt argLine gt Xmx1994391552 lt argLine gt ` the default MaxHeapSize on my AWS instance it runs slowly When I set it to ` lt argLine gt Xmx1822425088 lt argLine gt ` the default MaxHeapSize on the Azure instances GitHub uses it takes interminably long I ll see if I can attach and profile it

Jonathan Lennox · Answer

Looking at a memory snapshot in YourKit I see `io mockk impl stub SpyKStub` has a retained memory size of 1 930 015 280 bytes