Skip to content

Commit 3affb90

Browse files
qwwdfsadqwwdfsad
committed
Properly choose timeout exception with a recovered stacktrace to provide better debugging experience
Fixes #1625
1 parent 6aedb61 commit 3affb90

File tree

9 files changed

+155
-37
lines changed

9 files changed

+155
-37
lines changed

‎binary-compatibility-validator/reference-public-api/kotlinx-coroutines-core.txt

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -512,7 +512,9 @@ public final class kotlinx/coroutines/ThreadPoolDispatcherKt {
512512
public static final fun newSingleThreadContext (Ljava/lang/String;)Lkotlinx/coroutines/ExecutorCoroutineDispatcher;
513513
}
514514

515-
public final class kotlinx/coroutines/TimeoutCancellationException : java/util/concurrent/CancellationException {
515+
public final class kotlinx/coroutines/TimeoutCancellationException : java/util/concurrent/CancellationException, kotlinx/coroutines/CopyableThrowable {
516+
public synthetic fun createCopy ()Ljava/lang/Throwable;
517+
public fun createCopy ()Lkotlinx/coroutines/TimeoutCancellationException;
516518
}
517519

518520
public final class kotlinx/coroutines/TimeoutKt {

‎kotlinx-coroutines-core/common/src/JobSupport.kt

Lines changed: 17 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -247,8 +247,22 @@ public open class JobSupport constructor(active: Boolean) : Job, ChildJob, Paren
247247
if (state.isCancelling) return defaultCancellationException()
248248
return null
249249
}
250-
// Take either the first real exception (not a cancellation) or just the first exception
251-
return exceptions.firstOrNull { it !is CancellationException } ?: exceptions[0]
250+
/*
251+
* 1) If we have non-CE, use it as root cause
252+
* 2) If our original cause was TCE, use *non-original* TCE because of the special nature of TCE
253+
* * It is a CE, so it's not reported by children
254+
* * The first instance (cancellation cause) is created by timeout coroutine and has no meaningful stacktrace
255+
* * The potential second instance is thrown by withTimeout lexical block itself, then it has recovered stacktrace
256+
* 3) Just return the very first CE
257+
*/
258+
val firstNonCancellation = exceptions.firstOrNull { it !is CancellationException }
259+
if (firstNonCancellation != null) return firstNonCancellation
260+
val first = exceptions[0]
261+
if (first is TimeoutCancellationException) {
262+
val detailedTimeoutException = exceptions.firstOrNull { it !== first && it is TimeoutCancellationException }
263+
if (detailedTimeoutException != null) return detailedTimeoutException
264+
}
265+
return first
252266
}
253267

254268
private fun addSuppressedExceptions(rootCause: Throwable, exceptions: List<Throwable>) {
@@ -1073,7 +1087,7 @@ public open class JobSupport constructor(active: Boolean) : Job, ChildJob, Paren
10731087
get() = _exceptionsHolder.value
10741088
set(value) { _exceptionsHolder.value = value }
10751089

1076-
// NotE: cannot be modified when sealed
1090+
// Note: cannot be modified when sealed
10771091
val isSealed: Boolean get() = exceptionsHolder === SEALED
10781092
val isCancelling: Boolean get() = rootCause != null
10791093
override val isActive: Boolean get() = rootCause == null // !isCancelling

‎kotlinx-coroutines-core/common/src/Timeout.kt

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -114,5 +114,3 @@ internal fun TimeoutCancellationException(
114114
time: Long,
115115
coroutine: Job
116116
) : TimeoutCancellationException = TimeoutCancellationException("Timed out waiting for $time ms", coroutine)
117-
118-

‎kotlinx-coroutines-core/jvm/test-resources/stacktraces/timeout/testStacktraceIsRecoveredFromLexicalBlockWhenTriggeredByChild.txt

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,7 @@
1+
kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
2+
(Coroutine boundary)
3+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest.outerChildWithTimeout(StackTraceRecoveryWithTimeoutTest.kt:48)
4+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest$testStacktraceIsRecoveredFromLexicalBlockWhenTriggeredByChild$1.invokeSuspend(StackTraceRecoveryWithTimeoutTest.kt:40)
5+
Caused by: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
6+
at kotlinx.coroutines.TimeoutKt.TimeoutCancellationException(Timeout.kt:116)
7+
at kotlinx.coroutines.TimeoutCoroutine.run(Timeout.kt:86)

‎kotlinx-coroutines-core/jvm/test-resources/stacktraces/timeout/testStacktraceIsRecoveredFromSuspensionPoint.txt

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,10 @@
1+
kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
2+
(Coroutine boundary)
3+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest.suspendForever(StackTraceRecoveryWithTimeoutTest.kt:42)
4+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest$outerWithTimeout$2.invokeSuspend(StackTraceRecoveryWithTimeoutTest.kt:32)
5+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest.outerWithTimeout(StackTraceRecoveryWithTimeoutTest.kt:31)
6+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest$testStacktraceIsRecoveredFromSuspensionPoint$1.invokeSuspend(StackTraceRecoveryWithTimeoutTest.kt:19)
7+
Caused by: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
8+
at kotlinx.coroutines.TimeoutKt.TimeoutCancellationException(Timeout.kt:116)
9+
at kotlinx.coroutines.TimeoutCoroutine.run(Timeout.kt:86)
10+
at kotlinx.coroutines.EventLoopImplBase$DelayedRunnableTask.run(EventLoop.common.kt:492)

‎kotlinx-coroutines-core/jvm/test-resources/stacktraces/timeout/testStacktraceIsRecoveredFromSuspensionPointWithChild.txt

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,9 @@
1+
kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
2+
(Coroutine boundary)
3+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest.suspendForever(StackTraceRecoveryWithTimeoutTest.kt:92)
4+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest$outerChild$2.invokeSuspend(StackTraceRecoveryWithTimeoutTest.kt:78)
5+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest.outerChild(StackTraceRecoveryWithTimeoutTest.kt:74)
6+
at kotlinx.coroutines.exceptions.StackTraceRecoveryWithTimeoutTest$testStacktraceIsRecoveredFromSuspensionPointWithChild$1.invokeSuspend(StackTraceRecoveryWithTimeoutTest.kt:66)
7+
Caused by: kotlinx.coroutines.TimeoutCancellationException: Timed out waiting for 200 ms
8+
at kotlinx.coroutines.TimeoutKt.TimeoutCancellationException(Timeout.kt:116)
9+
at kotlinx.coroutines.TimeoutCoroutine.run(Timeout.kt:86)

‎kotlinx-coroutines-core/jvm/test/AsyncJvmTest.kt

Lines changed: 20 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -4,42 +4,32 @@
44

55
package kotlinx.coroutines
66

7+
import kotlin.coroutines.*
78
import kotlin.test.*
89

910
class AsyncJvmTest : TestBase() {
1011
// This must be a common test but it fails on JS because of KT-21961
11-
@Test
12-
fun testAsyncWithFinally() = runTest {
13-
expect(1)
12+
suspend fun test() {
13+
println("test.begin")
14+
delay(5000)
15+
println("test.end")
16+
}
17+
18+
suspend fun proxy() {
19+
println("?")
20+
test()
21+
println("?")
22+
}
1423

15-
@Suppress("UNREACHABLE_CODE")
16-
val d = async {
17-
expect(3)
18-
try {
19-
yield() // to main, will cancel
20-
} finally {
21-
expect(6) // will go there on await
22-
return@async "Fail" // result will not override cancellation
24+
// @Test
25+
fun main() {
26+
println("AA")
27+
runBlocking {
28+
withTimeout(100) {
29+
proxy()
30+
println()
2331
}
24-
expectUnreached()
25-
"Fail2"
26-
}
27-
expect(2)
28-
yield() // to async
29-
expect(4)
30-
check(d.isActive && !d.isCompleted && !d.isCancelled)
31-
d.cancel()
32-
check(!d.isActive && !d.isCompleted && d.isCancelled)
33-
check(!d.isActive && !d.isCompleted && d.isCancelled)
34-
expect(5)
35-
try {
36-
d.await() // awaits
37-
expectUnreached() // does not complete normally
38-
} catch (e: Throwable) {
39-
expect(7)
40-
check(e is CancellationException)
32+
println()
4133
}
42-
check(!d.isActive && d.isCompleted && d.isCancelled)
43-
finish(8)
4434
}
4535
}

‎kotlinx-coroutines-core/jvm/test/exceptions/StackTraceRecoveryWithTimeoutTest.kt

Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
1+
/*
2+
* Copyright 2016-2019 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
5+
package kotlinx.coroutines.exceptions
6+
7+
import kotlinx.coroutines.*
8+
import org.junit.*
9+
import org.junit.rules.*
10+
11+
class StackTraceRecoveryWithTimeoutTest : TestBase() {
12+
13+
@get:Rule
14+
val name = TestName()
15+
16+
@Test
17+
fun testStacktraceIsRecoveredFromSuspensionPoint() = runTest {
18+
try {
19+
outerWithTimeout()
20+
} catch (e: TimeoutCancellationException) {
21+
verifyStackTrace("timeout/${name.methodName}", e)
22+
}
23+
}
24+
25+
private suspend fun outerWithTimeout() {
26+
withTimeout(200) {
27+
suspendForever()
28+
}
29+
expectUnreached()
30+
}
31+
32+
private suspend fun suspendForever() {
33+
hang { }
34+
expectUnreached()
35+
}
36+
37+
@Test
38+
fun testStacktraceIsRecoveredFromLexicalBlockWhenTriggeredByChild() = runTest {
39+
try {
40+
outerChildWithTimeout()
41+
} catch (e: TimeoutCancellationException) {
42+
verifyStackTrace("timeout/${name.methodName}", e)
43+
}
44+
}
45+
46+
private suspend fun outerChildWithTimeout() {
47+
withTimeout(200) {
48+
launch {
49+
withTimeoutInChild()
50+
}
51+
yield()
52+
}
53+
expectUnreached()
54+
}
55+
56+
private suspend fun withTimeoutInChild() {
57+
withTimeout(300) {
58+
hang { }
59+
}
60+
expectUnreached()
61+
}
62+
63+
@Test
64+
fun testStacktraceIsRecoveredFromSuspensionPointWithChild() = runTest {
65+
try {
66+
outerChild()
67+
} catch (e: TimeoutCancellationException) {
68+
verifyStackTrace("timeout/${name.methodName}", e)
69+
}
70+
}
71+
72+
private suspend fun outerChild() {
73+
withTimeout(200) {
74+
launch {
75+
smallWithTimeout()
76+
}
77+
suspendForever()
78+
}
79+
expectUnreached()
80+
}
81+
82+
private suspend fun smallWithTimeout() {
83+
withTimeout(100) {
84+
suspendForever()
85+
}
86+
expectUnreached()
87+
}
88+
}

‎kotlinx-coroutines-core/jvm/test/exceptions/Stacktraces.kt

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ public fun verifyStackTrace(e: Throwable, vararg traces: String) {
2121
}
2222

2323
public fun verifyStackTrace(path: String, e: Throwable) {
24-
val resource = Job.javaClass.classLoader.getResourceAsStream("stacktraces/$path.txt")
24+
val resource = Job::class.java.classLoader.getResourceAsStream("stacktraces/$path.txt")
2525
val lines = resource.reader().readLines()
2626
verifyStackTrace(e, *lines.toTypedArray())
2727
}

0 commit comments

Comments
 (0)