test(audio-rooms): InteropDebug step logger + harness diagnostics

When an interop test fails today the report shows a generic AssertionError pointing at a `runBlocking {` line — useless for narrowing down which sub-step (mintToken, WT connect, ANNOUNCE, SUBSCRIBE_OK, frame round-trip) actually exploded. This adds a small InteropDebug helper that: - prints a labelled "▶ start" / "✔ ok" / "✘ fail — Class: msg ⟵ Cause: msg" trail per step (output gated on `-DnestsInterop=true` so the default test run stays silent) - walks chained `cause` so the surface message reveals the real network / protocol error instead of the wrapping string - pretty-prints NestsSpeakerState / NestsListenerState (Failed in particular unwraps `cause` for the report) Each test body in NostrNestsRoundTripInteropTest + NostrNestsMultiPeerInteropTest now wraps connect / startBroadcasting / subscribeSpeaker / await-frames in `InteropDebug.stepSuspending(...)` so a failure points at the exact sub-step rather than the test method. Harness diagnostics: when `start()` fails, capture `docker compose ps` + recent logs for moq-auth / moq-relay / strfry into the IllegalStateException message before tearing the stack down. Without this, the test report only shows "exited with code 1" — operators have to re-run by hand to find out which container crashed. Output is hidden by default; only surfaces when `-DnestsInterop=true` (or the explicit `-DnestsInteropDebug=true`) is set.
2026-04-26 20:10:43 +00:00
parent e71a2b26ef
commit 5f90588fe4
4 changed files with 424 additions and 105 deletions
@@ -0,0 +1,190 @@
+/*
+ * Copyright (c) 2025 Vitor Pamplona
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy of
+ * this software and associated documentation files (the "Software"), to deal in
+ * the Software without restriction, including without limitation the rights to use,
+ * copy, modify, merge, publish, distribute, sublicense, and/or sell copies of the
+ * Software, and to permit persons to whom the Software is furnished to do so,
+ * subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in all
+ * copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS
+ * FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
+ * COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN
+ * AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
+ * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
+ */
+package com.vitorpamplona.nestsclient.interop
+
+import com.vitorpamplona.nestsclient.NestsListenerState
+import com.vitorpamplona.nestsclient.NestsSpeakerState
+import kotlin.test.fail
+
+/**
+ * Shared debug helpers for the interop tests. Gradle captures stdout
+ * per test and renders it in the HTML report — these helpers make
+ * the report explain exactly which sub-step of a multi-step interop
+ * scenario fired (or didn't), without forcing every assert into a
+ * giant message string.
+ *
+ * Output is silent unless `-DnestsInteropDebug=true` (or the harness
+ * is enabled). That keeps the default test run noise-free.
+ */
+object InteropDebug {
+    private val enabled: Boolean by lazy {
+        // If the harness is on, the test is going to talk to a real
+        // network anyway — surface every step. Otherwise allow an
+        // explicit opt-in.
+        System.getProperty(NostrNestsHarness.ENABLE_PROPERTY) == "true" ||
+            System.getProperty("nestsInteropDebug") == "true"
+    }
+
+    /** Print a labelled checkpoint. Cheap; safe in inner loops. */
+    fun checkpoint(
+        scope: String,
+        message: String,
+    ) {
+        if (!enabled) return
+        println("· [$scope] $message")
+    }
+
+    /**
+     * Run [block] surrounded by an "▶ start" / "✔ ok" / "✘ fail" log.
+     * Re-throws any exception so the test still fails — but the report
+     * makes it obvious which step actually exploded.
+     */
+    inline fun <T> step(
+        scope: String,
+        name: String,
+        block: () -> T,
+    ): T {
+        checkpoint(scope, "▶ $name")
+        return try {
+            block().also { checkpoint(scope, "✔ $name") }
+        } catch (t: Throwable) {
+            checkpoint(scope, "✘ $name — ${describe(t)}")
+            throw t
+        }
+    }
+
+    /**
+     * Async-friendly variant for `suspend` step bodies.
+     */
+    suspend inline fun <T> stepSuspending(
+        scope: String,
+        name: String,
+        block: () -> T,
+    ): T {
+        checkpoint(scope, "▶ $name")
+        return try {
+            block().also { checkpoint(scope, "✔ $name") }
+        } catch (t: Throwable) {
+            checkpoint(scope, "✘ $name — ${describe(t)}")
+            throw t
+        }
+    }
+
+    /**
+     * One-line summary of [t] including the chained cause(s) — useful
+     * because the surface message often hides the real reason in
+     * `cause.cause.cause...` (network → NestsException → AssertionError
+     * is a common stack here).
+     */
+    fun describe(t: Throwable): String =
+        buildString {
+            var current: Throwable? = t
+            var depth = 0
+            while (current != null && depth < 5) {
+                if (depth > 0) append(" ⟵ ")
+                append(current::class.simpleName).append(": ").append(current.message ?: "(no message)")
+                current = current.cause
+                depth += 1
+            }
+        }
+
+    /**
+     * Pretty-print a [NestsSpeakerState] — for [Failed] in particular,
+     * unwraps the chained cause so the assertion message names the
+     * real network error rather than the wrapping string.
+     */
+    fun describe(state: NestsSpeakerState): String =
+        when (state) {
+            is NestsSpeakerState.Failed -> {
+                "Failed(reason='${state.reason}'" +
+                    (state.cause?.let { ", cause=${describe(it)}" } ?: "") +
+                    ")"
+            }
+
+            is NestsSpeakerState.Connected -> {
+                "Connected(room=${state.room.moqNamespace()}, moqVersion=0x${state.negotiatedMoqVersion.toString(16)})"
+            }
+
+            is NestsSpeakerState.Broadcasting -> {
+                "Broadcasting(room=${state.room.moqNamespace()}, isMuted=${state.isMuted})"
+            }
+
+            else -> {
+                state.toString()
+            }
+        }
+
+    /** Mirror of [describe] for the listener side. */
+    fun describe(state: NestsListenerState): String =
+        when (state) {
+            is NestsListenerState.Failed -> {
+                "Failed(reason='${state.reason}'" +
+                    (state.cause?.let { ", cause=${describe(it)}" } ?: "") +
+                    ")"
+            }
+
+            is NestsListenerState.Connected -> {
+                "Connected(room=${state.room.moqNamespace()}, moqVersion=0x${state.negotiatedMoqVersion.toString(16)})"
+            }
+
+            else -> {
+                state.toString()
+            }
+        }
+
+    /**
+     * Assert [actual] is [NestsSpeakerState.Connected] or
+     * [NestsSpeakerState.Broadcasting], printing a richly-described
+     * failure message including any nested cause.
+     */
+    fun assertSpeakerReached(
+        scope: String,
+        expectedClass: String,
+        actual: NestsSpeakerState,
+    ) {
+        val ok =
+            when (expectedClass) {
+                "Connected" -> actual is NestsSpeakerState.Connected
+                "Broadcasting" -> actual is NestsSpeakerState.Broadcasting
+                else -> error("unsupported expectedClass=$expectedClass")
+            }
+        if (!ok) {
+            fail("[$scope] speaker did not reach $expectedClass — was ${describe(actual)}")
+        }
+        checkpoint(scope, "speaker @ $expectedClass — ${describe(actual)}")
+    }
+
+    fun assertListenerReached(
+        scope: String,
+        expectedClass: String,
+        actual: NestsListenerState,
+    ) {
+        val ok =
+            when (expectedClass) {
+                "Connected" -> actual is NestsListenerState.Connected
+                else -> error("unsupported expectedClass=$expectedClass")
+            }
+        if (!ok) {
+            fail("[$scope] listener did not reach $expectedClass — was ${describe(actual)}")
+        }
+        checkpoint(scope, "listener @ $expectedClass — ${describe(actual)}")
+    }
+}
@@ -162,10 +162,17 @@ class NostrNestsHarness private constructor(
                // otherwise hits the first test of the second class.
                waitForHealth("http://127.0.0.1:$AUTH_HOST_PORT/health", PORT_READY_TIMEOUT_MS)
            } catch (t: Throwable) {
-                // If readiness probe fails, tear down so we don't leak the
-                // stack into the next test run.
+                // Capture container state + recent logs BEFORE tearing
+                // down so the failure message is actually actionable.
+                // Otherwise we get "Port 8090 not ready in 90 s" with
+                // zero clue whether moq-auth crashed, the build failed,
+                // or something else was binding the port.
+                val diagnostics = captureFailureDiagnostics(workDir)
                runCatching { runDocker(workDir, "down", "-v", "--remove-orphans") }
-                throw t
+                throw IllegalStateException(
+                    "harness start failed: ${t.message}\n--- diagnostics ---\n$diagnostics",
+                    t,
+                )
            }
            return NostrNestsHarness(
                workDir = workDir,
@@ -287,6 +294,46 @@ class NostrNestsHarness private constructor(
            }
        }

+        /**
+         * Snapshot `docker compose ps` + the tail of each service's
+         * logs into a single string for inclusion in a thrown
+         * exception message. Best-effort — never throws, so it can
+         * be called from a [start] catch handler without masking the
+         * original error.
+         */
+        private fun captureFailureDiagnostics(workDir: File): String =
+            buildString {
+                append("== docker compose ps ==\n")
+                append(captureDocker(workDir, listOf("ps")))
+                for (service in listOf("moq-auth", "moq-relay", "strfry")) {
+                    append("\n== docker compose logs --tail 30 $service ==\n")
+                    append(captureDocker(workDir, listOf("logs", "--tail", "30", service)))
+                }
+            }
+
+        /**
+         * Run a docker compose subcommand and return its combined
+         * stdout/stderr; on any failure return the error text instead
+         * of throwing.
+         */
+        private fun captureDocker(
+            workDir: File,
+            args: List<String>,
+        ): String =
+            try {
+                val process =
+                    ProcessBuilder(listOf("docker", "compose", "-f", COMPOSE_FILE) + args)
+                        .directory(workDir)
+                        .redirectErrorStream(true)
+                        .start()
+                process.inputStream
+                    .bufferedReader()
+                    .readText()
+                    .also { process.waitFor() }
+            } catch (t: Throwable) {
+                "(failed to capture: ${t.message})"
+            }
+
        private fun waitForPort(
            host: String,
            port: Int,
@@ -21,10 +21,8 @@
 package com.vitorpamplona.nestsclient.interop

 import com.vitorpamplona.nestsclient.NestsListener
-import com.vitorpamplona.nestsclient.NestsListenerState
 import com.vitorpamplona.nestsclient.NestsRoomConfig
 import com.vitorpamplona.nestsclient.NestsSpeaker
-import com.vitorpamplona.nestsclient.NestsSpeakerState
 import com.vitorpamplona.nestsclient.OkHttpNestsClient
 import com.vitorpamplona.nestsclient.audio.AudioCapture
 import com.vitorpamplona.nestsclient.audio.OpusEncoder
@@ -52,8 +50,7 @@ import org.junit.BeforeClass
 import org.junit.Test
 import kotlin.test.assertContentEquals
 import kotlin.test.assertEquals
-import kotlin.test.assertNotNull
-import kotlin.test.assertTrue
+import kotlin.test.fail

 /**
 * Phase-4 multi-peer interop tests. Each test brings up a real
@@ -92,6 +89,9 @@ class NostrNestsMultiPeerInteropTest {
            val listenerSignerA = NostrSignerInternal(KeyPair())
            val listenerSignerB = NostrSignerInternal(KeyPair())

+            val scope = "fanout"
+            InteropDebug.checkpoint(scope, "room=${speakerRoom.moqNamespace()} speaker=${speakerSigner.pubKey.take(8)}")
+
            try {
                val speaker =
                    connectSpeaker(
@@ -99,26 +99,39 @@ class NostrNestsMultiPeerInteropTest {
                        room = speakerRoom,
                        signer = speakerSigner,
                        capture = capture,
+                        debugScope = scope,
                    )
-                speaker.startBroadcasting()
+                InteropDebug.stepSuspending(scope, "speaker.startBroadcasting") { speaker.startBroadcasting() }
+                InteropDebug.assertSpeakerReached(scope, "Broadcasting", speaker.state.value)

-                val listenerA = connectListener(pumpScope, speakerRoom, listenerSignerA)
-                val listenerB = connectListener(pumpScope, speakerRoom, listenerSignerB)
+                val listenerA = connectListener(pumpScope, speakerRoom, listenerSignerA, debugScope = "$scope/listenerA")
+                val listenerB = connectListener(pumpScope, speakerRoom, listenerSignerB, debugScope = "$scope/listenerB")

-                val subA = listenerA.subscribeSpeaker(speakerSigner.pubKey)
-                val subB = listenerB.subscribeSpeaker(speakerSigner.pubKey)
+                val subA =
+                    InteropDebug.stepSuspending("$scope/listenerA", "subscribeSpeaker(${speakerSigner.pubKey.take(8)})") {
+                        listenerA.subscribeSpeaker(speakerSigner.pubKey)
+                    }
+                val subB =
+                    InteropDebug.stepSuspending("$scope/listenerB", "subscribeSpeaker(${speakerSigner.pubKey.take(8)})") {
+                        listenerB.subscribeSpeaker(speakerSigner.pubKey)
+                    }

                val collectedA = collectFrames(pumpScope, subA, FRAMES_FANOUT)
                val collectedB = collectFrames(pumpScope, subB, FRAMES_FANOUT)

                delay(SUBSCRIBE_SETTLE_MS)
+                InteropDebug.checkpoint(scope, "pushing $FRAMES_FANOUT frames")
                for (i in 0 until FRAMES_FANOUT) {
                    capture.push(shortArrayOf(i.toShort()))
                    delay(FRAME_SPACING_MS)
                }

-                assertFrameSequence(collectedA.await(), FRAMES_FANOUT, "listener A")
-                assertFrameSequence(collectedB.await(), FRAMES_FANOUT, "listener B")
+                InteropDebug.stepSuspending(scope, "await listener A frames") {
+                    assertFrameSequence(collectedA.await(), FRAMES_FANOUT, "$scope/listenerA")
+                }
+                InteropDebug.stepSuspending(scope, "await listener B frames") {
+                    assertFrameSequence(collectedB.await(), FRAMES_FANOUT, "$scope/listenerB")
+                }

                runCatching { subA.unsubscribe() }
                runCatching { subB.unsubscribe() }
@@ -154,47 +167,88 @@ class NostrNestsMultiPeerInteropTest {
            val captureA = DriverCapture()
            val captureB = DriverCapture()

+            val scope = "multispeaker"
+            InteropDebug.checkpoint(scope, "room=${room.moqNamespace()} A=${signerA.pubKey.take(8)} B=${signerB.pubKey.take(8)}")
+
            try {
                val speakerA =
-                    connectSpeaker(pumpScope, room, signerA, captureA, encoderPrefix = "A:")
+                    connectSpeaker(
+                        pumpScope,
+                        room,
+                        signerA,
+                        captureA,
+                        encoderPrefix = "A:",
+                        debugScope = "$scope/speakerA",
+                    )
                val speakerB =
-                    connectSpeaker(pumpScope, room, signerB, captureB, encoderPrefix = "B:")
-                speakerA.startBroadcasting()
-                speakerB.startBroadcasting()
+                    connectSpeaker(
+                        pumpScope,
+                        room,
+                        signerB,
+                        captureB,
+                        encoderPrefix = "B:",
+                        debugScope = "$scope/speakerB",
+                    )
+                InteropDebug.stepSuspending("$scope/speakerA", "startBroadcasting") { speakerA.startBroadcasting() }
+                InteropDebug.assertSpeakerReached("$scope/speakerA", "Broadcasting", speakerA.state.value)
+                InteropDebug.stepSuspending("$scope/speakerB", "startBroadcasting") { speakerB.startBroadcasting() }
+                InteropDebug.assertSpeakerReached("$scope/speakerB", "Broadcasting", speakerB.state.value)

-                val listener = connectListener(pumpScope, room, listenerSigner)
-                val subA = listener.subscribeSpeaker(signerA.pubKey)
-                val subB = listener.subscribeSpeaker(signerB.pubKey)
+                val listener = connectListener(pumpScope, room, listenerSigner, debugScope = "$scope/listener")
+                val subA =
+                    InteropDebug.stepSuspending("$scope/listener", "subscribeSpeaker(A=${signerA.pubKey.take(8)})") {
+                        listener.subscribeSpeaker(signerA.pubKey)
+                    }
+                val subB =
+                    InteropDebug.stepSuspending("$scope/listener", "subscribeSpeaker(B=${signerB.pubKey.take(8)})") {
+                        listener.subscribeSpeaker(signerB.pubKey)
+                    }

                val collectedA = collectFrames(pumpScope, subA, FRAMES_MULTI_SPEAKER)
                val collectedB = collectFrames(pumpScope, subB, FRAMES_MULTI_SPEAKER)

                delay(SUBSCRIBE_SETTLE_MS)
+                InteropDebug.checkpoint(scope, "pushing $FRAMES_MULTI_SPEAKER frames into each capture")
                for (i in 0 until FRAMES_MULTI_SPEAKER) {
                    captureA.push(shortArrayOf((i + 0).toShort()))
                    captureB.push(shortArrayOf((i + 100).toShort()))
                    delay(FRAME_SPACING_MS)
                }

-                val resA = collectedA.await()
-                val resB = collectedB.await()
-                assertNotNull(resA, "listener never received speaker-A frames")
-                assertNotNull(resB, "listener never received speaker-B frames")
-                assertEquals(FRAMES_MULTI_SPEAKER, resA.size, "speaker A count")
-                assertEquals(FRAMES_MULTI_SPEAKER, resB.size, "speaker B count")
+                val resA =
+                    InteropDebug.stepSuspending(scope, "await speaker A frames") { collectedA.await() }
+                val resB =
+                    InteropDebug.stepSuspending(scope, "await speaker B frames") { collectedB.await() }
+                if (resA == null) {
+                    fail(
+                        "[$scope] listener never received speaker-A frames within ${RECEIVE_TIMEOUT_MS}ms — " +
+                            "speakerA=${InteropDebug.describe(speakerA.state.value)}, " +
+                            "listener=${InteropDebug.describe(listener.state.value)}",
+                    )
+                }
+                if (resB == null) {
+                    fail(
+                        "[$scope] listener never received speaker-B frames within ${RECEIVE_TIMEOUT_MS}ms — " +
+                            "speakerB=${InteropDebug.describe(speakerB.state.value)}, " +
+                            "listener=${InteropDebug.describe(listener.state.value)}",
+                    )
+                }
+                InteropDebug.checkpoint(scope, "received ${resA.size} A-frames, ${resB.size} B-frames")
+                assertEquals(FRAMES_MULTI_SPEAKER, resA.size, "[$scope] speaker A count")
+                assertEquals(FRAMES_MULTI_SPEAKER, resB.size, "[$scope] speaker B count")

                resA.forEachIndexed { idx, obj ->
                    assertContentEquals(
                        "A:".encodeToByteArray() + byteArrayOf(idx.toByte()),
                        obj.payload,
-                        "speaker A frame $idx — must not contain B's payload (no cross-talk)",
+                        "[$scope] speaker A frame $idx — must not contain B's payload (no cross-talk)",
                    )
                }
                resB.forEachIndexed { idx, obj ->
                    assertContentEquals(
                        "B:".encodeToByteArray() + byteArrayOf((idx + 100).toByte()),
                        obj.payload,
-                        "speaker B frame $idx — must not contain A's payload (no cross-talk)",
+                        "[$scope] speaker B frame $idx — must not contain A's payload (no cross-talk)",
                    )
                }

@@ -228,27 +282,38 @@ class NostrNestsMultiPeerInteropTest {
            val pumpScope = CoroutineScope(supervisor + Dispatchers.IO)
            val capture = DriverCapture()

+            val scope = "presub"
+            InteropDebug.checkpoint(scope, "room=${room.moqNamespace()} speaker=${speakerSigner.pubKey.take(8)}")
+
            try {
-                val listener = connectListener(pumpScope, room, listenerSigner)
-                val sub = listener.subscribeSpeaker(speakerSigner.pubKey)
+                val listener = connectListener(pumpScope, room, listenerSigner, debugScope = "$scope/listener")
+                val sub =
+                    InteropDebug.stepSuspending("$scope/listener", "subscribeSpeaker(${speakerSigner.pubKey.take(8)})") {
+                        listener.subscribeSpeaker(speakerSigner.pubKey)
+                    }
                val collected = collectFrames(pumpScope, sub, FRAMES_PRESUB)

                // Wait briefly so the SUBSCRIBE is on the relay before
                // the publisher arrives — the relay should hold it.
                delay(SUBSCRIBE_SETTLE_MS)
+                InteropDebug.checkpoint(scope, "subscribe settled — bringing speaker up now")

-                val speaker = connectSpeaker(pumpScope, room, speakerSigner, capture)
-                speaker.startBroadcasting()
+                val speaker = connectSpeaker(pumpScope, room, speakerSigner, capture, debugScope = "$scope/speaker")
+                InteropDebug.stepSuspending("$scope/speaker", "startBroadcasting") { speaker.startBroadcasting() }
+                InteropDebug.assertSpeakerReached("$scope/speaker", "Broadcasting", speaker.state.value)

                // Give the announce + publisher-side subscribe matchup
                // time to plumb before pushing frames.
                delay(SUBSCRIBE_SETTLE_MS)
+                InteropDebug.checkpoint(scope, "pushing $FRAMES_PRESUB frames into capture")
                for (i in 0 until FRAMES_PRESUB) {
                    capture.push(shortArrayOf(i.toShort()))
                    delay(FRAME_SPACING_MS)
                }

-                assertFrameSequence(collected.await(), FRAMES_PRESUB, "pre-subscribed listener")
+                InteropDebug.stepSuspending(scope, "await pre-subscribed listener frames") {
+                    assertFrameSequence(collected.await(), FRAMES_PRESUB, "$scope/listener")
+                }

                runCatching { sub.unsubscribe() }
                runCatching { listener.close() }
@@ -268,22 +333,22 @@ class NostrNestsMultiPeerInteropTest {
        signer: NostrSignerInternal,
        capture: AudioCapture,
        encoderPrefix: String = "FRAME-",
+        debugScope: String = "speaker(${signer.pubKey.take(8)})",
    ): NestsSpeaker {
        val speaker =
-            connectNestsSpeaker(
-                httpClient = http,
-                transport = transport,
-                scope = scope,
-                room = room,
-                signer = signer,
-                speakerPubkeyHex = signer.pubKey,
-                captureFactory = { capture },
-                encoderFactory = { StubEncoder(encoderPrefix.encodeToByteArray()) },
-            )
-        assertTrue(
-            speaker.state.value is NestsSpeakerState.Connected,
-            "speaker did not reach Connected — was ${speaker.state.value}",
-        )
+            InteropDebug.stepSuspending(debugScope, "connectNestsSpeaker") {
+                connectNestsSpeaker(
+                    httpClient = http,
+                    transport = transport,
+                    scope = scope,
+                    room = room,
+                    signer = signer,
+                    speakerPubkeyHex = signer.pubKey,
+                    captureFactory = { capture },
+                    encoderFactory = { StubEncoder(encoderPrefix.encodeToByteArray()) },
+                )
+            }
+        InteropDebug.assertSpeakerReached(debugScope, "Connected", speaker.state.value)
        return speaker
    }

@@ -291,19 +356,19 @@ class NostrNestsMultiPeerInteropTest {
        scope: CoroutineScope,
        room: NestsRoomConfig,
        signer: NostrSignerInternal,
+        debugScope: String = "listener(${signer.pubKey.take(8)})",
    ): NestsListener {
        val listener =
-            connectNestsListener(
-                httpClient = http,
-                transport = transport,
-                scope = scope,
-                room = room,
-                signer = signer,
-            )
-        assertTrue(
-            listener.state.value is NestsListenerState.Connected,
-            "listener did not reach Connected — was ${listener.state.value}",
-        )
+            InteropDebug.stepSuspending(debugScope, "connectNestsListener") {
+                connectNestsListener(
+                    httpClient = http,
+                    transport = transport,
+                    scope = scope,
+                    room = room,
+                    signer = signer,
+                )
+            }
+        InteropDebug.assertListenerReached(debugScope, "Connected", listener.state.value)
        return listener
    }

@@ -322,7 +387,14 @@ class NostrNestsMultiPeerInteropTest {
        expectedCount: Int,
        who: String,
    ) {
-        assertNotNull(objs, "$who did not receive $expectedCount frames within ${RECEIVE_TIMEOUT_MS}ms")
+        if (objs == null) {
+            fail(
+                "$who did not receive $expectedCount frames within ${RECEIVE_TIMEOUT_MS}ms — " +
+                    "verify the speaker actually announced + the relay forwarded; " +
+                    "look upstream for ✘ checkpoints in the captured stdout",
+            )
+        }
+        InteropDebug.checkpoint(who, "received ${objs.size} frames (expected $expectedCount)")
        assertEquals(expectedCount, objs.size, "$who frame count")
        objs.forEachIndexed { idx, obj ->
            assertEquals(idx.toLong(), obj.objectId, "$who object id at index $idx")
@@ -20,14 +20,14 @@
 */
 package com.vitorpamplona.nestsclient.interop

-import com.vitorpamplona.nestsclient.NestsListenerState
 import com.vitorpamplona.nestsclient.NestsRoomConfig
-import com.vitorpamplona.nestsclient.NestsSpeakerState
 import com.vitorpamplona.nestsclient.OkHttpNestsClient
 import com.vitorpamplona.nestsclient.audio.AudioCapture
+import com.vitorpamplona.nestsclient.audio.AudioRoomMoqLiteBroadcaster
 import com.vitorpamplona.nestsclient.audio.OpusEncoder
 import com.vitorpamplona.nestsclient.connectNestsListener
 import com.vitorpamplona.nestsclient.connectNestsSpeaker
+import com.vitorpamplona.nestsclient.moq.SubscribeHandle
 import com.vitorpamplona.nestsclient.transport.QuicWebTransportFactory
 import com.vitorpamplona.quartz.nip01Core.crypto.KeyPair
 import com.vitorpamplona.quartz.nip01Core.signers.NostrSignerInternal
@@ -48,8 +48,7 @@ import org.junit.BeforeClass
 import org.junit.Test
 import kotlin.test.assertContentEquals
 import kotlin.test.assertEquals
-import kotlin.test.assertNotNull
-import kotlin.test.assertTrue
+import kotlin.test.fail

 /**
 * End-to-end interop test. Drives the production [connectNestsSpeaker]
@@ -58,11 +57,10 @@ import kotlin.test.assertTrue
 * (`MoqLitePublisherHandle`), the listener subscribes by speaker
 * pubkey (`broadcast=pubkey`, `track="audio/data"`), the speaker
 * pushes deterministic Opus-shaped payloads through the
- * [com.vitorpamplona.nestsclient.audio.AudioRoomMoqLiteBroadcaster]
- * pipeline, and the listener collects them via
- * [com.vitorpamplona.nestsclient.moq.SubscribeHandle.objects] (which
- * the moq-lite adapter wraps over `MoqLiteFrame` so existing decoder
- * / player code keeps working).
+ * [AudioRoomMoqLiteBroadcaster] pipeline, and the listener collects
+ * them via [SubscribeHandle.objects] (which the moq-lite adapter
+ * wraps over `MoqLiteFrame` so existing decoder / player code keeps
+ * working).
 *
 * Verifies:
 *   - QuicWebTransportFactory + PermissiveCertificateValidator can speak
@@ -118,43 +116,47 @@ class NostrNestsRoundTripInteropTest {
            val capture = DriverCapture()
            val encoder = StubEncoder(prefix = "FRAME-".encodeToByteArray())

+            val scope = "round-trip"
+            InteropDebug.checkpoint(scope, "room=${room.moqNamespace()} authBase=${room.authBaseUrl} endpoint=${room.endpoint}")
+
            try {
                val speaker =
-                    connectNestsSpeaker(
-                        httpClient = httpClient,
-                        transport = transport,
-                        scope = pumpScope,
-                        room = room,
-                        signer = signer,
-                        speakerPubkeyHex = pubkey,
-                        captureFactory = { capture },
-                        encoderFactory = { encoder },
-                    )
-                assertTrue(
-                    speaker.state.value is NestsSpeakerState.Connected,
-                    "speaker did not reach Connected — was ${speaker.state.value}",
-                )
+                    InteropDebug.stepSuspending(scope, "connectNestsSpeaker") {
+                        connectNestsSpeaker(
+                            httpClient = httpClient,
+                            transport = transport,
+                            scope = pumpScope,
+                            room = room,
+                            signer = signer,
+                            speakerPubkeyHex = pubkey,
+                            captureFactory = { capture },
+                            encoderFactory = { encoder },
+                        )
+                    }
+                InteropDebug.assertSpeakerReached(scope, "Connected", speaker.state.value)

-                val broadcast = speaker.startBroadcasting()
-                assertTrue(
-                    speaker.state.value is NestsSpeakerState.Broadcasting,
-                    "speaker did not reach Broadcasting — was ${speaker.state.value}",
-                )
+                val broadcast =
+                    InteropDebug.stepSuspending(scope, "speaker.startBroadcasting") {
+                        speaker.startBroadcasting()
+                    }
+                InteropDebug.assertSpeakerReached(scope, "Broadcasting", speaker.state.value)

                val listener =
-                    connectNestsListener(
-                        httpClient = httpClient,
-                        transport = transport,
-                        scope = pumpScope,
-                        room = room,
-                        signer = signer,
-                    )
-                assertTrue(
-                    listener.state.value is NestsListenerState.Connected,
-                    "listener did not reach Connected — was ${listener.state.value}",
-                )
+                    InteropDebug.stepSuspending(scope, "connectNestsListener") {
+                        connectNestsListener(
+                            httpClient = httpClient,
+                            transport = transport,
+                            scope = pumpScope,
+                            room = room,
+                            signer = signer,
+                        )
+                    }
+                InteropDebug.assertListenerReached(scope, "Connected", listener.state.value)

-                val subscription = listener.subscribeSpeaker(pubkey)
+                val subscription =
+                    InteropDebug.stepSuspending(scope, "listener.subscribeSpeaker(pubkey)") {
+                        listener.subscribeSpeaker(pubkey)
+                    }

                // Start collecting before the speaker publishes anything —
                // moq-lite group frames that arrive before .objects.collect
@@ -172,6 +174,7 @@ class NostrNestsRoundTripInteropTest {
                // and rolls back the object id without queuing a datagram).
                delay(SUBSCRIBE_SETTLE_MS)

+                InteropDebug.checkpoint(scope, "pushing $N_FRAMES frames into capture")
                for (i in 0 until N_FRAMES) {
                    capture.push(shortArrayOf(i.toShort()))
                    // Pace frames slightly so a transient datagram drop
@@ -179,11 +182,18 @@ class NostrNestsRoundTripInteropTest {
                    delay(FRAME_SPACING_MS)
                }

-                val datagrams = received.await()
-                assertNotNull(
-                    datagrams,
-                    "Did not receive $N_FRAMES moq-lite frames within ${RECEIVE_TIMEOUT_MS}ms",
-                )
+                val datagrams =
+                    InteropDebug.stepSuspending(scope, "await $N_FRAMES frames on subscription") {
+                        received.await()
+                    }
+                if (datagrams == null) {
+                    fail(
+                        "[$scope] Did not receive $N_FRAMES moq-lite frames within ${RECEIVE_TIMEOUT_MS}ms — " +
+                            "speaker=${InteropDebug.describe(speaker.state.value)}, " +
+                            "listener=${InteropDebug.describe(listener.state.value)}",
+                    )
+                }
+                InteropDebug.checkpoint(scope, "received ${datagrams.size} frames (expected $N_FRAMES)")
                assertEquals(N_FRAMES, datagrams.size, "expected exactly $N_FRAMES objects")

                datagrams.forEachIndexed { idx, obj ->