From 780860f04125e32f14ec871b3a4997e6197be4dd Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Fri, 27 Jan 2023 15:57:59 +0100 Subject: [PATCH 01/11] Allow specifying the timeout for `runTest` Deprecate `dispatchTimeoutMs`, as this is a confusing implementation detail that made it to the final API. We use the fact that the `runTest(Duration)` overload was never published, so we can reuse it to have the `Duration` mean the whole-test timeout in a backward-compatible manner. --- .../api/kotlinx-coroutines-test.api | 9 +- .../common/src/TestBuilders.kt | 231 ++++++++++++------ .../common/src/TestCoroutineDispatchers.kt | 1 - .../common/src/TestCoroutineScheduler.kt | 31 ++- .../common/src/TestDispatcher.kt | 2 - .../common/src/TestScope.kt | 4 - .../common/test/RunTestTest.kt | 7 +- .../js/src/TestBuilders.kt | 7 + .../jvm/src/TestBuildersJvm.kt | 19 ++ .../src/migration/TestBuildersDeprecated.kt | 2 +- .../jvm/test/MultithreadingTest.kt | 22 +- .../native/src/TestBuilders.kt | 10 + 12 files changed, 242 insertions(+), 103 deletions(-) diff --git a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api index 53aa355c5b..e132de2fd0 100644 --- a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api +++ b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api @@ -22,10 +22,10 @@ public final class kotlinx/coroutines/test/TestBuildersKt { public static final fun runTest (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;)V public static synthetic fun runTest$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V public static synthetic fun runTest$default (Lkotlinx/coroutines/test/TestCoroutineScope;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V - public static synthetic fun runTest$default (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V - public static final fun runTest-8Mi8wO0 (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;)V - public static final fun runTest-8Mi8wO0 (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;)V - public static synthetic fun runTest-8Mi8wO0$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V + public static final fun runTest-Kx4hsE0 (Lkotlin/coroutines/CoroutineContext;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;)V + public static final fun runTest-Kx4hsE0 (Lkotlinx/coroutines/test/TestScope;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;)V + public static synthetic fun runTest-Kx4hsE0$default (Lkotlin/coroutines/CoroutineContext;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;ILjava/lang/Object;)V + public static synthetic fun runTest-Kx4hsE0$default (Lkotlinx/coroutines/test/TestScope;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;ILjava/lang/Object;)V public static final fun runTestWithLegacyScope (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;)V public static synthetic fun runTestWithLegacyScope$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V } @@ -66,6 +66,7 @@ public final class kotlinx/coroutines/test/TestCoroutineScheduler : kotlin/corou public static final field Key Lkotlinx/coroutines/test/TestCoroutineScheduler$Key; public fun ()V public final fun advanceTimeBy (J)V + public final fun advanceTimeBy-LRDsOJo (J)V public final fun advanceUntilIdle ()V public final fun getCurrentTime ()J public final fun getTimeSource ()Lkotlin/time/TimeSource; diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index e9d8fec0d3..40849fd353 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -7,11 +7,13 @@ package kotlinx.coroutines.test import kotlinx.coroutines.* +import kotlinx.coroutines.flow.* import kotlinx.coroutines.selects.* import kotlin.coroutines.* import kotlin.jvm.* import kotlin.time.* import kotlin.time.Duration.Companion.milliseconds +import kotlin.time.Duration.Companion.seconds /** * A test result. @@ -29,7 +31,6 @@ import kotlin.time.Duration.Companion.milliseconds * * Don't nest functions returning a [TestResult]. */ @Suppress("NO_ACTUAL_FOR_EXPECT") -@ExperimentalCoroutinesApi public expect class TestResult /** @@ -118,6 +119,12 @@ public expect class TestResult * * If the created coroutine completes with an exception, then this exception will be thrown at the end of the test. * + * #### Timing out + * + * There's a built-in timeout of 10 seconds for the test body. If the test body doesn't complete within this time, + * then the test fails with an [UncompletedCoroutinesError]. The timeout can be changed by setting the [timeout] + * parameter. + * * #### Reported exceptions * * Unhandled exceptions will be thrown at the end of the test. @@ -131,12 +138,6 @@ public expect class TestResult * Otherwise, the test will be failed (which, on JVM and Native, means that [runTest] itself will throw * [AssertionError], whereas on JS, the `Promise` will fail with it). * - * In the general case, if there are active jobs, it's impossible to detect if they are going to complete eventually due - * to the asynchronous nature of coroutines. In order to prevent tests hanging in this scenario, [runTest] will wait - * for [dispatchTimeout] (by default, 60 seconds) from the moment when [TestCoroutineScheduler] becomes - * idle before throwing [AssertionError]. If some dispatcher linked to [TestCoroutineScheduler] receives a - * task during that time, the timer gets reset. - * * ### Configuration * * [context] can be used to affect the environment of the code under test. Beside just being passed to the coroutine @@ -148,12 +149,12 @@ public expect class TestResult @ExperimentalCoroutinesApi public fun runTest( context: CoroutineContext = EmptyCoroutineContext, - dispatchTimeout: Duration = DEFAULT_DISPATCH_TIMEOUT, + timeout: Duration? = null, testBody: suspend TestScope.() -> Unit ): TestResult { if (context[RunningInRunTest] != null) throw IllegalStateException("Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details.") - return TestScope(context + RunningInRunTest).runTest(dispatchTimeout, testBody) + return TestScope(context + RunningInRunTest).runTest(timeout, testBody) } /** @@ -270,27 +271,33 @@ public fun runTest( * @throws IllegalArgumentException if the [context] is invalid. See the [TestScope] constructor docs for details. */ @ExperimentalCoroutinesApi +@Deprecated( + "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", + ReplaceWith("runTest(context, timeout = with(kotlin.time.Duration.Companion) { dispatchTimeoutMs.milliseconds }, testBody)"), + DeprecationLevel.WARNING +) public fun runTest( context: CoroutineContext = EmptyCoroutineContext, dispatchTimeoutMs: Long, testBody: suspend TestScope.() -> Unit -): TestResult = runTest( - context = context, - dispatchTimeout = dispatchTimeoutMs.milliseconds, - testBody = testBody -) +): TestResult { + if (context[RunningInRunTest] != null) + throw IllegalStateException("Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details.") + @Suppress("DEPRECATION") + return TestScope(context + RunningInRunTest).runTest(dispatchTimeoutMs = dispatchTimeoutMs, testBody) +} /** * Performs [runTest] on an existing [TestScope]. */ -@ExperimentalCoroutinesApi public fun TestScope.runTest( - dispatchTimeout: Duration, + timeout: Duration? = null, testBody: suspend TestScope.() -> Unit ): TestResult = asSpecificImplementation().let { it.enter() createTestResult { - runTestCoroutine(it, dispatchTimeout, TestScopeImpl::tryGetCompletionCause, testBody) { + runTestCoroutine(it, null, timeout, TestScopeImpl::tryGetCompletionCause, testBody) { backgroundScope.cancel() testScheduler.advanceUntilIdleOr { false } it.leave() @@ -300,15 +307,33 @@ public fun TestScope.runTest( /** * Performs [runTest] on an existing [TestScope]. + * + * In the general case, if there are active jobs, it's impossible to detect if they are going to complete eventually due + * to the asynchronous nature of coroutines. In order to prevent tests hanging in this scenario, [runTest] will wait + * for [dispatchTimeoutMs] from the moment when [TestCoroutineScheduler] becomes + * idle before throwing [AssertionError]. If some dispatcher linked to [TestCoroutineScheduler] receives a + * task during that time, the timer gets reset. */ @ExperimentalCoroutinesApi +@Deprecated( + "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", + ReplaceWith("this.runTest(timeout = with(kotlin.time.Duration.Companion) { dispatchTimeoutMs.milliseconds }, testBody)"), + DeprecationLevel.WARNING +) public fun TestScope.runTest( - dispatchTimeoutMs: Long = DEFAULT_DISPATCH_TIMEOUT_MS, + dispatchTimeoutMs: Long, testBody: suspend TestScope.() -> Unit -): TestResult = runTest( - dispatchTimeout = dispatchTimeoutMs.milliseconds, - testBody = testBody -) +): TestResult = asSpecificImplementation().let { + it.enter() + createTestResult { + runTestCoroutine(it, dispatchTimeoutMs.milliseconds, null, TestScopeImpl::tryGetCompletionCause, testBody) { + backgroundScope.cancel() + testScheduler.advanceUntilIdleOr { false } + it.leave() + } + } +} /** * Runs [testProcedure], creating a [TestResult]. @@ -327,20 +352,26 @@ internal object RunningInRunTest : CoroutineContext.Key, Corou /** The default timeout to use when waiting for asynchronous completions of the coroutines managed by * a [TestCoroutineScheduler]. */ internal const val DEFAULT_DISPATCH_TIMEOUT_MS = 60_000L -internal val DEFAULT_DISPATCH_TIMEOUT = DEFAULT_DISPATCH_TIMEOUT_MS.milliseconds + +/** + * The default timeout to use when running a test. + */ +internal val DEFAULT_TIMEOUT = 10.seconds /** * Run the [body][testBody] of the [test coroutine][coroutine], waiting for asynchronous completions for at most - * [dispatchTimeout], and performing the [cleanup] procedure at the end. + * [dispatchTimeout], allowing the total runtime of a test of at most [testTimeout], + * and performing the [cleanup] procedure at the end. * * [tryGetCompletionCause] is the [JobSupport.completionCause], which is passed explicitly because it is protected. * * The [cleanup] procedure may either throw [UncompletedCoroutinesError] to denote that child coroutines were leaked, or * return a list of uncaught exceptions that should be reported at the end of the test. */ -internal suspend fun > CoroutineScope.runTestCoroutine( +internal suspend fun > CoroutineScope.runTestCoroutine( coroutine: T, - dispatchTimeout: Duration, + dispatchTimeout: Duration?, + testTimeout: Duration?, tryGetCompletionCause: T.() -> Throwable?, testBody: suspend T.() -> Unit, cleanup: () -> List, @@ -350,59 +381,104 @@ internal suspend fun > CoroutineScope.runTestCoroutin coroutine.start(CoroutineStart.UNDISPATCHED, coroutine) { testBody() } - /** - * The general procedure here is as follows: - * 1. Try running the work that the scheduler knows about, both background and foreground. - * - * 2. Wait until we run out of foreground work to do. This could mean one of the following: - * * The main coroutine is already completed. This is checked separately; then we leave the procedure. - * * It's switched to another dispatcher that doesn't know about the [TestCoroutineScheduler]. - * * Generally, it's waiting for something external (like a network request, or just an arbitrary callback). - * * The test simply hanged. - * * The main coroutine is waiting for some background work. - * - * 3. We await progress from things that are not the code under test: - * the background work that the scheduler knows about, the external callbacks, - * the work on dispatchers not linked to the scheduler, etc. - * - * When we observe that the code under test can proceed, we go to step 1 again. - * If there is no activity for [dispatchTimeoutMs] milliseconds, we consider the test to have hanged. - * - * The background work is not running on a dedicated thread. - * Instead, the test thread itself is used, by spawning a separate coroutine. - */ - var completed = false - while (!completed) { - scheduler.advanceUntilIdle() - if (coroutine.isCompleted) { - /* don't even enter `withTimeout`; this allows to use a timeout of zero to check that there are no + if (dispatchTimeout != null) { + require(testTimeout == null) { "Only one of dispatchTimeout and testTimeout can be specified" } + /** + * This is the legacy behavior, kept for now for compatibility only. + * + * The general procedure here is as follows: + * 1. Try running the work that the scheduler knows about, both background and foreground. + * + * 2. Wait until we run out of foreground work to do. This could mean one of the following: + * * The main coroutine is already completed. This is checked separately; then we leave the procedure. + * * It's switched to another dispatcher that doesn't know about the [TestCoroutineScheduler]. + * * Generally, it's waiting for something external (like a network request, or just an arbitrary callback). + * * The test simply hanged. + * * The main coroutine is waiting for some background work. + * + * 3. We await progress from things that are not the code under test: + * the background work that the scheduler knows about, the external callbacks, + * the work on dispatchers not linked to the scheduler, etc. + * + * When we observe that the code under test can proceed, we go to step 1 again. + * If there is no activity for [dispatchTimeoutMs] milliseconds, we consider the test to have hanged. + * + * The background work is not running on a dedicated thread. + * Instead, the test thread itself is used, by spawning a separate coroutine. + */ + var completed = false + while (!completed) { + scheduler.advanceUntilIdle() + if (coroutine.isCompleted) { + /* don't even enter `withTimeout`; this allows to use a timeout of zero to check that there are no non-trivial dispatches. */ - completed = true - continue + completed = true + continue + } + // in case progress depends on some background work, we need to keep spinning it. + val backgroundWorkRunner = launch(CoroutineName("background work runner")) { + while (true) { + val executedSomething = scheduler.tryRunNextTaskUnless { !isActive } + if (executedSomething) { + // yield so that the `select` below has a chance to finish successfully or time out + yield() + } else { + // no more tasks, we should suspend until there are some more. + // this doesn't interfere with the `select` below, because different channels are used. + scheduler.receiveDispatchEvent() + } + } + } + try { + select { + coroutine.onJoin { + // observe that someone completed the test coroutine and leave without waiting for the timeout + completed = true + } + scheduler.onDispatchEventForeground { + // we received knowledge that `scheduler` observed a dispatch event, so we reset the timeout + } + onTimeout(dispatchTimeout) { + handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup)?.let { throw it } + } + } + } finally { + backgroundWorkRunner.cancelAndJoin() + } } - // in case progress depends on some background work, we need to keep spinning it. - val backgroundWorkRunner = launch(CoroutineName("background work runner")) { + } else { + val lastKnownPosition = MutableStateFlow(null) + /** + * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, + * but on the JVM and Native, this means that the timeout can be processed even while the test runner is busy + * doing some synchronous work. + */ + val workRunner = launch(Dispatchers.Default + CoroutineName("kotlinx.coroutines.test runner")) { while (true) { - scheduler.tryRunNextTaskUnless { !isActive } - // yield so that the `select` below has a chance to check if its conditions are fulfilled - yield() + lastKnownPosition.value = getLastKnownPosition() + val executedSomething = scheduler.tryRunNextTaskUnless { !isActive } + if (executedSomething) { + // yield to check for cancellation + yield() + } else { + // no more tasks, we should suspend until there are some more + scheduler.receiveDispatchEvent() + } } } + val timeout = testTimeout ?: DEFAULT_TIMEOUT try { - select { - coroutine.onJoin { - // observe that someone completed the test coroutine and leave without waiting for the timeout - completed = true - } - scheduler.onDispatchEvent { - // we received knowledge that `scheduler` observed a dispatch event, so we reset the timeout - } - onTimeout(dispatchTimeout) { - handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup) - } + withTimeout(timeout) { + coroutine.join() + } + } catch (_: TimeoutCancellationException) { + val exception = handleTimeout(coroutine, timeout, tryGetCompletionCause, cleanup) + exception?.let { + dumpCoroutinesAndThrow(it, lastKnownPosition.value) } } finally { - backgroundWorkRunner.cancelAndJoin() + coroutine.cancelAndJoin() + workRunner.cancelAndJoin() } } coroutine.getCompletionExceptionOrNull()?.let { exception -> @@ -421,12 +497,12 @@ internal suspend fun > CoroutineScope.runTestCoroutin * Invoked on timeout in [runTest]. Almost always just builds a nice [UncompletedCoroutinesError] and throws it. * However, sometimes it detects that the coroutine completed, in which case it returns normally. */ -private inline fun> handleTimeout( +private inline fun > handleTimeout( coroutine: T, dispatchTimeout: Duration, tryGetCompletionCause: T.() -> Throwable?, cleanup: () -> List, -) { +): AssertionError? { val uncaughtExceptions = try { cleanup() } catch (e: UncompletedCoroutinesError) { @@ -442,14 +518,14 @@ private inline fun> handleTimeout( message += ", there were active child jobs: $activeChildren" if (completionCause != null && activeChildren.isEmpty()) { if (coroutine.isCompleted) - return + return null // TODO: can this really ever happen? message += ", the test coroutine was not completed" } val error = UncompletedCoroutinesError(message) completionCause?.let { cause -> error.addSuppressed(cause) } uncaughtExceptions.forEach { error.addSuppressed(it) } - throw error + return error } internal fun List.throwAll() { @@ -458,3 +534,8 @@ internal fun List.throwAll() { throw this } } + +internal expect fun getLastKnownPosition(): Any? + + +internal expect fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt b/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt index e99fe8b124..3777cd26f8 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt @@ -137,7 +137,6 @@ private class UnconfinedTestDispatcherImpl( * * @see UnconfinedTestDispatcher for a dispatcher that is not confined to any particular thread. */ -@ExperimentalCoroutinesApi @Suppress("FunctionName") public fun StandardTestDispatcher( scheduler: TestCoroutineScheduler? = null, diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt index 5f7198cfff..38abe54e08 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt @@ -26,7 +26,6 @@ import kotlin.time.* * virtual time as needed (via [advanceUntilIdle]), or run the tasks that are scheduled to run as soon as possible but * haven't yet been dispatched (via [runCurrent]). */ -@ExperimentalCoroutinesApi public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCoroutineScheduler), CoroutineContext.Element { @@ -49,6 +48,9 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout get() = synchronized(lock) { field } private set + /** A channel for notifying about the fact that a foreground work dispatch recently happened. */ + private val dispatchEventsForeground: Channel = Channel(CONFLATED) + /** A channel for notifying about the fact that a dispatch recently happened. */ private val dispatchEvents: Channel = Channel(CONFLATED) @@ -73,8 +75,8 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout val time = addClamping(currentTime, timeDeltaMillis) val event = TestDispatchEvent(dispatcher, count, time, marker as Any, isForeground) { isCancelled(marker) } events.addLast(event) - /** can't be moved above: otherwise, [onDispatchEvent] could consume the token sent here before there's - * actually anything in the event queue. */ + /** can't be moved above: otherwise, [onDispatchEventForeground] or [receiveDispatchEvent] could consume the + * token sent here before there's actually anything in the event queue. */ sendDispatchEvent(context) DisposableHandle { synchronized(lock) { @@ -109,7 +111,6 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * milliseconds by which the execution of this method has advanced the virtual time. If you want to recreate that * functionality, query [currentTime] before and after the execution to achieve the same result. */ - @ExperimentalCoroutinesApi public fun advanceUntilIdle(): Unit = advanceUntilIdleOr { events.none(TestDispatchEvent<*>::isForeground) } /** @@ -125,7 +126,6 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout /** * Runs the tasks that are scheduled to execute at this moment of virtual time. */ - @ExperimentalCoroutinesApi public fun runCurrent() { val timeMark = synchronized(lock) { currentTime } while (true) { @@ -177,6 +177,14 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout } } + /** + * Moves the virtual clock of this dispatcher forward by [the specified amount][delayTime], running the + * scheduled tasks in the meantime. + * + * @throws IllegalStateException if passed a negative [delay][delayTime]. + */ + public fun advanceTimeBy(delayTime: Duration): Unit = advanceTimeBy(delayTime.inWholeMicroseconds) + /** * Checks that the only tasks remaining in the scheduler are cancelled. */ @@ -191,19 +199,24 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * [context] is the context in which the task will be dispatched. */ internal fun sendDispatchEvent(context: CoroutineContext) { + dispatchEvents.trySend(Unit) if (context[BackgroundWork] !== BackgroundWork) - dispatchEvents.trySend(Unit) + dispatchEventsForeground.trySend(Unit) } /** - * Consumes the knowledge that a dispatch event happened recently. + * Waits for a notification about a dispatch event. + */ + internal suspend fun receiveDispatchEvent() = dispatchEvents.receive() + + /** + * Consumes the knowledge that a foreground work dispatch event happened recently. */ - internal val onDispatchEvent: SelectClause1 get() = dispatchEvents.onReceive + internal val onDispatchEventForeground: SelectClause1 get() = dispatchEventsForeground.onReceive /** * Returns the [TimeSource] representation of the virtual time of this scheduler. */ - @ExperimentalCoroutinesApi @ExperimentalTime public val timeSource: TimeSource = object : AbstractLongTimeSource(DurationUnit.MILLISECONDS) { override fun read(): Long = currentTime diff --git a/kotlinx-coroutines-test/common/src/TestDispatcher.kt b/kotlinx-coroutines-test/common/src/TestDispatcher.kt index 8ed8192b9e..33ee9334d5 100644 --- a/kotlinx-coroutines-test/common/src/TestDispatcher.kt +++ b/kotlinx-coroutines-test/common/src/TestDispatcher.kt @@ -16,10 +16,8 @@ import kotlin.jvm.* * * [UnconfinedTestDispatcher] is a dispatcher that behaves like [Dispatchers.Unconfined] while allowing to control * the virtual time. */ -@ExperimentalCoroutinesApi public abstract class TestDispatcher internal constructor() : CoroutineDispatcher(), Delay { /** The scheduler that this dispatcher is linked to. */ - @ExperimentalCoroutinesApi public abstract val scheduler: TestCoroutineScheduler /** Notifies the dispatcher that it should process a single event marked with [marker] happening at time [time]. */ diff --git a/kotlinx-coroutines-test/common/src/TestScope.kt b/kotlinx-coroutines-test/common/src/TestScope.kt index 15d48a2ae2..0a15ab2d2e 100644 --- a/kotlinx-coroutines-test/common/src/TestScope.kt +++ b/kotlinx-coroutines-test/common/src/TestScope.kt @@ -40,12 +40,10 @@ import kotlin.time.* * paused by default, like [StandardTestDispatcher]. * * No access to the list of unhandled exceptions. */ -@ExperimentalCoroutinesApi public sealed interface TestScope : CoroutineScope { /** * The delay-skipping scheduler used by the test dispatchers running the code in this scope. */ - @ExperimentalCoroutinesApi public val testScheduler: TestCoroutineScheduler /** @@ -82,7 +80,6 @@ public sealed interface TestScope : CoroutineScope { * } * ``` */ - @ExperimentalCoroutinesApi public val backgroundScope: CoroutineScope } @@ -156,7 +153,6 @@ public val TestScope.testTimeSource: TimeSource get() = testScheduler.timeSource * @throws IllegalArgumentException if [context] has an [CoroutineExceptionHandler] that is not an * [UncaughtExceptionCaptor]. */ -@ExperimentalCoroutinesApi @Suppress("FunctionName") public fun TestScope(context: CoroutineContext = EmptyCoroutineContext): TestScope { val ctxWithDispatcher = context.withDelaySkipping() diff --git a/kotlinx-coroutines-test/common/test/RunTestTest.kt b/kotlinx-coroutines-test/common/test/RunTestTest.kt index 0315543d54..6d6a01c6c6 100644 --- a/kotlinx-coroutines-test/common/test/RunTestTest.kt +++ b/kotlinx-coroutines-test/common/test/RunTestTest.kt @@ -72,7 +72,12 @@ class RunTestTest { /** Tests that too low of a dispatch timeout causes crashes. */ @Test fun testRunTestWithSmallTimeout() = testResultMap({ fn -> - assertFailsWith { fn() } + try { + fn() + fail("shouldn't be reached") + } catch (e: Throwable) { + assertIs(e) + } }) { runTest(dispatchTimeoutMs = 100) { withContext(Dispatchers.Default) { diff --git a/kotlinx-coroutines-test/js/src/TestBuilders.kt b/kotlinx-coroutines-test/js/src/TestBuilders.kt index 9da91ffc39..9b07c8ba28 100644 --- a/kotlinx-coroutines-test/js/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/js/src/TestBuilders.kt @@ -13,3 +13,10 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> GlobalScope.promise { testProcedure() } + +internal actual fun getLastKnownPosition(): Any? = null + +internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { + console.error(exception) + throw exception +} diff --git a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt index 06fbe81064..f8b7fd3d9c 100644 --- a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt +++ b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt @@ -4,6 +4,7 @@ package kotlinx.coroutines.test import kotlinx.coroutines.* +import kotlinx.coroutines.debug.internal.* @Suppress("ACTUAL_WITHOUT_EXPECT") public actual typealias TestResult = Unit @@ -13,3 +14,21 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> testProcedure() } } + +internal actual fun getLastKnownPosition(): Any? = Thread.currentThread() + +internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { + val thread = lastKnownPosition as? Thread + @Suppress("INVISIBLE_REFERENCE", "INVISIBLE_MEMBER") + if (DebugProbesImpl.isInstalled) { + DebugProbesImpl.install() + try { + DebugProbesImpl.dumpCoroutines(System.err) + System.err.flush() + } finally { + DebugProbesImpl.uninstall() + } + } + thread?.stackTrace?.let { exception.stackTrace = it } + throw exception +} diff --git a/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt b/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt index c0d6c17cb6..888895680b 100644 --- a/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt +++ b/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt @@ -165,7 +165,7 @@ public fun runTestWithLegacyScope( throw IllegalStateException("Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details.") val testScope = TestBodyCoroutine(createTestCoroutineScope(context + RunningInRunTest)) return createTestResult { - runTestCoroutine(testScope, dispatchTimeoutMs.milliseconds, TestBodyCoroutine::tryGetCompletionCause, testBody) { + runTestCoroutine(testScope, dispatchTimeoutMs.milliseconds, null, TestBodyCoroutine::tryGetCompletionCause, testBody) { try { testScope.cleanup() emptyList() diff --git a/kotlinx-coroutines-test/jvm/test/MultithreadingTest.kt b/kotlinx-coroutines-test/jvm/test/MultithreadingTest.kt index 90a16d0622..2ac577c41b 100644 --- a/kotlinx-coroutines-test/jvm/test/MultithreadingTest.kt +++ b/kotlinx-coroutines-test/jvm/test/MultithreadingTest.kt @@ -99,14 +99,24 @@ class MultithreadingTest { } } - /** Tests that [StandardTestDispatcher] is confined to the thread that interacts with the scheduler. */ + /** Tests that [StandardTestDispatcher] is not executed in-place but confined to the thread in which the + * virtual time control happens. */ @Test - fun testStandardTestDispatcherIsConfined() = runTest { + fun testStandardTestDispatcherIsConfined(): Unit = runBlocking { + val scheduler = TestCoroutineScheduler() val initialThread = Thread.currentThread() - withContext(Dispatchers.IO) { - val ioThread = Thread.currentThread() - assertNotSame(initialThread, ioThread) + val job = launch(StandardTestDispatcher(scheduler)) { + assertEquals(initialThread, Thread.currentThread()) + withContext(Dispatchers.IO) { + val ioThread = Thread.currentThread() + assertNotSame(initialThread, ioThread) + } + assertEquals(initialThread, Thread.currentThread()) + } + scheduler.advanceUntilIdle() + while (job.isActive) { + scheduler.receiveDispatchEvent() + scheduler.advanceUntilIdle() } - assertEquals(initialThread, Thread.currentThread()) } } diff --git a/kotlinx-coroutines-test/native/src/TestBuilders.kt b/kotlinx-coroutines-test/native/src/TestBuilders.kt index a959901919..b16478d101 100644 --- a/kotlinx-coroutines-test/native/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/native/src/TestBuilders.kt @@ -4,6 +4,7 @@ package kotlinx.coroutines.test import kotlinx.coroutines.* +import kotlin.native.concurrent.* @Suppress("ACTUAL_WITHOUT_EXPECT") public actual typealias TestResult = Unit @@ -13,3 +14,12 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> testProcedure() } } + +internal actual fun getLastKnownPosition(): Any? = null + +@OptIn(ExperimentalStdlibApi::class) +internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { + // log exception + processUnhandledException(exception) + throw exception +} From 38620ffe65ed320ad76c44519d03f7e54b7ddf63 Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 30 Jan 2023 15:26:30 +0100 Subject: [PATCH 02/11] ~ --- .../common/src/TestBuilders.kt | 6 ++--- .../common/src/TestCoroutineScheduler.kt | 23 ++++++++++--------- 2 files changed, 15 insertions(+), 14 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 40849fd353..644cb57a96 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -125,6 +125,9 @@ public expect class TestResult * then the test fails with an [UncompletedCoroutinesError]. The timeout can be changed by setting the [timeout] * parameter. * + * On the JVM, if `DebugProbes` from the `kotlinx-coroutines-debug` module are installed, the current dump of the + * coroutines' stack is printed to the console on timeout. + * * #### Reported exceptions * * Unhandled exceptions will be thrown at the end of the test. @@ -146,7 +149,6 @@ public expect class TestResult * * @throws IllegalArgumentException if the [context] is invalid. See the [TestScope] constructor docs for details. */ -@ExperimentalCoroutinesApi public fun runTest( context: CoroutineContext = EmptyCoroutineContext, timeout: Duration? = null, @@ -270,7 +272,6 @@ public fun runTest( * * @throws IllegalArgumentException if the [context] is invalid. See the [TestScope] constructor docs for details. */ -@ExperimentalCoroutinesApi @Deprecated( "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", @@ -314,7 +315,6 @@ public fun TestScope.runTest( * idle before throwing [AssertionError]. If some dispatcher linked to [TestCoroutineScheduler] receives a * task during that time, the timer gets reset. */ -@ExperimentalCoroutinesApi @Deprecated( "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt index 38abe54e08..8cc4915a9c 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt @@ -13,6 +13,7 @@ import kotlinx.coroutines.selects.* import kotlin.coroutines.* import kotlin.jvm.* import kotlin.time.* +import kotlin.time.Duration.Companion.milliseconds /** * This is a scheduler for coroutines used in tests, providing the delay-skipping behavior. @@ -153,10 +154,18 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * @throws IllegalStateException if passed a negative [delay][delayTimeMillis]. */ @ExperimentalCoroutinesApi - public fun advanceTimeBy(delayTimeMillis: Long) { - require(delayTimeMillis >= 0) { "Can not advance time by a negative delay: $delayTimeMillis" } + public fun advanceTimeBy(delayTimeMillis: Long): Unit = advanceTimeBy(delayTimeMillis.milliseconds) + + /** + * Moves the virtual clock of this dispatcher forward by [the specified amount][delayTime], running the + * scheduled tasks in the meantime. + * + * @throws IllegalStateException if passed a negative [delay][delayTime]. + */ + public fun advanceTimeBy(delayTime: Duration) { + require(!delayTime.isNegative()) { "Can not advance time by a negative delay: $delayTime" } val startingTime = currentTime - val targetTime = addClamping(startingTime, delayTimeMillis) + val targetTime = addClamping(startingTime, delayTime.inWholeMilliseconds) while (true) { val event = synchronized(lock) { val timeMark = currentTime @@ -177,14 +186,6 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout } } - /** - * Moves the virtual clock of this dispatcher forward by [the specified amount][delayTime], running the - * scheduled tasks in the meantime. - * - * @throws IllegalStateException if passed a negative [delay][delayTime]. - */ - public fun advanceTimeBy(delayTime: Duration): Unit = advanceTimeBy(delayTime.inWholeMicroseconds) - /** * Checks that the only tasks remaining in the scheduler are cancelled. */ From 99a8b7da05dd82b9e4be544d1dfc0bb697c653d0 Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Tue, 31 Jan 2023 16:17:27 +0100 Subject: [PATCH 03/11] Add tests, fix problems --- .../api/kotlinx-coroutines-test.api | 8 +- .../common/src/TestBuilders.kt | 55 +++++++++----- .../common/src/TestScope.kt | 6 +- .../common/test/RunTestTest.kt | 74 ++++++++++++++++--- .../js/src/TestBuilders.kt | 7 +- .../jvm/src/TestBuildersJvm.kt | 9 ++- .../native/src/TestBuilders.kt | 9 +-- 7 files changed, 117 insertions(+), 51 deletions(-) diff --git a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api index e132de2fd0..0c054e5fff 100644 --- a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api +++ b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api @@ -22,10 +22,10 @@ public final class kotlinx/coroutines/test/TestBuildersKt { public static final fun runTest (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;)V public static synthetic fun runTest$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V public static synthetic fun runTest$default (Lkotlinx/coroutines/test/TestCoroutineScope;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V - public static final fun runTest-Kx4hsE0 (Lkotlin/coroutines/CoroutineContext;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;)V - public static final fun runTest-Kx4hsE0 (Lkotlinx/coroutines/test/TestScope;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;)V - public static synthetic fun runTest-Kx4hsE0$default (Lkotlin/coroutines/CoroutineContext;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;ILjava/lang/Object;)V - public static synthetic fun runTest-Kx4hsE0$default (Lkotlinx/coroutines/test/TestScope;Lkotlin/time/Duration;Lkotlin/jvm/functions/Function2;ILjava/lang/Object;)V + public static final fun runTest-8Mi8wO0 (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;)V + public static final fun runTest-8Mi8wO0 (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;)V + public static synthetic fun runTest-8Mi8wO0$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V + public static synthetic fun runTest-8Mi8wO0$default (Lkotlinx/coroutines/test/TestScope;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V public static final fun runTestWithLegacyScope (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;)V public static synthetic fun runTestWithLegacyScope$default (Lkotlin/coroutines/CoroutineContext;JLkotlin/jvm/functions/Function2;ILjava/lang/Object;)V } diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 644cb57a96..2587f427b9 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -125,6 +125,10 @@ public expect class TestResult * then the test fails with an [UncompletedCoroutinesError]. The timeout can be changed by setting the [timeout] * parameter. * + * The test finishes by the timeout procedure cancelling the test body. If the code inside the test body does not + * respond to cancellation, we will not be able to make the test execution stop, in which case, the test will hang + * despite our best efforts to terminate it. + * * On the JVM, if `DebugProbes` from the `kotlinx-coroutines-debug` module are installed, the current dump of the * coroutines' stack is printed to the console on timeout. * @@ -151,7 +155,7 @@ public expect class TestResult */ public fun runTest( context: CoroutineContext = EmptyCoroutineContext, - timeout: Duration? = null, + timeout: Duration = DEFAULT_TIMEOUT, testBody: suspend TestScope.() -> Unit ): TestResult { if (context[RunningInRunTest] != null) @@ -293,7 +297,7 @@ public fun runTest( * Performs [runTest] on an existing [TestScope]. */ public fun TestScope.runTest( - timeout: Duration? = null, + timeout: Duration = DEFAULT_TIMEOUT, testBody: suspend TestScope.() -> Unit ): TestResult = asSpecificImplementation().let { it.enter() @@ -382,7 +386,7 @@ internal suspend fun > CoroutineScope.runTestCorouti testBody() } if (dispatchTimeout != null) { - require(testTimeout == null) { "Only one of dispatchTimeout and testTimeout can be specified" } + check(testTimeout == null) { "Only one of dispatchTimeout and testTimeout can be specified" } /** * This is the legacy behavior, kept for now for compatibility only. * @@ -439,7 +443,7 @@ internal suspend fun > CoroutineScope.runTestCorouti // we received knowledge that `scheduler` observed a dispatch event, so we reset the timeout } onTimeout(dispatchTimeout) { - handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup)?.let { throw it } + throw handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup) } } } finally { @@ -447,6 +451,10 @@ internal suspend fun > CoroutineScope.runTestCorouti } } } else { + check(testTimeout != null) { "Either dispatchTimeout or testTimeout must be specified" } + /** + * The thread in which the task was last seen executing. + */ val lastKnownPosition = MutableStateFlow(null) /** * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, @@ -466,19 +474,26 @@ internal suspend fun > CoroutineScope.runTestCorouti } } } - val timeout = testTimeout ?: DEFAULT_TIMEOUT try { - withTimeout(timeout) { + withTimeout(testTimeout) { coroutine.join() + workRunner.cancelAndJoin() } } catch (_: TimeoutCancellationException) { - val exception = handleTimeout(coroutine, timeout, tryGetCompletionCause, cleanup) - exception?.let { - dumpCoroutinesAndThrow(it, lastKnownPosition.value) - } - } finally { - coroutine.cancelAndJoin() + val exception = handleTimeout(coroutine, testTimeout, tryGetCompletionCause, cleanup) + dumpCoroutines() + /** + * There's a race that may lead to the misleading results here, but it's better than nothing. + * The race: `lastKnownPosition` is read, then the task executed in `workRunner` completes, + * then `updateStacktrace` does its thing, but the thread is already busy doing something else. + */ + updateStacktrace(exception, lastKnownPosition.value) + // we can't abandon the work we're doing, so if it hanged, we'll still hang, despite the timeout. + (coroutine as CoroutineScope).cancel("The test timed out", exception) + coroutine.join() workRunner.cancelAndJoin() + scheduler.advanceUntilIdleOr { false } + throw exception } } coroutine.getCompletionExceptionOrNull()?.let { exception -> @@ -494,15 +509,14 @@ internal suspend fun > CoroutineScope.runTestCorouti } /** - * Invoked on timeout in [runTest]. Almost always just builds a nice [UncompletedCoroutinesError] and throws it. - * However, sometimes it detects that the coroutine completed, in which case it returns normally. + * Invoked on timeout in [runTest]. Just builds a nice [UncompletedCoroutinesError] and returns it. */ private inline fun > handleTimeout( coroutine: T, dispatchTimeout: Duration, tryGetCompletionCause: T.() -> Throwable?, cleanup: () -> List, -): AssertionError? { +): AssertionError { val uncaughtExceptions = try { cleanup() } catch (e: UncompletedCoroutinesError) { @@ -517,10 +531,10 @@ private inline fun > handleTimeout( if (activeChildren.isNotEmpty()) message += ", there were active child jobs: $activeChildren" if (completionCause != null && activeChildren.isEmpty()) { - if (coroutine.isCompleted) - return null - // TODO: can this really ever happen? - message += ", the test coroutine was not completed" + message += if (coroutine.isCompleted) + ", the test coroutine completed" + else + ", the test coroutine was not completed" } val error = UncompletedCoroutinesError(message) completionCause?.let { cause -> error.addSuppressed(cause) } @@ -537,5 +551,6 @@ internal fun List.throwAll() { internal expect fun getLastKnownPosition(): Any? +internal expect fun dumpCoroutines() -internal expect fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) +internal expect fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable diff --git a/kotlinx-coroutines-test/common/src/TestScope.kt b/kotlinx-coroutines-test/common/src/TestScope.kt index 0a15ab2d2e..5ebdea02a0 100644 --- a/kotlinx-coroutines-test/common/src/TestScope.kt +++ b/kotlinx-coroutines-test/common/src/TestScope.kt @@ -50,9 +50,9 @@ public sealed interface TestScope : CoroutineScope { * A scope for background work. * * This scope is automatically cancelled when the test finishes. - * Additionally, while the coroutines in this scope are run as usual when - * using [advanceTimeBy] and [runCurrent], [advanceUntilIdle] will stop advancing the virtual time - * once only the coroutines in this scope are left unprocessed. + * The coroutines in this scope are run as usual when using [advanceTimeBy] and [runCurrent]. + * [advanceUntilIdle], on the other hand, will stop advancing the virtual time once only the coroutines in this + * scope are left unprocessed. * * Failures in coroutines in this scope do not terminate the test. * Instead, they are reported at the end of the test. diff --git a/kotlinx-coroutines-test/common/test/RunTestTest.kt b/kotlinx-coroutines-test/common/test/RunTestTest.kt index 6d6a01c6c6..8c3b000651 100644 --- a/kotlinx-coroutines-test/common/test/RunTestTest.kt +++ b/kotlinx-coroutines-test/common/test/RunTestTest.kt @@ -9,7 +9,10 @@ import kotlinx.coroutines.internal.* import kotlinx.coroutines.flow.* import kotlin.coroutines.* import kotlin.test.* +import kotlin.time.* +import kotlin.time.Duration.Companion.milliseconds +@OptIn(ExperimentalTime::class) class RunTestTest { /** Tests that [withContext] that sends work to other threads works in [runTest]. */ @@ -52,7 +55,7 @@ class RunTestTest { /** Tests that even the dispatch timeout of `0` is fine if all the dispatches go through the same scheduler. */ @Test - fun testRunTestWithZeroTimeoutWithControlledDispatches() = runTest(dispatchTimeoutMs = 0) { + fun testRunTestWithZeroDispatchTimeoutWithControlledDispatches() = runTest(dispatchTimeoutMs = 0) { // below is some arbitrary concurrent code where all dispatches go through the same scheduler. launch { delay(2000) @@ -71,7 +74,7 @@ class RunTestTest { /** Tests that too low of a dispatch timeout causes crashes. */ @Test - fun testRunTestWithSmallTimeout() = testResultMap({ fn -> + fun testRunTestWithSmallDispatchTimeout() = testResultMap({ fn -> try { fn() fail("shouldn't be reached") @@ -88,6 +91,48 @@ class RunTestTest { } } + /** + * Tests that [runTest] times out after the specified time. + */ + @Test + fun testRunTestWithSmallTimeout() = testResultMap({ fn -> + try { + fn() + fail("shouldn't be reached") + } catch (e: Throwable) { + assertIs(e) + } + }) { + runTest(timeout = 100.milliseconds) { + withContext(Dispatchers.Default) { + delay(10000) + 3 + } + fail("shouldn't be reached") + } + } + + /** Tests that [runTest] times out after the specified time, even if the test framework always knows the test is + * still doing something. */ + @Test + fun testRunTestWithSmallTimeoutAndManyDispatches() = testResultMap({ fn -> + try { + fn() + fail("shouldn't be reached") + } catch (e: Throwable) { + assertIs(e) + } + }) { + runTest(timeout = 100.milliseconds) { + while (true) { + withContext(Dispatchers.Default) { + delay(10) + 3 + } + } + } + } + /** Tests that, on timeout, the names of the active coroutines are listed, * whereas the names of the completed ones are not. */ @Test @@ -130,20 +175,27 @@ class RunTestTest { } } }) { - runTest(dispatchTimeoutMs = 10) { - launch { - withContext(NonCancellable) { - awaitCancellation() + runTest(timeout = 10.milliseconds) { + launch(start = CoroutineStart.UNDISPATCHED) { + withContext(NonCancellable + Dispatchers.Default) { + delay(100.milliseconds) } } - yield() throw TestException("A") } } /** Tests that real delays can be accounted for with a large enough dispatch timeout. */ @Test - fun testRunTestWithLargeTimeout() = runTest(dispatchTimeoutMs = 5000) { + fun testRunTestWithLargeDispatchTimeout() = runTest(dispatchTimeoutMs = 5000) { + withContext(Dispatchers.Default) { + delay(50) + } + } + + /** Tests that delays can be accounted for with a large enough timeout. */ + @Test + fun testRunTestWithLargeTimeout() = runTest(timeout = 5000.milliseconds) { withContext(Dispatchers.Default) { delay(50) } @@ -164,7 +216,7 @@ class RunTestTest { } } }) { - runTest(dispatchTimeoutMs = 1) { + runTest(timeout = 1.milliseconds) { coroutineContext[CoroutineExceptionHandler]!!.handleException(coroutineContext, TestException("A")) withContext(Dispatchers.Default) { delay(10000) @@ -329,7 +381,7 @@ class RunTestTest { } } - /** Tests that [TestCoroutineScope.runTest] does not inherit the exception handler and works. */ + /** Tests that [TestScope.runTest] does not inherit the exception handler and works. */ @Test fun testScopeRunTestExceptionHandler(): TestResult { val scope = TestScope() @@ -354,7 +406,7 @@ class RunTestTest { * The test will hang if this is not the case. */ @Test - fun testCoroutineCompletingWithoutDispatch() = runTest(dispatchTimeoutMs = Long.MAX_VALUE) { + fun testCoroutineCompletingWithoutDispatch() = runTest(timeout = Duration.INFINITE) { launch(Dispatchers.Default) { delay(100) } } } diff --git a/kotlinx-coroutines-test/js/src/TestBuilders.kt b/kotlinx-coroutines-test/js/src/TestBuilders.kt index 9b07c8ba28..cf7f37a0bb 100644 --- a/kotlinx-coroutines-test/js/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/js/src/TestBuilders.kt @@ -16,7 +16,6 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> internal actual fun getLastKnownPosition(): Any? = null -internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { - console.error(exception) - throw exception -} +internal actual fun dumpCoroutines() { } + +internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable = exception diff --git a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt index f8b7fd3d9c..eed4e0660c 100644 --- a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt +++ b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt @@ -17,8 +17,7 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> internal actual fun getLastKnownPosition(): Any? = Thread.currentThread() -internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { - val thread = lastKnownPosition as? Thread +internal actual fun dumpCoroutines() { @Suppress("INVISIBLE_REFERENCE", "INVISIBLE_MEMBER") if (DebugProbesImpl.isInstalled) { DebugProbesImpl.install() @@ -29,6 +28,10 @@ internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPositi DebugProbesImpl.uninstall() } } +} + +internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable { + val thread = lastKnownPosition as? Thread thread?.stackTrace?.let { exception.stackTrace = it } - throw exception + return exception } diff --git a/kotlinx-coroutines-test/native/src/TestBuilders.kt b/kotlinx-coroutines-test/native/src/TestBuilders.kt index b16478d101..c9c23e4036 100644 --- a/kotlinx-coroutines-test/native/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/native/src/TestBuilders.kt @@ -17,9 +17,6 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> internal actual fun getLastKnownPosition(): Any? = null -@OptIn(ExperimentalStdlibApi::class) -internal actual fun dumpCoroutinesAndThrow(exception: Throwable, lastKnownPosition: Any?) { - // log exception - processUnhandledException(exception) - throw exception -} +internal actual fun dumpCoroutines() { } + +internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable = exception From d2853b26ad9a0f7a596e09a84a730bc615c31a88 Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Tue, 31 Jan 2023 16:38:31 +0100 Subject: [PATCH 04/11] Migrate to Duration in tests, add TestScope.advanceTimeBy(Duration) overload --- .../api/kotlinx-coroutines-test.api | 1 + .../common/src/TestScope.kt | 10 ++++++++++ .../common/test/TestCoroutineSchedulerTest.kt | 19 ++++++++++--------- .../common/test/TestScopeTest.kt | 7 ++++--- 4 files changed, 25 insertions(+), 12 deletions(-) diff --git a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api index 0c054e5fff..153e4bbfc5 100644 --- a/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api +++ b/kotlinx-coroutines-test/api/kotlinx-coroutines-test.api @@ -117,6 +117,7 @@ public final class kotlinx/coroutines/test/TestScopeKt { public static final fun TestScope (Lkotlin/coroutines/CoroutineContext;)Lkotlinx/coroutines/test/TestScope; public static synthetic fun TestScope$default (Lkotlin/coroutines/CoroutineContext;ILjava/lang/Object;)Lkotlinx/coroutines/test/TestScope; public static final fun advanceTimeBy (Lkotlinx/coroutines/test/TestScope;J)V + public static final fun advanceTimeBy-HG0u8IE (Lkotlinx/coroutines/test/TestScope;J)V public static final fun advanceUntilIdle (Lkotlinx/coroutines/test/TestScope;)V public static final fun getCurrentTime (Lkotlinx/coroutines/test/TestScope;)J public static final fun getTestTimeSource (Lkotlinx/coroutines/test/TestScope;)Lkotlin/time/TimeSource; diff --git a/kotlinx-coroutines-test/common/src/TestScope.kt b/kotlinx-coroutines-test/common/src/TestScope.kt index 5ebdea02a0..5bac46d51b 100644 --- a/kotlinx-coroutines-test/common/src/TestScope.kt +++ b/kotlinx-coroutines-test/common/src/TestScope.kt @@ -120,6 +120,16 @@ public fun TestScope.runCurrent(): Unit = testScheduler.runCurrent() @ExperimentalCoroutinesApi public fun TestScope.advanceTimeBy(delayTimeMillis: Long): Unit = testScheduler.advanceTimeBy(delayTimeMillis) +/** + * Moves the virtual clock of this dispatcher forward by [the specified amount][delayTime], running the + * scheduled tasks in the meantime. + * + * @throws IllegalStateException if passed a negative [delay][delayTime]. + * @see TestCoroutineScheduler.advanceTimeBy + */ +@ExperimentalCoroutinesApi +public fun TestScope.advanceTimeBy(delayTime: Duration): Unit = testScheduler.advanceTimeBy(delayTime) + /** * The [test scheduler][TestScope.testScheduler] as a [TimeSource]. * @see TestCoroutineScheduler.timeSource diff --git a/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt b/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt index d050e9c8c0..ed30e07449 100644 --- a/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt +++ b/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt @@ -8,6 +8,7 @@ import kotlinx.coroutines.* import kotlin.test.* import kotlin.time.* import kotlin.time.Duration.Companion.seconds +import kotlin.time.Duration.Companion.milliseconds class TestCoroutineSchedulerTest { /** Tests that `TestCoroutineScheduler` attempts to detect if there are several instances of it. */ @@ -28,7 +29,7 @@ class TestCoroutineSchedulerTest { delay(15) entered = true } - testScheduler.advanceTimeBy(15) + testScheduler.advanceTimeBy(15.milliseconds) assertFalse(entered) testScheduler.runCurrent() assertTrue(entered) @@ -39,7 +40,7 @@ class TestCoroutineSchedulerTest { fun testAdvanceTimeByWithNegativeDelay() { val scheduler = TestCoroutineScheduler() assertFailsWith { - scheduler.advanceTimeBy(-1) + scheduler.advanceTimeBy((-1).milliseconds) } } @@ -65,7 +66,7 @@ class TestCoroutineSchedulerTest { assertEquals(Long.MAX_VALUE - 1, currentTime) enteredNearInfinity = true } - testScheduler.advanceTimeBy(Long.MAX_VALUE) + testScheduler.advanceTimeBy(Duration.INFINITE) assertFalse(enteredInfinity) assertTrue(enteredNearInfinity) assertEquals(Long.MAX_VALUE, currentTime) @@ -95,10 +96,10 @@ class TestCoroutineSchedulerTest { } assertEquals(1, stage) assertEquals(0, currentTime) - advanceTimeBy(2_000) + advanceTimeBy(2.seconds) assertEquals(3, stage) assertEquals(2_000, currentTime) - advanceTimeBy(2) + advanceTimeBy(2.milliseconds) assertEquals(4, stage) assertEquals(2_002, currentTime) } @@ -120,11 +121,11 @@ class TestCoroutineSchedulerTest { delay(1) stage += 10 } - testScheduler.advanceTimeBy(1) + testScheduler.advanceTimeBy(1.milliseconds) assertEquals(0, stage) runCurrent() assertEquals(2, stage) - testScheduler.advanceTimeBy(1) + testScheduler.advanceTimeBy(1.milliseconds) assertEquals(2, stage) runCurrent() assertEquals(22, stage) @@ -143,10 +144,10 @@ class TestCoroutineSchedulerTest { delay(SLOW) stage = 3 } - scheduler.advanceTimeBy(SLOW) + scheduler.advanceTimeBy(SLOW.milliseconds) stage = 2 } - scheduler.advanceTimeBy(SLOW) + scheduler.advanceTimeBy(SLOW.milliseconds) assertEquals(1, stage) scheduler.runCurrent() assertEquals(2, stage) diff --git a/kotlinx-coroutines-test/common/test/TestScopeTest.kt b/kotlinx-coroutines-test/common/test/TestScopeTest.kt index 45f7f3ef80..97defaa921 100644 --- a/kotlinx-coroutines-test/common/test/TestScopeTest.kt +++ b/kotlinx-coroutines-test/common/test/TestScopeTest.kt @@ -9,6 +9,7 @@ import kotlinx.coroutines.channels.* import kotlinx.coroutines.flow.* import kotlin.coroutines.* import kotlin.test.* +import kotlin.time.Duration.Companion.milliseconds class TestScopeTest { /** Tests failing to create a [TestScope] with incorrect contexts. */ @@ -249,7 +250,7 @@ class TestScopeTest { assertEquals(1, j) } job.join() - advanceTimeBy(199) // should work the same for the background tasks + advanceTimeBy(199.milliseconds) // should work the same for the background tasks assertEquals(2, i) assertEquals(4, j) advanceUntilIdle() // once again, should do nothing @@ -377,7 +378,7 @@ class TestScopeTest { } }) { - runTest(dispatchTimeoutMs = 100) { + runTest(timeout = 100.milliseconds) { backgroundScope.launch { while (true) { yield() @@ -407,7 +408,7 @@ class TestScopeTest { } }) { - runTest(UnconfinedTestDispatcher(), dispatchTimeoutMs = 100) { + runTest(UnconfinedTestDispatcher(), timeout = 100.milliseconds) { /** * Having a coroutine like this will still cause the test to hang: backgroundScope.launch { From 3531ebe1b2e67744140b9f0b0a878c97fcc8a9de Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 13 Feb 2023 12:12:12 +0100 Subject: [PATCH 05/11] Fixes for the review --- kotlinx-coroutines-test/common/src/TestBuilders.kt | 8 ++++---- .../common/src/TestCoroutineScheduler.kt | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 2587f427b9..82abf9bd40 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -122,8 +122,7 @@ public expect class TestResult * #### Timing out * * There's a built-in timeout of 10 seconds for the test body. If the test body doesn't complete within this time, - * then the test fails with an [UncompletedCoroutinesError]. The timeout can be changed by setting the [timeout] - * parameter. + * then the test fails with an [AssertionError]. The timeout can be changed by setting the [timeout] parameter. * * The test finishes by the timeout procedure cancelling the test body. If the code inside the test body does not * respond to cancellation, we will not be able to make the test execution stop, in which case, the test will hang @@ -294,7 +293,7 @@ public fun runTest( } /** - * Performs [runTest] on an existing [TestScope]. + * Performs [runTest] on an existing [TestScope]. See the documentation for [runTest] for details. */ public fun TestScope.runTest( timeout: Duration = DEFAULT_TIMEOUT, @@ -466,7 +465,8 @@ internal suspend fun > CoroutineScope.runTestCorouti lastKnownPosition.value = getLastKnownPosition() val executedSomething = scheduler.tryRunNextTaskUnless { !isActive } if (executedSomething) { - // yield to check for cancellation + /** Yield to check for cancellation. On JS, we can't use [ensureActive] here, as the cancellation + * procedure needs a chance to run concurrently. */ yield() } else { // no more tasks, we should suspend until there are some more diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt index 8cc4915a9c..b18b4a0b95 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt @@ -151,7 +151,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * * Overflowing the target time used to lead to nothing being done, but will now run the tasks scheduled at up to * (but not including) [Long.MAX_VALUE]. * - * @throws IllegalStateException if passed a negative [delay][delayTimeMillis]. + * @throws IllegalArgumentException if passed a negative [delay][delayTimeMillis]. */ @ExperimentalCoroutinesApi public fun advanceTimeBy(delayTimeMillis: Long): Unit = advanceTimeBy(delayTimeMillis.milliseconds) @@ -160,7 +160,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * Moves the virtual clock of this dispatcher forward by [the specified amount][delayTime], running the * scheduled tasks in the meantime. * - * @throws IllegalStateException if passed a negative [delay][delayTime]. + * @throws IllegalArgumentException if passed a negative [delay][delayTime]. */ public fun advanceTimeBy(delayTime: Duration) { require(!delayTime.isNegative()) { "Can not advance time by a negative delay: $delayTime" } From 4417a416eb5d0d3ebcf3c39287199421020d6751 Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 13 Feb 2023 14:59:01 +0100 Subject: [PATCH 06/11] Extract the non-legacy code to a separate function --- .../common/src/TestBuilders.kt | 250 ++++++++++-------- .../common/src/TestScope.kt | 9 +- .../common/test/RunTestTest.kt | 5 +- .../common/test/StandardTestDispatcherTest.kt | 2 +- .../common/test/TestCoroutineSchedulerTest.kt | 2 +- .../common/test/TestScopeTest.kt | 8 +- .../src/migration/TestBuildersDeprecated.kt | 45 ++-- 7 files changed, 182 insertions(+), 139 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 82abf9bd40..a938c579f0 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -301,10 +301,76 @@ public fun TestScope.runTest( ): TestResult = asSpecificImplementation().let { it.enter() createTestResult { - runTestCoroutine(it, null, timeout, TestScopeImpl::tryGetCompletionCause, testBody) { + /** TODO: moving this [AbstractCoroutine.start] call outside [createTestResult] fails on JS. */ + it.start(CoroutineStart.UNDISPATCHED, it) { + testBody() + } + /** + * The thread in which the task was last seen executing. + */ + val lastKnownPosition = MutableStateFlow(null) + + /** + * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, + * but on the JVM and Native, this means that the timeout can be processed even while the test runner is busy + * doing some synchronous work. + */ + val workRunner = launch(Dispatchers.Default + CoroutineName("kotlinx.coroutines.test runner")) { + while (true) { + lastKnownPosition.value = getLastKnownPosition() + val executedSomething = testScheduler.tryRunNextTaskUnless { !isActive } + if (executedSomething) { + /** yield to check for cancellation. On JS, we can't use [ensureActive] here, as the cancellation + * procedure needs a chance to run concurrently. */ + yield() + } else { + // no more tasks, we should suspend until there are some more + testScheduler.receiveDispatchEvent() + } + } + } + var timeoutError: Throwable? = null + try { + withTimeout(timeout) { + it.join() + workRunner.cancelAndJoin() + } + } catch (_: TimeoutCancellationException) { + val activeChildren = it.children.filter(Job::isActive).toList() + val completionCause = if (it.isCancelled) it.tryGetCompletionCause() else null + var message = "After waiting for $timeout" + if (completionCause == null) + message += ", the test coroutine is not completing" + if (activeChildren.isNotEmpty()) + message += ", there were active child jobs: $activeChildren" + if (completionCause != null && activeChildren.isEmpty()) { + message += if (it.isCompleted) + ", the test coroutine completed" + else + ", the test coroutine was not completed" + } + timeoutError = UncompletedCoroutinesError(message) + dumpCoroutines() + /** + * There's a race that may lead to the misleading results here, but it's better than nothing. + * The race: `lastKnownPosition` is read, then the task executed in `workRunner` completes, + * then `updateStacktrace` does its thing, but the thread is already busy doing something else. + */ + updateStacktrace(timeoutError, lastKnownPosition.value) + val cancellationException = CancellationException("The test timed out", timeoutError) + (it as Job).cancel(cancellationException) + // we can't abandon the work we're doing, so if it hanged, we'll still hang, despite the timeout. + it.join() + it.getCompletionExceptionOrNull()?.let { exception -> + if (exception !== cancellationException) + timeoutError.addSuppressed(exception) + } + workRunner.cancelAndJoin() + } finally { backgroundScope.cancel() testScheduler.advanceUntilIdleOr { false } - it.leave() + val uncaughtExceptions = it.leave() + throwAll(timeoutError ?: it.getCompletionExceptionOrNull(), uncaughtExceptions) } } } @@ -329,11 +395,12 @@ public fun TestScope.runTest( testBody: suspend TestScope.() -> Unit ): TestResult = asSpecificImplementation().let { it.enter() + @Suppress("DEPRECATION") createTestResult { - runTestCoroutine(it, dispatchTimeoutMs.milliseconds, null, TestScopeImpl::tryGetCompletionCause, testBody) { + runTestCoroutineLegacy(it, dispatchTimeoutMs.milliseconds, TestScopeImpl::tryGetCompletionCause, testBody) { backgroundScope.cancel() testScheduler.advanceUntilIdleOr { false } - it.leave() + it.legacyLeave() } } } @@ -363,18 +430,17 @@ internal val DEFAULT_TIMEOUT = 10.seconds /** * Run the [body][testBody] of the [test coroutine][coroutine], waiting for asynchronous completions for at most - * [dispatchTimeout], allowing the total runtime of a test of at most [testTimeout], - * and performing the [cleanup] procedure at the end. + * [dispatchTimeout] and performing the [cleanup] procedure at the end. * * [tryGetCompletionCause] is the [JobSupport.completionCause], which is passed explicitly because it is protected. * * The [cleanup] procedure may either throw [UncompletedCoroutinesError] to denote that child coroutines were leaked, or * return a list of uncaught exceptions that should be reported at the end of the test. */ -internal suspend fun > CoroutineScope.runTestCoroutine( +@Deprecated("Used for support of legacy behavior") +internal suspend fun > CoroutineScope.runTestCoroutineLegacy( coroutine: T, - dispatchTimeout: Duration?, - testTimeout: Duration?, + dispatchTimeout: Duration, tryGetCompletionCause: T.() -> Throwable?, testBody: suspend T.() -> Unit, cleanup: () -> List, @@ -384,116 +450,67 @@ internal suspend fun > CoroutineScope.runTestCorouti coroutine.start(CoroutineStart.UNDISPATCHED, coroutine) { testBody() } - if (dispatchTimeout != null) { - check(testTimeout == null) { "Only one of dispatchTimeout and testTimeout can be specified" } - /** - * This is the legacy behavior, kept for now for compatibility only. - * - * The general procedure here is as follows: - * 1. Try running the work that the scheduler knows about, both background and foreground. - * - * 2. Wait until we run out of foreground work to do. This could mean one of the following: - * * The main coroutine is already completed. This is checked separately; then we leave the procedure. - * * It's switched to another dispatcher that doesn't know about the [TestCoroutineScheduler]. - * * Generally, it's waiting for something external (like a network request, or just an arbitrary callback). - * * The test simply hanged. - * * The main coroutine is waiting for some background work. - * - * 3. We await progress from things that are not the code under test: - * the background work that the scheduler knows about, the external callbacks, - * the work on dispatchers not linked to the scheduler, etc. - * - * When we observe that the code under test can proceed, we go to step 1 again. - * If there is no activity for [dispatchTimeoutMs] milliseconds, we consider the test to have hanged. - * - * The background work is not running on a dedicated thread. - * Instead, the test thread itself is used, by spawning a separate coroutine. - */ - var completed = false - while (!completed) { - scheduler.advanceUntilIdle() - if (coroutine.isCompleted) { - /* don't even enter `withTimeout`; this allows to use a timeout of zero to check that there are no - non-trivial dispatches. */ - completed = true - continue - } - // in case progress depends on some background work, we need to keep spinning it. - val backgroundWorkRunner = launch(CoroutineName("background work runner")) { - while (true) { - val executedSomething = scheduler.tryRunNextTaskUnless { !isActive } - if (executedSomething) { - // yield so that the `select` below has a chance to finish successfully or time out - yield() - } else { - // no more tasks, we should suspend until there are some more. - // this doesn't interfere with the `select` below, because different channels are used. - scheduler.receiveDispatchEvent() - } - } - } - try { - select { - coroutine.onJoin { - // observe that someone completed the test coroutine and leave without waiting for the timeout - completed = true - } - scheduler.onDispatchEventForeground { - // we received knowledge that `scheduler` observed a dispatch event, so we reset the timeout - } - onTimeout(dispatchTimeout) { - throw handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup) - } - } - } finally { - backgroundWorkRunner.cancelAndJoin() - } + /** + * This is the legacy behavior, kept for now for compatibility only. + * + * The general procedure here is as follows: + * 1. Try running the work that the scheduler knows about, both background and foreground. + * + * 2. Wait until we run out of foreground work to do. This could mean one of the following: + * * The main coroutine is already completed. This is checked separately; then we leave the procedure. + * * It's switched to another dispatcher that doesn't know about the [TestCoroutineScheduler]. + * * Generally, it's waiting for something external (like a network request, or just an arbitrary callback). + * * The test simply hanged. + * * The main coroutine is waiting for some background work. + * + * 3. We await progress from things that are not the code under test: + * the background work that the scheduler knows about, the external callbacks, + * the work on dispatchers not linked to the scheduler, etc. + * + * When we observe that the code under test can proceed, we go to step 1 again. + * If there is no activity for [dispatchTimeoutMs] milliseconds, we consider the test to have hanged. + * + * The background work is not running on a dedicated thread. + * Instead, the test thread itself is used, by spawning a separate coroutine. + */ + var completed = false + while (!completed) { + scheduler.advanceUntilIdle() + if (coroutine.isCompleted) { + /* don't even enter `withTimeout`; this allows to use a timeout of zero to check that there are no + non-trivial dispatches. */ + completed = true + continue } - } else { - check(testTimeout != null) { "Either dispatchTimeout or testTimeout must be specified" } - /** - * The thread in which the task was last seen executing. - */ - val lastKnownPosition = MutableStateFlow(null) - /** - * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, - * but on the JVM and Native, this means that the timeout can be processed even while the test runner is busy - * doing some synchronous work. - */ - val workRunner = launch(Dispatchers.Default + CoroutineName("kotlinx.coroutines.test runner")) { + // in case progress depends on some background work, we need to keep spinning it. + val backgroundWorkRunner = launch(CoroutineName("background work runner")) { while (true) { - lastKnownPosition.value = getLastKnownPosition() val executedSomething = scheduler.tryRunNextTaskUnless { !isActive } if (executedSomething) { - /** Yield to check for cancellation. On JS, we can't use [ensureActive] here, as the cancellation - * procedure needs a chance to run concurrently. */ + // yield so that the `select` below has a chance to finish successfully or time out yield() } else { - // no more tasks, we should suspend until there are some more + // no more tasks, we should suspend until there are some more. + // this doesn't interfere with the `select` below, because different channels are used. scheduler.receiveDispatchEvent() } } } try { - withTimeout(testTimeout) { - coroutine.join() - workRunner.cancelAndJoin() + select { + coroutine.onJoin { + // observe that someone completed the test coroutine and leave without waiting for the timeout + completed = true + } + scheduler.onDispatchEventForeground { + // we received knowledge that `scheduler` observed a dispatch event, so we reset the timeout + } + onTimeout(dispatchTimeout) { + throw handleTimeout(coroutine, dispatchTimeout, tryGetCompletionCause, cleanup) + } } - } catch (_: TimeoutCancellationException) { - val exception = handleTimeout(coroutine, testTimeout, tryGetCompletionCause, cleanup) - dumpCoroutines() - /** - * There's a race that may lead to the misleading results here, but it's better than nothing. - * The race: `lastKnownPosition` is read, then the task executed in `workRunner` completes, - * then `updateStacktrace` does its thing, but the thread is already busy doing something else. - */ - updateStacktrace(exception, lastKnownPosition.value) - // we can't abandon the work we're doing, so if it hanged, we'll still hang, despite the timeout. - (coroutine as CoroutineScope).cancel("The test timed out", exception) - coroutine.join() - workRunner.cancelAndJoin() - scheduler.advanceUntilIdleOr { false } - throw exception + } finally { + backgroundWorkRunner.cancelAndJoin() } } coroutine.getCompletionExceptionOrNull()?.let { exception -> @@ -503,9 +520,9 @@ internal suspend fun > CoroutineScope.runTestCorouti // it's normal that some jobs are not completed if the test body has failed, won't clutter the output emptyList() } - (listOf(exception) + exceptions).throwAll() + throwAll(exception, exceptions) } - cleanup().throwAll() + throwAll(null, cleanup()) } /** @@ -542,10 +559,17 @@ private inline fun > handleTimeout( return error } -internal fun List.throwAll() { - firstOrNull()?.apply { - drop(1).forEach { addSuppressed(it) } - throw this +internal fun throwAll(head: Throwable?, other: List) { + if (head != null) { + other.forEach { head.addSuppressed(it) } + throw head + } else { + with(other) { + firstOrNull()?.apply { + drop(1).forEach { addSuppressed(it) } + throw this + } + } } } diff --git a/kotlinx-coroutines-test/common/src/TestScope.kt b/kotlinx-coroutines-test/common/src/TestScope.kt index 5bac46d51b..a0a29a9553 100644 --- a/kotlinx-coroutines-test/common/src/TestScope.kt +++ b/kotlinx-coroutines-test/common/src/TestScope.kt @@ -236,8 +236,15 @@ internal class TestScopeImpl(context: CoroutineContext) : } } + /** Called at the end of the test. May only be called once. Returns the list of caught unhandled exceptions. */ + fun leave(): List = synchronized(lock) { + check(entered && !finished) + finished = true + uncaughtExceptions + } + /** Called at the end of the test. May only be called once. */ - fun leave(): List { + fun legacyLeave(): List { val exceptions = synchronized(lock) { check(entered && !finished) finished = true diff --git a/kotlinx-coroutines-test/common/test/RunTestTest.kt b/kotlinx-coroutines-test/common/test/RunTestTest.kt index 8c3b000651..45444783a8 100644 --- a/kotlinx-coroutines-test/common/test/RunTestTest.kt +++ b/kotlinx-coroutines-test/common/test/RunTestTest.kt @@ -100,6 +100,7 @@ class RunTestTest { fn() fail("shouldn't be reached") } catch (e: Throwable) { + e.printStackTrace() assertIs(e) } }) { @@ -169,7 +170,7 @@ class RunTestTest { } catch (e: UncompletedCoroutinesError) { @Suppress("INVISIBLE_MEMBER") val suppressed = unwrap(e).suppressedExceptions - assertEquals(1, suppressed.size) + assertEquals(1, suppressed.size, "$suppressed") assertIs(suppressed[0]).also { assertEquals("A", it.message) } @@ -210,7 +211,7 @@ class RunTestTest { } catch (e: UncompletedCoroutinesError) { @Suppress("INVISIBLE_MEMBER") val suppressed = unwrap(e).suppressedExceptions - assertEquals(1, suppressed.size) + assertEquals(1, suppressed.size, "$suppressed") assertIs(suppressed[0]).also { assertEquals("A", it.message) } diff --git a/kotlinx-coroutines-test/common/test/StandardTestDispatcherTest.kt b/kotlinx-coroutines-test/common/test/StandardTestDispatcherTest.kt index 9e9c93e10e..280d668588 100644 --- a/kotlinx-coroutines-test/common/test/StandardTestDispatcherTest.kt +++ b/kotlinx-coroutines-test/common/test/StandardTestDispatcherTest.kt @@ -20,7 +20,7 @@ class StandardTestDispatcherTest: OrderedExecutionTestBase() { @AfterTest fun cleanup() { scope.runCurrent() - assertEquals(listOf(), scope.asSpecificImplementation().leave()) + assertEquals(listOf(), scope.asSpecificImplementation().legacyLeave()) } /** Tests that the [StandardTestDispatcher] follows an execution order similar to `runBlocking`. */ diff --git a/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt b/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt index ed30e07449..7203dbd270 100644 --- a/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt +++ b/kotlinx-coroutines-test/common/test/TestCoroutineSchedulerTest.kt @@ -250,7 +250,7 @@ class TestCoroutineSchedulerTest { } } advanceUntilIdle() - asSpecificImplementation().leave().throwAll() + throwAll(null, asSpecificImplementation().legacyLeave()) if (timesOut) assertTrue(caughtException) else diff --git a/kotlinx-coroutines-test/common/test/TestScopeTest.kt b/kotlinx-coroutines-test/common/test/TestScopeTest.kt index 97defaa921..9ab6a6140b 100644 --- a/kotlinx-coroutines-test/common/test/TestScopeTest.kt +++ b/kotlinx-coroutines-test/common/test/TestScopeTest.kt @@ -96,7 +96,7 @@ class TestScopeTest { } assertFalse(result) scope.asSpecificImplementation().enter() - assertFailsWith { scope.asSpecificImplementation().leave() } + assertFailsWith { scope.asSpecificImplementation().legacyLeave() } assertFalse(result) } @@ -112,7 +112,7 @@ class TestScopeTest { } assertFalse(result) scope.asSpecificImplementation().enter() - assertFailsWith { scope.asSpecificImplementation().leave() } + assertFailsWith { scope.asSpecificImplementation().legacyLeave() } assertFalse(result) } @@ -129,7 +129,7 @@ class TestScopeTest { job.cancel() assertFalse(result) scope.asSpecificImplementation().enter() - assertFailsWith { scope.asSpecificImplementation().leave() } + assertFailsWith { scope.asSpecificImplementation().legacyLeave() } assertFalse(result) } @@ -163,7 +163,7 @@ class TestScopeTest { launch(SupervisorJob()) { throw TestException("y") } launch(SupervisorJob()) { throw TestException("z") } runCurrent() - val e = asSpecificImplementation().leave() + val e = asSpecificImplementation().legacyLeave() assertEquals(3, e.size) assertEquals("x", e[0].message) assertEquals("y", e[1].message) diff --git a/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt b/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt index 888895680b..c7ef9cc8e7 100644 --- a/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt +++ b/kotlinx-coroutines-test/jvm/src/migration/TestBuildersDeprecated.kt @@ -50,10 +50,12 @@ import kotlin.time.Duration.Companion.milliseconds * then they must implement [DelayController] and [TestCoroutineExceptionHandler] respectively. * @param testBody The code of the unit-test. */ -@Deprecated("Use `runTest` instead to support completing from other dispatchers. " + - "Please see the migration guide for details: " + - "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", - level = DeprecationLevel.WARNING) +@Deprecated( + "Use `runTest` instead to support completing from other dispatchers. " + + "Please see the migration guide for details: " + + "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", + level = DeprecationLevel.WARNING +) // Since 1.6.0, ERROR in 1.7.0 and removed as experimental in 1.8.0 public fun runBlockingTest( context: CoroutineContext = EmptyCoroutineContext, @@ -91,20 +93,20 @@ public fun runBlockingTestOnTestScope( val throwable = try { scope.getCompletionExceptionOrNull() } catch (e: IllegalStateException) { - null // the deferred was not completed yet; `scope.leave()` should complain then about unfinished jobs + null // the deferred was not completed yet; `scope.legacyLeave()` should complain then about unfinished jobs } scope.backgroundScope.cancel() scope.testScheduler.advanceUntilIdleOr { false } throwable?.let { val exceptions = try { - scope.leave() + scope.legacyLeave() } catch (e: UncompletedCoroutinesError) { listOf() } - (listOf(it) + exceptions).throwAll() + throwAll(it, exceptions) return } - scope.leave().throwAll() + throwAll(null, scope.legacyLeave()) val jobs = completeContext.activeJobs() - startJobs if (jobs.isNotEmpty()) throw UncompletedCoroutinesError("Some jobs were not completed at the end of the test: $jobs") @@ -118,10 +120,12 @@ public fun runBlockingTestOnTestScope( * [migration guide](https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md) * for an instruction on how to update the code for the new API. */ -@Deprecated("Use `runTest` instead to support completing from other dispatchers. " + - "Please see the migration guide for details: " + - "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", - level = DeprecationLevel.WARNING) +@Deprecated( + "Use `runTest` instead to support completing from other dispatchers. " + + "Please see the migration guide for details: " + + "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", + level = DeprecationLevel.WARNING +) // Since 1.6.0, ERROR in 1.7.0 and removed as experimental in 1.8.0 public fun TestCoroutineScope.runBlockingTest(block: suspend TestCoroutineScope.() -> Unit): Unit = runBlockingTest(coroutineContext, block) @@ -142,10 +146,12 @@ public fun TestScope.runBlockingTest(block: suspend TestScope.() -> Unit): Unit * [migration guide](https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md) * for an instruction on how to update the code for the new API. */ -@Deprecated("Use `runTest` instead to support completing from other dispatchers. " + - "Please see the migration guide for details: " + - "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", - level = DeprecationLevel.WARNING) +@Deprecated( + "Use `runTest` instead to support completing from other dispatchers. " + + "Please see the migration guide for details: " + + "https://github.com/Kotlin/kotlinx.coroutines/blob/master/kotlinx-coroutines-test/MIGRATION.md", + level = DeprecationLevel.WARNING +) // Since 1.6.0, ERROR in 1.7.0 and removed as experimental in 1.8.0 public fun TestCoroutineDispatcher.runBlockingTest(block: suspend TestCoroutineScope.() -> Unit): Unit = runBlockingTest(this, block) @@ -165,7 +171,12 @@ public fun runTestWithLegacyScope( throw IllegalStateException("Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details.") val testScope = TestBodyCoroutine(createTestCoroutineScope(context + RunningInRunTest)) return createTestResult { - runTestCoroutine(testScope, dispatchTimeoutMs.milliseconds, null, TestBodyCoroutine::tryGetCompletionCause, testBody) { + runTestCoroutineLegacy( + testScope, + dispatchTimeoutMs.milliseconds, + TestBodyCoroutine::tryGetCompletionCause, + testBody + ) { try { testScope.cleanup() emptyList() From 579ab0f0bd4782c9622bb49485de0563a2550fbb Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 13 Feb 2023 15:07:52 +0100 Subject: [PATCH 07/11] Improve the deprecation notices --- kotlinx-coroutines-test/common/src/TestBuilders.kt | 6 ++++-- kotlinx-coroutines-test/common/test/RunTestTest.kt | 1 - 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index a938c579f0..0ce55bafd1 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -278,7 +278,8 @@ public fun runTest( @Deprecated( "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", - ReplaceWith("runTest(context, timeout = with(kotlin.time.Duration.Companion) { dispatchTimeoutMs.milliseconds }, testBody)"), + ReplaceWith("runTest(context, timeout = dispatchTimeoutMs.milliseconds, testBody)", + "kotlin.time.Duration.Companion.milliseconds"), DeprecationLevel.WARNING ) public fun runTest( @@ -387,7 +388,8 @@ public fun TestScope.runTest( @Deprecated( "Define a total timeout for the whole test instead of using dispatchTimeoutMs. " + "Warning: the proposed replacement is not identical as it uses 'dispatchTimeoutMs' as the timeout for the whole test!", - ReplaceWith("this.runTest(timeout = with(kotlin.time.Duration.Companion) { dispatchTimeoutMs.milliseconds }, testBody)"), + ReplaceWith("this.runTest(timeout = dispatchTimeoutMs.milliseconds, testBody)", + "kotlin.time.Duration.Companion.milliseconds"), DeprecationLevel.WARNING ) public fun TestScope.runTest( diff --git a/kotlinx-coroutines-test/common/test/RunTestTest.kt b/kotlinx-coroutines-test/common/test/RunTestTest.kt index 45444783a8..e6a060b210 100644 --- a/kotlinx-coroutines-test/common/test/RunTestTest.kt +++ b/kotlinx-coroutines-test/common/test/RunTestTest.kt @@ -12,7 +12,6 @@ import kotlin.test.* import kotlin.time.* import kotlin.time.Duration.Companion.milliseconds -@OptIn(ExperimentalTime::class) class RunTestTest { /** Tests that [withContext] that sends work to other threads works in [runTest]. */ From 9fd86bb9fc1ad3bc975610b3919698c0e5b99726 Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 13 Feb 2023 15:16:55 +0100 Subject: [PATCH 08/11] Restore the ExperimentalCoroutinesApi markers --- kotlinx-coroutines-test/common/src/TestBuilders.kt | 3 +++ .../common/src/TestCoroutineDispatchers.kt | 1 + kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt | 5 +++++ kotlinx-coroutines-test/common/src/TestDispatcher.kt | 2 ++ kotlinx-coroutines-test/common/src/TestScope.kt | 4 ++++ 5 files changed, 15 insertions(+) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 0ce55bafd1..4417969eaa 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -31,6 +31,7 @@ import kotlin.time.Duration.Companion.seconds * * Don't nest functions returning a [TestResult]. */ @Suppress("NO_ACTUAL_FOR_EXPECT") +@ExperimentalCoroutinesApi public expect class TestResult /** @@ -152,6 +153,7 @@ public expect class TestResult * * @throws IllegalArgumentException if the [context] is invalid. See the [TestScope] constructor docs for details. */ +@ExperimentalCoroutinesApi public fun runTest( context: CoroutineContext = EmptyCoroutineContext, timeout: Duration = DEFAULT_TIMEOUT, @@ -296,6 +298,7 @@ public fun runTest( /** * Performs [runTest] on an existing [TestScope]. See the documentation for [runTest] for details. */ +@ExperimentalCoroutinesApi public fun TestScope.runTest( timeout: Duration = DEFAULT_TIMEOUT, testBody: suspend TestScope.() -> Unit diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt b/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt index 3777cd26f8..e99fe8b124 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineDispatchers.kt @@ -137,6 +137,7 @@ private class UnconfinedTestDispatcherImpl( * * @see UnconfinedTestDispatcher for a dispatcher that is not confined to any particular thread. */ +@ExperimentalCoroutinesApi @Suppress("FunctionName") public fun StandardTestDispatcher( scheduler: TestCoroutineScheduler? = null, diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt index b18b4a0b95..95f9a5b49e 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt @@ -27,6 +27,7 @@ import kotlin.time.Duration.Companion.milliseconds * virtual time as needed (via [advanceUntilIdle]), or run the tasks that are scheduled to run as soon as possible but * haven't yet been dispatched (via [runCurrent]). */ +@ExperimentalCoroutinesApi public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCoroutineScheduler), CoroutineContext.Element { @@ -112,6 +113,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * milliseconds by which the execution of this method has advanced the virtual time. If you want to recreate that * functionality, query [currentTime] before and after the execution to achieve the same result. */ + @ExperimentalCoroutinesApi public fun advanceUntilIdle(): Unit = advanceUntilIdleOr { events.none(TestDispatchEvent<*>::isForeground) } /** @@ -127,6 +129,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout /** * Runs the tasks that are scheduled to execute at this moment of virtual time. */ + @ExperimentalCoroutinesApi public fun runCurrent() { val timeMark = synchronized(lock) { currentTime } while (true) { @@ -162,6 +165,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout * * @throws IllegalArgumentException if passed a negative [delay][delayTime]. */ + @ExperimentalCoroutinesApi public fun advanceTimeBy(delayTime: Duration) { require(!delayTime.isNegative()) { "Can not advance time by a negative delay: $delayTime" } val startingTime = currentTime @@ -218,6 +222,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout /** * Returns the [TimeSource] representation of the virtual time of this scheduler. */ + @ExperimentalCoroutinesApi @ExperimentalTime public val timeSource: TimeSource = object : AbstractLongTimeSource(DurationUnit.MILLISECONDS) { override fun read(): Long = currentTime diff --git a/kotlinx-coroutines-test/common/src/TestDispatcher.kt b/kotlinx-coroutines-test/common/src/TestDispatcher.kt index 33ee9334d5..8ed8192b9e 100644 --- a/kotlinx-coroutines-test/common/src/TestDispatcher.kt +++ b/kotlinx-coroutines-test/common/src/TestDispatcher.kt @@ -16,8 +16,10 @@ import kotlin.jvm.* * * [UnconfinedTestDispatcher] is a dispatcher that behaves like [Dispatchers.Unconfined] while allowing to control * the virtual time. */ +@ExperimentalCoroutinesApi public abstract class TestDispatcher internal constructor() : CoroutineDispatcher(), Delay { /** The scheduler that this dispatcher is linked to. */ + @ExperimentalCoroutinesApi public abstract val scheduler: TestCoroutineScheduler /** Notifies the dispatcher that it should process a single event marked with [marker] happening at time [time]. */ diff --git a/kotlinx-coroutines-test/common/src/TestScope.kt b/kotlinx-coroutines-test/common/src/TestScope.kt index a0a29a9553..a301ff966b 100644 --- a/kotlinx-coroutines-test/common/src/TestScope.kt +++ b/kotlinx-coroutines-test/common/src/TestScope.kt @@ -40,10 +40,12 @@ import kotlin.time.* * paused by default, like [StandardTestDispatcher]. * * No access to the list of unhandled exceptions. */ +@ExperimentalCoroutinesApi public sealed interface TestScope : CoroutineScope { /** * The delay-skipping scheduler used by the test dispatchers running the code in this scope. */ + @ExperimentalCoroutinesApi public val testScheduler: TestCoroutineScheduler /** @@ -80,6 +82,7 @@ public sealed interface TestScope : CoroutineScope { * } * ``` */ + @ExperimentalCoroutinesApi public val backgroundScope: CoroutineScope } @@ -163,6 +166,7 @@ public val TestScope.testTimeSource: TimeSource get() = testScheduler.timeSource * @throws IllegalArgumentException if [context] has an [CoroutineExceptionHandler] that is not an * [UncaughtExceptionCaptor]. */ +@ExperimentalCoroutinesApi @Suppress("FunctionName") public fun TestScope(context: CoroutineContext = EmptyCoroutineContext): TestScope { val ctxWithDispatcher = context.withDelaySkipping() From 38f3bab46109847c141c9684a601ff69a364ce3d Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Fri, 17 Feb 2023 15:43:44 +0100 Subject: [PATCH 09/11] Don't attempt a pretty stacktrace on runTest timeout --- .../common/src/TestBuilders.kt | 25 ++++--------------- .../common/test/RunTestTest.kt | 1 - .../js/src/TestBuilders.kt | 4 --- .../jvm/src/TestBuildersJvm.kt | 8 ------ .../native/src/TestBuilders.kt | 4 --- 5 files changed, 5 insertions(+), 37 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 4417969eaa..656d406f79 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -14,6 +14,7 @@ import kotlin.jvm.* import kotlin.time.* import kotlin.time.Duration.Companion.milliseconds import kotlin.time.Duration.Companion.seconds +import kotlinx.coroutines.internal.* /** * A test result. @@ -309,11 +310,6 @@ public fun TestScope.runTest( it.start(CoroutineStart.UNDISPATCHED, it) { testBody() } - /** - * The thread in which the task was last seen executing. - */ - val lastKnownPosition = MutableStateFlow(null) - /** * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, * but on the JVM and Native, this means that the timeout can be processed even while the test runner is busy @@ -321,7 +317,6 @@ public fun TestScope.runTest( */ val workRunner = launch(Dispatchers.Default + CoroutineName("kotlinx.coroutines.test runner")) { while (true) { - lastKnownPosition.value = getLastKnownPosition() val executedSomething = testScheduler.tryRunNextTaskUnless { !isActive } if (executedSomething) { /** yield to check for cancellation. On JS, we can't use [ensureActive] here, as the cancellation @@ -355,19 +350,13 @@ public fun TestScope.runTest( } timeoutError = UncompletedCoroutinesError(message) dumpCoroutines() - /** - * There's a race that may lead to the misleading results here, but it's better than nothing. - * The race: `lastKnownPosition` is read, then the task executed in `workRunner` completes, - * then `updateStacktrace` does its thing, but the thread is already busy doing something else. - */ - updateStacktrace(timeoutError, lastKnownPosition.value) - val cancellationException = CancellationException("The test timed out", timeoutError) + val cancellationException = CancellationException("The test timed out") (it as Job).cancel(cancellationException) // we can't abandon the work we're doing, so if it hanged, we'll still hang, despite the timeout. it.join() - it.getCompletionExceptionOrNull()?.let { exception -> - if (exception !== cancellationException) - timeoutError.addSuppressed(exception) + val completion = it.getCompletionExceptionOrNull() + if (completion != null && completion !== cancellationException) { + timeoutError.addSuppressed(completion) } workRunner.cancelAndJoin() } finally { @@ -578,8 +567,4 @@ internal fun throwAll(head: Throwable?, other: List) { } } -internal expect fun getLastKnownPosition(): Any? - internal expect fun dumpCoroutines() - -internal expect fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable diff --git a/kotlinx-coroutines-test/common/test/RunTestTest.kt b/kotlinx-coroutines-test/common/test/RunTestTest.kt index e6a060b210..183eb8cb3a 100644 --- a/kotlinx-coroutines-test/common/test/RunTestTest.kt +++ b/kotlinx-coroutines-test/common/test/RunTestTest.kt @@ -99,7 +99,6 @@ class RunTestTest { fn() fail("shouldn't be reached") } catch (e: Throwable) { - e.printStackTrace() assertIs(e) } }) { diff --git a/kotlinx-coroutines-test/js/src/TestBuilders.kt b/kotlinx-coroutines-test/js/src/TestBuilders.kt index cf7f37a0bb..97c9da0eee 100644 --- a/kotlinx-coroutines-test/js/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/js/src/TestBuilders.kt @@ -14,8 +14,4 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> testProcedure() } -internal actual fun getLastKnownPosition(): Any? = null - internal actual fun dumpCoroutines() { } - -internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable = exception diff --git a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt index eed4e0660c..0521fd22ae 100644 --- a/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt +++ b/kotlinx-coroutines-test/jvm/src/TestBuildersJvm.kt @@ -15,8 +15,6 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> } } -internal actual fun getLastKnownPosition(): Any? = Thread.currentThread() - internal actual fun dumpCoroutines() { @Suppress("INVISIBLE_REFERENCE", "INVISIBLE_MEMBER") if (DebugProbesImpl.isInstalled) { @@ -29,9 +27,3 @@ internal actual fun dumpCoroutines() { } } } - -internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable { - val thread = lastKnownPosition as? Thread - thread?.stackTrace?.let { exception.stackTrace = it } - return exception -} diff --git a/kotlinx-coroutines-test/native/src/TestBuilders.kt b/kotlinx-coroutines-test/native/src/TestBuilders.kt index c9c23e4036..607dec6a73 100644 --- a/kotlinx-coroutines-test/native/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/native/src/TestBuilders.kt @@ -15,8 +15,4 @@ internal actual fun createTestResult(testProcedure: suspend CoroutineScope.() -> } } -internal actual fun getLastKnownPosition(): Any? = null - internal actual fun dumpCoroutines() { } - -internal actual fun updateStacktrace(exception: Throwable, lastKnownPosition: Any?): Throwable = exception From 4fe30ec6bcf76395a41d7595103762486cfc153b Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Mon, 20 Feb 2023 14:30:29 +0100 Subject: [PATCH 10/11] Don't use Dispatchers.DEFAULT for the test runner --- kotlinx-coroutines-test/build.gradle.kts | 12 +++- .../common/src/TestBuilders.kt | 72 ++++++++++--------- .../common/src/TestCoroutineScheduler.kt | 7 +- .../jvm/test/DumpOnTimeoutTest.kt | 48 +++++++++++++ 4 files changed, 101 insertions(+), 38 deletions(-) create mode 100644 kotlinx-coroutines-test/jvm/test/DumpOnTimeoutTest.kt diff --git a/kotlinx-coroutines-test/build.gradle.kts b/kotlinx-coroutines-test/build.gradle.kts index 98d3e9fa74..c968fc4991 100644 --- a/kotlinx-coroutines-test/build.gradle.kts +++ b/kotlinx-coroutines-test/build.gradle.kts @@ -1,9 +1,9 @@ -import org.jetbrains.kotlin.gradle.plugin.mpp.* - /* * Copyright 2016-2021 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license. */ +import org.jetbrains.kotlin.gradle.plugin.mpp.* + val experimentalAnnotations = listOf( "kotlin.Experimental", "kotlinx.coroutines.ExperimentalCoroutinesApi", @@ -19,4 +19,12 @@ kotlin { binaryOptions["memoryModel"] = "experimental" } } + + sourceSets { + jvmTest { + dependencies { + implementation(project(":kotlinx-coroutines-debug")) + } + } + } } diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 656d406f79..280d0de9b5 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -303,19 +303,19 @@ public fun runTest( public fun TestScope.runTest( timeout: Duration = DEFAULT_TIMEOUT, testBody: suspend TestScope.() -> Unit -): TestResult = asSpecificImplementation().let { - it.enter() +): TestResult = asSpecificImplementation().let { scope -> + scope.enter() createTestResult { /** TODO: moving this [AbstractCoroutine.start] call outside [createTestResult] fails on JS. */ - it.start(CoroutineStart.UNDISPATCHED, it) { + scope.start(CoroutineStart.UNDISPATCHED, scope) { + /* we're using `UNDISPATCHED` to avoid the event loop, but we do want to set up the timeout machinery + before any code executes, so we have to park here. */ + yield() testBody() } - /** - * We run the tasks in the test coroutine using [Dispatchers.Default]. On JS, this does nothing particularly, - * but on the JVM and Native, this means that the timeout can be processed even while the test runner is busy - * doing some synchronous work. - */ - val workRunner = launch(Dispatchers.Default + CoroutineName("kotlinx.coroutines.test runner")) { + var timeoutError: Throwable? = null + var cancellationException: CancellationException? = null + val workRunner = launch(CoroutineName("kotlinx.coroutines.test runner")) { while (true) { val executedSomething = testScheduler.tryRunNextTaskUnless { !isActive } if (executedSomething) { @@ -323,47 +323,49 @@ public fun TestScope.runTest( * procedure needs a chance to run concurrently. */ yield() } else { - // no more tasks, we should suspend until there are some more + // waiting for the next task to be scheduled, or for the test runner to be cancelled testScheduler.receiveDispatchEvent() } } } - var timeoutError: Throwable? = null try { withTimeout(timeout) { - it.join() + coroutineContext.job.invokeOnCompletion(onCancelling = true) { exception -> + if (exception is TimeoutCancellationException) { + dumpCoroutines() + val activeChildren = scope.children.filter(Job::isActive).toList() + val completionCause = if (scope.isCancelled) scope.tryGetCompletionCause() else null + var message = "After waiting for $timeout" + if (completionCause == null) + message += ", the test coroutine is not completing" + if (activeChildren.isNotEmpty()) + message += ", there were active child jobs: $activeChildren" + if (completionCause != null && activeChildren.isEmpty()) { + message += if (scope.isCompleted) + ", the test coroutine completed" + else + ", the test coroutine was not completed" + } + timeoutError = UncompletedCoroutinesError(message) + cancellationException = CancellationException("The test timed out") + (scope as Job).cancel(cancellationException!!) + } + } + scope.join() workRunner.cancelAndJoin() } } catch (_: TimeoutCancellationException) { - val activeChildren = it.children.filter(Job::isActive).toList() - val completionCause = if (it.isCancelled) it.tryGetCompletionCause() else null - var message = "After waiting for $timeout" - if (completionCause == null) - message += ", the test coroutine is not completing" - if (activeChildren.isNotEmpty()) - message += ", there were active child jobs: $activeChildren" - if (completionCause != null && activeChildren.isEmpty()) { - message += if (it.isCompleted) - ", the test coroutine completed" - else - ", the test coroutine was not completed" - } - timeoutError = UncompletedCoroutinesError(message) - dumpCoroutines() - val cancellationException = CancellationException("The test timed out") - (it as Job).cancel(cancellationException) - // we can't abandon the work we're doing, so if it hanged, we'll still hang, despite the timeout. - it.join() - val completion = it.getCompletionExceptionOrNull() + scope.join() + val completion = scope.getCompletionExceptionOrNull() if (completion != null && completion !== cancellationException) { - timeoutError.addSuppressed(completion) + timeoutError!!.addSuppressed(completion) } workRunner.cancelAndJoin() } finally { backgroundScope.cancel() testScheduler.advanceUntilIdleOr { false } - val uncaughtExceptions = it.leave() - throwAll(timeoutError ?: it.getCompletionExceptionOrNull(), uncaughtExceptions) + val uncaughtExceptions = scope.leave() + throwAll(timeoutError ?: scope.getCompletionExceptionOrNull(), uncaughtExceptions) } } } diff --git a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt index 95f9a5b49e..cdb669c0b3 100644 --- a/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt +++ b/kotlinx-coroutines-test/common/src/TestCoroutineScheduler.kt @@ -77,7 +77,7 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout val time = addClamping(currentTime, timeDeltaMillis) val event = TestDispatchEvent(dispatcher, count, time, marker as Any, isForeground) { isCancelled(marker) } events.addLast(event) - /** can't be moved above: otherwise, [onDispatchEventForeground] or [receiveDispatchEvent] could consume the + /** can't be moved above: otherwise, [onDispatchEventForeground] or [onDispatchEvent] could consume the * token sent here before there's actually anything in the event queue. */ sendDispatchEvent(context) DisposableHandle { @@ -214,6 +214,11 @@ public class TestCoroutineScheduler : AbstractCoroutineContextElement(TestCorout */ internal suspend fun receiveDispatchEvent() = dispatchEvents.receive() + /** + * Consumes the knowledge that a dispatch event happened recently. + */ + internal val onDispatchEvent: SelectClause1 get() = dispatchEvents.onReceive + /** * Consumes the knowledge that a foreground work dispatch event happened recently. */ diff --git a/kotlinx-coroutines-test/jvm/test/DumpOnTimeoutTest.kt b/kotlinx-coroutines-test/jvm/test/DumpOnTimeoutTest.kt new file mode 100644 index 0000000000..814e5f0667 --- /dev/null +++ b/kotlinx-coroutines-test/jvm/test/DumpOnTimeoutTest.kt @@ -0,0 +1,48 @@ +/* + * Copyright 2016-2023 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license. + */ + +package kotlinx.coroutines.test + +import kotlinx.coroutines.* +import kotlinx.coroutines.debug.* +import org.junit.Test +import java.io.* +import kotlin.test.* +import kotlin.time.Duration.Companion.milliseconds + +class DumpOnTimeoutTest { + /** + * Tests that the dump on timeout contains the correct stacktrace. + */ + @Test + fun testDumpOnTimeout() { + val oldErr = System.err + val baos = ByteArrayOutputStream() + try { + System.setErr(PrintStream(baos, true)) + DebugProbes.withDebugProbes { + try { + runTest(timeout = 100.milliseconds) { + uniquelyNamedFunction() + } + throw IllegalStateException("unreachable") + } catch (e: UncompletedCoroutinesError) { + // do nothing + } + } + baos.toString().let { + assertTrue(it.contains("uniquelyNamedFunction"), "Actual trace:\n$it") + } + } finally { + System.setErr(oldErr) + } + } + + fun CoroutineScope.uniquelyNamedFunction() { + while (true) { + ensureActive() + Thread.sleep(10) + } + } +} From c516eee7c4743bbc2d918b1c5adce1f1e40abb7a Mon Sep 17 00:00:00 2001 From: Dmitry Khalanskiy Date: Tue, 21 Feb 2023 12:25:41 +0100 Subject: [PATCH 11/11] ~ --- kotlinx-coroutines-test/common/src/TestBuilders.kt | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/kotlinx-coroutines-test/common/src/TestBuilders.kt b/kotlinx-coroutines-test/common/src/TestBuilders.kt index 280d0de9b5..de16967a41 100644 --- a/kotlinx-coroutines-test/common/src/TestBuilders.kt +++ b/kotlinx-coroutines-test/common/src/TestBuilders.kt @@ -160,8 +160,9 @@ public fun runTest( timeout: Duration = DEFAULT_TIMEOUT, testBody: suspend TestScope.() -> Unit ): TestResult { - if (context[RunningInRunTest] != null) - throw IllegalStateException("Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details.") + check(context[RunningInRunTest] == null) { + "Calls to `runTest` can't be nested. Please read the docs on `TestResult` for details." + } return TestScope(context + RunningInRunTest).runTest(timeout, testBody) }