Skip to content

Commit

Permalink
Disable DebugProbes.enableCreationStackTraces by default (#4028)
Browse files Browse the repository at this point in the history
Adjust tests and the documentation

Rationale: this option implies significant and non-trivial overhead, yet its utility is unclear (e.g., we got a multitude of signals that this option brings no use and none that it's useful even when asked explicitly)

Fixes #3783
  • Loading branch information
qwwdfsad authored Feb 15, 2024
1 parent c5a579e commit 90d9a30
Show file tree
Hide file tree
Showing 13 changed files with 125 additions and 145 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,7 @@ internal object DebugProbesImpl {
private val sequenceNumber = atomic(0L)

internal var sanitizeStackTraces: Boolean = true
internal var enableCreationStackTraces: Boolean = true
internal var enableCreationStackTraces: Boolean = false
public var ignoreCoroutinesWithEmptyContext: Boolean = true

/*
Expand Down
14 changes: 2 additions & 12 deletions kotlinx-coroutines-debug/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -70,8 +70,8 @@ When used as Java agent, `"kotlinx.coroutines.debug.enable.creation.stack.trace"

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.
For that, it is strongly recommended not to enable [DebugProbes.enableCreationStackTraces], as enabling it makes
the performance overhead of the debug probes non-negligible.
With creation stack-traces disabled, the typical overhead of enabled debug probes is a single-digit percentage of the total
application throughput.

Expand Down Expand Up @@ -123,16 +123,6 @@ Coroutine "coroutine#2":DeferredCoroutine{Active}@289d1c02, state: SUSPENDED
at ExampleKt.combineResults(Example.kt:11)
at ExampleKt$computeValue$2.invokeSuspend(Example.kt:7)
at ExampleKt$main$1$deferred$1.invokeSuspend(Example.kt:25)
at _COROUTINE._CREATION._(CoroutineDebugging.kt)
at kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)
at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:25)
at kotlinx.coroutines.BuildersKt.async$default(Unknown Source)
at ExampleKt$main$1.invokeSuspend(Example.kt:25)
at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)
at kotlinx.coroutines.DispatchedTask.run(Dispatched.kt:233)
at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
at ExampleKt.main(Example.kt:23)
at ExampleKt.main(Example.kt)
... More coroutines here ...
Expand Down
7 changes: 3 additions & 4 deletions kotlinx-coroutines-debug/src/DebugProbes.kt
Original file line number Diff line number Diff line change
Expand Up @@ -65,12 +65,11 @@ public object DebugProbes {

/**
* 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.
* 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.
* to be disabled in production environments to avoid performance overhead of capturing real stacktraces.
*
* `true` by default.
* `false` by default.
*/
public var enableCreationStackTraces: Boolean
get() = DebugProbesImpl.enableCreationStackTraces
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,7 @@ 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.
* and can be optionally enabled if the creation stack traces are necessary.
*
* Example of usage:
* ```
Expand All @@ -34,7 +34,7 @@ import java.util.concurrent.*
public class CoroutinesTimeout(
private val testTimeoutMs: Long,
private val cancelOnTimeout: Boolean = false,
private val enableCoroutineCreationStackTraces: Boolean = true
private val enableCoroutineCreationStackTraces: Boolean = false
) : TestRule {

@Suppress("UNUSED") // Binary compatibility
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ internal class CoroutinesTimeoutException(val timeoutMs: Long): Exception("test
* Additionally, it installs [DebugProbes] and dumps all coroutines at the moment of the timeout. It also cancels
* 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.
* and can be optionally enabled if the creation stack traces are necessary.
*
* Beware that if several tests that use this extension set [enableCoroutineCreationStackTraces] to different values and
* execute in parallel, the behavior is ill-defined. In order to avoid conflicts between different instances of this
Expand Down Expand Up @@ -51,7 +51,7 @@ internal class CoroutinesTimeoutException(val timeoutMs: Long): Exception("test
* */
// NB: the constructor is not private so that JUnit is able to call it via reflection.
internal class CoroutinesTimeoutExtension internal constructor(
private val enableCoroutineCreationStackTraces: Boolean = true,
private val enableCoroutineCreationStackTraces: Boolean = false,
private val timeoutMs: Long? = null,
private val cancelOnTimeout: Boolean? = null): InvocationInterceptor
{
Expand Down Expand Up @@ -272,4 +272,4 @@ internal class CoroutinesTimeoutExtension internal constructor(
): T =
runWithTimeoutDumpingCoroutines(methodName, testTimeoutMs, cancelOnTimeout,
{ CoroutinesTimeoutException(testTimeoutMs) }, { invocation.proceed() })
}
}
7 changes: 7 additions & 0 deletions kotlinx-coroutines-debug/test/CoroutinesDumpTest.kt
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package kotlinx.coroutines.debug

import kotlinx.coroutines.testing.*
import kotlinx.coroutines.*
import org.junit.*
import org.junit.Test
import kotlin.coroutines.*
import kotlin.test.*
Expand All @@ -10,6 +11,12 @@ class CoroutinesDumpTest : DebugTestBase() {
private val monitor = Any()
private var coroutineThread: Thread? = null // guarded by monitor

@Before
override fun setUp() {
super.setUp()
DebugProbes.enableCreationStackTraces = true
}

@Test
fun testSuspendedCoroutine() = runBlocking {
val deferred = async(Dispatchers.Default) {
Expand Down
59 changes: 23 additions & 36 deletions kotlinx-coroutines-debug/test/DebugProbesTest.kt
Original file line number Diff line number Diff line change
Expand Up @@ -18,14 +18,14 @@ class DebugProbesTest : DebugTestBase() {
val deferred = createDeferred()
val traces = listOf(
"java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:14)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:49)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt:44)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsync\$1.invokeSuspend(DebugProbesTest.kt:17)\n",
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:14)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:49)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt:44)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsync\$1.invokeSuspend(DebugProbesTest.kt:17)\n",
"Caused by: java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:14)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)"
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:14)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)"
)
nestedMethod(deferred, traces)
deferred.join()
Expand All @@ -38,25 +38,15 @@ class DebugProbesTest : DebugTestBase() {
val deferred = createDeferred()
val traces = listOf(
"java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsyncWithProbes\$1\$1.invokeSuspend(DebugProbesTest.kt:62)\n" +
"\tat _COROUTINE._CREATION._(CoroutineDebugging.kt)\n" +
"\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt)\n" +
"\tat kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt)\n" +
"\tat kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable\$default(Cancellable.kt)\n" +
"\tat kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt)\n" +
"\tat kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt)\n" +
"\tat kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt)\n" +
"\tat kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)\n" +
"\tat kotlinx.coroutines.testing.TestBase.runTest(TestBase.kt)\n" +
"\tat kotlinx.coroutines.testing.TestBase.runTest\$default(TestBase.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.testAsyncWithProbes(DebugProbesTest.kt)",
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsyncWithProbes\$1\$1.invokeSuspend(DebugProbesTest.kt:62)",
"Caused by: java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt)\n")
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt)\n"
)
nestedMethod(deferred, traces)
deferred.join()
}
Expand All @@ -69,18 +59,15 @@ class DebugProbesTest : DebugTestBase() {
val deferred = createDeferred()
val traces = listOf(
"java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:71)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt:66)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsyncWithSanitizedProbes\$1\$1.invokeSuspend(DebugProbesTest.kt:87)\n" +
"\tat _COROUTINE._CREATION._(CoroutineDebugging.kt)\n" +
"\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)\n" +
"\tat kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:23)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.testAsyncWithSanitizedProbes(DebugProbesTest.kt:38)",
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
"\tat _COROUTINE._BOUNDARY._(CoroutineDebugging.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:71)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest.nestedMethod(DebugProbesTest.kt:66)\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$testAsyncWithSanitizedProbes\$1\$1.invokeSuspend(DebugProbesTest.kt:87)",
"Caused by: java.util.concurrent.ExecutionException\n" +
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)\n")
"\tat kotlinx.coroutines.debug.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)\n"
)
nestedMethod(deferred, traces)
deferred.join()
}
Expand Down
2 changes: 1 addition & 1 deletion kotlinx-coroutines-debug/test/DebugTestBase.kt
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ open class DebugTestBase : TestBase() {
open fun setUp() {
before()
DebugProbes.sanitizeStackTraces = false
DebugProbes.enableCreationStackTraces = true
DebugProbes.enableCreationStackTraces = false
DebugProbes.install()
}

Expand Down
47 changes: 47 additions & 0 deletions kotlinx-coroutines-debug/test/DumpWithCreationStackTraceTest.kt
Original file line number Diff line number Diff line change
@@ -0,0 +1,47 @@
package kotlinx.coroutines.debug

import kotlinx.coroutines.*
import org.junit.*
import org.junit.Test
import kotlin.test.*

class DumpWithCreationStackTraceTest : DebugTestBase() {
@Before
override fun setUp() {
super.setUp()
DebugProbes.enableCreationStackTraces = true
}

@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)\n" +
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.enhanceStackTraceWithThreadDumpImpl(DebugProbesImpl.kt)\n" +
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutinesSynchronized(DebugProbesImpl.kt)\n" +
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt)\n" +
"\tat kotlinx.coroutines.debug.DebugProbes.dumpCoroutines(DebugProbes.kt:182)\n" +
"\tat kotlinx.coroutines.debug.StacktraceUtilsKt.verifyDump(StacktraceUtils.kt)\n" +
"\tat kotlinx.coroutines.debug.StacktraceUtilsKt.verifyDump\$default(StacktraceUtils.kt)\n" +
"\tat kotlinx.coroutines.debug.DumpWithCreationStackTraceTest\$testCoroutinesDump\$1.invokeSuspend(DumpWithCreationStackTraceTest.kt)\n" +
"\tat _COROUTINE._CREATION._(CoroutineDebugging.kt)\n" +
"\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt)",

"Coroutine \"coroutine#2\":DeferredCoroutine{Active}@383fa309, state: SUSPENDED\n" +
"\tat kotlinx.coroutines.debug.DumpWithCreationStackTraceTest\$createActiveDeferred\$1.invokeSuspend(DumpWithCreationStackTraceTest.kt)"
)
deferred.cancelAndJoin()
}


private fun CoroutineScope.createActiveDeferred(): Deferred<*> = async {
suspendingMethod()
assertTrue(true)
}

private suspend fun suspendingMethod() {
delay(Long.MAX_VALUE)
}
}
42 changes: 0 additions & 42 deletions kotlinx-coroutines-debug/test/DumpWithoutCreationStackTraceTest.kt

This file was deleted.

Loading

0 comments on commit 90d9a30

Please sign in to comment.