Skip to content

Commit 7964e32

Browse files
committed
Do not aggregate all coroutine info into a single string before dumping it to the out in DebugProbes.dumpCoroutines
Previously it was done intentionally to reduce synchronization window of DebugProbesImpl, but still have a consistent view of the world and to avoid interleaving with other usages of out. Apparently, applications with a significant amount of coroutines (e.g. Ktor) may spend a lot of time or even experience OOM in DebugProbes.dumpCoroutines. To make it usable in such applications, we dump coroutines incrementally without releasing a lock in DebugProbesImpl (thus significantly increasing synchronization window) while holding a lock on out to still have a continuous dump in out. Fixes #1535
1 parent bda9c79 commit 7964e32

File tree

2 files changed

+23
-16
lines changed

2 files changed

+23
-16
lines changed

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

+22-15
Original file line numberDiff line numberDiff line change
@@ -123,16 +123,23 @@ internal object DebugProbesImpl {
123123
.toList()
124124
}
125125

126-
public fun dumpCoroutines(out: PrintStream) {
127-
// Avoid inference with other out/err invocations by creating a string first
128-
dumpCoroutines().let { out.println(it) }
126+
public fun dumpCoroutines(out: PrintStream) = synchronized(out) {
127+
/*
128+
* This method synchronizes both on `out` and `this` for a reason:
129+
* 1) Synchronization on `this` is required to have a consistent snapshot of coroutines.
130+
* 2) Synchronization on `out` is not required, but prohibits interleaving with any other
131+
* (asynchronous) attempt to write to this `out` (System.out by default).
132+
* Yet this prevents the progress of coroutines until they are fully dumped to the out which we find acceptable compromise.
133+
*/
134+
dumpCoroutinesSynchronized(out)
129135
}
130136

137+
131138
@Synchronized
132-
private fun dumpCoroutines(): String = buildString {
139+
private fun dumpCoroutinesSynchronized(out: PrintStream) {
133140
check(isInstalled) { "Debug probes are not installed" }
134141
// Synchronization window can be reduce even more, but no need to do it here
135-
append("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
142+
out.print("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
136143
capturedCoroutines
137144
.asSequence()
138145
.sortedBy { it.info.sequenceNumber }
@@ -145,16 +152,22 @@ internal object DebugProbesImpl {
145152
else
146153
info.state.toString()
147154

148-
append("\n\nCoroutine ${owner.delegate}, state: $state")
155+
out.print("\n\nCoroutine ${owner.delegate}, state: $state")
149156
if (observedStackTrace.isEmpty()) {
150-
append("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
151-
printStackTrace(info.creationStackTrace)
157+
out.print("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
158+
printStackTrace(out, info.creationStackTrace)
152159
} else {
153-
printStackTrace(enhancedStackTrace)
160+
printStackTrace(out, enhancedStackTrace)
154161
}
155162
}
156163
}
157164

165+
private fun printStackTrace(out: PrintStream, frames: List<StackTraceElement>) {
166+
frames.forEach { frame ->
167+
out.print("\n\tat $frame")
168+
}
169+
}
170+
158171
/**
159172
* Tries to enhance [coroutineTrace] (obtained by call to [CoroutineInfo.lastObservedStackTrace]) with
160173
* thread dump of [CoroutineInfo.lastObservedThread].
@@ -249,12 +262,6 @@ internal object DebugProbesImpl {
249262
}
250263
}
251264

252-
private fun StringBuilder.printStackTrace(frames: List<StackTraceElement>) {
253-
frames.forEach { frame ->
254-
append("\n\tat $frame")
255-
}
256-
}
257-
258265
internal fun probeCoroutineResumed(frame: Continuation<*>) = updateState(frame, State.RUNNING)
259266

260267
internal fun probeCoroutineSuspended(frame: Continuation<*>) = updateState(frame, State.SUSPENDED)

kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt

+1-1
Original file line numberDiff line numberDiff line change
@@ -147,7 +147,7 @@ class RunningThreadStackMergeTest : DebugTestBase() {
147147
verifyDump("Coroutine \"coroutine#1\":BlockingCoroutine{Active}@4bcd176c, state: RUNNING\n" +
148148
"\tat java.lang.Thread.getStackTrace(Thread.java:1552)\n" +
149149
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.enhanceStackTraceWithThreadDump(DebugProbesImpl.kt:147)\n" +
150-
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:122)\n" +
150+
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutinesSynchronized(DebugProbesImpl.kt:122)\n" +
151151
"\tat kotlinx.coroutines.debug.internal.DebugProbesImpl.dumpCoroutines(DebugProbesImpl.kt:109)\n" +
152152
"\tat kotlinx.coroutines.debug.DebugProbes.dumpCoroutines(DebugProbes.kt:122)\n" +
153153
"\tat kotlinx.coroutines.debug.StracktraceUtilsKt.verifyDump(StracktraceUtils.kt)\n" +

0 commit comments

Comments
 (0)