Skip to content

Commit 8f3b484

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

File tree

2 files changed

+23
-17
lines changed

2 files changed

+23
-17
lines changed

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

+22-16
Original file line numberDiff line numberDiff line change
@@ -123,16 +123,22 @@ 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" }
134-
// Synchronization window can be reduce even more, but no need to do it here
135-
append("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
141+
out.print("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
136142
capturedCoroutines
137143
.asSequence()
138144
.sortedBy { it.info.sequenceNumber }
@@ -145,16 +151,22 @@ internal object DebugProbesImpl {
145151
else
146152
info.state.toString()
147153

148-
append("\n\nCoroutine ${owner.delegate}, state: $state")
154+
out.print("\n\nCoroutine ${owner.delegate}, state: $state")
149155
if (observedStackTrace.isEmpty()) {
150-
append("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
151-
printStackTrace(info.creationStackTrace)
156+
out.print("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
157+
printStackTrace(out, info.creationStackTrace)
152158
} else {
153-
printStackTrace(enhancedStackTrace)
159+
printStackTrace(out, enhancedStackTrace)
154160
}
155161
}
156162
}
157163

164+
private fun printStackTrace(out: PrintStream, frames: List<StackTraceElement>) {
165+
frames.forEach { frame ->
166+
out.print("\n\tat $frame")
167+
}
168+
}
169+
158170
/**
159171
* Tries to enhance [coroutineTrace] (obtained by call to [CoroutineInfo.lastObservedStackTrace]) with
160172
* thread dump of [CoroutineInfo.lastObservedThread].
@@ -249,12 +261,6 @@ internal object DebugProbesImpl {
249261
}
250262
}
251263

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

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