diff --git a/README.md b/README.md index ba10d6b19d..7a827a2bc9 100644 --- a/README.md +++ b/README.md @@ -277,6 +277,7 @@ The `develop` branch is pushed to `master` during release. [ListenableFuture.await]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-guava/kotlinx.coroutines.guava/com.google.common.util.concurrent.-listenable-future/await.html +[Task.await]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-play-services/kotlinx.coroutines.tasks/com.google.android.gms.tasks.-task/await.html [Publisher.collect]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-reactive/kotlinx.coroutines.reactive/org.reactivestreams.-publisher/collect.html diff --git a/kotlinx-coroutines-debug/README.md b/kotlinx-coroutines-debug/README.md index 2704859815..4128e1078b 100644 --- a/kotlinx-coroutines-debug/README.md +++ b/kotlinx-coroutines-debug/README.md @@ -55,9 +55,20 @@ stacktraces will be dumped to the console. ### Using as JVM agent -It is possible to use this module as a standalone JVM agent to enable debug probes on the application startup. +Debug module can also be used as a standalone JVM agent to enable debug probes on the application startup. You can run your application with an additional argument: `-javaagent:kotlinx-coroutines-debug-1.3.4.jar`. Additionally, on Linux and Mac OS X you can use `kill -5 $pid` command in order to force your application to print all alive coroutines. +When used as Java agent, `"kotlinx.coroutines.debug.enable.creation.stack.trace"` system property can be used to control +[DebugProbes.enableCreationStackTraces] along with agent startup. + +### Using in production environment + +It is possible to run an application in production environments with debug probes in order to monitor its +state and improve its observability. +For that, it is strongly recommended to switch off [DebugProbes.enableCreationStackTraces] property to significantly +reduce the overhead of debug probes and make it insignificant. +With creation stack-traces disabled, the typical overhead of enabled debug probes is a single-digit percentage of the total +application throughput. ### Example of usage @@ -128,8 +139,13 @@ Dumping only deferred ### Status of the API -API is purely experimental and it is not guaranteed that it won't be changed (while it is marked as `@ExperimentalCoroutinesApi`). -Do not use this module in production environment and do not rely on the format of the data produced by [DebugProbes]. +API is experimental, and it is not guaranteed it won't be changed (while it is marked as `@ExperimentalCoroutinesApi`). +Like the rest of experimental API, `DebugProbes` is carefully designed, tested and ready to use in both test and production +environments. It is marked as experimental to leave us the room to enrich the output data in a potentially backwards incompatible manner +to further improve diagnostics and debugging experience. + +The output format of [DebugProbes] can be changed in the future and it is not recommended to rely on the string representation +of the dump programmatically. ### Debug agent and Android @@ -161,6 +177,7 @@ java.lang.NoClassDefFoundError: Failed resolution of: Ljava/lang/management/Mana [DebugProbes.dumpCoroutinesInfo]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/dump-coroutines-info.html [DebugProbes.printJob]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-job.html [DebugProbes.printScope]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/print-scope.html +[DebugProbes.enableCreationStackTraces]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/enable-creation-stack-traces.html [CoroutinesTimeout]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug.junit4/-coroutines-timeout/index.html diff --git a/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api b/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api index 3fba3e2f3a..6061f03899 100644 --- a/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api +++ b/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api @@ -13,6 +13,7 @@ public final class kotlinx/coroutines/debug/DebugProbes { public final fun dumpCoroutines (Ljava/io/PrintStream;)V public static synthetic fun dumpCoroutines$default (Lkotlinx/coroutines/debug/DebugProbes;Ljava/io/PrintStream;ILjava/lang/Object;)V public final fun dumpCoroutinesInfo ()Ljava/util/List; + public final fun getEnableCreationStackTraces ()Z public final fun getSanitizeStackTraces ()Z public final fun install ()V public final fun isInstalled ()Z @@ -22,6 +23,7 @@ public final class kotlinx/coroutines/debug/DebugProbes { public final fun printScope (Lkotlinx/coroutines/CoroutineScope;Ljava/io/PrintStream;)V public static synthetic fun printScope$default (Lkotlinx/coroutines/debug/DebugProbes;Lkotlinx/coroutines/CoroutineScope;Ljava/io/PrintStream;ILjava/lang/Object;)V public final fun scopeToString (Lkotlinx/coroutines/CoroutineScope;)Ljava/lang/String; + public final fun setEnableCreationStackTraces (Z)V public final fun setSanitizeStackTraces (Z)V public final fun uninstall ()V public final fun withDebugProbes (Lkotlin/jvm/functions/Function0;)V @@ -35,17 +37,27 @@ public final class kotlinx/coroutines/debug/State : java/lang/Enum { public static fun values ()[Lkotlinx/coroutines/debug/State; } +public synthetic class kotlinx/coroutines/debug/internal/DebugProbesImplSequenceNumberRefVolatile { + public fun (J)V +} + public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout : org/junit/rules/TestRule { public static final field Companion Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion; public fun (JZ)V public synthetic fun (JZILkotlin/jvm/internal/DefaultConstructorMarker;)V + public fun (JZZ)V + public synthetic fun (JZZILkotlin/jvm/internal/DefaultConstructorMarker;)V public fun apply (Lorg/junit/runners/model/Statement;Lorg/junit/runner/Description;)Lorg/junit/runners/model/Statement; } public final class kotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion { + public final fun seconds (I)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; public final fun seconds (IZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; + public final fun seconds (IZZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; + public final fun seconds (J)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; public final fun seconds (JZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; - public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;IZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; - public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;JZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; + public final fun seconds (JZZ)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; + public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;IZZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; + public static synthetic fun seconds$default (Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout$Companion;JZZILjava/lang/Object;)Lkotlinx/coroutines/debug/junit4/CoroutinesTimeout; } diff --git a/kotlinx-coroutines-debug/src/AgentPremain.kt b/kotlinx-coroutines-debug/src/AgentPremain.kt index 94ff0098b3..aa842ce327 100644 --- a/kotlinx-coroutines-debug/src/AgentPremain.kt +++ b/kotlinx-coroutines-debug/src/AgentPremain.kt @@ -11,9 +11,14 @@ import java.lang.instrument.* @Suppress("unused") internal object AgentPremain { + private val enableCreationStackTraces = + System.getProperty("kotlinx.coroutines.debug.enable.creation.stack.trace")?.toBoolean() + ?: DebugProbes.enableCreationStackTraces + @JvmStatic public fun premain(args: String?, instrumentation: Instrumentation) { Installer.premain(args, instrumentation) + DebugProbes.enableCreationStackTraces = enableCreationStackTraces DebugProbes.install() installSignalHandler() } @@ -21,7 +26,13 @@ internal object AgentPremain { private fun installSignalHandler() { try { Signal.handle(Signal("TRAP")) { // kill -5 - DebugProbes.dumpCoroutines() + if (DebugProbes.isInstalled) { + // Case with 'isInstalled' changed between this check-and-act is not considered + // a real debug probes use-case, thus is not guarded against. + DebugProbes.dumpCoroutines() + } else { + println("""Cannot perform coroutines dump, debug probes are disabled""") + } } } catch (t: Throwable) { System.err.println("Failed to install signal handler: $t") diff --git a/kotlinx-coroutines-debug/src/CoroutineInfo.kt b/kotlinx-coroutines-debug/src/CoroutineInfo.kt index 97bc2be595..d92d9b6b8b 100644 --- a/kotlinx-coroutines-debug/src/CoroutineInfo.kt +++ b/kotlinx-coroutines-debug/src/CoroutineInfo.kt @@ -16,7 +16,7 @@ import kotlin.coroutines.jvm.internal.* @ExperimentalCoroutinesApi public class CoroutineInfo internal constructor( val context: CoroutineContext, - private val creationStackBottom: CoroutineStackFrame, + private val creationStackBottom: CoroutineStackFrame?, @JvmField internal val sequenceNumber: Long ) { @@ -28,6 +28,7 @@ public class CoroutineInfo internal constructor( /** * Creation stacktrace of the coroutine. + * Can be empty if [DebugProbes.enableCreationStackTraces] is not set. */ public val creationStackTrace: List get() = creationStackTrace() @@ -66,8 +67,9 @@ public class CoroutineInfo internal constructor( } private fun creationStackTrace(): List { + val bottom = creationStackBottom ?: return emptyList() // Skip "Coroutine creation stacktrace" frame - return sequence { yieldFrames(creationStackBottom.callerFrame) }.toList() + return sequence { yieldFrames(bottom.callerFrame) }.toList() } private tailrec suspend fun SequenceScope.yieldFrames(frame: CoroutineStackFrame?) { diff --git a/kotlinx-coroutines-debug/src/DebugProbes.kt b/kotlinx-coroutines-debug/src/DebugProbes.kt index eb6a59b6c1..f164e7ccdc 100644 --- a/kotlinx-coroutines-debug/src/DebugProbes.kt +++ b/kotlinx-coroutines-debug/src/DebugProbes.kt @@ -28,20 +28,30 @@ import kotlin.coroutines.* * * `probeCoroutineCreated` is invoked on every coroutine creation using stdlib intrinsics. * * Overhead: - * * Every created coroutine is stored in a weak hash map, thus adding additional GC pressure. - * * On every created coroutine, stacktrace of the current thread is dumped. - * * On every `resume` and `suspend`, [WeakHashMap] is updated under a global lock. + * * Every created coroutine is stored in a concurrent hash map and hash map is looked up and + * updated on each suspension and resumption. + * * If [DebugProbes.enableCreationStackTraces] is enabled, stack trace of the current thread is captured on + * each created coroutine that is a rough equivalent of throwing an exception per each created coroutine. */ @ExperimentalCoroutinesApi public object DebugProbes { /** - * Whether coroutine creation stacktraces should be sanitized. + * Whether coroutine creation stack traces should be sanitized. * Sanitization removes all frames from `kotlinx.coroutines` package except * the first one and the last one to simplify diagnostic. */ public var sanitizeStackTraces: Boolean = true + /** + * Whether coroutine creation stack traces should be captured. + * When enabled, for each created coroutine a stack trace of the current + * thread is captured and attached to the coroutine. + * This option can be useful during local debug sessions, but is recommended + * to be disabled in production environments to avoid stack trace dumping overhead. + */ + public var enableCreationStackTraces: Boolean = true + /** * Determines whether debug probes were [installed][DebugProbes.install]. */ @@ -132,5 +142,5 @@ public object DebugProbes { internal fun probeCoroutineResumed(frame: Continuation<*>) = DebugProbesImpl.probeCoroutineResumed(frame) internal fun probeCoroutineSuspended(frame: Continuation<*>) = DebugProbesImpl.probeCoroutineSuspended(frame) -internal fun probeCoroutineCreated(completion: kotlin.coroutines.Continuation): kotlin.coroutines.Continuation = +internal fun probeCoroutineCreated(completion: Continuation): Continuation = DebugProbesImpl.probeCoroutineCreated(completion) diff --git a/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt b/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt index a7ceb1468d..090d3e5d89 100644 --- a/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt +++ b/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt @@ -4,6 +4,7 @@ package kotlinx.coroutines.debug.internal +import kotlinx.atomicfu.* import kotlinx.coroutines.* import kotlinx.coroutines.debug.* import net.bytebuddy.* @@ -12,8 +13,10 @@ import net.bytebuddy.dynamic.loading.* import java.io.* import java.text.* import java.util.* +import java.util.concurrent.* +import java.util.concurrent.locks.* import kotlin.collections.ArrayList -import kotlin.collections.HashMap +import kotlin.concurrent.* import kotlin.coroutines.* import kotlin.coroutines.jvm.internal.* import kotlinx.coroutines.internal.artificialFrame as createArtificialFrame // IDEA bug workaround @@ -26,12 +29,20 @@ import kotlinx.coroutines.internal.artificialFrame as createArtificialFrame // I internal object DebugProbesImpl { private const val ARTIFICIAL_FRAME_MESSAGE = "Coroutine creation stacktrace" private val dateFormat = SimpleDateFormat("yyyy/MM/dd HH:mm:ss") - private val capturedCoroutines = HashSet>() + private val capturedCoroutines = Collections.newSetFromMap(ConcurrentHashMap, Boolean>()) @Volatile private var installations = 0 internal val isInstalled: Boolean get() = installations > 0 // To sort coroutines by creation order, used as unique id - private var sequenceNumber: Long = 0 + private val sequenceNumber = atomic(0L) + /* + * RW-lock that guards all debug probes state changes. + * All individual coroutine state transitions are guarded by read-lock + * and do not interfere with each other. + * All state reads are guarded by the write lock to guarantee a strongly-consistent + * snapshot of the system. + */ + private val coroutineStateLock = ReentrantReadWriteLock() /* * This is an optimization in the face of KT-29997: @@ -41,10 +52,9 @@ internal object DebugProbesImpl { * Then at least three RUNNING -> RUNNING transitions will occur consecutively and complexity of each is O(depth). * To avoid that quadratic complexity, we are caching lookup result for such chains in this map and update it incrementally. */ - private val callerInfoCache = HashMap() + private val callerInfoCache = ConcurrentHashMap() - @Synchronized - public fun install() { + public fun install(): Unit = coroutineStateLock.write { if (++installations > 1) return ByteBuddyAgent.install() @@ -58,8 +68,7 @@ internal object DebugProbesImpl { .load(cl.classLoader, ClassReloadingStrategy.fromInstalledAgent()) } - @Synchronized - public fun uninstall() { + public fun uninstall(): Unit = coroutineStateLock.write { check(isInstalled) { "Agent was not installed" } if (--installations != 0) return @@ -75,8 +84,7 @@ internal object DebugProbesImpl { .load(cl.classLoader, ClassReloadingStrategy.fromInstalledAgent()) } - @Synchronized - public fun hierarchyToString(job: Job): String { + public fun hierarchyToString(job: Job): String = coroutineStateLock.write { check(isInstalled) { "Debug probes are not installed" } val jobToStack = capturedCoroutines .filter { it.delegate.context[Job] != null } @@ -114,8 +122,7 @@ internal object DebugProbesImpl { @Suppress("DEPRECATION_ERROR") // JobSupport private val Job.debugString: String get() = if (this is JobSupport) toDebugString() else toString() - @Synchronized - public fun dumpCoroutinesInfo(): List { + public fun dumpCoroutinesInfo(): List = coroutineStateLock.write { check(isInstalled) { "Debug probes are not installed" } return capturedCoroutines.asSequence() .map { it.info.copy() } // Copy as CoroutineInfo can be mutated concurrently by DebugProbes @@ -123,10 +130,10 @@ internal object DebugProbesImpl { .toList() } - public fun dumpCoroutines(out: PrintStream) = synchronized(out) { + public fun dumpCoroutines(out: PrintStream): Unit = synchronized(out) { /* * This method synchronizes both on `out` and `this` for a reason: - * 1) Synchronization on `this` is required to have a consistent snapshot of coroutines. + * 1) Taking a write lock is required to have a consistent snapshot of coroutines. * 2) Synchronization on `out` is not required, but prohibits interleaving with any other * (asynchronous) attempt to write to this `out` (System.out by default). * Yet this prevents the progress of coroutines until they are fully dumped to the out which we find acceptable compromise. @@ -134,8 +141,7 @@ internal object DebugProbesImpl { dumpCoroutinesSynchronized(out) } - @Synchronized - private fun dumpCoroutinesSynchronized(out: PrintStream) { + private fun dumpCoroutinesSynchronized(out: PrintStream): Unit = coroutineStateLock.write { check(isInstalled) { "Debug probes are not installed" } out.print("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}") capturedCoroutines @@ -277,8 +283,8 @@ internal object DebugProbesImpl { updateState(owner, frame, state) } - @Synchronized // See comment to callerInfoCache - private fun updateRunningState(frame: CoroutineStackFrame, state: State) { + // See comment to callerInfoCache + private fun updateRunningState(frame: CoroutineStackFrame, state: State): Unit = coroutineStateLock.read { if (!isInstalled) return // Lookup coroutine info in cache or by traversing stack frame val info: CoroutineInfo @@ -288,7 +294,8 @@ internal object DebugProbesImpl { } else { info = frame.owner()?.info ?: return // Guard against improper implementations of CoroutineStackFrame and bugs in the compiler - callerInfoCache.remove(info.lastObservedFrame?.realCaller()) + val realCaller = info.lastObservedFrame?.realCaller() + if (realCaller != null) callerInfoCache.remove(realCaller) } info.updateState(state, frame as Continuation<*>) @@ -302,8 +309,7 @@ internal object DebugProbesImpl { return if (caller.getStackTraceElement() != null) caller else caller.realCaller() } - @Synchronized - private fun updateState(owner: CoroutineOwner<*>, frame: Continuation<*>, state: State) { + private fun updateState(owner: CoroutineOwner<*>, frame: Continuation<*>, state: State) = coroutineStateLock.read { if (!isInstalled) return owner.info.updateState(state, frame) } @@ -313,6 +319,7 @@ internal object DebugProbesImpl { private tailrec fun CoroutineStackFrame.owner(): CoroutineOwner<*>? = if (this is CoroutineOwner<*>) this else callerFrame?.owner() + // Not guarded by the lock at all, does not really affect consistency internal fun probeCoroutineCreated(completion: Continuation): Continuation { if (!isInstalled) return completion /* @@ -327,34 +334,39 @@ internal object DebugProbesImpl { * even more verbose (it will attach coroutine creation stacktrace to all exceptions), * and then using CoroutineOwner completion as unique identifier of coroutineSuspended/resumed calls. */ - val stacktrace = sanitizeStackTrace(Exception()) - val frame = stacktrace.foldRight(null) { frame, acc -> - object : CoroutineStackFrame { - override val callerFrame: CoroutineStackFrame? = acc - override fun getStackTraceElement(): StackTraceElement = frame + + val frame = if (DebugProbes.enableCreationStackTraces) { + val stacktrace = sanitizeStackTrace(Exception()) + stacktrace.foldRight(null) { frame, acc -> + object : CoroutineStackFrame { + override val callerFrame: CoroutineStackFrame? = acc + override fun getStackTraceElement(): StackTraceElement = frame + } } - }!! + } else { + null + } return createOwner(completion, frame) } - @Synchronized - private fun createOwner(completion: Continuation, frame: CoroutineStackFrame): Continuation { + private fun createOwner(completion: Continuation, frame: CoroutineStackFrame?): Continuation { if (!isInstalled) return completion - val info = CoroutineInfo(completion.context, frame, ++sequenceNumber) + val info = CoroutineInfo(completion.context, frame, sequenceNumber.incrementAndGet()) val owner = CoroutineOwner(completion, info, frame) capturedCoroutines += owner + if (!isInstalled) capturedCoroutines.clear() return owner } - @Synchronized + // Not guarded by the lock at all, does not really affect consistency private fun probeCoroutineCompleted(owner: CoroutineOwner<*>) { capturedCoroutines.remove(owner) /* * This removal is a guard against improperly implemented CoroutineStackFrame * and bugs in the compiler. */ - val caller = owner.info.lastObservedFrame?.realCaller() + val caller = owner.info.lastObservedFrame?.realCaller() ?: return callerInfoCache.remove(caller) } @@ -365,8 +377,14 @@ internal object DebugProbesImpl { private class CoroutineOwner( @JvmField val delegate: Continuation, @JvmField val info: CoroutineInfo, - frame: CoroutineStackFrame - ) : Continuation by delegate, CoroutineStackFrame by frame { + private val frame: CoroutineStackFrame? + ) : Continuation by delegate, CoroutineStackFrame { + + override val callerFrame: CoroutineStackFrame? + get() = frame?.callerFrame + + override fun getStackTraceElement(): StackTraceElement? = frame?.getStackTraceElement() + override fun resumeWith(result: Result) { probeCoroutineCompleted(this) delegate.resumeWith(result) diff --git a/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt b/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt index 16b5356721..0f14ade89c 100644 --- a/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt +++ b/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt @@ -17,6 +17,8 @@ import java.util.concurrent.* * * Additionally, this rule installs [DebugProbes] and dumps all coroutines at the moment of the timeout. * It may cancel coroutines on timeout if [cancelOnTimeout] set to `true`. + * [enableCoroutineCreationStackTraces] controls the corresponding [DebugProbes.enableCreationStackTraces] property + * and can be optionally disabled to speed-up tests if creation stack traces are not needed. * * Example of usage: * ``` @@ -35,15 +37,21 @@ import java.util.concurrent.* */ public class CoroutinesTimeout( private val testTimeoutMs: Long, - private val cancelOnTimeout: Boolean = false + private val cancelOnTimeout: Boolean = false, + private val enableCoroutineCreationStackTraces: Boolean = true ) : TestRule { + @Suppress("UNUSED") // Binary compatibility + constructor(testTimeoutMs: Long, cancelOnTimeout: Boolean = false) : this(testTimeoutMs, cancelOnTimeout, true) + init { require(testTimeoutMs > 0) { "Expected positive test timeout, but had $testTimeoutMs" } /* * Install probes in the constructor, so all the coroutines launched from within * target test constructor will be captured */ + // Do not preserve previous state for unit-test environment + DebugProbes.enableCreationStackTraces = enableCoroutineCreationStackTraces DebugProbes.install() } @@ -51,14 +59,28 @@ public class CoroutinesTimeout( /** * Creates [CoroutinesTimeout] rule with the given timeout in seconds. */ - public fun seconds(seconds: Int, cancelOnTimeout: Boolean = false): CoroutinesTimeout = - seconds(seconds.toLong(), cancelOnTimeout) + @JvmOverloads + public fun seconds( + seconds: Int, + cancelOnTimeout: Boolean = false, + enableCoroutineCreationStackTraces: Boolean = true + ): CoroutinesTimeout = + seconds(seconds.toLong(), cancelOnTimeout, enableCoroutineCreationStackTraces) /** * Creates [CoroutinesTimeout] rule with the given timeout in seconds. */ - public fun seconds(seconds: Long, cancelOnTimeout: Boolean = false): CoroutinesTimeout = - CoroutinesTimeout(TimeUnit.SECONDS.toMillis(seconds), cancelOnTimeout) // Overflow is properly handled by TimeUnit + @JvmOverloads + public fun seconds( + seconds: Long, + cancelOnTimeout: Boolean = false, + enableCoroutineCreationStackTraces: Boolean = true + ): CoroutinesTimeout = + CoroutinesTimeout( + TimeUnit.SECONDS.toMillis(seconds), // Overflow is properly handled by TimeUnit + cancelOnTimeout, + enableCoroutineCreationStackTraces + ) } /** diff --git a/kotlinx-coroutines-debug/test/DebugTestBase.kt b/kotlinx-coroutines-debug/test/DebugTestBase.kt index 3e4abea27d..2a37f5883c 100644 --- a/kotlinx-coroutines-debug/test/DebugTestBase.kt +++ b/kotlinx-coroutines-debug/test/DebugTestBase.kt @@ -18,6 +18,7 @@ open class DebugTestBase : TestBase() { open fun setUp() { before() DebugProbes.sanitizeStackTraces = false + DebugProbes.enableCreationStackTraces = true DebugProbes.install() } @@ -29,4 +30,4 @@ open class DebugTestBase : TestBase() { onCompletion() } } -} \ No newline at end of file +} diff --git a/kotlinx-coroutines-debug/test/DumpWithoutCreationStackTraceTest.kt b/kotlinx-coroutines-debug/test/DumpWithoutCreationStackTraceTest.kt new file mode 100644 index 0000000000..89782e4c45 --- /dev/null +++ b/kotlinx-coroutines-debug/test/DumpWithoutCreationStackTraceTest.kt @@ -0,0 +1,44 @@ +/* + * Copyright 2016-2020 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license. + */ +package kotlinx.coroutines.debug + +import kotlinx.coroutines.* +import org.junit.* +import org.junit.Test +import kotlin.test.* + +class DumpWithoutCreationStackTraceTest : DebugTestBase() { + @Before + override fun setUp() { + super.setUp() + DebugProbes.enableCreationStackTraces = false + } + + @Test + fun testCoroutinesDump() = runTest { + val deferred = createActiveDeferred() + yield() + verifyDump( + "Coroutine \"coroutine#1\":BlockingCoroutine{Active}@70d1cb56, state: RUNNING\n" + + "\tat java.lang.Thread.getStackTrace(Thread.java:1559)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.enhanceStackTraceWithThreadDump(DebugProbesImpl.kt:188)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutinesSynchronized(DebugProbesImpl.kt:153)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:141)", + + "Coroutine \"coroutine#2\":DeferredCoroutine{Active}@383fa309, state: SUSPENDED\n" + + "\tat kotlinx.coroutines.debug.DumpWithoutCreationStackTraceTest\$createActiveDeferred\$1.invokeSuspend(DumpWithoutCreationStackTraceTest.kt:63)" + ) + deferred.cancelAndJoin() + } + + + private fun CoroutineScope.createActiveDeferred(): Deferred<*> = async { + suspendingMethod() + assertTrue(true) + } + + private suspend fun suspendingMethod() { + delay(Long.MAX_VALUE) + } +} diff --git a/kotlinx-coroutines-debug/test/StracktraceUtils.kt b/kotlinx-coroutines-debug/test/StracktraceUtils.kt index de31ac10a4..12a39c0041 100644 --- a/kotlinx-coroutines-debug/test/StracktraceUtils.kt +++ b/kotlinx-coroutines-debug/test/StracktraceUtils.kt @@ -80,14 +80,14 @@ public fun verifyDump(vararg traces: String, ignoredCoroutine: String? = null) { val expected = traces[index - 1].applyBackspace().split("\n\t(Coroutine creation stacktrace)\n", limit = 2) val actual = value.applyBackspace().split("\n\t(Coroutine creation stacktrace)\n", limit = 2) - assertEquals(expected.size, actual.size) + assertEquals(expected.size, actual.size, "Creation stacktrace should be part of the expected input") expected.withIndex().forEach { (index, trace) -> val actualTrace = actual[index].trimStackTrace().sanitizeAddresses() val expectedTrace = trace.trimStackTrace().sanitizeAddresses() val actualLines = actualTrace.split("\n") val expectedLines = expectedTrace.split("\n") - for (i in 0 until expectedLines.size) { + for (i in expectedLines.indices) { assertEquals(expectedLines[i], actualLines[i]) } } diff --git a/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutDisabledTracesTest.kt b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutDisabledTracesTest.kt new file mode 100644 index 0000000000..886007c3e8 --- /dev/null +++ b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutDisabledTracesTest.kt @@ -0,0 +1,47 @@ +/* + * Copyright 2016-2020 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license. + */ + +package kotlinx.coroutines.debug.junit4 + +import kotlinx.coroutines.* +import org.junit.* +import org.junit.runners.model.* + +class CoroutinesTimeoutDisabledTracesTest : TestBase() { + + @Rule + @JvmField + public val validation = TestFailureValidation( + 500, true, false, + TestResultSpec( + "hangingTest", expectedOutParts = listOf( + "Coroutines dump", + "Test hangingTest timed out after 500 milliseconds", + "BlockingCoroutine{Active}", + "at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutDisabledTracesTest.hangForever", + "at kotlinx.coroutines.debug.junit4.CoroutinesTimeoutDisabledTracesTest.waitForHangJob" + ), + notExpectedOutParts = listOf("Coroutine creation stacktrace"), + error = TestTimedOutException::class.java + ) + ) + + private val job = GlobalScope.launch(Dispatchers.Unconfined) { hangForever() } + + private suspend fun hangForever() { + suspendCancellableCoroutine { } + expectUnreached() + } + + @Test + fun hangingTest() = runBlocking { + waitForHangJob() + expectUnreached() + } + + private suspend fun waitForHangJob() { + job.join() + expectUnreached() + } +} diff --git a/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutEagerTest.kt b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutEagerTest.kt index eaef43ddaa..0845f5bcb3 100644 --- a/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutEagerTest.kt +++ b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutEagerTest.kt @@ -13,7 +13,7 @@ class CoroutinesTimeoutEagerTest : TestBase() { @Rule @JvmField public val validation = TestFailureValidation( - 500, true, + 500, true, true, TestResultSpec( "hangingTest", expectedOutParts = listOf( "Coroutines dump", diff --git a/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt index fb170c071c..ac3408e20a 100644 --- a/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt +++ b/kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt @@ -13,7 +13,7 @@ class CoroutinesTimeoutTest : TestBase() { @Rule @JvmField public val validation = TestFailureValidation( - 1000, false, + 1000, false, true, TestResultSpec("throwingTest", error = RuntimeException::class.java), TestResultSpec("successfulTest"), TestResultSpec( diff --git a/kotlinx-coroutines-debug/test/junit4/TestFailureValidation.kt b/kotlinx-coroutines-debug/test/junit4/TestFailureValidation.kt index a10c51183e..34ba679adb 100644 --- a/kotlinx-coroutines-debug/test/junit4/TestFailureValidation.kt +++ b/kotlinx-coroutines-debug/test/junit4/TestFailureValidation.kt @@ -11,13 +11,19 @@ import org.junit.runners.model.* import java.io.* import kotlin.test.* -internal fun TestFailureValidation(timeoutMs: Long, cancelOnTimeout: Boolean, vararg specs: TestResultSpec): RuleChain = +internal fun TestFailureValidation( + timeoutMs: Long, + cancelOnTimeout: Boolean, + creationStackTraces: Boolean, + vararg specs: TestResultSpec +): RuleChain = RuleChain .outerRule(TestFailureValidation(specs.associateBy { it.testName })) .around( CoroutinesTimeout( timeoutMs, - cancelOnTimeout + cancelOnTimeout, + creationStackTraces ) )