fix(runtime): keep span async slice begin/end ordered; release 0.1.0-ALPHA03

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:<name>` 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.

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")
 }
 ```
 

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")
 }
 ```
 

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")
 }
 ```
 

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")
         }
     }
 }

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 {

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<String>())
+        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)
+    }
 }

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