CoroutinesTimeout debug rule for JUnit 4

README.md

@@ -39,6 +39,7 @@ GlobalScope.launch {
   * `Dispatchers.setMain` to override `Dispatchers.Main` in tests.
 * [debug](kotlinx-coroutines-debug/README.md) — debug utilities for coroutines.
   * `DebugProbes` API to probe, keep track of, print and dump active coroutines.
+  * `CoroutinesTimeout` test rule to automatically dump coroutines on test timeout.
 * [reactive](reactive/README.md) — modules that provide builders and iteration support for various reactive streams libraries:
   * Reactive Streams, RxJava 2.x, and Project Reactor. 
 * [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

@@ -38,3 +38,15 @@ public final class kotlinx/coroutines/debug/State : java/lang/Enum {
 	public static fun values ()[Lkotlinx/coroutines/debug/State;
 }
 
+public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout : org/junit/rules/TestRule {
+	public static final field Companion Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;
+	public fun <init> (JZ)V
+	public synthetic fun <init> (JZILkotlin/jvm/internal/DefaultConstructorMarker;)V
+	public fun apply (Lorg/junit/runners/model/Statement;Lorg/junit/runner/Description;)Lorg/junit/runners/model/Statement;
+}
+
+public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion {
+	public final fun seconds (IZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout;
+	public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;IZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout;
+}
+

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

@@ -14,7 +14,7 @@ fun main() = runBlocking<Unit> {
         println("The answer is ${concurrentSum()}")
     }
     println("Completed in $time ms")
-//sampleEnd    
+//sampleEnd
 }
 
 suspend fun concurrentSum(): Int = coroutineScope {

kotlinx-coroutines-debug/README.md

@@ -22,6 +22,38 @@ dependencies {
 }
 ```
 
+### Using in unit tests
+
+For JUnit4 debug module provides special test rule, [CoroutinesTimeout], for installing debug probes
+and to dump coroutines on timeout to simplify tests debugging.
+
+Its usage is better demonstrated by the example (runnable code is [here](test/TestRuleExample.kt)):
+
+```kotlin
+class TestRuleExample {
+    @Rule
+    @JvmField
+    public val timeout = CoroutinesTimeout.seconds(1)
+
+    private suspend fun someFunctionDeepInTheStack() {
+        withContext(Dispatchers.IO) {
+            delay(Long.MAX_VALUE) // Hang method
+        }  
+    }
+
+    @Test
+    fun hangingTest() = runBlocking {
+        val job = launch {
+            someFunctionDeepInTheStack()
+        }
+        job.join() // Join will hang
+    }
+}
+```
+
+After 1 second, test will fail with `TestTimeoutException` and all coroutines (`runBlocking` and `launch`) and their
+stacktraces will be dumped to the console.
+
 ### Using as JVM agent
 
 It is possible to use this module as a standalone JVM agent to enable debug probes on the application startup.
@@ -112,4 +144,6 @@ Do not use this module in production environment and do not rely on the format o
 [DebugProbes.dumpCoroutinesState]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/dump-coroutines-state.html
 [DebugProbes.printJob]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-job.html
 [DebugProbes.printScope]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-scope.html
+<!--- INDEX kotlinx.coroutines.debug.junit4 -->
+[CoroutinesTimeout]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug.junit4/-coroutines-timeout/index.html
 <!--- END -->

kotlinx-coroutines-debug/build.gradle

@@ -5,6 +5,7 @@
 apply plugin: "com.github.johnrengelman.shadow"
 
 dependencies {
+    compileOnly "junit:junit:$junit_version"
     compile "net.bytebuddy:byte-buddy:$byte_buddy_version"
     compile "net.bytebuddy:byte-buddy-agent:$byte_buddy_version"
 }

kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt

@@ -0,0 +1,60 @@
+/*
+ * Copyright 2016-2019 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
+ */
+
+package kotlinx.coroutines.debug.junit4
+
+import kotlinx.coroutines.debug.*
+import org.junit.rules.*
+import org.junit.runner.*
+import org.junit.runners.model.*
+import java.util.concurrent.*
+
+/**
+ * Coroutines timeout rule for JUnit4 that is applied to all methods in the class.
+ * This rule is very similar to [Timeout] rule: it runs tests in a separate thread,
+ * fails tests after the given timeout and interrupts test thread.
+ *
+ * Additionally, this rule installs [DebugProbes] and dumps all coroutines at the moment of the timeout.
+ * It may cancel coroutines on timeout if [cancelOnTimeout] set to `true`.
+ *
+ * Example of usage:
+ * ```
+ * class HangingTest {
+ *
+ *   @Rule
+ *   @JvmField
+ *   val timeout = CoroutinesTimeout.seconds(5)
+ *
+ *   @Test
+ *   fun testThatHangs() = runBlocking {
+ *     ...
+ *     delay(Long.MAX_VALUE) // somewhere deep in the stack
+ *     ...
+ *   }
+ * }
+ * ```
+ */
+public class CoroutinesTimeout(
+    private val testTimeoutMs: Long,
+    private val cancelOnTimeout: Boolean = false
+) : TestRule {
+
+    init {
+        require(testTimeoutMs > 0) { "Expected positive test timeout, but had $testTimeoutMs" }
+    }
+
+    companion object {
+        /**
+         * Creates [CoroutinesTimeout] rule with the given timeout in seconds.
+         */
+        public fun seconds(seconds: Int, cancelOnTimeout: Boolean = false): CoroutinesTimeout =
+            CoroutinesTimeout(TimeUnit.SECONDS.toMillis(seconds.toLong()), cancelOnTimeout)
+    }
+
+    /**
+     * @suppress suppress from Dokka
+     */
+    override fun apply(base: Statement, description: Description): Statement =
+        CoroutinesTimeoutStatement(base, description, testTimeoutMs, cancelOnTimeout)
+}

kotlinx-coroutines-debug/src/junit4/CoroutinesTimeoutStatement.kt

@@ -0,0 +1,89 @@
+/*
+ * Copyright 2016-2019 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
+ */
+
+package kotlinx.coroutines.debug.junit4
+
+import kotlinx.coroutines.debug.*
+import org.junit.runner.*
+import org.junit.runners.model.*
+import java.util.concurrent.*
+
+internal class CoroutinesTimeoutStatement(
+    testStatement: Statement,
+    private val testDescription: Description,
+    private val testTimeoutMs: Long,
+    private val cancelOnTimeout: Boolean = false
+) : Statement() {
+
+    private val testStartedLatch = CountDownLatch(1)
+
+    private val testResult = FutureTask<Unit> {
+        testStartedLatch.countDown()
+        testStatement.evaluate()
+    }
+
+    /*
+     * We are using hand-rolled thread instead of single thread executor
+     * in order to be able to safely interrupt thread in the end of a test
+     */
+    private val testThread =  Thread(testResult, "Timeout test thread").apply { isDaemon = true }
+
+    override fun evaluate() {
+        DebugProbes.install()
+        testThread.start()
+        // Await until test is started to take only test execution time into account
+        testStartedLatch.await()
+        try {
+            testResult.get(testTimeoutMs, TimeUnit.MILLISECONDS)
+            return
+        } catch (e: TimeoutException) {
+            handleTimeout(testDescription)
+        } catch (e: ExecutionException) {
+            throw e.cause ?: e
+        } finally {
+            DebugProbes.uninstall()
+        }
+    }
+
+    private fun handleTimeout(description: Description) {
+        val units =
+            if (testTimeoutMs % 1000 == 0L)
+                "${testTimeoutMs / 1000} seconds"
+            else "$testTimeoutMs milliseconds"
+
+        val message = "Test ${description.methodName} timed out after $units"
+        System.err.println("\n$message\n")
+        System.err.flush()
+
+        DebugProbes.dumpCoroutines()
+        System.out.flush() // Synchronize serr/sout
+
+        /*
+         * Order is important:
+         * 1) Create exception with a stacktrace of hang test
+         * 2) Cancel all coroutines via debug agent API (changing system state!)
+         * 3) Throw created exception
+         */
+        val exception = createTimeoutException(message, testThread)
+        cancelIfNecessary()
+        // If timed out test throws an exception, we can't do much except ignoring it
+        throw exception
+    }
+
+    private fun cancelIfNecessary() {
+        if (cancelOnTimeout) {
+            DebugProbes.dumpCoroutinesState().forEach {
+                it.jobOrNull?.cancel()
+            }
+        }
+    }
+
+    private fun createTimeoutException(message: String, thread: Thread): Exception {
+        val stackTrace = thread.stackTrace
+        val exception = TestTimedOutException(testTimeoutMs, TimeUnit.MILLISECONDS)
+        exception.stackTrace = stackTrace
+        thread.interrupt()
+        return exception
+    }
+}

kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt

@@ -81,6 +81,7 @@ class CoroutinesDumpTest : TestBase() {
     fun testRunningCoroutineWithSuspensionPoint() = synchronized(monitor) {
         val deferred = GlobalScope.async {
             activeMethod(shouldSuspend = true)
+            yield() // tail-call
         }
 
         awaitCoroutineStarted()
@@ -143,11 +144,11 @@ class CoroutinesDumpTest : TestBase() {
 
     private suspend fun activeMethod(shouldSuspend: Boolean) {
         nestedActiveMethod(shouldSuspend)
-        delay(1)
+        assertTrue(true) // tail-call
     }
 
     private suspend fun nestedActiveMethod(shouldSuspend: Boolean) {
-        if (shouldSuspend) delay(1)
+        if (shouldSuspend) yield()
         notifyTest()
         while (coroutineContext[Job]!!.isActive) {
             Thread.sleep(100)
@@ -156,11 +157,11 @@ class CoroutinesDumpTest : TestBase() {
 
     private suspend fun sleepingOuterMethod() {
         sleepingNestedMethod()
-        delay(1)
+        yield()
     }
 
     private suspend fun sleepingNestedMethod() {
-        delay(1)
+        yield()
         notifyTest()
         delay(Long.MAX_VALUE)
     }

kotlinx-coroutines-debug/test/TestRuleExample.kt

@@ -0,0 +1,42 @@
+/*
+ * Copyright 2016-2019 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
+ */
+
+import kotlinx.coroutines.*
+import kotlinx.coroutines.debug.junit4.*
+import org.junit.*
+
+@Ignore // do not run it on CI
+class TestRuleExample {
+
+    @JvmField
+    @Rule
+    public val timeout = CoroutinesTimeout.seconds(1)
+
+    private suspend fun someFunctionDeepInTheStack() {
+        withContext(Dispatchers.IO) {
+            delay(Long.MAX_VALUE)
+            println("This line is never executed")
+        }
+
+        println("This line is never executed as well")
+    }
+
+    @Test
+    fun hangingTest() = runBlocking {
+        val job = launch {
+            someFunctionDeepInTheStack()
+        }
+
+        println("Doing some work...")
+        job.join()
+    }
+
+    @Test
+    fun successfulTest() = runBlocking {
+        launch {
+            delay(10)
+        }.join()
+    }
+
+}

kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt

@@ -0,0 +1,56 @@
+/*
+ * Copyright 2016-2019 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
+ */
+
+package kotlinx.coroutines.debug.junit4
+
+import junit4.*
+import kotlinx.coroutines.*
+import org.junit.*
+import org.junit.runners.model.*
+
+class CoroutinesTimeoutTest : TestBase() {
+
+    @Rule
+    @JvmField
+    public val validation = TestFailureValidation(
+        1000, false,
+        TestResultSpec("throwingTest", error = RuntimeException::class.java),
+        TestResultSpec("successfulTest"),
+        TestResultSpec(
+            "hangingTest", expectedOutParts = listOf(
+                "Coroutines dump",
+                "Test hangingTest timed out after 1 seconds",
+                "BlockingCoroutine{Active}",
+                "runBlocking",
+                "at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutTest.suspendForever",
+                "at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutTest\$hangingTest\$1.invokeSuspend"),
+            notExpectedOutParts = listOf("delay", "throwingTest"),
+            error = TestTimedOutException::class.java)
+    )
+
+    @Test
+    fun hangingTest() = runBlocking<Unit> {
+        suspendForever()
+        expectUnreached()
+    }
+
+    private suspend fun suspendForever() {
+        delay(Long.MAX_VALUE)
+        expectUnreached()
+    }
+
+    @Test
+    fun throwingTest() = runBlocking<Unit> {
+        throw RuntimeException()
+    }
+
+    @Test
+    fun successfulTest() = runBlocking {
+        val job = launch {
+            yield()
+        }
+
+        job.join()
+    }
+}