Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Disable DebugProbes.enableCreationStackTraces by default #4028

Merged
merged 3 commits into from
Feb 15, 2024
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
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
10 changes: 0 additions & 10 deletions kotlinx-coroutines-debug/README.md
Original file line number Diff line number Diff line change
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 keeping debug probes enabled.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I understood the previous version better. With enableCreationStackTraces, you copy a bunch of stackframe descriptions with many strings around on every coroutine creation, which is expensive, ok, this makes sense. What does the new text mean? This option changes the behavior while the debug probes are enabled, it doesn't force them to be enabled longer than needed, right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This text is indeed misleading, changed it.

you copy a bunch of stackframe descriptions with many strings around on every coroutine creation

Surprisingly, this one is quite fast. The heaviest performance hitter is Throwable.fillInStackTrace. JVM upcall + stack unwinding are quite costly.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

About exceptions performance: https://shipilev.net/blog/2014/exceptional-performance/
That's why we have overridden fillInStackTrace in some places

*
* `true` by default.
* `false` by default.
*/
public var enableCreationStackTraces: Boolean
get() = DebugProbesImpl.enableCreationStackTraces
Expand Down
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.