diff --git a/binary-compatibility-validator/reference-public-api/kotlinx-coroutines-debug.txt b/binary-compatibility-validator/reference-public-api/kotlinx-coroutines-debug.txt index 96a35c7f83..183495af5c 100644 --- a/binary-compatibility-validator/reference-public-api/kotlinx-coroutines-debug.txt +++ b/binary-compatibility-validator/reference-public-api/kotlinx-coroutines-debug.txt @@ -1,11 +1,11 @@ -public final class kotlinx/coroutines/debug/CoroutineState { - public final fun component1 ()Lkotlin/coroutines/Continuation; - public final fun copy (Lkotlin/coroutines/Continuation;Lkotlin/coroutines/jvm/internal/CoroutineStackFrame;J)Lkotlinx/coroutines/debug/CoroutineState; - public static synthetic fun copy$default (Lkotlinx/coroutines/debug/CoroutineState;Lkotlin/coroutines/Continuation;Lkotlin/coroutines/jvm/internal/CoroutineStackFrame;JILjava/lang/Object;)Lkotlinx/coroutines/debug/CoroutineState; +public final class kotlinx/coroutines/debug/CoroutineInfo { + public final fun component1 ()Lkotlin/coroutines/CoroutineContext; + public final fun copy (Lkotlin/coroutines/CoroutineContext;Lkotlin/coroutines/jvm/internal/CoroutineStackFrame;J)Lkotlinx/coroutines/debug/CoroutineInfo; + public static synthetic fun copy$default (Lkotlinx/coroutines/debug/CoroutineInfo;Lkotlin/coroutines/CoroutineContext;Lkotlin/coroutines/jvm/internal/CoroutineStackFrame;JILjava/lang/Object;)Lkotlinx/coroutines/debug/CoroutineInfo; public fun equals (Ljava/lang/Object;)Z - public final fun getContinuation ()Lkotlin/coroutines/Continuation; + public final fun getContext ()Lkotlin/coroutines/CoroutineContext; public final fun getCreationStackTrace ()Ljava/util/List; - public final fun getJobOrNull ()Lkotlinx/coroutines/Job; + public final fun getJob ()Lkotlinx/coroutines/Job; public final fun getState ()Lkotlinx/coroutines/debug/State; public fun hashCode ()I public final fun lastObservedStackTrace ()Ljava/util/List; @@ -16,7 +16,7 @@ public final class kotlinx/coroutines/debug/DebugProbes { public static final field INSTANCE Lkotlinx/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 dumpCoroutinesState ()Ljava/util/List; + public final fun dumpCoroutinesInfo ()Ljava/util/List; public final fun getSanitizeStackTraces ()Z public final fun install ()V public final fun jobToString (Lkotlinx/coroutines/Job;)Ljava/lang/String; diff --git a/kotlinx-coroutines-core/common/src/Timeout.kt b/kotlinx-coroutines-core/common/src/Timeout.kt index 6ffb97c705..efda5a7b17 100644 --- a/kotlinx-coroutines-core/common/src/Timeout.kt +++ b/kotlinx-coroutines-core/common/src/Timeout.kt @@ -83,8 +83,8 @@ private open class TimeoutCoroutine( @JvmField val uCont: Continuation // unintercepted continuation ) : AbstractCoroutine(uCont.context, active = true), Runnable, Continuation, CoroutineStackFrame { override val defaultResumeMode: Int get() = MODE_DIRECT - override val callerFrame: CoroutineStackFrame? get() = (uCont as? CoroutineStackFrame)?.callerFrame - override fun getStackTraceElement(): StackTraceElement? = (uCont as? CoroutineStackFrame)?.getStackTraceElement() + override val callerFrame: CoroutineStackFrame? get() = (uCont as? CoroutineStackFrame) + override fun getStackTraceElement(): StackTraceElement? = null override val cancelsParent: Boolean get() = false // it throws exception to parent instead of cancelling it diff --git a/kotlinx-coroutines-debug/README.md b/kotlinx-coroutines-debug/README.md index 0dc413cd7d..25fc745649 100644 --- a/kotlinx-coroutines-debug/README.md +++ b/kotlinx-coroutines-debug/README.md @@ -10,7 +10,7 @@ Call to [DebugProbes.install] installs debug agent via ByteBuddy and starts spyi After that, you can use [DebugProbes.dumpCoroutines] to print all active (suspended or running) coroutines, including their state, creation and suspension stacktraces. -Additionally, it is possible to process the list of such coroutines via [DebugProbes.dumpCoroutinesState] or dump isolated parts +Additionally, it is possible to process the list of such coroutines via [DebugProbes.dumpCoroutinesInfo] or dump isolated parts of coroutines hierarchy referenced by a [Job] or [CoroutineScope] instances using [DebugProbes.printJob] and [DebugProbes.printScope] respectively. ### Using in your project @@ -159,7 +159,7 @@ java.lang.NoClassDefFoundError: Failed resolution of: Ljava/lang/management/Mana [DebugProbes]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/index.html [DebugProbes.install]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/install.html [DebugProbes.dumpCoroutines]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/dump-coroutines.html -[DebugProbes.dumpCoroutinesState]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug/-debug-probes/dump-coroutines-state.html +[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 diff --git a/kotlinx-coroutines-debug/src/CoroutineState.kt b/kotlinx-coroutines-debug/src/CoroutineInfo.kt similarity index 90% rename from kotlinx-coroutines-debug/src/CoroutineState.kt rename to kotlinx-coroutines-debug/src/CoroutineInfo.kt index 9d4489d4be..2d4b6805f1 100644 --- a/kotlinx-coroutines-debug/src/CoroutineState.kt +++ b/kotlinx-coroutines-debug/src/CoroutineInfo.kt @@ -12,11 +12,11 @@ import kotlin.coroutines.* import kotlin.coroutines.jvm.internal.* /** - * Class describing coroutine state. + * Class describing coroutine info such as its context, state and stacktrace. */ @ExperimentalCoroutinesApi -public data class CoroutineState internal constructor( - public val continuation: Continuation<*>, +public data class CoroutineInfo internal constructor( + val context: CoroutineContext, private val creationStackBottom: CoroutineStackFrame, @JvmField internal val sequenceNumber: Long ) { @@ -25,7 +25,7 @@ public data class CoroutineState internal constructor( * [Job] associated with a current coroutine or null. * May be later used in [DebugProbes.printJob]. */ - public val jobOrNull: Job? get() = continuation.context[Job] + public val job: Job? get() = context[Job] /** * Creation stacktrace of the coroutine. @@ -42,11 +42,12 @@ public data class CoroutineState internal constructor( @JvmField internal var lastObservedThread: Thread? = null - private var lastObservedFrame: CoroutineStackFrame? = null + @JvmField + internal var lastObservedFrame: CoroutineStackFrame? = null // Copy constructor - internal constructor(coroutine: Continuation<*>, state: CoroutineState) : this( - coroutine, + internal constructor(coroutine: Continuation<*>, state: CoroutineInfo) : this( + coroutine.context, state.creationStackBottom, state.sequenceNumber ) { @@ -54,6 +55,21 @@ public data class CoroutineState internal constructor( this.lastObservedFrame = state.lastObservedFrame } + /** + * Last observed stacktrace of the coroutine captured on its suspension or resumption point. + * It means that for [running][State.RUNNING] coroutines resulting stacktrace is inaccurate and + * reflects stacktrace of the resumption point, not the actual current stacktrace. + */ + public fun lastObservedStackTrace(): List { + var frame: CoroutineStackFrame? = lastObservedFrame ?: return emptyList() + val result = ArrayList() + while (frame != null) { + frame.getStackTraceElement()?.let { result.add(sanitize(it)) } + frame = frame.callerFrame + } + return result + } + private fun creationStackTrace(): List { // Skip "Coroutine creation stacktrace" frame return sequence { yieldFrames(creationStackBottom.callerFrame) }.toList() @@ -79,21 +95,6 @@ public data class CoroutineState internal constructor( lastObservedThread = null } } - - /** - * Last observed stacktrace of the coroutine captured on its suspension or resumption point. - * It means that for [running][State.RUNNING] coroutines resulting stacktrace is inaccurate and - * reflects stacktrace of the resumption point, not the actual current stacktrace. - */ - public fun lastObservedStackTrace(): List { - var frame: CoroutineStackFrame? = lastObservedFrame ?: return emptyList() - val result = ArrayList() - while (frame != null) { - frame.getStackTraceElement()?.let { result.add(sanitize(it)) } - frame = frame.callerFrame - } - return result - } } /** diff --git a/kotlinx-coroutines-debug/src/DebugProbes.kt b/kotlinx-coroutines-debug/src/DebugProbes.kt index af30c5e811..a81fd7a880 100644 --- a/kotlinx-coroutines-debug/src/DebugProbes.kt +++ b/kotlinx-coroutines-debug/src/DebugProbes.kt @@ -95,10 +95,10 @@ public object DebugProbes { printJob(scope.coroutineContext[Job] ?: error("Job is not present in the scope"), out) /** - * Returns all existing coroutine states. + * Returns all existing coroutines info. * The resulting collection represents a consistent snapshot of all existing coroutines at the moment of invocation. */ - public fun dumpCoroutinesState(): List = DebugProbesImpl.dumpCoroutinesState() + public fun dumpCoroutinesInfo(): List = DebugProbesImpl.dumpCoroutinesInfo() /** * Dumps all active coroutines into the given output stream, providing a consistent snapshot of all existing coroutines at the moment of invocation. diff --git a/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt b/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt index c97515eefb..29b1e36e09 100644 --- a/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt +++ b/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt @@ -6,7 +6,6 @@ package kotlinx.coroutines.debug.internal import kotlinx.coroutines.* import kotlinx.coroutines.debug.* -import kotlinx.coroutines.internal.artificialFrame import net.bytebuddy.* import net.bytebuddy.agent.* import net.bytebuddy.dynamic.loading.* @@ -14,8 +13,10 @@ import java.io.* import java.text.* import java.util.* import kotlin.collections.ArrayList +import kotlin.collections.HashMap import kotlin.coroutines.* import kotlin.coroutines.jvm.internal.* +import kotlinx.coroutines.internal.artificialFrame as createArtificialFrame // IDEA bug workaround /** * Mirror of [DebugProbes] with actual implementation. @@ -25,13 +26,23 @@ import kotlin.coroutines.jvm.internal.* 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 = WeakHashMap, CoroutineState>() + private val capturedCoroutines = HashSet>() @Volatile private var installations = 0 private val isInstalled: Boolean get() = installations > 0 // To sort coroutines by creation order, used as unique id private var sequenceNumber: Long = 0 + /* + * This is an optimization in the face of KT-29997: + * Consider suspending call stack a()->b()->c() and c() completes its execution and every call is + * "almost" in tail position. + * + * 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() + @Synchronized public fun install() { if (++installations > 1) return @@ -53,6 +64,7 @@ internal object DebugProbesImpl { if (--installations != 0) return capturedCoroutines.clear() + callerInfoCache.clear() val cl = Class.forName("kotlin.coroutines.jvm.internal.DebugProbesKt") val cl2 = Class.forName("kotlinx.coroutines.debug.internal.NoOpProbesKt") @@ -67,17 +79,17 @@ internal object DebugProbesImpl { public fun hierarchyToString(job: Job): String { check(isInstalled) { "Debug probes are not installed" } val jobToStack = capturedCoroutines - .filterKeys { it.delegate.context[Job] != null } - .mapKeys { it.key.delegate.context[Job]!! } + .filter { it.delegate.context[Job] != null } + .associateBy({ it.delegate.context[Job]!! }, {it.info}) return buildString { job.build(jobToStack, this, "") } } - private fun Job.build(map: Map, builder: StringBuilder, indent: String) { - val state = map[this] + private fun Job.build(map: Map, builder: StringBuilder, indent: String) { + val info = map[this] val newIndent: String - if (state == null) { // Append coroutine without stacktrace + if (info == null) { // Append coroutine without stacktrace // Do not print scoped coroutines and do not increase indentation level @Suppress("INVISIBLE_REFERENCE") if (this !is kotlinx.coroutines.internal.ScopeCoroutine<*>) { @@ -88,9 +100,9 @@ internal object DebugProbesImpl { } } else { // Append coroutine with its last stacktrace element - val element = state.lastObservedStackTrace().firstOrNull() - val contState = state.state - builder.append("$indent$debugString, continuation is $contState at line $element\n") + val element = info.lastObservedStackTrace().firstOrNull() + val state = info.state + builder.append("$indent$debugString, continuation is $state at line $element\n") newIndent = indent + "\t" } // Append children with new indent @@ -103,39 +115,40 @@ internal object DebugProbesImpl { private val Job.debugString: String get() = if (this is JobSupport) toDebugString() else toString() @Synchronized - public fun dumpCoroutinesState(): List { + public fun dumpCoroutinesInfo(): List { check(isInstalled) { "Debug probes are not installed" } - return capturedCoroutines.entries.asSequence() - .map { CoroutineState(it.key.delegate, it.value) } + return capturedCoroutines.asSequence() + .map { CoroutineInfo(it.delegate, it.info) } .sortedBy { it.sequenceNumber } .toList() } public fun dumpCoroutines(out: PrintStream) { - check(isInstalled) { "Debug probes are not installed" } // Avoid inference with other out/err invocations by creating a string first dumpCoroutines().let { out.println(it) } } @Synchronized private fun dumpCoroutines(): String = buildString { + check(isInstalled) { "Debug probes are not installed" } // Synchronization window can be reduce even more, but no need to do it here append("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}") capturedCoroutines .asSequence() - .sortedBy { it.value.sequenceNumber } - .forEach { (key, value) -> - val observedStackTrace = value.lastObservedStackTrace() - val enhancedStackTrace = enhanceStackTraceWithThreadDump(value, observedStackTrace) - val state = if (value.state == State.RUNNING && enhancedStackTrace === observedStackTrace) - "${value.state} (Last suspension stacktrace, not an actual stacktrace)" + .sortedBy { it.info.sequenceNumber } + .forEach { owner -> + val info = owner.info + val observedStackTrace = info.lastObservedStackTrace() + val enhancedStackTrace = enhanceStackTraceWithThreadDump(info, observedStackTrace) + val state = if (info.state == State.RUNNING && enhancedStackTrace === observedStackTrace) + "${info.state} (Last suspension stacktrace, not an actual stacktrace)" else - value.state.toString() + info.state.toString() - append("\n\nCoroutine $key, state: $state") + append("\n\nCoroutine ${owner.delegate}, state: $state") if (observedStackTrace.isEmpty()) { - append("\n\tat ${artificialFrame(ARTIFICIAL_FRAME_MESSAGE)}") - printStackTrace(value.creationStackTrace) + append("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}") + printStackTrace(info.creationStackTrace) } else { printStackTrace(enhancedStackTrace) } @@ -143,17 +156,17 @@ internal object DebugProbesImpl { } /** - * Tries to enhance [coroutineTrace] (obtained by call to [CoroutineState.lastObservedStackTrace]) with - * thread dump of [CoroutineState.lastObservedThread]. + * Tries to enhance [coroutineTrace] (obtained by call to [CoroutineInfo.lastObservedStackTrace]) with + * thread dump of [CoroutineInfo.lastObservedThread]. * * Returns [coroutineTrace] if enhancement was unsuccessful or the enhancement result. */ private fun enhanceStackTraceWithThreadDump( - state: CoroutineState, + info: CoroutineInfo, coroutineTrace: List ): List { - val thread = state.lastObservedThread - if (state.state != State.RUNNING || thread == null) return coroutineTrace + val thread = info.lastObservedThread + if (info.state != State.RUNNING || thread == null) return coroutineTrace // Avoid security manager issues val actualTrace = runCatching { thread.stackTrace }.getOrNull() ?: return coroutineTrace @@ -168,12 +181,11 @@ internal object DebugProbesImpl { * 2) Find the next frame after BaseContinuationImpl.resumeWith (continuation machinery). * Invariant: this method is called under the lock, so such method **should** be present * in continuation stacktrace. - * * 3) Find target method in continuation stacktrace (metadata-based) * 4) Prepend dumped stacktrace (trimmed by target frame) to continuation stacktrace * * Heuristic may fail on recursion and overloads, but it will be automatically improved - * with KT-29997 + * with KT-29997. */ val indexOfResumeWith = actualTrace.indexOfFirst { it.className == "kotlin.coroutines.jvm.internal.BaseContinuationImpl" && @@ -181,33 +193,62 @@ internal object DebugProbesImpl { it.fileName == "ContinuationImpl.kt" } - // We haven't found "BaseContinuationImpl.resumeWith" resume call in stacktrace - // This is some inconsistency in machinery, do not fail, fallback - val continuationFrame = actualTrace.getOrNull(indexOfResumeWith - 1) - ?: return coroutineTrace - - val continuationStartFrame = coroutineTrace.indexOfFirst { - it.fileName == continuationFrame.fileName && - it.className == continuationFrame.className && - it.methodName == continuationFrame.methodName - } + 1 + val (continuationStartFrame, frameSkipped) = findContinuationStartIndex( + indexOfResumeWith, + actualTrace, + coroutineTrace) - if (continuationStartFrame == 0) return coroutineTrace + if (continuationStartFrame == -1) return coroutineTrace - val expectedSize = indexOfResumeWith + coroutineTrace.size - continuationStartFrame + val delta = if (frameSkipped) 1 else 0 + val expectedSize = indexOfResumeWith + coroutineTrace.size - continuationStartFrame - 1 - delta val result = ArrayList(expectedSize) - - for (index in 0 until indexOfResumeWith) { + for (index in 0 until indexOfResumeWith - delta) { result += actualTrace[index] } - for (index in continuationStartFrame until coroutineTrace.size) { + for (index in continuationStartFrame + 1 until coroutineTrace.size) { result += coroutineTrace[index] } return result } + /** + * Tries to find the lowest meaningful frame above `resumeWith` in the real stacktrace and + * its match in a coroutines stacktrace (steps 2-3 in heuristic). + * + * This method does more than just matching `realTrace.indexOf(resumeWith) - 1`: + * If method above `resumeWith` has no line number (thus it is `stateMachine.invokeSuspend`), + * it's skipped and attempt to match next one is made because state machine could have been missing in the original coroutine stacktrace. + * + * Returns index of such frame (or -1) and flag indicating whether frame with state machine was skipped + */ + private fun findContinuationStartIndex( + indexOfResumeWith: Int, + actualTrace: Array, + coroutineTrace: List + ): Pair { + val result = findIndexOfFrame(indexOfResumeWith - 1, actualTrace, coroutineTrace) + if (result == -1) return findIndexOfFrame(indexOfResumeWith - 2, actualTrace, coroutineTrace) to true + return result to false + } + + private fun findIndexOfFrame( + frameIndex: Int, + actualTrace: Array, + coroutineTrace: List + ): Int { + val continuationFrame = actualTrace.getOrNull(frameIndex) + ?: return -1 + + return coroutineTrace.indexOfFirst { + it.fileName == continuationFrame.fileName && + it.className == continuationFrame.className && + it.methodName == continuationFrame.methodName + } + } + private fun StringBuilder.printStackTrace(frames: List) { frames.forEach { frame -> append("\n\tat $frame") @@ -219,23 +260,53 @@ internal object DebugProbesImpl { internal fun probeCoroutineSuspended(frame: Continuation<*>) = updateState(frame, State.SUSPENDED) private fun updateState(frame: Continuation<*>, state: State) { - if (!isInstalled) return + // KT-29997 is here only since 1.3.30 + if (state == State.RUNNING && KotlinVersion.CURRENT.isAtLeast(1, 3, 30)) { + val stackFrame = frame as? CoroutineStackFrame ?: return + updateRunningState(stackFrame, state) + return + } + // Find ArtificialStackFrame of the coroutine - val owner = frame.owner() + val owner = frame.owner() ?: return updateState(owner, frame, state) } + @Synchronized // See comment to callerInfoCache + private fun updateRunningState(frame: CoroutineStackFrame, state: State) { + if (!isInstalled) return + // Lookup coroutine info in cache or by traversing stack frame + val info: CoroutineInfo + val cached = callerInfoCache.remove(frame) + if (cached != null) { + info = cached + } else { + info = frame.owner()?.info ?: return + // Guard against improper implementations of CoroutineStackFrame and bugs in the compiler + callerInfoCache.remove(info.lastObservedFrame?.realCaller()) + } + + info.updateState(state, frame as Continuation<*>) + // Do not cache it for proxy-classes such as ScopeCoroutines + val caller = frame.realCaller() ?: return + callerInfoCache[caller] = info + } + + private tailrec fun CoroutineStackFrame.realCaller(): CoroutineStackFrame? { + val caller = callerFrame ?: return null + return if (caller.getStackTraceElement() != null) caller else caller.realCaller() + } + @Synchronized - private fun updateState(owner: ArtificialStackFrame<*>?, frame: Continuation<*>, state: State) { - val coroutineState = capturedCoroutines[owner] ?: return - coroutineState.updateState(state, frame) + private fun updateState(owner: CoroutineOwner<*>, frame: Continuation<*>, state: State) { + if (!isInstalled) return + owner.info.updateState(state, frame) } - private fun Continuation<*>.owner(): ArtificialStackFrame<*>? = - (this as? CoroutineStackFrame)?.owner() + private fun Continuation<*>.owner(): CoroutineOwner<*>? = (this as? CoroutineStackFrame)?.owner() - private tailrec fun CoroutineStackFrame.owner(): ArtificialStackFrame<*>? = - if (this is ArtificialStackFrame<*>) this else callerFrame?.owner() + private tailrec fun CoroutineStackFrame.owner(): CoroutineOwner<*>? = + if (this is CoroutineOwner<*>) this else callerFrame?.owner() internal fun probeCoroutineCreated(completion: Continuation): Continuation { if (!isInstalled) return completion @@ -249,7 +320,7 @@ internal object DebugProbesImpl { * Here we replace completion with a sequence of CoroutineStackFrame objects * which represents creation stacktrace, thus making stacktrace recovery mechanism * even more verbose (it will attach coroutine creation stacktrace to all exceptions), - * and then using this artificial frame as an identifier of coroutineSuspended/resumed calls. + * and then using CoroutineOwner completion as unique identifier of coroutineSuspended/resumed calls. */ val stacktrace = sanitizeStackTrace(Exception()) val frame = stacktrace.foldRight(null) { frame, acc -> @@ -257,24 +328,38 @@ internal object DebugProbesImpl { override val callerFrame: CoroutineStackFrame? = acc override fun getStackTraceElement(): StackTraceElement = frame } - } - return ArtificialStackFrame(completion, frame!!).also { - storeFrame(it, completion) - } + }!! + + return createOwner(completion, frame) } @Synchronized - private fun storeFrame(frame: ArtificialStackFrame, completion: Continuation) { - capturedCoroutines[frame] = CoroutineState(completion, frame, ++sequenceNumber) + private fun createOwner(completion: Continuation, frame: CoroutineStackFrame): Continuation { + if (!isInstalled) return completion + val info = CoroutineInfo(completion.context, frame, ++sequenceNumber) + val owner = CoroutineOwner(completion, info, frame) + capturedCoroutines += owner + return owner } @Synchronized - private fun probeCoroutineCompleted(coroutine: ArtificialStackFrame<*>) { - capturedCoroutines.remove(coroutine) + 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() + callerInfoCache.remove(caller) } - private class ArtificialStackFrame( + /** + * This class is injected as completion of all continuations in [probeCoroutineCompleted]. + * It is owning the coroutine info and responsible for managing all its external info related to debug agent. + */ + private class CoroutineOwner( @JvmField val delegate: Continuation, + @JvmField val info: CoroutineInfo, frame: CoroutineStackFrame ) : Continuation by delegate, CoroutineStackFrame by frame { override fun resumeWith(result: Result) { @@ -292,7 +377,7 @@ internal object DebugProbesImpl { if (!DebugProbes.sanitizeStackTraces) { return List(size - probeIndex) { - if (it == 0) artificialFrame(ARTIFICIAL_FRAME_MESSAGE) else stackTrace[it + probeIndex] + if (it == 0) createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE) else stackTrace[it + probeIndex] } } @@ -302,7 +387,7 @@ internal object DebugProbesImpl { * output will be [e, i1, i3, e, i4, e, i5, i7] */ val result = ArrayList(size - probeIndex + 1) - result += artificialFrame(ARTIFICIAL_FRAME_MESSAGE) + result += createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE) var includeInternalFrame = true for (i in (probeIndex + 1) until size - 1) { val element = stackTrace[i] diff --git a/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeoutStatement.kt b/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeoutStatement.kt index fd74fa96ec..a00a17d58d 100644 --- a/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeoutStatement.kt +++ b/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeoutStatement.kt @@ -73,8 +73,8 @@ internal class CoroutinesTimeoutStatement( private fun cancelIfNecessary() { if (cancelOnTimeout) { - DebugProbes.dumpCoroutinesState().forEach { - it.jobOrNull?.cancel() + DebugProbes.dumpCoroutinesInfo().forEach { + it.job?.cancel() } } } diff --git a/kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt b/kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt index dd4dc79b80..35e9d1e9f2 100644 --- a/kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt +++ b/kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt @@ -5,32 +5,13 @@ package kotlinx.coroutines.debug import kotlinx.coroutines.* -import org.junit.* import org.junit.Test import kotlin.coroutines.* import kotlin.test.* -@Suppress("SUSPENSION_POINT_INSIDE_MONITOR") // bug in 1.3.0 FE -class CoroutinesDumpTest : TestBase() { - +class CoroutinesDumpTest : DebugTestBase() { private val monitor = Any() - @Before - fun setUp() { - before() - DebugProbes.sanitizeStackTraces = false - DebugProbes.install() - } - - @After - fun tearDown() { - try { - DebugProbes.uninstall() - } finally { - onCompletion() - } - } - @Test fun testSuspendedCoroutine() = synchronized(monitor) { val deferred = GlobalScope.async { @@ -49,8 +30,8 @@ class CoroutinesDumpTest : TestBase() { "\tat kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:23)\n" + "\tat kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:99)\n") - val found = DebugProbes.dumpCoroutinesState().single { it.jobOrNull === deferred } - assertSame(deferred, found.jobOrNull) + val found = DebugProbes.dumpCoroutinesInfo().single { it.job === deferred } + assertSame(deferred, found.job) runBlocking { deferred.cancelAndJoin() } } @@ -85,8 +66,10 @@ class CoroutinesDumpTest : TestBase() { } awaitCoroutineStarted() + Thread.sleep(10) verifyDump( - "Coroutine \"coroutine#1\":DeferredCoroutine{Active}@1e4a7dd4, state: RUNNING (Last suspension stacktrace, not an actual stacktrace)\n" + + "Coroutine \"coroutine#1\":DeferredCoroutine{Active}@1e4a7dd4, state: RUNNING\n" + + "\tat java.lang.Thread.sleep(Native Method)\n" + "\tat kotlinx.coroutines.debug.CoroutinesDumpTest.nestedActiveMethod(CoroutinesDumpTest.kt:111)\n" + "\tat kotlinx.coroutines.debug.CoroutinesDumpTest.activeMethod(CoroutinesDumpTest.kt:106)\n" + "\tat kotlinx.coroutines.debug.CoroutinesDumpTest\$testRunningCoroutineWithSuspensionPoint\$1\$deferred\$1.invokeSuspend(CoroutinesDumpTest.kt:71)\n" + @@ -111,7 +94,7 @@ class CoroutinesDumpTest : TestBase() { } awaitCoroutineStarted() - val coroutine = DebugProbes.dumpCoroutinesState().first() + val coroutine = DebugProbes.dumpCoroutinesInfo().first() val result = coroutine.creationStackTrace.fold(StringBuilder()) { acc, element -> acc.append(element.toString()) acc.append('\n') diff --git a/kotlinx-coroutines-debug/test/DebugTestBase.kt b/kotlinx-coroutines-debug/test/DebugTestBase.kt new file mode 100644 index 0000000000..7ce214992b --- /dev/null +++ b/kotlinx-coroutines-debug/test/DebugTestBase.kt @@ -0,0 +1,32 @@ +/* + * Copyright 2016-2019 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 kotlinx.coroutines.debug.junit4.* +import org.junit.* + +open class DebugTestBase : TestBase() { + + @JvmField + @Rule + val timeout = CoroutinesTimeout.seconds(10) + + @Before + open fun setUp() { + before() + DebugProbes.sanitizeStackTraces = false + DebugProbes.install() + } + + @After + fun tearDown() { + try { + DebugProbes.uninstall() + } finally { + onCompletion() + } + } +} \ No newline at end of file diff --git a/kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt b/kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt index b5e53bf3ec..72082942e8 100644 --- a/kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt +++ b/kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt @@ -4,36 +4,19 @@ package kotlinx.coroutines.debug import kotlinx.coroutines.* -import org.junit.* import org.junit.Test import java.util.concurrent.* import kotlin.test.* -class RunningThreadStackMergeTest : TestBase() { +class RunningThreadStackMergeTest : DebugTestBase() { private val testMainBlocker = CountDownLatch(1) // Test body blocks on it private val coroutineBlocker = CyclicBarrier(2) // Launched coroutine blocks on it - @Before - fun setUp() { - before() - DebugProbes.install() - } - - @After - fun tearDown() { - try { - DebugProbes.uninstall() - } finally { - onCompletion() - } - } - @Test fun testStackMergeWithContext() = runTest { launchCoroutine() awaitCoroutineStarted() - verifyDump( "Coroutine \"coroutine#1\":BlockingCoroutine{Active}@62230679", // <- this one is ignored "Coroutine \"coroutine#2\":StandaloneCoroutine{Active}@50284dc4, state: RUNNING\n" + @@ -49,7 +32,7 @@ class RunningThreadStackMergeTest : TestBase() { "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest\$launchCoroutine\$1.invokeSuspend(RunningThreadStackMergeTest.kt:68)\n" + "\t(Coroutine creation stacktrace)\n" + "\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)", - ignoredCoroutine = "BlockingCoroutine" + ignoredCoroutine = ":BlockingCoroutine" ) coroutineBlocker.await() } @@ -102,26 +85,11 @@ class RunningThreadStackMergeTest : TestBase() { "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest\$launchEscapingCoroutine\$1.invokeSuspend(RunningThreadStackMergeTest.kt:116)\n" + "\t(Coroutine creation stacktrace)\n" + "\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)", - ignoredCoroutine = "BlockingCoroutine" + ignoredCoroutine = ":BlockingCoroutine" ) coroutineBlocker.await() } - @Test - fun testRunBlocking() = runBlocking { - verifyDump("Coroutine \"coroutine#1\":BlockingCoroutine{Active}@4bcd176c, state: RUNNING\n" + - "\tat java.lang.Thread.getStackTrace(Thread.java:1552)\n" + - "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.enhanceStackTraceWithThreadDump(DebugProbesImpl.kt:147)\n" + - "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:122)\n" + - "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:109)\n" + - "\tat kotlinx.coroutines.debug.DebugProbes.dumpCoroutines(DebugProbes.kt:122)\n" + - "\tat kotlinx.coroutines.debug.StracktraceUtilsKt.verifyDump(StracktraceUtils.kt)\n" + - "\tat kotlinx.coroutines.debug.StracktraceUtilsKt.verifyDump\$default(StracktraceUtils.kt)\n" + - "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest\$testRunBlocking\$1.invokeSuspend(RunningThreadStackMergeTest.kt:112)\n" + - "\t(Coroutine creation stacktrace)\n" + - "\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)\n") - } - private fun CoroutineScope.launchEscapingCoroutine() { launch(Dispatchers.Default) { suspendingFunctionWithContext() @@ -138,6 +106,57 @@ class RunningThreadStackMergeTest : TestBase() { assertTrue(true) } + @Test + fun testMergeThroughInvokeSuspend() = runTest { + launchEscapingCoroutineWithoutContext() + awaitCoroutineStarted() + verifyDump( + "Coroutine \"coroutine#1\":BlockingCoroutine{Active}@62230679", // <- this one is ignored + "Coroutine \"coroutine#2\":StandaloneCoroutine{Active}@3aea3c67, state: RUNNING\n" + + "\tat sun.misc.Unsafe.park(Native Method)\n" + + "\tat java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)\n" + + "\tat java.util.concurrent.locks.AbstractQueuedSynchronizer\$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)\n" + + "\tat java.util.concurrent.CyclicBarrier.dowait(CyclicBarrier.java:234)\n" + + "\tat java.util.concurrent.CyclicBarrier.await(CyclicBarrier.java:362)\n" + + "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest.nonSuspendingFun(RunningThreadStackMergeTest.kt:83)\n" + + "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest.suspendingFunctionWithoutContext(RunningThreadStackMergeTest.kt:160)\n" + + "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest\$launchEscapingCoroutineWithoutContext\$1.invokeSuspend(RunningThreadStackMergeTest.kt:153)\n" + + "\t(Coroutine creation stacktrace)\n" + + "\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)", + ignoredCoroutine = ":BlockingCoroutine" + ) + coroutineBlocker.await() + } + + private fun CoroutineScope.launchEscapingCoroutineWithoutContext() { + launch(Dispatchers.Default) { + suspendingFunctionWithoutContext() + assertTrue(true) + } + } + + private suspend fun suspendingFunctionWithoutContext() { + actualSuspensionPoint() + nonSuspendingFun() + assertTrue(true) + } + + @Test + fun testRunBlocking() = runBlocking { + verifyDump("Coroutine \"coroutine#1\":BlockingCoroutine{Active}@4bcd176c, state: RUNNING\n" + + "\tat java.lang.Thread.getStackTrace(Thread.java:1552)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.enhanceStackTraceWithThreadDump(DebugProbesImpl.kt:147)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:122)\n" + + "\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:109)\n" + + "\tat kotlinx.coroutines.debug.DebugProbes.dumpCoroutines(DebugProbes.kt:122)\n" + + "\tat kotlinx.coroutines.debug.StracktraceUtilsKt.verifyDump(StracktraceUtils.kt)\n" + + "\tat kotlinx.coroutines.debug.StracktraceUtilsKt.verifyDump\$default(StracktraceUtils.kt)\n" + + "\tat kotlinx.coroutines.debug.RunningThreadStackMergeTest\$testRunBlocking\$1.invokeSuspend(RunningThreadStackMergeTest.kt:112)\n" + + "\t(Coroutine creation stacktrace)\n" + + "\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)\n") + } + + private suspend fun actualSuspensionPoint() { nestedSuspensionPoint() assertTrue(true) diff --git a/kotlinx-coroutines-debug/test/SanitizedProbesTest.kt b/kotlinx-coroutines-debug/test/SanitizedProbesTest.kt index 4d35d02c50..3ee80ad38f 100644 --- a/kotlinx-coroutines-debug/test/SanitizedProbesTest.kt +++ b/kotlinx-coroutines-debug/test/SanitizedProbesTest.kt @@ -13,21 +13,11 @@ import org.junit.Test import java.util.concurrent.* import kotlin.test.* -class SanitizedProbesTest : TestBase() { +class SanitizedProbesTest : DebugTestBase() { @Before - fun setUp() { - before() + override fun setUp() { + super.setUp() DebugProbes.sanitizeStackTraces = true - DebugProbes.install() - } - - @After - fun tearDown() { - try { - DebugProbes.uninstall() - } finally { - onCompletion() - } } @Test diff --git a/kotlinx-coroutines-debug/test/ScopedBuildersTest.kt b/kotlinx-coroutines-debug/test/ScopedBuildersTest.kt index 25b46339ad..c762725569 100644 --- a/kotlinx-coroutines-debug/test/ScopedBuildersTest.kt +++ b/kotlinx-coroutines-debug/test/ScopedBuildersTest.kt @@ -8,22 +8,7 @@ import kotlinx.coroutines.* import org.junit.* import kotlin.coroutines.* -class ScopedBuildersTest : TestBase() { - @Before - fun setUp() { - before() - DebugProbes.sanitizeStackTraces = false - DebugProbes.install() - } - - @After - fun tearDown() { - try { - DebugProbes.uninstall() - } finally { - onCompletion() - } - } +class ScopedBuildersTest : DebugTestBase() { @Test fun testNestedScopes() = runBlocking { diff --git a/kotlinx-coroutines-debug/test/StartModeProbesTest.kt b/kotlinx-coroutines-debug/test/StartModeProbesTest.kt index bd33c5c9d2..a0297da396 100644 --- a/kotlinx-coroutines-debug/test/StartModeProbesTest.kt +++ b/kotlinx-coroutines-debug/test/StartModeProbesTest.kt @@ -9,23 +9,7 @@ import org.junit.* import org.junit.Test import kotlin.test.* -class StartModeProbesTest : TestBase() { - - @Before - fun setUp() { - before() - DebugProbes.sanitizeStackTraces = false - DebugProbes.install() - } - - @After - fun tearDown() { - try { - DebugProbes.uninstall() - } finally { - onCompletion() - } - } +class StartModeProbesTest : DebugTestBase() { @Test fun testUndispatched() = runTest { diff --git a/kotlinx-coroutines-debug/test/StracktraceUtils.kt b/kotlinx-coroutines-debug/test/StracktraceUtils.kt index 62dcd78d45..cab4ed86b3 100644 --- a/kotlinx-coroutines-debug/test/StracktraceUtils.kt +++ b/kotlinx-coroutines-debug/test/StracktraceUtils.kt @@ -97,7 +97,7 @@ public fun verifyPartialDump(createdCoroutinesCount: Int, vararg frames: String) trace.any { tr -> tr.contains(frame) } } - assertEquals(createdCoroutinesCount, DebugProbes.dumpCoroutinesState().size) + assertEquals(createdCoroutinesCount, DebugProbes.dumpCoroutinesInfo().size) assertTrue(matches) }