aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorVsevolod Tolstopyatov <qwwdfsad@gmail.com>2020-03-13 14:13:09 +0300
committerGitHub <noreply@github.com>2020-03-13 14:13:09 +0300
commit4116fbf1dda610d13095e0e23642a66862f56065 (patch)
tree31962b6bef452c56f1f3f15623e2feb49fa15dab
parent10fd73e8a1751819280ab4d7e4ba26b89ff57d9f (diff)
downloadplatform_external_kotlinx.coroutines-4116fbf1dda610d13095e0e23642a66862f56065.tar.gz
platform_external_kotlinx.coroutines-4116fbf1dda610d13095e0e23642a66862f56065.tar.bz2
platform_external_kotlinx.coroutines-4116fbf1dda610d13095e0e23642a66862f56065.zip
Make DebugProbes ready to production (#1862)
* Speed-up installed debug probes by splitting global probes lock to RW-lock, guard all state transitions with read lock and all read operations with write lock to guarantee a consistent snapshot * Prevent IllegalStateException during 'kill -5' command * Introduce flag to disable creation stacktrace capturing in DebugProbes * Support proposed changes in JUnit4 rules Fixes #1379 Fixes #1372
-rw-r--r--README.md1
-rw-r--r--kotlinx-coroutines-debug/README.md23
-rw-r--r--kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api16
-rw-r--r--kotlinx-coroutines-debug/src/AgentPremain.kt13
-rw-r--r--kotlinx-coroutines-debug/src/CoroutineInfo.kt6
-rw-r--r--kotlinx-coroutines-debug/src/DebugProbes.kt20
-rw-r--r--kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt86
-rw-r--r--kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt32
-rw-r--r--kotlinx-coroutines-debug/test/DebugTestBase.kt3
-rw-r--r--kotlinx-coroutines-debug/test/DumpWithoutCreationStackTraceTest.kt44
-rw-r--r--kotlinx-coroutines-debug/test/StracktraceUtils.kt4
-rw-r--r--kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutDisabledTracesTest.kt47
-rw-r--r--kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutEagerTest.kt2
-rw-r--r--kotlinx-coroutines-debug/test/junit4/CoroutinesTimeoutTest.kt2
-rw-r--r--kotlinx-coroutines-debug/test/junit4/TestFailureValidation.kt10
15 files changed, 250 insertions, 59 deletions
diff --git a/README.md b/README.md
index ba10d6b1..7a827a2b 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
<!--- MODULE kotlinx-coroutines-play-services -->
<!--- INDEX kotlinx.coroutines.tasks -->
+[Task.await]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-play-services/kotlinx.coroutines.tasks/com.google.android.gms.tasks.-task/await.html
<!--- MODULE kotlinx-coroutines-reactive -->
<!--- INDEX kotlinx.coroutines.reactive -->
[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 27048598..4128e107 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
<!--- INDEX kotlinx.coroutines.debug.junit4 -->
[CoroutinesTimeout]: https://kotlin.github.io/kotlinx.coroutines/kotlinx-coroutines-debug/kotlinx.coroutines.debug.junit4/-coroutines-timeout/index.html
<!--- END -->
diff --git a/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api b/kotlinx-coroutines-debug/api/kotlinx-coroutines-debug.api
index 3fba3e2f..6061f038 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 <init> (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 <init> (JZ)V
public synthetic fun <init> (JZILkotlin/jvm/internal/DefaultConstructorMarker;)V
+ public fun <init> (JZZ)V
+ public synthetic fun <init> (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 94ff0098..aa842ce3 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 97bc2be5..d92d9b6b 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<StackTraceElement> get() = creationStackTrace()
@@ -66,8 +67,9 @@ public class CoroutineInfo internal constructor(
}
private fun creationStackTrace(): List<StackTraceElement> {
+ val bottom = creationStackBottom ?: return emptyList()
// Skip "Coroutine creation stacktrace" frame
- return sequence<StackTraceElement> { yieldFrames(creationStackBottom.callerFrame) }.toList()
+ return sequence<StackTraceElement> { yieldFrames(bottom.callerFrame) }.toList()
}
private tailrec suspend fun SequenceScope<StackTraceElement>.yieldFrames(frame: CoroutineStackFrame?) {
diff --git a/kotlinx-coroutines-debug/src/DebugProbes.kt b/kotlinx-coroutines-debug/src/DebugProbes.kt
index eb6a59b6..f164e7cc 100644
--- a/kotlinx-coroutines-debug/src/DebugProbes.kt
+++ b/kotlinx-coroutines-debug/src/DebugProbes.kt
@@ -28,21 +28,31 @@ 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].
*/
public val isInstalled: Boolean get() = DebugProbesImpl.isInstalled
@@ -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 <T> probeCoroutineCreated(completion: kotlin.coroutines.Continuation<T>): kotlin.coroutines.Continuation<T> =
+internal fun <T> probeCoroutineCreated(completion: Continuation<T>): Continuation<T> =
DebugProbesImpl.probeCoroutineCreated(completion)
diff --git a/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt b/kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt
index a7ceb146..090d3e5d 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<CoroutineOwner<*>>()
+ private val capturedCoroutines = Collections.newSetFromMap(ConcurrentHashMap<CoroutineOwner<*>, 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<CoroutineStackFrame, CoroutineInfo>()
+ private val callerInfoCache = ConcurrentHashMap<CoroutineStackFrame, CoroutineInfo>()
- @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<CoroutineInfo> {
+ public fun dumpCoroutinesInfo(): List<CoroutineInfo> = 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 <T> probeCoroutineCreated(completion: Continuation<T>): Continuation<T> {
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<StackTraceElement, CoroutineStackFrame?>(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<StackTraceElement, CoroutineStackFrame?>(null) { frame, acc ->
+ object : CoroutineStackFrame {
+ override val callerFrame: CoroutineStackFrame? = acc
+ override fun getStackTraceElement(): StackTraceElement = frame
+ }
}
- }!!
+ } else {
+ null
+ }
return createOwner(completion, frame)
}
- @Synchronized
- private fun <T> createOwner(completion: Continuation<T>, frame: CoroutineStackFrame): Continuation<T> {
+ private fun <T> createOwner(completion: Continuation<T>, frame: CoroutineStackFrame?): Continuation<T> {
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<T>(
@JvmField val delegate: Continuation<T>,
@JvmField val info: CoroutineInfo,
- frame: CoroutineStackFrame
- ) : Continuation<T> by delegate, CoroutineStackFrame by frame {
+ private val frame: CoroutineStackFrame?
+ ) : Continuation<T> by delegate, CoroutineStackFrame {
+
+ override val callerFrame: CoroutineStackFrame?
+ get() = frame?.callerFrame
+
+ override fun getStackTraceElement(): StackTraceElement? = frame?.getStackTraceElement()
+
override fun resumeWith(result: Result<T>) {
probeCoroutineCompleted(this)
delegate.resumeWith(result)
diff --git a/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt b/kotlinx-coroutines-debug/src/junit4/CoroutinesTimeout.kt
index 16b53567..0f14ade8 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 3e4abea2..2a37f588 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 00000000..89782e4c
--- /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 de31ac10..12a39c00 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 00000000..886007c3
--- /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<Unit> { }
+ expectUnreached()
+ }
+
+ @Test
+ fun hangingTest() = runBlocking<Unit> {
+ 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 eaef43dd..0845f5bc 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 fb170c07..ac3408e2 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 a10c5118..34ba679a 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
)
)