Skip to content

Commit cca82e7

Browse files
authored
Improve DebugProbes performance (Kotlin#3534)
* Get rid of RW lock that was contended enough on reads to be observable by non-concurrent coroutines-heavy code (up to 30% of throughput on IDEA-specific benchmark) * Tweak the code to be DRF in the absence of RW lock * Document snapshots' weak consistency guarantee Fixes Kotlin#3527
1 parent eac0b07 commit cca82e7

File tree

5 files changed

+111
-38
lines changed

5 files changed

+111
-38
lines changed

benchmarks/build.gradle.kts

+1
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,7 @@ dependencies {
5656

5757
implementation("com.typesafe.akka:akka-actor_2.12:2.5.0")
5858
implementation(project(":kotlinx-coroutines-core"))
59+
implementation(project(":kotlinx-coroutines-debug"))
5960
implementation(project(":kotlinx-coroutines-reactive"))
6061

6162
// add jmh dependency on main
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,71 @@
1+
/*
2+
* Copyright 2016-2022 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license.
3+
*/
4+
5+
package benchmarks.debug
6+
7+
import kotlinx.coroutines.*
8+
import kotlinx.coroutines.debug.*
9+
import org.openjdk.jmh.annotations.*
10+
import org.openjdk.jmh.annotations.State
11+
import java.util.concurrent.*
12+
13+
@Warmup(iterations = 5, time = 1)
14+
@Measurement(iterations = 5, time = 1)
15+
@Fork(value = 1)
16+
@BenchmarkMode(Mode.AverageTime)
17+
@OutputTimeUnit(TimeUnit.MICROSECONDS)
18+
@State(Scope.Benchmark)
19+
open class DebugProbesConcurrentBenchmark {
20+
21+
@Setup
22+
fun setup() {
23+
DebugProbes.sanitizeStackTraces = false
24+
DebugProbes.enableCreationStackTraces = false
25+
DebugProbes.install()
26+
}
27+
28+
@TearDown
29+
fun tearDown() {
30+
DebugProbes.uninstall()
31+
}
32+
33+
34+
@Benchmark
35+
fun run() = runBlocking<Long> {
36+
var sum = 0L
37+
repeat(8) {
38+
launch(Dispatchers.Default) {
39+
val seq = stressSequenceBuilder((1..100).asSequence()) {
40+
(1..it).asSequence()
41+
}
42+
43+
for (i in seq) {
44+
sum += i.toLong()
45+
}
46+
}
47+
}
48+
sum
49+
}
50+
51+
private fun <Node> stressSequenceBuilder(initialSequence: Sequence<Node>, children: (Node) -> Sequence<Node>): Sequence<Node> {
52+
return sequence {
53+
val initialIterator = initialSequence.iterator()
54+
if (!initialIterator.hasNext()) {
55+
return@sequence
56+
}
57+
val visited = HashSet<Node>()
58+
val sequences = ArrayDeque<Sequence<Node>>()
59+
sequences.addLast(initialIterator.asSequence())
60+
while (sequences.isNotEmpty()) {
61+
val currentSequence = sequences.removeFirst()
62+
for (node in currentSequence) {
63+
if (visited.add(node)) {
64+
yield(node)
65+
sequences.addLast(children(node))
66+
}
67+
}
68+
}
69+
}
70+
}
71+
}

kotlinx-coroutines-core/jvm/src/debug/internal/DebugCoroutineInfoImpl.kt

+4
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ internal const val SUSPENDED = "SUSPENDED"
1414

1515
/**
1616
* Internal implementation class where debugger tracks details it knows about each coroutine.
17+
* Its mutable fields can be updated concurrently, thus marked with `@Volatile`
1718
*/
1819
internal class DebugCoroutineInfoImpl(
1920
context: CoroutineContext?,
@@ -40,15 +41,18 @@ internal class DebugCoroutineInfoImpl(
4041
* Can be CREATED, RUNNING, SUSPENDED.
4142
*/
4243
public val state: String get() = _state
44+
@Volatile
4345
private var _state: String = CREATED
4446

4547
@JvmField
48+
@Volatile
4649
internal var lastObservedThread: Thread? = null
4750

4851
/**
4952
* We cannot keep a strong reference to the last observed frame of the coroutine, because this will
5053
* prevent garbage-collection of a coroutine that was lost.
5154
*/
55+
@Volatile
5256
private var _lastObservedFrame: WeakReference<CoroutineStackFrame>? = null
5357
internal var lastObservedFrame: CoroutineStackFrame?
5458
get() = _lastObservedFrame?.get()

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

+24-34
Original file line numberDiff line numberDiff line change
@@ -28,32 +28,23 @@ internal object DebugProbesImpl {
2828
private val capturedCoroutinesMap = ConcurrentWeakMap<CoroutineOwner<*>, Boolean>()
2929
private val capturedCoroutines: Set<CoroutineOwner<*>> get() = capturedCoroutinesMap.keys
3030

31-
@Volatile
32-
private var installations = 0
31+
private val installations = atomic(0)
3332

3433
/**
3534
* This internal method is used by IDEA debugger under the JVM name of
3635
* "isInstalled$kotlinx_coroutines_debug".
3736
*/
38-
internal val isInstalled: Boolean get() = installations > 0
37+
internal val isInstalled: Boolean get() = installations.value > 0
3938

4039
// To sort coroutines by creation order, used as unique id
4140
private val sequenceNumber = atomic(0L)
42-
/*
43-
* RW-lock that guards all debug probes state changes.
44-
* All individual coroutine state transitions are guarded by read-lock
45-
* and do not interfere with each other.
46-
* All state reads are guarded by the write lock to guarantee a strongly-consistent
47-
* snapshot of the system.
48-
*/
49-
private val coroutineStateLock = ReentrantReadWriteLock()
5041

5142
public var sanitizeStackTraces: Boolean = true
5243
public var enableCreationStackTraces: Boolean = true
5344

5445
/*
5546
* Substitute for service loader, DI between core and debug modules.
56-
* If the agent was installed via command line -javaagent parameter, do not use byte-byddy to avoud
47+
* If the agent was installed via command line -javaagent parameter, do not use byte-buddy to avoid dynamic attach.
5748
*/
5849
private val dynamicAttach = getDynamicAttach()
5950

@@ -77,16 +68,16 @@ internal object DebugProbesImpl {
7768
*/
7869
private val callerInfoCache = ConcurrentWeakMap<CoroutineStackFrame, DebugCoroutineInfoImpl>(weakRefQueue = true)
7970

80-
public fun install(): Unit = coroutineStateLock.write {
81-
if (++installations > 1) return
71+
fun install() {
72+
if (installations.incrementAndGet() > 1) return
8273
startWeakRefCleanerThread()
8374
if (AgentInstallationType.isInstalledStatically) return
8475
dynamicAttach?.invoke(true) // attach
8576
}
8677

87-
public fun uninstall(): Unit = coroutineStateLock.write {
78+
fun uninstall() {
8879
check(isInstalled) { "Agent was not installed" }
89-
if (--installations != 0) return
80+
if (installations.decrementAndGet() != 0) return
9081
stopWeakRefCleanerThread()
9182
capturedCoroutinesMap.clear()
9283
callerInfoCache.clear()
@@ -107,7 +98,7 @@ internal object DebugProbesImpl {
10798
thread.join()
10899
}
109100

110-
public fun hierarchyToString(job: Job): String = coroutineStateLock.write {
101+
fun hierarchyToString(job: Job): String {
111102
check(isInstalled) { "Debug probes are not installed" }
112103
val jobToStack = capturedCoroutines
113104
.filter { it.delegate.context[Job] != null }
@@ -149,20 +140,19 @@ internal object DebugProbesImpl {
149140
* Private method that dumps coroutines so that different public-facing method can use
150141
* to produce different result types.
151142
*/
152-
private inline fun <R : Any> dumpCoroutinesInfoImpl(crossinline create: (CoroutineOwner<*>, CoroutineContext) -> R): List<R> =
153-
coroutineStateLock.write {
154-
check(isInstalled) { "Debug probes are not installed" }
155-
capturedCoroutines
156-
.asSequence()
157-
// Stable ordering of coroutines by their sequence number
158-
.sortedBy { it.info.sequenceNumber }
159-
// Leave in the dump only the coroutines that were not collected while we were dumping them
160-
.mapNotNull { owner ->
161-
// Fuse map and filter into one operation to save an inline
162-
if (owner.isFinished()) null
163-
else owner.info.context?.let { context -> create(owner, context) }
164-
}.toList()
165-
}
143+
private inline fun <R : Any> dumpCoroutinesInfoImpl(crossinline create: (CoroutineOwner<*>, CoroutineContext) -> R): List<R> {
144+
check(isInstalled) { "Debug probes are not installed" }
145+
return capturedCoroutines
146+
.asSequence()
147+
// Stable ordering of coroutines by their sequence number
148+
.sortedBy { it.info.sequenceNumber }
149+
// Leave in the dump only the coroutines that were not collected while we were dumping them
150+
.mapNotNull { owner ->
151+
// Fuse map and filter into one operation to save an inline
152+
if (owner.isFinished()) null
153+
else owner.info.context?.let { context -> create(owner, context) }
154+
}.toList()
155+
}
166156

167157
/*
168158
* This method optimises the number of packages sent by the IDEA debugger
@@ -280,7 +270,7 @@ internal object DebugProbesImpl {
280270
return true
281271
}
282272

283-
private fun dumpCoroutinesSynchronized(out: PrintStream): Unit = coroutineStateLock.write {
273+
private fun dumpCoroutinesSynchronized(out: PrintStream) {
284274
check(isInstalled) { "Debug probes are not installed" }
285275
out.print("Coroutines dump ${dateFormat.format(System.currentTimeMillis())}")
286276
capturedCoroutines
@@ -441,7 +431,7 @@ internal object DebugProbesImpl {
441431
}
442432

443433
// See comment to callerInfoCache
444-
private fun updateRunningState(frame: CoroutineStackFrame, state: String): Unit = coroutineStateLock.read {
434+
private fun updateRunningState(frame: CoroutineStackFrame, state: String) {
445435
if (!isInstalled) return
446436
// Lookup coroutine info in cache or by traversing stack frame
447437
val info: DebugCoroutineInfoImpl
@@ -466,7 +456,7 @@ internal object DebugProbesImpl {
466456
return if (caller.getStackTraceElement() != null) caller else caller.realCaller()
467457
}
468458

469-
private fun updateState(owner: CoroutineOwner<*>, frame: Continuation<*>, state: String) = coroutineStateLock.read {
459+
private fun updateState(owner: CoroutineOwner<*>, frame: Continuation<*>, state: String) {
470460
if (!isInstalled) return
471461
owner.info.updateState(state, frame)
472462
}

kotlinx-coroutines-debug/src/DebugProbes.kt

+11-4
Original file line numberDiff line numberDiff line change
@@ -20,13 +20,20 @@ import kotlin.coroutines.*
2020
* asynchronous stack-traces and coroutine dumps (similar to [ThreadMXBean.dumpAllThreads] and `jstack` via [DebugProbes.dumpCoroutines].
2121
* All introspecting methods throw [IllegalStateException] if debug probes were not installed.
2222
*
23-
* Installed hooks:
23+
* ### Consistency guarantees
2424
*
25+
* All snapshotting operations (e.g. [dumpCoroutines]) are *weakly-consistent*, meaning that they happen
26+
* concurrently with coroutines progressing their own state. These operations are guaranteed to observe
27+
* each coroutine's state exactly once, but the state is not guaranteed to be the most recent before the operation.
28+
* In practice, it means that for snapshotting operations in progress, for each concurrent coroutine either
29+
* the state prior to the operation or the state that was reached during the current operation is observed.
30+
*
31+
* ### Installed hooks
2532
* * `probeCoroutineResumed` is invoked on every [Continuation.resume].
2633
* * `probeCoroutineSuspended` is invoked on every continuation suspension.
27-
* * `probeCoroutineCreated` is invoked on every coroutine creation using stdlib intrinsics.
34+
* * `probeCoroutineCreated` is invoked on every coroutine creation.
2835
*
29-
* Overhead:
36+
* ### Overhead
3037
* * Every created coroutine is stored in a concurrent hash map and hash map is looked up and
3138
* updated on each suspension and resumption.
3239
* * If [DebugProbes.enableCreationStackTraces] is enabled, stack trace of the current thread is captured on
@@ -118,7 +125,7 @@ public object DebugProbes {
118125
printJob(scope.coroutineContext[Job] ?: error("Job is not present in the scope"), out)
119126

120127
/**
121-
* Returns all existing coroutines info.
128+
* Returns all existing coroutines' info.
122129
* The resulting collection represents a consistent snapshot of all existing coroutines at the moment of invocation.
123130
*/
124131
public fun dumpCoroutinesInfo(): List<CoroutineInfo> = DebugProbesImpl.dumpCoroutinesInfo().map { CoroutineInfo(it) }

0 commit comments

Comments
 (0)