Skip to content

Commit

Permalink
Do not aggregate all coroutine info into a single string before dumpi…
Browse files Browse the repository at this point in the history
…ng 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
  • Loading branch information
qwwdfsad committed Sep 17, 2019
1 parent f62d35b commit 3826ae5
Show file tree
Hide file tree
Showing 2 changed files with 22 additions and 17 deletions.
37 changes: 21 additions & 16 deletions kotlinx-coroutines-debug/src/internal/DebugProbesImpl.kt
Original file line number Diff line number Diff line change
Expand Up @@ -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 }
Expand All @@ -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].
Expand Down Expand Up @@ -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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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" +
Expand Down

0 comments on commit 3826ae5

Please sign in to comment.