Skip to content

Commit 2bdd460

Browse files
authored
CoroutinesTimeout debug rule for JUnit 4 (#991)
Fixes #938
1 parent 3785348 commit 2bdd460

File tree

11 files changed

+405
-5
lines changed

11 files changed

+405
-5
lines changed

README.md

+1
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ GlobalScope.launch {
3636
* `Dispatchers.setMain` to override `Dispatchers.Main` in tests.
3737
* [debug](kotlinx-coroutines-debug/README.md) — debug utilities for coroutines.
3838
* `DebugProbes` API to probe, keep track of, print and dump active coroutines.
39+
* `CoroutinesTimeout` test rule to automatically dump coroutines on test timeout.
3940
* [reactive](reactive/README.md) — modules that provide builders and iteration support for various reactive streams libraries:
4041
* Reactive Streams, RxJava 2.x, and Project Reactor.
4142
* [ui](ui/README.md) — modules that provide coroutine dispatchers for various single-threaded UI libraries:

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

+12
Original file line numberDiff line numberDiff line change
@@ -38,3 +38,15 @@ public final class kotlinx/coroutines/debug/State : java/lang/Enum {
3838
public static fun values ()[Lkotlinx/coroutines/debug/State;
3939
}
4040

41+
public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout : org/junit/rules/TestRule {
42+
public static final field Companion Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;
43+
public fun <init> (JZ)V
44+
public synthetic fun <init> (JZILkotlin/jvm/internal/DefaultConstructorMarker;)V
45+
public fun apply (Lorg/junit/runners/model/Statement;Lorg/junit/runner/Description;)Lorg/junit/runners/model/Statement;
46+
}
47+
48+
public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion {
49+
public final fun seconds (IZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout;
50+
public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;IZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout;
51+
}
52+

kotlinx-coroutines-core/jvm/test/guide/example-compose-05.kt

+1-1
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@ fun main() = runBlocking<Unit> {
1414
println("The answer is ${concurrentSum()}")
1515
}
1616
println("Completed in $time ms")
17-
//sampleEnd
17+
//sampleEnd
1818
}
1919

2020
suspend fun concurrentSum(): Int = coroutineScope {

kotlinx-coroutines-debug/README.md

+34
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,38 @@ dependencies {
2222
}
2323
```
2424

25+
### Using in unit tests
26+
27+
For JUnit4 debug module provides special test rule, [CoroutinesTimeout], for installing debug probes
28+
and to dump coroutines on timeout to simplify tests debugging.
29+
30+
Its usage is better demonstrated by the example (runnable code is [here](test/TestRuleExample.kt)):
31+
32+
```kotlin
33+
class TestRuleExample {
34+
@Rule
35+
@JvmField
36+
public val timeout = CoroutinesTimeout.seconds(1)
37+
38+
private suspend fun someFunctionDeepInTheStack() {
39+
withContext(Dispatchers.IO) {
40+
delay(Long.MAX_VALUE) // Hang method
41+
}
42+
}
43+
44+
@Test
45+
fun hangingTest() = runBlocking {
46+
val job = launch {
47+
someFunctionDeepInTheStack()
48+
}
49+
job.join() // Join will hang
50+
}
51+
}
52+
```
53+
54+
After 1 second, test will fail with `TestTimeoutException` and all coroutines (`runBlocking` and `launch`) and their
55+
stacktraces will be dumped to the console.
56+
2557
### Using as JVM agent
2658

2759
It is possible to use this module as a standalone JVM agent to enable debug probes on the application startup.
@@ -130,4 +162,6 @@ java.lang.NoClassDefFoundError: Failed resolution of: Ljava/lang/management/Mana
130162
[DebugProbes.dumpCoroutinesState]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/dump-coroutines-state.html
131163
[DebugProbes.printJob]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-job.html
132164
[DebugProbes.printScope]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-scope.html
165+
<!--- INDEX kotlinx.coroutines.debug.junit4 -->
166+
[CoroutinesTimeout]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug.junit4/-coroutines-timeout/index.html
133167
<!--- END -->

kotlinx-coroutines-debug/build.gradle

+1
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
apply plugin: "com.github.johnrengelman.shadow"
66

77
dependencies {
8+
compileOnly "junit:junit:$junit_version"
89
compile "net.bytebuddy:byte-buddy:$byte_buddy_version"
910
compile "net.bytebuddy:byte-buddy-agent:$byte_buddy_version"
1011
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
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.debug.junit4
6+
7+
import kotlinx.coroutines.debug.*
8+
import org.junit.rules.*
9+
import org.junit.runner.*
10+
import org.junit.runners.model.*
11+
import java.util.concurrent.*
12+
13+
/**
14+
* Coroutines timeout rule for JUnit4 that is applied to all methods in the class.
15+
* This rule is very similar to [Timeout] rule: it runs tests in a separate thread,
16+
* fails tests after the given timeout and interrupts test thread.
17+
*
18+
* Additionally, this rule installs [DebugProbes] and dumps all coroutines at the moment of the timeout.
19+
* It may cancel coroutines on timeout if [cancelOnTimeout] set to `true`.
20+
*
21+
* Example of usage:
22+
* ```
23+
* class HangingTest {
24+
*
25+
* @Rule
26+
* @JvmField
27+
* val timeout = CoroutinesTimeout.seconds(5)
28+
*
29+
* @Test
30+
* fun testThatHangs() = runBlocking {
31+
* ...
32+
* delay(Long.MAX_VALUE) // somewhere deep in the stack
33+
* ...
34+
* }
35+
* }
36+
* ```
37+
*/
38+
public class CoroutinesTimeout(
39+
private val testTimeoutMs: Long,
40+
private val cancelOnTimeout: Boolean = false
41+
) : TestRule {
42+
43+
init {
44+
require(testTimeoutMs > 0) { "Expected positive test timeout, but had $testTimeoutMs" }
45+
}
46+
47+
companion object {
48+
/**
49+
* Creates [CoroutinesTimeout] rule with the given timeout in seconds.
50+
*/
51+
public fun seconds(seconds: Int, cancelOnTimeout: Boolean = false): CoroutinesTimeout =
52+
CoroutinesTimeout(TimeUnit.SECONDS.toMillis(seconds.toLong()), cancelOnTimeout)
53+
}
54+
55+
/**
56+
* @suppress suppress from Dokka
57+
*/
58+
override fun apply(base: Statement, description: Description): Statement =
59+
CoroutinesTimeoutStatement(base, description, testTimeoutMs, cancelOnTimeout)
60+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,89 @@
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.debug.junit4
6+
7+
import kotlinx.coroutines.debug.*
8+
import org.junit.runner.*
9+
import org.junit.runners.model.*
10+
import java.util.concurrent.*
11+
12+
internal class CoroutinesTimeoutStatement(
13+
testStatement: Statement,
14+
private val testDescription: Description,
15+
private val testTimeoutMs: Long,
16+
private val cancelOnTimeout: Boolean = false
17+
) : Statement() {
18+
19+
private val testStartedLatch = CountDownLatch(1)
20+
21+
private val testResult = FutureTask<Unit> {
22+
testStartedLatch.countDown()
23+
testStatement.evaluate()
24+
}
25+
26+
/*
27+
* We are using hand-rolled thread instead of single thread executor
28+
* in order to be able to safely interrupt thread in the end of a test
29+
*/
30+
private val testThread = Thread(testResult, "Timeout test thread").apply { isDaemon = true }
31+
32+
override fun evaluate() {
33+
DebugProbes.install()
34+
testThread.start()
35+
// Await until test is started to take only test execution time into account
36+
testStartedLatch.await()
37+
try {
38+
testResult.get(testTimeoutMs, TimeUnit.MILLISECONDS)
39+
return
40+
} catch (e: TimeoutException) {
41+
handleTimeout(testDescription)
42+
} catch (e: ExecutionException) {
43+
throw e.cause ?: e
44+
} finally {
45+
DebugProbes.uninstall()
46+
}
47+
}
48+
49+
private fun handleTimeout(description: Description) {
50+
val units =
51+
if (testTimeoutMs % 1000 == 0L)
52+
"${testTimeoutMs / 1000} seconds"
53+
else "$testTimeoutMs milliseconds"
54+
55+
val message = "Test ${description.methodName} timed out after $units"
56+
System.err.println("\n$message\n")
57+
System.err.flush()
58+
59+
DebugProbes.dumpCoroutines()
60+
System.out.flush() // Synchronize serr/sout
61+
62+
/*
63+
* Order is important:
64+
* 1) Create exception with a stacktrace of hang test
65+
* 2) Cancel all coroutines via debug agent API (changing system state!)
66+
* 3) Throw created exception
67+
*/
68+
val exception = createTimeoutException(message, testThread)
69+
cancelIfNecessary()
70+
// If timed out test throws an exception, we can't do much except ignoring it
71+
throw exception
72+
}
73+
74+
private fun cancelIfNecessary() {
75+
if (cancelOnTimeout) {
76+
DebugProbes.dumpCoroutinesState().forEach {
77+
it.jobOrNull?.cancel()
78+
}
79+
}
80+
}
81+
82+
private fun createTimeoutException(message: String, thread: Thread): Exception {
83+
val stackTrace = thread.stackTrace
84+
val exception = TestTimedOutException(testTimeoutMs, TimeUnit.MILLISECONDS)
85+
exception.stackTrace = stackTrace
86+
thread.interrupt()
87+
return exception
88+
}
89+
}

kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt

+5-4
Original file line numberDiff line numberDiff line change
@@ -81,6 +81,7 @@ class CoroutinesDumpTest : TestBase() {
8181
fun testRunningCoroutineWithSuspensionPoint() = synchronized(monitor) {
8282
val deferred = GlobalScope.async {
8383
activeMethod(shouldSuspend = true)
84+
yield() // tail-call
8485
}
8586

8687
awaitCoroutineStarted()
@@ -143,11 +144,11 @@ class CoroutinesDumpTest : TestBase() {
143144

144145
private suspend fun activeMethod(shouldSuspend: Boolean) {
145146
nestedActiveMethod(shouldSuspend)
146-
delay(1)
147+
assertTrue(true) // tail-call
147148
}
148149

149150
private suspend fun nestedActiveMethod(shouldSuspend: Boolean) {
150-
if (shouldSuspend) delay(1)
151+
if (shouldSuspend) yield()
151152
notifyTest()
152153
while (coroutineContext[Job]!!.isActive) {
153154
Thread.sleep(100)
@@ -156,11 +157,11 @@ class CoroutinesDumpTest : TestBase() {
156157

157158
private suspend fun sleepingOuterMethod() {
158159
sleepingNestedMethod()
159-
delay(1)
160+
yield()
160161
}
161162

162163
private suspend fun sleepingNestedMethod() {
163-
delay(1)
164+
yield()
164165
notifyTest()
165166
delay(Long.MAX_VALUE)
166167
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,42 @@
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+
import kotlinx.coroutines.*
6+
import kotlinx.coroutines.debug.junit4.*
7+
import org.junit.*
8+
9+
@Ignore // do not run it on CI
10+
class TestRuleExample {
11+
12+
@JvmField
13+
@Rule
14+
public val timeout = CoroutinesTimeout.seconds(1)
15+
16+
private suspend fun someFunctionDeepInTheStack() {
17+
withContext(Dispatchers.IO) {
18+
delay(Long.MAX_VALUE)
19+
println("This line is never executed")
20+
}
21+
22+
println("This line is never executed as well")
23+
}
24+
25+
@Test
26+
fun hangingTest() = runBlocking {
27+
val job = launch {
28+
someFunctionDeepInTheStack()
29+
}
30+
31+
println("Doing some work...")
32+
job.join()
33+
}
34+
35+
@Test
36+
fun successfulTest() = runBlocking {
37+
launch {
38+
delay(10)
39+
}.join()
40+
}
41+
42+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,56 @@
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.debug.junit4
6+
7+
import junit4.*
8+
import kotlinx.coroutines.*
9+
import org.junit.*
10+
import org.junit.runners.model.*
11+
12+
class CoroutinesTimeoutTest : TestBase() {
13+
14+
@Rule
15+
@JvmField
16+
public val validation = TestFailureValidation(
17+
1000, false,
18+
TestResultSpec("throwingTest", error = RuntimeException::class.java),
19+
TestResultSpec("successfulTest"),
20+
TestResultSpec(
21+
"hangingTest", expectedOutParts = listOf(
22+
"Coroutines dump",
23+
"Test hangingTest timed out after 1 seconds",
24+
"BlockingCoroutine{Active}",
25+
"runBlocking",
26+
"at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutTest.suspendForever",
27+
"at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutTest\$hangingTest\$1.invokeSuspend"),
28+
notExpectedOutParts = listOf("delay", "throwingTest"),
29+
error = TestTimedOutException::class.java)
30+
)
31+
32+
@Test
33+
fun hangingTest() = runBlocking<Unit> {
34+
suspendForever()
35+
expectUnreached()
36+
}
37+
38+
private suspend fun suspendForever() {
39+
delay(Long.MAX_VALUE)
40+
expectUnreached()
41+
}
42+
43+
@Test
44+
fun throwingTest() = runBlocking<Unit> {
45+
throw RuntimeException()
46+
}
47+
48+
@Test
49+
fun successfulTest() = runBlocking {
50+
val job = launch {
51+
yield()
52+
}
53+
54+
job.join()
55+
}
56+
}

0 commit comments

Comments
 (0)