Skip to content

Commit b43f8af

Browse files
committed
[WIP] Introducing coroutine-debug module with probe-based agent
* Agent automatically captures stacktrace when coroutine is created * Agent patches coroutine completion, so backtrace augmentation (#493) prepends creation stacktrace to the augmented stacktrace * Agent can be dynamically loaded and unloaded Fixes #74
1 parent 4380dd9 commit b43f8af

File tree

6 files changed

+307
-1
lines changed

6 files changed

+307
-1
lines changed
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,8 @@
1+
/*
2+
* Copyright 2016-2018 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
5+
dependencies {
6+
compile "net.bytebuddy:byte-buddy:$byte_buddy_version"
7+
compile "net.bytebuddy:byte-buddy-agent:$byte_buddy_version"
8+
}
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,160 @@
1+
/*
2+
* Copyright 2016-2018 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
5+
@file:Suppress("unused")
6+
7+
package kotlinx.coroutines
8+
9+
import kotlinx.coroutines.internal.*
10+
import kotlinx.coroutines.internal.CoroutineStackFrame
11+
import net.bytebuddy.*
12+
import net.bytebuddy.agent.*
13+
import net.bytebuddy.dynamic.loading.*
14+
import java.lang.management.*
15+
import java.util.*
16+
import kotlin.collections.ArrayList
17+
import kotlin.coroutines.*
18+
19+
/**
20+
* Debug probes support.
21+
*
22+
* Debug probes is a dynamic attach mechanism, which installs multiple hooks into [Continuation] machinery.
23+
* It significantly slows down all coroutine-related code, but in return provides a lot of debug information, including
24+
* asynchronous stack-traces and coroutine dumps (similar to [ThreadMXBean.dumpAllThreads] and `jstack`.
25+
*
26+
* Installed hooks:
27+
*
28+
* * `probeCoroutineResumed` is invoked on every [Continuation.resume].
29+
* * `probeCoroutineSuspended` is invoked on every continuation suspension.
30+
* * `probeCoroutineCreated` is invoked on every coroutine creation using stdlib intrinsics.
31+
*
32+
* Overhead:
33+
* * Every created continuation is stored in a weak hash map, thus adding additional GC pressure
34+
* * On every created continuation, stacktrace of the current thread is dumped
35+
* * On every `resume` and `suspend`, [WeakHashMap] is updated under a global lock
36+
*
37+
* **WARNING: DO NOT USE DEBUG PROBES IN PRODUCTION ENVIRONMENT**
38+
*/
39+
public object DebugProbes {
40+
private val traces = WeakHashMap<Continuation<*>, Array<StackTraceElement>>()
41+
private var installed: Boolean = false
42+
43+
/**
44+
* Installs a [DebugProbes] instead of no-op stdlib probes by redefining
45+
* debug probes class using the same class loader.
46+
*
47+
* **WARNING: DO NOT USE DEBUG PROBES IN PRODUCTION ENVIRONMENT**
48+
* Subsequent invocations of this method have no effect.
49+
*/
50+
@Synchronized
51+
public fun install() {
52+
if (installed) {
53+
return
54+
}
55+
56+
installed = true
57+
ByteBuddyAgent.install()
58+
val cl = Class.forName("kotlin.coroutines.jvm.internal.DebugProbesKt")
59+
val cl2 = Class.forName("kotlinx.coroutines.DebugProbesKt")
60+
61+
ByteBuddy()
62+
.redefine(cl2)
63+
.name(cl.name)
64+
.make()
65+
.load(cl.classLoader, ClassReloadingStrategy.fromInstalledAgent())
66+
}
67+
68+
/**
69+
* Uninstall debug probes
70+
*/
71+
@Synchronized
72+
public fun uninstall() {
73+
if (!installed) {
74+
return
75+
}
76+
77+
traces.clear()
78+
ByteBuddyAgent.install()
79+
val cl = Class.forName("kotlin.coroutines.jvm.internal.DebugProbesKt")
80+
val cl2 = Class.forName("kotlinx.coroutines.NoOpProbesKt")
81+
82+
ByteBuddy()
83+
.redefine(cl2)
84+
.name(cl.name)
85+
.make()
86+
.load(cl.classLoader, ClassReloadingStrategy.fromInstalledAgent())
87+
}
88+
89+
/**
90+
* Invokes given block of code with installed debug probes and unistall probes in the end.
91+
* **NOTE:** this method is not composable, it will uninstall debug probes even if they were installed
92+
* prior to method invocation
93+
*/
94+
public inline fun withDebugProbes(block: () -> Unit) {
95+
install()
96+
try {
97+
block()
98+
} finally {
99+
uninstall()
100+
}
101+
}
102+
103+
104+
public fun dumpCoroutines(): String = TODO("Not implemented")
105+
106+
@Synchronized
107+
internal fun probeCoroutineResumed(frame: Continuation<*>) {
108+
}
109+
110+
@Synchronized
111+
internal fun probeCoroutineSuspended(frame: Continuation<*>) {
112+
}
113+
114+
@Synchronized
115+
internal fun <T> probeCoroutineCreated(completion: kotlin.coroutines.Continuation<T>): kotlin.coroutines.Continuation<T> {
116+
val stacktrace = sanitizedStackTrace(Exception())
117+
traces[completion] = stacktrace
118+
119+
// TODO create lazy proxy and reverse stacktrace on demand
120+
val frames = ArrayList<CoroutineStackFrame?>(stacktrace.size)
121+
for ((index, frame) in stacktrace.reversed().withIndex()) {
122+
frames += object : CoroutineStackFrame {
123+
override val callerFrame: CoroutineStackFrame?
124+
get() = if (index == 0) null else frames[index - 1]
125+
126+
override fun getStackTraceElement(): StackTraceElement = frame
127+
}
128+
}
129+
130+
return object : Continuation<T> by completion, CoroutineStackFrame by frames.last()!! {}
131+
}
132+
133+
private fun <T : Throwable> sanitizedStackTrace(throwable: T): Array<StackTraceElement> {
134+
val stackTrace = throwable.stackTrace
135+
val size = stackTrace.size
136+
137+
var lastIntrinsic = -1
138+
for (i in 0 until size) {
139+
val name = stackTrace[i].className
140+
if ("kotlin.coroutines.jvm.internal.DebugProbesKt" == name) {
141+
lastIntrinsic = i
142+
}
143+
}
144+
145+
val startIndex = lastIntrinsic + 1
146+
return Array(size - lastIntrinsic) {
147+
if (it == 0) {
148+
artificialFrame("Coroutine creation callsite")
149+
} else {
150+
stackTrace[startIndex + it - 1]
151+
}
152+
}
153+
}
154+
}
155+
156+
// Stubs which are injected as coroutine probes. Require direct match of signatures
157+
internal fun probeCoroutineResumed(frame: Continuation<*>) = DebugProbes.probeCoroutineResumed(frame)
158+
internal fun probeCoroutineSuspended(frame: Continuation<*>) = DebugProbes.probeCoroutineSuspended(frame)
159+
internal fun <T> probeCoroutineCreated(completion: kotlin.coroutines.Continuation<T>): kotlin.coroutines.Continuation<T> =
160+
DebugProbes.probeCoroutineCreated(completion)
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,16 @@
1+
/*
2+
* Copyright 2016-2018 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
5+
@file:Suppress("unused")
6+
7+
package kotlinx.coroutines
8+
9+
import kotlin.coroutines.*
10+
11+
@JvmName("probeCoroutineResumed")
12+
internal fun probeCoroutineResumedNoOp(frame: Continuation<*>) = Unit
13+
@JvmName("probeCoroutineSuspended")
14+
internal fun probeCoroutineSuspendedNoOp(frame: Continuation<*>) = Unit
15+
@JvmName("probeCoroutineCreated")
16+
internal fun <T> probeCoroutineCreatedNoOp(completion: kotlin.coroutines.Continuation<T>): kotlin.coroutines.Continuation<T> = completion
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,119 @@
1+
/*
2+
* Copyright 2016-2018 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
package kotlinx.coroutines
5+
6+
import org.junit.Test
7+
import java.io.*
8+
import java.util.concurrent.*
9+
import kotlin.test.*
10+
11+
class DebugProbesTest : TestBase() {
12+
13+
private fun CoroutineScope.createDeferred(): Deferred<*> = async {
14+
throw ExecutionException(null)
15+
}
16+
17+
@Test
18+
fun testAsync() = runTest {
19+
20+
val deferred = createDeferred()
21+
val traces = listOf(
22+
"java.util.concurrent.ExecutionException\n" +
23+
"\t(Current coroutine stacktrace)\n" +
24+
"\tat kotlinx/coroutines/DeferredCoroutine.await\$suspendImpl(Deferred.kt:234)\n" +
25+
"\tat kotlinx/coroutines/DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:49)\n" +
26+
"\tat kotlinx/coroutines/DebugProbesTest.nestedMethod(DebugProbesTest.kt:44)\n" +
27+
"\tat kotlinx/coroutines/DebugProbesTest\$testAsync\$1.invokeSuspend(DebugProbesTest.kt:17)\n" +
28+
"Caused by: java.util.concurrent.ExecutionException\n" +
29+
"\tat kotlinx.coroutines.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
30+
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)\n"
31+
)
32+
nestedMethod(deferred, traces)
33+
deferred.join()
34+
}
35+
36+
@Test
37+
fun testAsyncWithProbes() = DebugProbes.withDebugProbes {
38+
runTest {
39+
val deferred = createDeferred()
40+
val traces = listOf(
41+
"java.util.concurrent.ExecutionException\n" +
42+
"\t(Current coroutine stacktrace)\n" +
43+
"\tat kotlinx/coroutines/DeferredCoroutine.await\$suspendImpl(Deferred.kt:234)\n" +
44+
"\tat kotlinx/coroutines/DebugProbesTest.oneMoreNestedMethod(DebugProbesTest.kt:71)\n" +
45+
"\tat kotlinx/coroutines/DebugProbesTest.nestedMethod(DebugProbesTest.kt:66)\n" +
46+
"\tat kotlinx/coroutines/DebugProbesTest\$testAsyncWithProbes\$1\$1.invokeSuspend(DebugProbesTest.kt:43)\n" +
47+
"\t(Coroutine creation callsite)\n" +
48+
"\tat kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt.createCoroutineUnintercepted(IntrinsicsJvm.kt:116)\n" +
49+
"\tat kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:23)\n" +
50+
"\tat kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:99)\n" +
51+
"\tat kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:148)\n" +
52+
"\tat kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:45)\n" +
53+
"\tat kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)\n" +
54+
"\tat kotlinx.coroutines.TestBase.runTest(TestBase.kt:138)\n" +
55+
"\tat kotlinx.coroutines.TestBase.runTest\$default(TestBase.kt:19)\n" +
56+
"\tat kotlinx.coroutines.DebugProbesTest.testAsyncWithProbes(DebugProbesTest.kt:38)",
57+
"Caused by: java.util.concurrent.ExecutionException\n" +
58+
"\tat kotlinx.coroutines.DebugProbesTest\$createDeferred\$1.invokeSuspend(DebugProbesTest.kt:16)\n" +
59+
"\tat kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)\n")
60+
nestedMethod(deferred, traces)
61+
deferred.join()
62+
}
63+
}
64+
65+
66+
private suspend fun nestedMethod(deferred: Deferred<*>, traces: List<String>) {
67+
oneMoreNestedMethod(deferred, traces)
68+
assertTrue(true) // Prevent tail-call optimization
69+
}
70+
71+
private suspend fun oneMoreNestedMethod(deferred: Deferred<*>, traces: List<String>) {
72+
try {
73+
deferred.await()
74+
expectUnreached()
75+
} catch (e: ExecutionException) {
76+
verifyStackTrace(e, traces)
77+
}
78+
}
79+
80+
private fun verifyStackTrace(e: Throwable, traces: List<String>) {
81+
val stacktrace = toStackTrace(e)
82+
traces.forEach {
83+
assertTrue(stacktrace.trimStackTrace().contains(it.trimStackTrace()),
84+
"\nExpected trace element:\n$it\n\nActual stacktrace:\n$stacktrace")
85+
}
86+
87+
val causes = stacktrace.count("Caused by")
88+
assertNotEquals(0, causes)
89+
assertEquals(causes, traces.map { it.count("Caused by") }.sum())
90+
}
91+
92+
private fun toStackTrace(t: Throwable): String {
93+
val sw = StringWriter() as Writer
94+
t.printStackTrace(PrintWriter(sw))
95+
return sw.toString()
96+
}
97+
98+
99+
private fun String.trimStackTrace(): String {
100+
return applyBackspace(trimIndent().replace(Regex(":[0-9]+"), ""))
101+
}
102+
103+
private fun applyBackspace(line: String): String {
104+
val array = line.toCharArray()
105+
val stack = CharArray(array.size)
106+
var stackSize = -1
107+
for (c in array) {
108+
if (c != '\b') {
109+
stack[++stackSize] = c
110+
} else {
111+
--stackSize
112+
}
113+
}
114+
115+
return String(stack, 0, stackSize)
116+
}
117+
118+
private fun String.count(substring: String): Int = split(substring).size - 1
119+
}

gradle.properties

+2-1
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,13 @@
11
# Kotlin
2-
version=0.26.0-rc13-SNAPSHOT
2+
version=0.26.0-rc13
33
group=org.jetbrains.kotlinx
44
kotlin_version=1.3.0-rc-6
55
kotlin_native_version=0.9
66

77
# Dependencies
88
junit_version=4.12
99
atomicFU_version=0.11.6
10+
byte_buddy_version=1.8.22
1011
html_version=0.6.8
1112
lincheck_version=1.9
1213
dokka_version=0.9.16-rdev-2-mpp-hacks

settings.gradle

+2
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@ module('binary-compatibility-validator')
2323
module('common/kotlinx-coroutines-core-common')
2424

2525
module('core/kotlinx-coroutines-core')
26+
module('core/kotlinx-coroutines-debug')
2627

2728
module('integration/kotlinx-coroutines-guava')
2829
module('integration/kotlinx-coroutines-jdk8')
@@ -45,3 +46,4 @@ module('js/js-stub')
4546
module('js/example-frontend-js')
4647

4748
module('native/kotlinx-coroutines-core-native')
49+

0 commit comments

Comments
 (0)