Introduce flag to disable creation stacktrace capturing in DebugProbes

Author: qwwdfsad

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

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 -->

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;
 }
 

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()
     }

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?) {

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].
      */

kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt

@@ -334,18 +334,23 @@ 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)
     }
 
-    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.incrementAndGet())
         val owner = CoroutineOwner(completion, info, frame)
@@ -372,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)

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,30 +37,50 @@ 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()
     }
 
     companion object {
         /**
          * 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
+            )
     }
 
     /**

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()
         }
     }
-}
+}

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)
+    }
+}

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])
             }
         }