https://kotlinlang.org logo
Title
t

taer

01/12/2021, 3:02 PM
Question on the output of test failures. The stack traces I get are pretty much useless sometimes. Is there something I'm doing incorrect? Will post in thread
java.lang.AssertionError: <null> should not equal <null>
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:91)
	at kotlinx.coroutines.CoroutineScopeKt.coroutineScope(CoroutineScope.kt:194)
	at io.kotest.core.internal.TestCaseExecutor.executeInScope(TestCaseExecutor.kt:252)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1$1.invokeSuspend(TestCaseExecutor.kt:227)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1$1.invoke(TestCaseExecutor.kt)
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturnIgnoreTimeout(Undispatched.kt:102)
	at kotlinx.coroutines.TimeoutKt.setupTimeout(Timeout.kt:120)
	at kotlinx.coroutines.TimeoutKt.withTimeout(Timeout.kt:37)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1.invokeSuspend(TestCaseExecutor.kt:226)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1.invoke(TestCaseExecutor.kt)
	at io.kotest.engine.ExecutorExecutionContext$executeWithTimeoutInterruption$$inlined$suspendCoroutine$lambda$2.invokeSuspend(ExecutorExecutionContext.kt:56)
	at ???(Coroutine boundary.?(?)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1$1.invokeSuspend(TestCaseExecutor.kt:227)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1.invokeSuspend(TestCaseExecutor.kt:226)
	at io.kotest.core.internal.TestCaseExecutor.executeAndWait(TestCaseExecutor.kt:212)
	at io.kotest.core.internal.TestCaseExecutor.invokeTestCase(TestCaseExecutor.kt:180)
	at io.kotest.core.internal.TestCaseExecutor.executeActiveTest(TestCaseExecutor.kt:149)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1$1.invokeSuspend(TestCaseExecutor.kt:87)
	at io.kotest.core.internal.TestCaseExecutor.executeIfActive(TestCaseExecutor.kt:113)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1.invokeSuspend(TestCaseExecutor.kt:87)
	at io.kotest.core.internal.TestCaseExecutor.execute(TestCaseExecutor.kt:67)
	at io.kotest.engine.runners.SingleInstanceSpecRunner.runTest(SingleInstanceSpecRunner.kt:73)
Caused by: java.lang.AssertionError: <null> should not equal <null>
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturn(Undispatched.kt:91)
	at kotlinx.coroutines.CoroutineScopeKt.coroutineScope(CoroutineScope.kt:194)
	at io.kotest.core.internal.TestCaseExecutor.executeInScope(TestCaseExecutor.kt:252)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1$1.invokeSuspend(TestCaseExecutor.kt:227)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1$1.invoke(TestCaseExecutor.kt)
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturnIgnoreTimeout(Undispatched.kt:102)
	at kotlinx.coroutines.TimeoutKt.setupTimeout(Timeout.kt:120)
	at kotlinx.coroutines.TimeoutKt.withTimeout(Timeout.kt:37)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1.invokeSuspend(TestCaseExecutor.kt:226)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3$1.invoke(TestCaseExecutor.kt)
	at io.kotest.engine.ExecutorExecutionContext$executeWithTimeoutInterruption$$inlined$suspendCoroutine$lambda$2.invokeSuspend(ExecutorExecutionContext.kt:56)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:274)
	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
	at io.kotest.engine.ExecutorExecutionContext.executeWithTimeoutInterruption(ExecutorExecutionContext.kt:55)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3.invokeSuspend(TestCaseExecutor.kt:225)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1$3.invoke(TestCaseExecutor.kt)
	at io.kotest.mpp.ReplayKt.replay(replay.kt:18)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1.invokeSuspend(TestCaseExecutor.kt:220)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2$1.invoke(TestCaseExecutor.kt)
	at io.kotest.engine.ExecutorExecutionContext$executeWithTimeoutInterruption$$inlined$suspendCoroutine$lambda$2.invokeSuspend(ExecutorExecutionContext.kt:56)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:274)
	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
	at io.kotest.engine.ExecutorExecutionContext.executeWithTimeoutInterruption(ExecutorExecutionContext.kt:55)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2.invokeSuspend(TestCaseExecutor.kt:213)
	at io.kotest.core.internal.TestCaseExecutor$executeAndWait$2.invoke(TestCaseExecutor.kt)
	at kotlinx.coroutines.intrinsics.UndispatchedKt.startUndispatchedOrReturnIgnoreTimeout(Undispatched.kt:102)
	at kotlinx.coroutines.TimeoutKt.setupTimeout(Timeout.kt:120)
	at kotlinx.coroutines.TimeoutKt.withTimeout(Timeout.kt:37)
	at io.kotest.core.internal.TestCaseExecutor.executeAndWait(TestCaseExecutor.kt:212)
	at io.kotest.core.internal.TestCaseExecutor.invokeTestCase(TestCaseExecutor.kt:180)
	at io.kotest.core.internal.TestCaseExecutor.executeActiveTest(TestCaseExecutor.kt:149)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1$1.invokeSuspend(TestCaseExecutor.kt:87)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1$1.invoke(TestCaseExecutor.kt)
	at io.kotest.core.internal.TestCaseExecutor.executeIfActive(TestCaseExecutor.kt:113)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1.invokeSuspend(TestCaseExecutor.kt:87)
	at io.kotest.core.internal.TestCaseExecutor$intercept$innerExecute$1.invoke(TestCaseExecutor.kt)
	at io.kotest.core.internal.TestCaseExecutor.intercept(TestCaseExecutor.kt:101)
	at io.kotest.core.internal.TestCaseExecutor.execute(TestCaseExecutor.kt:67)
	at io.kotest.engine.runners.SingleInstanceSpecRunner.runTest(SingleInstanceSpecRunner.kt:73)
	at io.kotest.engine.runners.SingleInstanceSpecRunner$execute$2$invokeSuspend$$inlined$invoke$lambda$1.invokeSuspend(SingleInstanceSpecRunner.kt:83)
	at io.kotest.engine.runners.SingleInstanceSpecRunner$execute$2$invokeSuspend$$inlined$invoke$lambda$1.invoke(SingleInstanceSpecRunner.kt)
	at io.kotest.engine.spec.SpecRunner$runParallel$$inlined$map$lambda$2$1.invokeSuspend(SpecRunner.kt:80)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:56)
	at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:274)
	at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:84)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59)
	at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
	at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38)
	at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
	at io.kotest.engine.spec.SpecRunner$runParallel$$inlined$map$lambda$2.run(SpecRunner.kt:79)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
This is a stack trace I have:
There's not a single line in there helping me find the assertion that failed. I think the issue is the test looks like this.
test("Data generation") {
        val generateData = store.generateData(listOf(ReferenceFields.refEnumField.id))
        assertSoftly(generateData.first().valuesList.single()) {
            id shouldBe ReferenceFields.refEnumField.id
            value.valueCase shouldBe ValueHolder.ValueCase.ENUM
            value.enum.ordinal shouldBeGreaterThan 0
            Common.TenantType.forNumber(value.enum.ordinal) shouldNotBe null
        }
    }
The failure was obviously here
Common.TenantType.forNumber(value.enum.ordinal) shouldNotBe null
Was it not in a stack trace due to the assertSoftly? Any advice on making the stack traces easier to debug?
s

sam

01/12/2021, 10:36 PM
Hmmm thatis crap I agree
It might also be because it's a coroutine
Try adding this somewhere
System.setProperty("kotlinx.coroutines.debug", "on")
And if that helps, we should make sure kotest is setting it so you don't have to
t

taer

01/13/2021, 7:36 PM
Of course now it's doing the right thing(the original test has morphed considerably
weird. The other tests dont do this. There's something special about him. And no, the property setting didn't help
Changing the assertSoftly to a with gets acceptable stacks again
So other tests that use the same assertSoftly error nicely. There are no coroutines or suspend functions being tested here.
some compiler helper? I will attach the 2 stack traces showing with vs asserrtSoftly.
s

sam

01/14/2021, 2:07 AM
So sometimes it works sometimes it doesn't?
Do you have any threading goijg on
t

taer

01/14/2021, 3:43 PM
None. It's a simple data generator.
Like, given a tree of types, fill it out(think something like kotests ARB, etc)
s

sam

01/14/2021, 3:45 PM
What about nested assertSoftyls ?
t

taer

01/20/2021, 6:17 PM
I reproduced it cleanly.
import io.kotest.assertions.assertSoftly
import io.kotest.core.spec.style.FunSpec
import io.kotest.matchers.shouldBe
import kotlin.random.Random

class ATest : FunSpec({

    val foo = Random(1)
    val x = foo.nextInt()
    test("asserts") {
        assertSoftly {
            x shouldBe  5
//            x shouldBe  6
    }}
})
It seems like if you have just one assertion fail, you get the ugly stack trace. When I uncomment out the shouldBe 6, it has nice stacks
digging in a bit more, but this line is what erases the goodies in stacktraces.kt
throwable.stackTrace = UserStackTraceConverter.getUserStacktrace(throwable.stackTrace)
yeah. if only one tosses, then it's not wrapped in a MultiAssertion. If this line just always wrapped the list, I think it would work: https://github.com/kotest/kotest/blob/master/kotest-assertions/kotest-assertions-shared/src/commonMain/kotlin/io/kotest/assertions/ErrorCollector.kt
It looks like MultiAssertionError's createMessage call would handle that just fine as well
s

sam

01/20/2021, 7:05 PM
nice work thanks
could you do me a favour and log a ticket with this info
t

taer

01/20/2021, 7:09 PM
Sure sure
I can PR fix that.. What direction would you prefer? Just throw the MultiAssertion failure w/ a single element? Or try to fix the filtering?
s

sam

01/20/2021, 8:02 PM
I didn't fully understand the issue. Why does it fail if you only have 1 error. Because the clean doesn't work properly on a single errors but does on MultiAssertion ?
t

taer

01/20/2021, 8:05 PM
yeah. The clean drops the stack traces till it finds a non-kotest. Actaully, that should instantly stop dropping in that case. I managed to checkout the code, I'll take a peek to see
s

sam

01/20/2021, 8:05 PM
There's some tests for clean too, and that's one of the reasons all the tests are in com.sksamuel rather than io.kotest
so we can see stacks
It could be that the filtering is just broken in other ways
Happy for a PR too yes
t

taer

01/20/2021, 8:07 PM
ahh.. yeah. It's because "toList() here is the stackTrace array
return toList().dropUntilFirstKotestClass().dropUntilFirstNonKotestClass().toTypedArray()
it drops till it finds a kotest class, then drops till the non-kotest.
in the single case, the top is non-kotest, so gets dropped
wrapping the single in the MultiAssertion gives it something to find right at the top
s

sam

01/20/2021, 8:10 PM
wouldn't this fail for all single assertions
even those outside of softly
and dropUntilFirstKotestClass will not drop anything if the first line is not kotest ?
t

taer

01/20/2021, 8:12 PM
looks like when it's in hard mode, the error collectors throwCollectedErrors isn't called, and the error is just instantly rethrown
fun ErrorCollector.collectOrThrow(error: Throwable) {
   when (getCollectionMode()) {
      ErrorCollectionMode.Soft -> pushError(error)
      ErrorCollectionMode.Hard -> throw error
   }
}
s

sam

01/20/2021, 8:12 PM
sounds like we just need a bunch of tests around hard/soft multi/single stack trace cleaning
and the issue will wash out
t

taer

01/20/2021, 8:13 PM
yaeh.. I don't see the cleaning tests BTW
is it in a different repo?
never mind. intellij failure
actually, the cleaning case seems like it just shouldn't be applied. The comment in
dropUntilUserClass
states
* Sometimes, it's possible for the Stacktrace to contain classes that are not from Kotest,
   * such as classes from sun.reflect or anything from Java. After clearing these classes, we'll be at Kotest
   * stacktrace, which will contain exceptions from the Runners and some other classes
   * After everything from Kotest we'll finally be at user classes, at which point the stacktrace is clean and is
   * returned.
In the simple case of 1 shouldBe 2, the top level class is the user's class. I don't see the cleaning call being made for anything other than the assertSoftly case TBH
s

sam

01/20/2021, 8:47 PM
but isn't the 1 shouldBe 2 showing the user class because it's been cleaned ?
t

taer

01/20/2021, 8:52 PM
ah.. was looking for the call only to
UserStackTraceConverter.getUserStacktrace
I think I see it..
The shouldBe gets cleaned when it's thrown.
Then the cleaned version is added to the list
if it's an assertSoftly
ie, the exception added to the list in the errorCollector has already been cleansed.
The clean is working perfectly. The reason it works when you have 2+ assertions is the MultiAssertionError assertion error is created inside a io.kotest package, which will be stripped off
maybe. I'm writing the tests now
repushed. checking locally in our project as well
It worked locally, and I pushed up. Fixed the compile error. It's failing now w/ what looks like a dependency issue perhaps?
java.lang.NoSuchMethodError: org.springframework.test.context.TestContext.computeAttribute(Ljava/lang/String;Ljava/util/function/Function;)Ljava/lang/Object;
s

sam

01/20/2021, 9:57 PM
hmmm odd
seems that way
master is green
but i guess if you only changed assert softly
oh yeah master is broken because of some change
ok I should have fixed master
t

taer

01/20/2021, 10:10 PM
I'll re-start the I can push up a no-op to restart it
s

sam

01/20/2021, 10:12 PM
ok