diff --git a/CHANGELOG.md b/CHANGELOG.md index 0c770a0..47bae2e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,14 @@ The format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/) and ### Changed +- Runtime family version bumped to `0.1.0-ALPHA03` (`RUNTIME_VERSION`); install snippets in the runtime READMEs now use it. + +### Fixed + +- **`AndroidTraceSink` span slices truncated under concurrency**: the async slice `span:` could receive `begin`/`end` out of order when segments of one span started and finished on several threads, which made Perfetto show only the first fraction of the span (observed on an Android 15 emulator: ~110 ms of a 1.3 s span). The span transition and its trace call are now one atomic operation, so `begin`/`end` strictly alternate. Covered by a multi-threaded regression test. + +### Changed + - Runtime family version bumped to `0.1.0-ALPHA02` (`RUNTIME_VERSION`); install snippets in the runtime READMEs now use it. - **`:runtime-tracing-jvm` is now `:runtime-tracing`**, a Kotlin Multiplatform module (JVM + Android) published as `io.github.santimattius:structured-coroutines-runtime-tracing`. `PerfettoTraceSink` now also works on Android with an `androidx.tracing` `Tracer`, adding slice arguments (`queue_delay_ns`, `span_name`, ...) and span flows that `AndroidTraceSink` cannot express (#170). Migration from `0.1.0-ALPHA01`: replace the `...-tracing-jvm` artifact with `...-tracing`; the package and API are unchanged. Verified on an Android 15 emulator by an instrumented test. diff --git a/coroutines-runtime/README.md b/coroutines-runtime/README.md index 2f56b47..5070e9e 100644 --- a/coroutines-runtime/README.md +++ b/coroutines-runtime/README.md @@ -40,17 +40,17 @@ runtime-benchmark ─────┘ ## Installation Group `io.github.santimattius`; all published runtime artifacts share the `RUNTIME_VERSION` from -`gradle.properties` (currently `0.1.0-ALPHA02`). +`gradle.properties` (currently `0.1.0-ALPHA03`). ```kotlin // build.gradle.kts (Kotlin Multiplatform) kotlin { sourceSets { commonMain.dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime:0.1.0-ALPHA03") } commonTest.dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA03") } } } @@ -59,7 +59,7 @@ kotlin { ```kotlin // build.gradle.kts (JVM / desktop tracing) dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime-tracing:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime-tracing:0.1.0-ALPHA03") } ``` diff --git a/coroutines-runtime/runtime-test/README.md b/coroutines-runtime/runtime-test/README.md index 16756dd..9cf348f 100644 --- a/coroutines-runtime/runtime-test/README.md +++ b/coroutines-runtime/runtime-test/README.md @@ -10,7 +10,7 @@ and `TraceSinkContract` (reusable checks every `TraceSink` should pass). It is a ```kotlin commonTest.dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA03") } ``` diff --git a/coroutines-runtime/runtime-tracing/README.md b/coroutines-runtime/runtime-tracing/README.md index 373e269..93fe815 100644 --- a/coroutines-runtime/runtime-tracing/README.md +++ b/coroutines-runtime/runtime-tracing/README.md @@ -12,7 +12,7 @@ and span flows, which `android.os.Trace` cannot express. It is a separate artifa ```kotlin dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime-tracing:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime-tracing:0.1.0-ALPHA03") } ``` diff --git a/coroutines-runtime/runtime/README.md b/coroutines-runtime/runtime/README.md index 1bbda08..6bcace9 100644 --- a/coroutines-runtime/runtime/README.md +++ b/coroutines-runtime/runtime/README.md @@ -32,10 +32,10 @@ toolkit's `PROJECT_VERSION`. kotlin { sourceSets { commonMain.dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime:0.1.0-ALPHA03") } commonTest.dependencies { - implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA02") + implementation("io.github.santimattius:structured-coroutines-runtime-test:0.1.0-ALPHA03") } } } diff --git a/coroutines-runtime/runtime/src/jvmAndAndroidMain/kotlin/io/github/santimattius/structured/runtime/SystemTraceSink.kt b/coroutines-runtime/runtime/src/jvmAndAndroidMain/kotlin/io/github/santimattius/structured/runtime/SystemTraceSink.kt index 9653c19..9ce9f8a 100644 --- a/coroutines-runtime/runtime/src/jvmAndAndroidMain/kotlin/io/github/santimattius/structured/runtime/SystemTraceSink.kt +++ b/coroutines-runtime/runtime/src/jvmAndAndroidMain/kotlin/io/github/santimattius/structured/runtime/SystemTraceSink.kt @@ -153,22 +153,30 @@ internal class SystemTraceSink( } } + // The map transition and the matching trace call run inside one atomic per-key operation, so + // begin/end reach the tracer in the same order as the 0 -> 1 and 1 -> 0 transitions. Doing the + // call after the map update let a concurrent Started overtake a Finished and interleave + // begin, begin, end on the same cookie. private fun spanStarted(spanId: Long, spanName: String?) { - val count = activeSpans.merge(spanId, 1) { a, b -> a + b } - if (count == 1) api.beginAsyncSection(spanSliceName(spanName), spanId.toInt()) + activeSpans.compute(spanId) { _, count -> + if (count == null) { + runCatching { api.beginAsyncSection(spanSliceName(spanName), spanId.toInt()) } + 1 + } else { + count + 1 + } + } } private fun spanFinished(spanId: Long, spanName: String?) { - var closed = false activeSpans.computeIfPresent(spanId) { _, count -> if (count <= 1) { - closed = true + runCatching { api.endAsyncSection(spanSliceName(spanName), spanId.toInt()) } null } else { count - 1 } } - if (closed) api.endAsyncSection(spanSliceName(spanName), spanId.toInt()) } private fun countersFor(label: String): Counters { diff --git a/coroutines-runtime/runtime/src/jvmTest/kotlin/io/github/santimattius/structured/runtime/SystemTraceSinkTest.kt b/coroutines-runtime/runtime/src/jvmTest/kotlin/io/github/santimattius/structured/runtime/SystemTraceSinkTest.kt index 5fff432..539dc49 100644 --- a/coroutines-runtime/runtime/src/jvmTest/kotlin/io/github/santimattius/structured/runtime/SystemTraceSinkTest.kt +++ b/coroutines-runtime/runtime/src/jvmTest/kotlin/io/github/santimattius/structured/runtime/SystemTraceSinkTest.kt @@ -370,4 +370,39 @@ class SystemTraceSinkTest { api.counters().filter { it.contains("queue_delay_max_us") }, ) } + + @Test + fun concurrentSegmentsOfOneSpanAlternateBeginAndEndStrictly() { + val async = java.util.Collections.synchronizedList(ArrayList()) + val api = object : SystemTraceApi { + override fun isEnabled() = true + override fun beginSection(name: String) = Unit + override fun endSection() = Unit + override fun setCounter(name: String, value: Long) = Unit + override fun beginAsyncSection(name: String, cookie: Int) { async += "begin" } + override fun endAsyncSection(name: String, cookie: Int) { async += "end" } + } + val sink = SystemTraceSink(api) + val threads = 8 + val perThread = 5_000 + val start = CountDownLatch(1) + val pool = Executors.newFixedThreadPool(threads) + repeat(threads) { + pool.execute { + start.await() + repeat(perThread) { + sink.emit(startedIn(5L, "storm")) + sink.emit(finishedIn(5L, "storm")) + } + } + } + start.countDown() + pool.shutdown() + assertTrue(pool.awaitTermination(60, TimeUnit.SECONDS)) + val seq = async.toList() + // A span is either open or closed: begin/end must alternate, starting with begin. + val broken = seq.zipWithNext().count { (a, b) -> a == b } + assertEquals(0, broken, "begin/end did not alternate $broken times out of ${seq.size}") + assertEquals(seq.size % 2, 0) + } } diff --git a/gradle.properties b/gradle.properties index 25b9296..6ad06c5 100644 --- a/gradle.properties +++ b/gradle.properties @@ -9,7 +9,7 @@ kotlin.code.style=official PROJECT_GROUP=io.github.santimattius PROJECT_VERSION=1.2.1 # :runtime versions independently on its own 0.x train (see coroutines-runtime/runtime/build.gradle.kts) -RUNTIME_VERSION=0.1.0-ALPHA02 +RUNTIME_VERSION=0.1.0-ALPHA03 # Maven Central mavenCentralPublishing=true signAllPublications=true