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.

Fixes #1535

Author: qwwdfsad

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

@@ -123,16 +123,21 @@ internal object DebugProbesImpl {
             .toList()
     }
 
-    public fun dumpCoroutines(out: PrintStream) {
-        // Avoid inference with other out/err invocations by creating a string first
-        dumpCoroutines().let { out.println(it) }
+    public fun dumpCoroutines(out: PrintStream) = synchronized(out) {
+        /*
+         * This method synchronizes both on `out` and `this` for a reason:
+         * 1) Synchronization on `this` is required to have a consistent snapshot of coroutines.
+         * 2) Synchronization on `out` is not required, but prohibits interleaving with any other
+         *    (asynchronous) attempt to write to this `out` (System.out by default).
+         * Yet this prevents the progress of coroutines until they are fully dumped to the out which we find acceptable compromise.
+         */
+        dumpCoroutinesSynchronized(out)
     }
 
     @Synchronized
-    private fun dumpCoroutines(): String = buildString {
+    private fun dumpCoroutinesSynchronized(out: PrintStream) {
         check(isInstalled) { "Debug probes are not installed" }
-        // Synchronization window can be reduce even more, but no need to do it here
-        append("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
+        out.print("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
         capturedCoroutines
             .asSequence()
             .sortedBy { it.info.sequenceNumber }
@@ -145,16 +150,22 @@ internal object DebugProbesImpl {
                 else
                     info.state.toString()
 
-                append("\n\nCoroutine ${owner.delegate}, state: $state")
+                out.print("\n\nCoroutine ${owner.delegate}, state: $state")
                 if (observedStackTrace.isEmpty()) {
-                    append("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
-                    printStackTrace(info.creationStackTrace)
+                    out.print("\n\tat ${createArtificialFrame(ARTIFICIAL_FRAME_MESSAGE)}")
+                    printStackTrace(out, info.creationStackTrace)
                 } else {
-                    printStackTrace(enhancedStackTrace)
+                    printStackTrace(out, enhancedStackTrace)
                 }
             }
     }
 
+    private fun printStackTrace(out: PrintStream, frames: List<StackTraceElement>) {
+        frames.forEach { frame ->
+            out.print("\n\tat $frame")
+        }
+    }
+
     /**
      * Tries to enhance [coroutineTrace] (obtained by call to [CoroutineInfo.lastObservedStackTrace]) with
      * thread dump of [CoroutineInfo.lastObservedThread].
@@ -249,12 +260,6 @@ internal object DebugProbesImpl {
         }
     }
 
-    private fun StringBuilder.printStackTrace(frames: List<StackTraceElement>) {
-        frames.forEach { frame ->
-            append("\n\tat $frame")
-        }
-    }
-
     internal fun probeCoroutineResumed(frame: Continuation<*>) = updateState(frame, State.RUNNING)
 
     internal fun probeCoroutineSuspended(frame: Continuation<*>) = updateState(frame, State.SUSPENDED)

kotlinx-coroutines-debug/test/RunningThreadStackMergeTest.kt

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