Kotlin coroutine stacktraces not including line numbers


#1

I have a question, but first let me present my poorly-coded example:

class CoroutinesTests { // L9
    suspend fun foo() {
        delay(50)
        throw RuntimeException() // L12
    }

    @Test
    fun `has proper stacktrace`() {
        runBlocking { // L17
            foo() // L18
        }
    }

    private val savedCr = AtomicReference<Continuation<Boolean>>()
    suspend fun foo2() {
        delay(50)
        val result = suspendCoroutine<Boolean> { cr ->
            savedCr.set(cr)
        }
        println("Line 3: $result")
        throw RuntimeException() // L29
    }

    @Test
    fun `has busted stacktrace`() {
        val t = thread {
            runBlocking { // L35
                println("Line 1")
                println("Line 2")
                foo2() // L38
            }
        }
        while (savedCr.get() == null) {
            Thread.sleep(50L)
        }
        savedCr.get().resume(true)
        t.join()
    }
}

The first test case, in which an exception is thrown in a suspend function after a suspending operation, produces this stacktrace:

java.lang.RuntimeException
	at CoroutinesTests.foo(CoroutinesTests.kt:12)
	at CoroutinesTests$foo$1.doResume(CoroutinesTests.kt)
	at kotlin.coroutines.experimental.* <deleted 14 lines>
	at CoroutinesTests.has proper stacktrace(CoroutinesTests.kt:17)

If this were non-coroutine code, the stacktrace would include L18 somewhere; but this isn’t captured in the stacktrace. Instead there’s this doResume line which is supposedly in the file, but with no line number attached.

If you run the second test case, you get

Line 1
Line 2
Line 3: true
Exception in thread "Thread-0" java.lang.RuntimeException
	at CoroutinesTests.foo2(CoroutinesTests.kt:29)
	at CoroutinesTests$foo2$1.doResume(CoroutinesTests.kt)
	at kotlin.coroutines.experimental.* <deleted 7 lines>
	at CoroutinesTests$has busted stacktrace$t$1.invoke(CoroutinesTests.kt:35)
	at CoroutinesTests$has busted stacktrace$t$1.invoke(CoroutinesTests.kt:9)
	at kotlin.concurrent.ThreadsKt$thread$thread$1.run(Thread.kt:18)

Similarly, in this case, one of the stacktrace lines should include L38, the line that calls the suspending function. (Confusingly, the test case also passes, but I’m not especially interested in that part.)

In these examples it’s pretty obvious where the failure is, but for any non-trivial example it’s less straightforward, and not having complete stacktraces makes me nervous. Is this a bug, or just the way it is with the way coroutines are implemented?

Kotlin 1.2.41 coroutines 0.22.5.


#2

I think it may have something to do with the way coroutine execution is spread over multiple threads. Have you tried to use a single thread context for the execution?

You might also want to take a look at coroutine exception handlers.


#3

I tried adding newSingleThreadContext("foo") as the context for each runBlocking call, but no dice – stacktrace is unchanged.

Regarding the coroutine exception handler, I can’t seem to get it to work:

    @Test
    fun `has proper stacktrace`() {
        val context = newSingleThreadContext("foo") + CoroutineExceptionHandler { coroutineContext, throwable ->
            System.err.println("Exception in context $coroutineContext; throwable was $throwable")
        }
        runBlocking(context) {
            foo()
        }
    }

confusingly seems to have no effect – my callback never executes and the exception propagates like it did before.