From 8f8bcda2bc8462965c7e2a21657c3d56cc503fe8 Mon Sep 17 00:00:00 2001 From: Sam Edwards <264948+handstandsam@users.noreply.github.com> Date: Sun, 2 Aug 2026 08:44:54 -0600 Subject: [PATCH] Upstream 2026.08.02 --- .trailblaze-sync | 2 +- docs/generated/external-config.md | 2 +- docs/generated/functions/custom/wait.md | 9 +- .../android/AndroidTrailblazeRule.kt | 4 +- .../trailblaze/tools/sleep.tool.yaml | 2 + .../toolcalls/commands/SleepTrailblazeTool.kt | 82 +++++++ .../commands/WaitForChangeTrailblazeTool.kt | 14 +- .../commands/WaitForIdleSyncTrailblazeTool.kt | 19 +- .../memory/AssertMathTrailblazeTool.kt | 12 +- .../commands/SleepTrailblazeToolTest.kt | 143 ++++++++++++ .../WaitForChangeTrailblazeToolTest.kt | 104 +++++++++ .../WaitForIdleSyncTrailblazeToolTest.kt | 112 ++++++++++ .../trailblaze/yaml/ToolSerializationTest.kt | 67 ++++++ .../host/TrailblazeHostYamlRunner.kt | 7 +- .../trailblaze/host/rules/BaseComposeTest.kt | 4 +- .../host/rules/BaseHostTrailblazeTest.kt | 4 +- .../host/rules/BasePlaywrightElectronTest.kt | 4 +- .../host/rules/BasePlaywrightNativeTest.kt | 4 +- .../api/android/trailblaze-models.api | 1 + .../api/jvm/trailblaze-models.api | 1 + .../block/trailblaze/toolcalls/CoreTools.kt | 10 +- .../yaml/unified/RecordingResolution.kt | 73 +++++- .../trailblaze/toolsets/core_interaction.yaml | 1 + .../yaml/unified/RecordingResolutionTest.kt | 156 +++++++++++-- .../web/app/run-report-core.test.ts | 208 ++++++++++++++++++ .../trailrunner/web/app/run-report-extract.ts | 53 +++-- 26 files changed, 1015 insertions(+), 83 deletions(-) create mode 100644 trailblaze-common/src/commonMain/resources/trails/config/trailmaps/trailblaze/tools/sleep.tool.yaml create mode 100644 trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeTool.kt create mode 100644 trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeToolTest.kt create mode 100644 trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeToolTest.kt create mode 100644 trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeToolTest.kt diff --git a/.trailblaze-sync b/.trailblaze-sync index ec971526f..a7867ccc7 100644 --- a/.trailblaze-sync +++ b/.trailblaze-sync @@ -1 +1 @@ -6e278dc4acbede2988c75123f499d10b0cf7714f +e5cd7a49580860da9bb50f5f91ac18924d361e4b diff --git a/docs/generated/external-config.md b/docs/generated/external-config.md index 864b4c8ff..06ebf288c 100644 --- a/docs/generated/external-config.md +++ b/docs/generated/external-config.md @@ -171,7 +171,7 @@ Toolsets are declared in `trailmaps//toolsets/*.yaml`. They are pure YAML gr | `android_primitives` | Yes | `android-ondevice-accessibility`, `android-ondevice-instrumentation` | 7 | | `compose_core` | No | `compose` | 6 | | `compose_verification` | No | `compose` | 3 | -| `core_interaction` | Yes | `android-ondevice-accessibility`, `android-ondevice-instrumentation`, `ios-axe`, `ios-host` | 20 | +| `core_interaction` | Yes | `android-ondevice-accessibility`, `android-ondevice-instrumentation`, `ios-axe`, `ios-host` | 21 | | `memory` | No | `all drivers` | 8 | | `meta` | Yes | `all drivers` | 1 | | `mobile_primitives` | Yes | `android-ondevice-accessibility`, `android-ondevice-instrumentation`, `ios-axe`, `ios-host` | 5 | diff --git a/docs/generated/functions/custom/wait.md b/docs/generated/functions/custom/wait.md index 862d91e0f..2985048c1 100644 --- a/docs/generated/functions/custom/wait.md +++ b/docs/generated/functions/custom/wait.md @@ -4,8 +4,11 @@ # `wait` -Wait for a specified amount of time. Use when you see a loading screen — prefer this over -pressing the back button. +Settle on a loading screen: block until the UI goes quiet, up to a ceiling. This returns as soon +as the UI is idle, so on an already-static screen it returns almost immediately rather than +waiting the full time — it is a ceiling, not a duration. Use when you see a loading screen — +prefer this over pressing the back button. If you are waiting for something specific to appear, +assert on that element instead: a quiet UI does not mean the thing you expect has arrived. ## Source @@ -23,7 +26,7 @@ pressing the back button. ### Optional parameters - `timeToWaitInSeconds` — `Integer` - Unit: seconds. Default Value: 5 seconds. + Ceiling on how long to settle for, in seconds — not a guaranteed duration. Default Value: 5 seconds. ## Output diff --git a/trailblaze-android/src/main/java/xyz/block/trailblaze/android/AndroidTrailblazeRule.kt b/trailblaze-android/src/main/java/xyz/block/trailblaze/android/AndroidTrailblazeRule.kt index 8facb05f1..3599adfcf 100644 --- a/trailblaze-android/src/main/java/xyz/block/trailblaze/android/AndroidTrailblazeRule.kt +++ b/trailblaze-android/src/main/java/xyz/block/trailblaze/android/AndroidTrailblazeRule.kt @@ -677,11 +677,9 @@ open class AndroidTrailblazeRule( if (!trailblazeYaml.hasActionableSteps(trailItems)) { val trailName = trailConfig?.title ?: trailFilePath ?: "unknown" - val trailUrl = trailConfig?.metadata?.get("testRailUrl") throw TrailblazeException( "Trail '$trailName' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } diff --git a/trailblaze-common/src/commonMain/resources/trails/config/trailmaps/trailblaze/tools/sleep.tool.yaml b/trailblaze-common/src/commonMain/resources/trails/config/trailmaps/trailblaze/tools/sleep.tool.yaml new file mode 100644 index 000000000..ddb23c8f7 --- /dev/null +++ b/trailblaze-common/src/commonMain/resources/trails/config/trailmaps/trailblaze/tools/sleep.tool.yaml @@ -0,0 +1,2 @@ +id: sleep +class: xyz.block.trailblaze.toolcalls.commands.SleepTrailblazeTool diff --git a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeTool.kt b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeTool.kt new file mode 100644 index 000000000..c7247b955 --- /dev/null +++ b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeTool.kt @@ -0,0 +1,82 @@ +package xyz.block.trailblaze.toolcalls.commands + +import ai.koog.agents.core.tools.annotations.LLMDescription +import kotlin.time.TimeSource +import kotlinx.coroutines.delay +import kotlinx.serialization.Serializable +import xyz.block.trailblaze.toolcalls.HostLocalExecutableTrailblazeTool +import xyz.block.trailblaze.toolcalls.TrailblazeToolClass +import xyz.block.trailblaze.toolcalls.TrailblazeToolExecutionContext +import xyz.block.trailblaze.toolcalls.TrailblazeToolResult + +/** + * The only tool that consumes wall-clock time unconditionally. + * + * `wait` and `waitForChange` are settles: they return the moment the UI is quiet, so on a static + * screen both come back in ~150ms no matter what duration was asked for. That makes them useless + * for the case this tool exists for — letting something happen OFF-screen (a server-side value + * propagating) before the trail navigates to the screen that reads it. + * + * Implemented as a [HostLocalExecutableTrailblazeTool] so `BaseTrailblazeAgent.runTrailblazeTools` + * runs it in-process for EVERY agent, before driver-specific dispatch. That is what makes the + * duration driver-independent: there is no path on which it can degrade to a Maestro + * `WaitForAnimationToEnd`, the defect this tool exists to avoid. + * + * On the trail path it is also RPC-free. The MCP `step` / `trailblaze tool` path is not: + * `TrailblazeMcpBridgeImpl.executeHostLocalTool` handles only Playwright, so on an on-device driver + * the call goes over RPC and is bounded by `OnDeviceRpcTimeouts.HANDLER_AWAIT_CAP_MS` (15 min). The + * sleep still runs to completion there — [MAX_DURATION_MS] keeps every legal duration well inside + * that ceiling — but the transport cap does exist on that path. + * + * `surfaceToLlm = false`: a fixed sleep is correct when an author knows about an off-screen + * dependency, and almost always wrong when picked autonomously — the agent should assert on the + * element it expects instead. Hidden from the LLM toolbox; still callable from hand-authored + * trail YAML and scripted tools, and still recorded. + */ +@Serializable +@TrailblazeToolClass("sleep", surfaceToLlm = false) +@LLMDescription( + """ +Block for a fixed amount of wall-clock time, always consuming the full duration regardless of +what the UI is doing. Use only to let something happen off-screen (e.g. a server-side value +propagating) before navigating to the screen that reads it. To wait for something visible, +assert on that element instead — and to wait for the UI to settle, use waitForChange. + """, +) +data class SleepTrailblazeTool( + @LLMDescription("How long to sleep, in milliseconds. Must be between 100 and 300000 (5 minutes). Default 5000.") + val durationMs: Long = 5_000, +) : HostLocalExecutableTrailblazeTool { + + override val advertisedToolName: String get() = "sleep" + + override suspend fun execute( + toolExecutionContext: TrailblazeToolExecutionContext, + ): TrailblazeToolResult { + // Out of range is an error, not a clamp: silently coercing a too-long sleep would return + // before the requested duration while reporting success — the defect this tool removes. + if (durationMs !in MIN_DURATION_MS..MAX_DURATION_MS) { + return TrailblazeToolResult.Error.ExceptionThrown( + errorMessage = "sleep requires durationMs between $MIN_DURATION_MS and $MAX_DURATION_MS, but was $durationMs", + command = this, + ) + } + val startMark = TimeSource.Monotonic.markNow() + delay(durationMs) + val elapsedMs = startMark.elapsedNow().inWholeMilliseconds + return TrailblazeToolResult.Success( + message = "Slept ${elapsedMs}ms (requested ${durationMs}ms)", + ) + } + + companion object { + /** Anything shorter is a no-op that reads as a wait, and is almost always a units slip (`5` meaning 5 seconds). */ + const val MIN_DURATION_MS = 100L + + /** + * Held under the 10-minute run-poll inactivity window (`DaemonClient.RUN_POLL_TIMEOUT_MS`): a + * host-local sleep emits no progress, so a longer one is indistinguishable from a wedged run. + */ + const val MAX_DURATION_MS = 300_000L + } +} diff --git a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeTool.kt b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeTool.kt index 21d463272..c463a4fbf 100644 --- a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeTool.kt +++ b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeTool.kt @@ -1,6 +1,7 @@ package xyz.block.trailblaze.toolcalls.commands import ai.koog.agents.core.tools.annotations.LLMDescription +import kotlin.time.TimeSource import kotlinx.serialization.Serializable import maestro.orchestra.WaitForAnimationToEndCommand import xyz.block.trailblaze.toolcalls.ExecutableTrailblazeTool @@ -41,19 +42,24 @@ data class WaitForChangeTrailblazeTool( ) if (driverResult != null) return driverResult - // Unsupported driver (iOS / host / non-accessibility Android): degrade to a timed wait so - // the caller still gets a settle pause rather than a hard failure. - Console.log("waitForChange: driver has no change detection, falling back to a ${timeoutMs}ms timed wait") + // Unsupported driver (iOS / host / non-accessibility Android): degrade to an animation-end + // settle so the caller still gets a pause rather than a hard failure. + Console.log("waitForChange: driver has no change detection, falling back to a settle with a ${timeoutMs}ms ceiling") val agentForFallback = agent ?: return TrailblazeToolResult.Error.ExceptionThrown( errorMessage = "waitForChange could not run: no agent available to perform the wait", ) + val startMark = TimeSource.Monotonic.markNow() val result = agentForFallback.runMaestroCommands( maestroCommands = listOf(WaitForAnimationToEndCommand(timeout = timeoutMs.toString())), traceId = toolExecutionContext.traceId, ) if (result is TrailblazeToolResult.Success) { - return TrailblazeToolResult.Success(message = "waitForChange degraded to a ${timeoutMs}ms timed wait") + // `timeoutMs` is the ceiling the settle may take, never the time it spent (#5279). + val elapsedMs = startMark.elapsedNow().inWholeMilliseconds + return TrailblazeToolResult.Success( + message = "waitForChange degraded to a settle, which returned after ${elapsedMs}ms (ceiling ${timeoutMs}ms)", + ) } return result } diff --git a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeTool.kt b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeTool.kt index be8d187bd..74ac6ca84 100644 --- a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeTool.kt +++ b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeTool.kt @@ -1,6 +1,7 @@ package xyz.block.trailblaze.toolcalls.commands import ai.koog.agents.core.tools.annotations.LLMDescription +import kotlin.time.TimeSource import kotlinx.serialization.Serializable import maestro.orchestra.Command import maestro.orchestra.WaitForAnimationToEndCommand @@ -14,12 +15,15 @@ import xyz.block.trailblaze.toolcalls.isSuccess @TrailblazeToolClass("wait") @LLMDescription( """ -Wait for a specified amount of time. Use when you see a loading screen — prefer this over -pressing the back button. +Settle on a loading screen: block until the UI goes quiet, up to a ceiling. This returns as soon +as the UI is idle, so on an already-static screen it returns almost immediately rather than +waiting the full time — it is a ceiling, not a duration. Use when you see a loading screen — +prefer this over pressing the back button. If you are waiting for something specific to appear, +assert on that element instead: a quiet UI does not mean the thing you expect has arrived. """, ) data class WaitForIdleSyncTrailblazeTool( - @LLMDescription("Unit: seconds. Default Value: 5 seconds.") + @LLMDescription("Ceiling on how long to settle for, in seconds — not a guaranteed duration. Default Value: 5 seconds.") val timeToWaitInSeconds: Int = 5, ) : MapsToMaestroCommands() { override fun toMaestroCommands(): List = listOf( @@ -31,9 +35,16 @@ data class WaitForIdleSyncTrailblazeTool( override suspend fun execute( toolExecutionContext: TrailblazeToolExecutionContext, ): TrailblazeToolResult { + val startMark = TimeSource.Monotonic.markNow() val result = super.execute(toolExecutionContext) if (result.isSuccess()) { - return TrailblazeToolResult.Success(message = "Waited $timeToWaitInSeconds seconds") + // Report what actually elapsed. The old message stated the requested ceiling, which on a + // static screen overstated the real settle by ~30x and read in the log as a wait that + // had happened (#5279). + val elapsedMs = startMark.elapsedNow().inWholeMilliseconds + return TrailblazeToolResult.Success( + message = "Settled after ${elapsedMs}ms (ceiling ${timeToWaitInSeconds}s)", + ) } return result } diff --git a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/memory/AssertMathTrailblazeTool.kt b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/memory/AssertMathTrailblazeTool.kt index 92400fa26..f349e6d7d 100644 --- a/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/memory/AssertMathTrailblazeTool.kt +++ b/trailblaze-common/src/jvmAndAndroid/kotlin/xyz/block/trailblaze/toolcalls/commands/memory/AssertMathTrailblazeTool.kt @@ -32,7 +32,14 @@ data class AssertMathTrailblazeTool( * throws is surfaced. Reach for this only when a `[[prompt]]` read is subject to eventual * consistency (a value the app back-fills a beat after the action) — it bounds WHEN the read is * taken, never WHAT is asserted. Each retry re-reads through [ElementComparator.getElementValue], - * which captures a fresh screen, so the poll observes the updated value rather than a stale one. + * which captures the screen afresh. + * + * LIMITATION: a fresh capture is not a fresh fetch. This re-reads the rendered screen, not the + * underlying data, so it can only observe values the app itself updates in place. For a view the + * app populates once and refreshes only on navigation, every attempt re-reads the same stale + * number and no bound helps — polling cannot substitute for re-navigating. Observed against a + * balance screen of that shape: every capture across a minute of polling returned the same + * pre-update value, and shorter bounds failed identically. */ val timeoutMs: Long? = null, /** @@ -66,7 +73,8 @@ data class AssertMathTrailblazeTool( * A null [timeoutMs] runs [evaluateOnce] exactly once (unchanged single-shot behavior); a set * [timeoutMs] re-runs [evaluateOnce] each attempt — and because that path re-reads via * [ElementComparator.getElementValue] (a fresh screen capture per call), every retry observes the - * current screen instead of a cached snapshot. + * current screen instead of a cached snapshot. What the current screen *shows* is the app's + * business; see the LIMITATION on [timeoutMs]. */ internal fun executeWithClock( elementComparator: ElementComparator, diff --git a/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeToolTest.kt b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeToolTest.kt new file mode 100644 index 000000000..b84f9d8c3 --- /dev/null +++ b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/SleepTrailblazeToolTest.kt @@ -0,0 +1,143 @@ +package xyz.block.trailblaze.toolcalls.commands + +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertTrue +import kotlin.time.TimeSource +import kotlinx.coroutines.runBlocking +import kotlinx.datetime.Clock +import xyz.block.trailblaze.AgentMemory +import xyz.block.trailblaze.devices.TrailblazeDeviceId +import xyz.block.trailblaze.devices.TrailblazeDeviceInfo +import xyz.block.trailblaze.devices.TrailblazeDevicePlatform +import xyz.block.trailblaze.devices.TrailblazeDriverType +import xyz.block.trailblaze.logs.client.TrailblazeLogger +import xyz.block.trailblaze.logs.client.TrailblazeSession +import xyz.block.trailblaze.logs.client.TrailblazeSessionProvider +import xyz.block.trailblaze.logs.model.SessionId +import xyz.block.trailblaze.toolcalls.TrailblazeToolExecutionContext +import xyz.block.trailblaze.toolcalls.TrailblazeToolResult + +/** + * `sleep` exists because every other wait in the framework is a settle that returns as soon as + * the UI is quiet (#5279). So the assertion that matters is the wall-clock FLOOR: a test that + * only asserted `Success` would pass against the very settle-based implementation this tool was + * added to replace. + */ +class SleepTrailblazeToolTest { + + private val sleepMs = 400L + + @Test + fun `consumes the full requested duration instead of returning early`() { + val outerMark = TimeSource.Monotonic.markNow() + val result = runBlocking { SleepTrailblazeTool(durationMs = sleepMs).execute(context()) } + val outerElapsedMs = outerMark.elapsedNow().inWholeMilliseconds + + assertTrue(result is TrailblazeToolResult.Success, "expected Success but was $result") + // The load-bearing assertion. A settle-based implementation returns in ~150ms on a static + // screen; `WaitForAnimationToEnd` against a null driver returns in ~0ms. Both fail here. + assertTrue( + outerElapsedMs >= sleepMs, + "sleep(${sleepMs}ms) returned after only ${outerElapsedMs}ms — it did not consume wall-clock time", + ) + } + + @Test + fun `success message reports measured elapsed time, bounded by an independent measurement`() { + val outerMark = TimeSource.Monotonic.markNow() + val result = runBlocking { SleepTrailblazeTool(durationMs = sleepMs).execute(context()) } + val outerElapsedMs = outerMark.elapsedNow().inWholeMilliseconds + + val message = (result as TrailblazeToolResult.Success).message + val reportedMs = Regex("^Slept (\\d+)ms").find(message.orEmpty())?.groupValues?.get(1)?.toLong() + ?: error("message did not report an elapsed time in the documented shape: $message") + + // Brackets the reported number between the floor it must clear and a measurement taken + // strictly outside it — so the message cannot be an arbitrary constant, and in particular + // cannot be a duration that was never actually spent. + assertTrue(reportedMs >= sleepMs, "reported ${reportedMs}ms is below the requested ${sleepMs}ms") + assertTrue( + reportedMs <= outerElapsedMs, + "reported ${reportedMs}ms exceeds the ${outerElapsedMs}ms measured around the call, so it is not a real measurement", + ) + assertTrue( + message.orEmpty().contains("requested ${sleepMs}ms"), + "message should also state what was requested, was: $message", + ) + } + + @Test + fun `negative duration fails loudly rather than silently returning success`() { + // `delay` clamps a negative duration to zero, which would make this tool a silent no-op + // reporting success — the exact defect class it exists to remove. + val result = runBlocking { SleepTrailblazeTool(durationMs = -1).execute(context()) } + assertTrue( + result is TrailblazeToolResult.Error, + "a negative duration must be an error, but was $result", + ) + } + + @Test + fun `duration below the floor fails loudly rather than passing as a no-op`() { + // `durationMs: 5` is a units slip (5 seconds meant), and succeeds as a 5ms non-wait. + val result = runBlocking { + SleepTrailblazeTool(durationMs = SleepTrailblazeTool.MIN_DURATION_MS - 1).execute(context()) + } + assertTrue(result is TrailblazeToolResult.Error, "a sub-floor duration must be an error, but was $result") + } + + @Test + fun `duration above the cap fails loudly instead of being silently clamped`() { + // Clamping would return before the requested duration while reporting success, which is the + // early-return defect this tool exists to remove — so the cap must reject, not coerce. + val requested = SleepTrailblazeTool.MAX_DURATION_MS + 1 + val outerMark = TimeSource.Monotonic.markNow() + val result = runBlocking { SleepTrailblazeTool(durationMs = requested).execute(context()) } + val outerElapsedMs = outerMark.elapsedNow().inWholeMilliseconds + + assertTrue(result is TrailblazeToolResult.Error, "an over-cap duration must be an error, but was $result") + assertTrue( + outerElapsedMs < SleepTrailblazeTool.MAX_DURATION_MS, + "rejection took ${outerElapsedMs}ms — it slept before failing", + ) + } + + @Test + fun `bounds bracket the default duration`() { + assertTrue( + SleepTrailblazeTool().durationMs in SleepTrailblazeTool.MIN_DURATION_MS..SleepTrailblazeTool.MAX_DURATION_MS, + "the default duration is outside the range the tool accepts", + ) + // The cap must stay under the 10-minute run-poll inactivity window, which a silent + // host-local sleep cannot reset. + assertTrue( + SleepTrailblazeTool.MAX_DURATION_MS < 10 * 60 * 1000L, + "the cap allows a sleep long enough to trip the run-poll inactivity watchdog", + ) + } + + @Test + fun `default duration is five seconds`() { + assertEquals(5_000L, SleepTrailblazeTool().durationMs) + } + + private fun context(): TrailblazeToolExecutionContext = TrailblazeToolExecutionContext( + screenState = null, + traceId = null, + trailblazeDeviceInfo = TrailblazeDeviceInfo( + trailblazeDeviceId = TrailblazeDeviceId( + instanceId = "test-device", + trailblazeDevicePlatform = TrailblazeDevicePlatform.ANDROID, + ), + trailblazeDriverType = TrailblazeDriverType.ANDROID_ONDEVICE_INSTRUMENTATION, + widthPixels = 1080, + heightPixels = 1920, + ), + sessionProvider = TrailblazeSessionProvider { + TrailblazeSession(sessionId = SessionId("test-session"), startTime = Clock.System.now()) + }, + trailblazeLogger = TrailblazeLogger.createNoOp(), + memory = AgentMemory(), + ) +} diff --git a/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeToolTest.kt b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeToolTest.kt new file mode 100644 index 000000000..6d54e7bbb --- /dev/null +++ b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForChangeTrailblazeToolTest.kt @@ -0,0 +1,104 @@ +package xyz.block.trailblaze.toolcalls.commands + +import kotlin.test.Test +import kotlin.test.assertTrue +import kotlinx.coroutines.delay +import kotlinx.coroutines.runBlocking +import kotlinx.datetime.Clock +import maestro.orchestra.Command +import xyz.block.trailblaze.AgentMemory +import xyz.block.trailblaze.MaestroTrailblazeAgent +import xyz.block.trailblaze.devices.TrailblazeDeviceId +import xyz.block.trailblaze.devices.TrailblazeDeviceInfo +import xyz.block.trailblaze.devices.TrailblazeDevicePlatform +import xyz.block.trailblaze.devices.TrailblazeDriverType +import xyz.block.trailblaze.logs.client.TrailblazeLogger +import xyz.block.trailblaze.logs.client.TrailblazeSession +import xyz.block.trailblaze.logs.client.TrailblazeSessionProvider +import xyz.block.trailblaze.logs.model.SessionId +import xyz.block.trailblaze.logs.model.TraceId +import xyz.block.trailblaze.toolcalls.TrailblazeToolExecutionContext +import xyz.block.trailblaze.toolcalls.TrailblazeToolResult + +/** + * On a driver with no change detection (iOS / host / non-accessibility Android) `waitForChange` + * lowers to a Maestro `WaitForAnimationToEnd`, whose timeout is a CEILING. It nevertheless reported + * `"degraded to a ${timeoutMs}ms timed wait"` unconditionally — the same false-duration claim + * fixed for `wait` (#5279). + * + * The fake driver settles far faster than the ceiling, which is what makes this discriminating. + */ +class WaitForChangeTrailblazeToolTest { + + private val settleMs = 50L + private val timeoutMs = 8_000L + + /** Base [MaestroTrailblazeAgent.waitForTreeChange] returns null, so this exercises the fallback. */ + private class FastSettlingAgent(private val settleMs: Long) : MaestroTrailblazeAgent( + trailblazeLogger = TrailblazeLogger.createNoOp(), + trailblazeDeviceInfoProvider = { deviceInfo() }, + sessionProvider = TrailblazeSessionProvider { + TrailblazeSession(sessionId = SessionId("test-session"), startTime = Clock.System.now()) + }, + ) { + override suspend fun executeMaestroCommands( + commands: List, + traceId: TraceId?, + ): TrailblazeToolResult { + delay(settleMs) + return TrailblazeToolResult.Success() + } + } + + @Test + fun `unsupported-driver fallback reports the real settle, not the requested timeout`() { + val message = (runFallback() as TrailblazeToolResult.Success).message.orEmpty() + + val reportedMs = Regex("returned after (\\d+)ms").find(message)?.groupValues?.get(1)?.toLong() + ?: error("message did not report a measured settle in the documented shape: $message") + + assertTrue(reportedMs >= settleMs, "reported ${reportedMs}ms is below the ${settleMs}ms the driver took") + assertTrue( + reportedMs < timeoutMs, + "reported ${reportedMs}ms equals or exceeds the ${timeoutMs}ms ceiling — the message is still the requested duration, not the measured one", + ) + } + + @Test + fun `fallback message does not claim the timeout was spent waiting`() { + val message = (runFallback() as TrailblazeToolResult.Success).message.orEmpty() + // Pins the specific false string this change removed. + assertTrue( + !message.contains("degraded to a ${timeoutMs}ms timed wait"), + "message still claims the full timeout was spent waiting: $message", + ) + } + + private fun runFallback(): TrailblazeToolResult = runBlocking { + WaitForChangeTrailblazeTool(timeoutMs = timeoutMs).execute(context(FastSettlingAgent(settleMs))) + } + + private fun context(agent: MaestroTrailblazeAgent) = TrailblazeToolExecutionContext( + screenState = null, + traceId = null, + trailblazeDeviceInfo = deviceInfo(), + sessionProvider = TrailblazeSessionProvider { + TrailblazeSession(sessionId = SessionId("test-session"), startTime = Clock.System.now()) + }, + trailblazeLogger = TrailblazeLogger.createNoOp(), + memory = AgentMemory(), + maestroTrailblazeAgent = agent, + ) + + private companion object { + fun deviceInfo() = TrailblazeDeviceInfo( + trailblazeDeviceId = TrailblazeDeviceId( + instanceId = "test-device", + trailblazeDevicePlatform = TrailblazeDevicePlatform.IOS, + ), + trailblazeDriverType = TrailblazeDriverType.IOS_HOST, + widthPixels = 1170, + heightPixels = 2532, + ) + } +} diff --git a/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeToolTest.kt b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeToolTest.kt new file mode 100644 index 000000000..2c66dd72d --- /dev/null +++ b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/toolcalls/commands/WaitForIdleSyncTrailblazeToolTest.kt @@ -0,0 +1,112 @@ +package xyz.block.trailblaze.toolcalls.commands + +import kotlin.test.Test +import kotlin.test.assertTrue +import kotlinx.coroutines.delay +import kotlinx.coroutines.runBlocking +import kotlinx.datetime.Clock +import maestro.orchestra.Command +import xyz.block.trailblaze.AgentMemory +import xyz.block.trailblaze.MaestroTrailblazeAgent +import xyz.block.trailblaze.devices.TrailblazeDeviceId +import xyz.block.trailblaze.devices.TrailblazeDeviceInfo +import xyz.block.trailblaze.devices.TrailblazeDevicePlatform +import xyz.block.trailblaze.devices.TrailblazeDriverType +import xyz.block.trailblaze.logs.client.TrailblazeLogger +import xyz.block.trailblaze.logs.client.TrailblazeSession +import xyz.block.trailblaze.logs.client.TrailblazeSessionProvider +import xyz.block.trailblaze.logs.model.SessionId +import xyz.block.trailblaze.logs.model.TraceId +import xyz.block.trailblaze.toolcalls.TrailblazeToolExecutionContext +import xyz.block.trailblaze.toolcalls.TrailblazeToolResult + +/** + * `wait` lowers to a Maestro `WaitForAnimationToEnd`, whose timeout is a CEILING — the driver + * returns as soon as the UI is event-quiet. The tool nevertheless reported + * `"Waited $timeToWaitInSeconds seconds"` unconditionally, so an author reading the log saw a + * duration that was never spent (#5279). + * + * The fake driver below settles far faster than the requested ceiling, which is what makes these + * tests discriminating: the old hardcoded message passes any "did it succeed" assertion, and + * fails these. + */ +class WaitForIdleSyncTrailblazeToolTest { + + private val settleMs = 50L + private val ceilingSeconds = 30 + + /** Returns after [settleMs], mimicking a driver that finds the UI already quiet. */ + private class FastSettlingAgent(private val settleMs: Long) : MaestroTrailblazeAgent( + trailblazeLogger = TrailblazeLogger.createNoOp(), + trailblazeDeviceInfoProvider = { deviceInfo() }, + sessionProvider = TrailblazeSessionProvider { + TrailblazeSession(sessionId = SessionId("test-session"), startTime = Clock.System.now()) + }, + ) { + override suspend fun executeMaestroCommands( + commands: List, + traceId: TraceId?, + ): TrailblazeToolResult { + delay(settleMs) + return TrailblazeToolResult.Success() + } + } + + @Test + fun `success message reports the real settle, not the requested ceiling`() { + val result = runWait() + val message = (result as TrailblazeToolResult.Success).message.orEmpty() + + val reportedMs = Regex("^Settled after (\\d+)ms").find(message)?.groupValues?.get(1)?.toLong() + ?: error("message did not report a measured settle in the documented shape: $message") + + // The driver settled in ~50ms against a 30s ceiling. A message derived from the ceiling + // would report 30000; a measured one reports something far smaller. + assertTrue(reportedMs >= settleMs, "reported ${reportedMs}ms is below the ${settleMs}ms the driver took") + assertTrue( + reportedMs < ceilingSeconds * 1000L, + "reported ${reportedMs}ms equals or exceeds the ${ceilingSeconds}s ceiling — the message is still the requested duration, not the measured one", + ) + } + + @Test + fun `message does not claim the requested duration was waited`() { + val message = (runWait() as TrailblazeToolResult.Success).message.orEmpty() + // Pins the specific false string this change removed. + assertTrue( + !message.contains("Waited $ceilingSeconds seconds"), + "message still claims the full requested duration was waited: $message", + ) + } + + private fun runWait(): TrailblazeToolResult { + val agent = FastSettlingAgent(settleMs) + return runBlocking { + WaitForIdleSyncTrailblazeTool(timeToWaitInSeconds = ceilingSeconds).execute(context(agent)) + } + } + + private fun context(agent: MaestroTrailblazeAgent) = TrailblazeToolExecutionContext( + screenState = null, + traceId = null, + trailblazeDeviceInfo = deviceInfo(), + sessionProvider = TrailblazeSessionProvider { + TrailblazeSession(sessionId = SessionId("test-session"), startTime = Clock.System.now()) + }, + trailblazeLogger = TrailblazeLogger.createNoOp(), + memory = AgentMemory(), + maestroTrailblazeAgent = agent, + ) + + private companion object { + fun deviceInfo() = TrailblazeDeviceInfo( + trailblazeDeviceId = TrailblazeDeviceId( + instanceId = "test-device", + trailblazeDevicePlatform = TrailblazeDevicePlatform.ANDROID, + ), + trailblazeDriverType = TrailblazeDriverType.ANDROID_ONDEVICE_INSTRUMENTATION, + widthPixels = 1080, + heightPixels = 1920, + ) + } +} diff --git a/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/yaml/ToolSerializationTest.kt b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/yaml/ToolSerializationTest.kt index 46caf6022..571248334 100644 --- a/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/yaml/ToolSerializationTest.kt +++ b/trailblaze-common/src/jvmAndAndroidTest/kotlin/xyz/block/trailblaze/yaml/ToolSerializationTest.kt @@ -20,6 +20,7 @@ import xyz.block.trailblaze.toolcalls.commands.LongPressElementWithAccessibility import xyz.block.trailblaze.toolcalls.commands.LongPressOnElementWithTextTrailblazeTool import xyz.block.trailblaze.toolcalls.commands.PressKeyTrailblazeTool import xyz.block.trailblaze.toolcalls.commands.PressKeyTrailblazeTool.PressKeyCode +import xyz.block.trailblaze.toolcalls.commands.SleepTrailblazeTool import xyz.block.trailblaze.toolcalls.commands.SwipeTrailblazeTool import xyz.block.trailblaze.toolcalls.commands.TapOnElementWithAccessiblityTextTrailblazeTool import xyz.block.trailblaze.toolcalls.commands.TapOnElementWithTextTrailblazeTool @@ -685,6 +686,72 @@ trail: ) } + @Test + fun deserializeSleepDefaults() { + val yaml = """ +config: {} +trail: + - step: recorded + recording: + android: + - sleep: {} + """.trimIndent() + + val tools = decodeRecordedTools(yaml) + assertThat(tools.size).isEqualTo(1) + assertThat(tools[0]).isEqualTo( + TrailblazeToolYamlWrapper( + name = "sleep", + trailblazeTool = SleepTrailblazeTool(), + ), + ) + } + + @Test + fun deserializeSleepWithDuration() { + val yaml = """ +config: {} +trail: + - step: recorded + recording: + android: + - sleep: + durationMs: 12000 + """.trimIndent() + + val tools = decodeRecordedTools(yaml) + assertThat(tools.size).isEqualTo(1) + assertThat(tools[0]).isEqualTo( + TrailblazeToolYamlWrapper( + name = "sleep", + trailblazeTool = SleepTrailblazeTool(durationMs = 12000), + ), + ) + } + + @Test + fun sleepRoundTrip() { + val yaml = """ +config: {} +trail: + - step: recorded + recording: + android: + - sleep: + durationMs: 12000 + """.trimIndent() + + val tools = decodeRecordedTools(yaml) + val reDecoded = trailblazeYaml.decodeTools(trailblazeYaml.encodeTools(tools)) + assertThat(reDecoded.size).isEqualTo(1) + assertThat(reDecoded[0]).isEqualTo( + TrailblazeToolYamlWrapper( + name = "sleep", + trailblazeTool = SleepTrailblazeTool(durationMs = 12000), + ), + ) + } + @Test fun deserializeLaunchAppTool() { val yaml = """ diff --git a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/TrailblazeHostYamlRunner.kt b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/TrailblazeHostYamlRunner.kt index 010777389..11d0c7057 100644 --- a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/TrailblazeHostYamlRunner.kt +++ b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/TrailblazeHostYamlRunner.kt @@ -962,7 +962,6 @@ object TrailblazeHostYamlRunner { trailblazeYaml = trailblazeYaml, trailItems = trailItems, trailName = trailConfig?.title ?: runYamlRequest.trailFilePath, - trailUrl = trailConfig?.metadata?.get("testRailUrl"), ) for (item in trailItems) { @@ -1293,7 +1292,6 @@ object TrailblazeHostYamlRunner { trailblazeYaml = trailblazeYaml, trailItems = trailItems, trailName = trailConfig?.title ?: runYamlRequest.trailFilePath, - trailUrl = trailConfig?.metadata?.get("testRailUrl"), ) for (item in trailItems) { @@ -2329,7 +2327,6 @@ object TrailblazeHostYamlRunner { trailblazeYaml = trailblazeYaml, trailItems = trailItems, trailName = trailConfig?.title ?: runYamlRequest.trailFilePath, - trailUrl = trailConfig?.metadata?.get("testRailUrl"), ) // Fire the session-started callback BEFORE dispatching trail items but AFTER @@ -2484,13 +2481,11 @@ object TrailblazeHostYamlRunner { trailblazeYaml: xyz.block.trailblaze.yaml.TrailblazeYaml, trailItems: List, trailName: String?, - trailUrl: String?, ) { if (!trailblazeYaml.hasActionableSteps(trailItems)) { throw TrailblazeException( "Trail '${trailName ?: "unknown"}' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } } diff --git a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseComposeTest.kt b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseComposeTest.kt index 73e42fb2e..aafc1e616 100644 --- a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseComposeTest.kt +++ b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseComposeTest.kt @@ -207,11 +207,9 @@ class BaseComposeTest( if (!trailblazeYaml.hasActionableSteps(trailItems)) { val trailName = trailConfig?.title ?: trailFilePath ?: "unknown" - val trailUrl = trailConfig?.metadata?.get("testRailUrl") throw TrailblazeException( "Trail '$trailName' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } diff --git a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseHostTrailblazeTest.kt b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseHostTrailblazeTest.kt index db086b28d..370a44245 100644 --- a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseHostTrailblazeTest.kt +++ b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BaseHostTrailblazeTest.kt @@ -797,11 +797,9 @@ abstract class BaseHostTrailblazeTest( } if (!trailblazeYaml.hasActionableSteps(trailItems)) { val trailName = trailConfig?.title ?: trailFilePath ?: "unknown" - val trailUrl = trailConfig?.metadata?.get("testRailUrl") throw xyz.block.trailblaze.exception.TrailblazeException( "Trail '$trailName' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } lastToolResult = runTrail(trailItems, useRecordedSteps) diff --git a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightElectronTest.kt b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightElectronTest.kt index 9f2a75601..ccaab70af 100644 --- a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightElectronTest.kt +++ b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightElectronTest.kt @@ -362,11 +362,9 @@ class BasePlaywrightElectronTest( } if (!trailblazeYaml.hasActionableSteps(trailItems)) { val trailName = trailConfig?.title ?: trailFilePath ?: "unknown" - val trailUrl = trailConfig?.metadata?.get("testRailUrl") throw TrailblazeException( "Trail '$trailName' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } diff --git a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightNativeTest.kt b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightNativeTest.kt index c68151008..276632aee 100644 --- a/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightNativeTest.kt +++ b/trailblaze-host/src/main/java/xyz/block/trailblaze/host/rules/BasePlaywrightNativeTest.kt @@ -422,11 +422,9 @@ open class BasePlaywrightNativeTest( currentToolTraceId = traceId if (!trailblazeYaml.hasActionableSteps(trailItems)) { val trailName = trailConfig?.title ?: trailFilePath ?: "unknown" - val trailUrl = trailConfig?.metadata?.get("testRailUrl") throw xyz.block.trailblaze.exception.TrailblazeException( "Trail '$trailName' has no executable steps — this would be a false positive pass. " + - "Add prompts or tool steps to this trail file." + - (trailUrl?.let { " $it" } ?: ""), + "Add prompts or tool steps to this trail file.", ) } try { diff --git a/trailblaze-models/api/android/trailblaze-models.api b/trailblaze-models/api/android/trailblaze-models.api index 6895850c9..df8d950fe 100644 --- a/trailblaze-models/api/android/trailblaze-models.api +++ b/trailblaze-models/api/android/trailblaze-models.api @@ -11415,6 +11415,7 @@ public final class xyz/block/trailblaze/toolcalls/CoreTools { public static final field PRESS_BACK Ljava/lang/String; public static final field PRESS_KEY Ljava/lang/String; public static final field SCROLL_UNTIL_VISIBLE Ljava/lang/String; + public static final field SLEEP Ljava/lang/String; public static final field STOP_APP Ljava/lang/String; public static final field SWIPE Ljava/lang/String; public static final field TAP Ljava/lang/String; diff --git a/trailblaze-models/api/jvm/trailblaze-models.api b/trailblaze-models/api/jvm/trailblaze-models.api index 3e60c1301..22a527792 100644 --- a/trailblaze-models/api/jvm/trailblaze-models.api +++ b/trailblaze-models/api/jvm/trailblaze-models.api @@ -11431,6 +11431,7 @@ public final class xyz/block/trailblaze/toolcalls/CoreTools { public static final field PRESS_BACK Ljava/lang/String; public static final field PRESS_KEY Ljava/lang/String; public static final field SCROLL_UNTIL_VISIBLE Ljava/lang/String; + public static final field SLEEP Ljava/lang/String; public static final field STOP_APP Ljava/lang/String; public static final field SWIPE Ljava/lang/String; public static final field TAP Ljava/lang/String; diff --git a/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/toolcalls/CoreTools.kt b/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/toolcalls/CoreTools.kt index c2ca788df..badcaf0f1 100644 --- a/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/toolcalls/CoreTools.kt +++ b/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/toolcalls/CoreTools.kt @@ -133,7 +133,9 @@ object CoreTools { // ========================================================================= /** - * Wait for a specified duration. + * Settle until the UI goes quiet, bounded by a caller-supplied ceiling. Returns as soon as the + * UI is idle, so on a static screen it returns in ~150ms rather than the full duration. Use + * [SLEEP] when wall-clock time genuinely has to elapse. */ const val WAIT = "wait" @@ -143,6 +145,12 @@ object CoreTools { */ const val WAIT_FOR_CHANGE = "waitForChange" + /** + * Block for a fixed wall-clock duration, never returning early. The one tool that actually + * consumes the time it is asked for — unlike [WAIT] / [WAIT_FOR_CHANGE], which are settles. + */ + const val SLEEP = "sleep" + /** * Control network connectivity. */ diff --git a/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolution.kt b/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolution.kt index 3d9fd7a6b..c27a20898 100644 --- a/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolution.kt +++ b/trailblaze-models/src/commonMain/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolution.kt @@ -44,20 +44,37 @@ data class RecordingResolution( val toolCount: Int? get() = toolNames?.size /** - * `true` when this step replays a conditional wrapper, so its inner tools re-evaluate their - * condition on every run instead of firing blind. + * `true` when this step replays at least one tool that re-evaluates its condition on every run + * instead of firing blind. * * A conditional NL step does NOT automatically produce one: the recorder captures the concrete * path it happened to take, unguarded, and `block_runIf` is `surfaceToLlm: false`, so the agent * can't choose it either. A step whose text describes a condition but whose recording has no * guard has silently become unconditional. + * + * Deliberately `any`, not `all`: a step that mixes a guard with a blind tap still has the blind + * tap. This answers "does this step re-evaluate anything", not "is every tool in it guarded". */ val isConditionallyGuarded: Boolean get() = toolNames?.any { it in CONDITIONAL_TOOL_NAMES } == true companion object { - /** Recorded wrappers that re-evaluate a condition at replay time. */ - val CONDITIONAL_TOOL_NAMES = setOf("block_runIf", "runIf") + /** + * Recorded tools that re-evaluate their condition at replay time, in either of the two shapes + * that exist: a **wrapper** that gates inner recorded tools (`block_runIf`), and a + * **self-guarding** tool that probes and no-ops when its target is absent + * (`block_dismissIfPresent`). Both mean the step doesn't fire blind, which is the only property + * [isConditionallyGuarded] and [TrailRecordingResolution.lostGuardsVersus] depend on — so + * limiting this to wrappers would report a device that used the self-guarding form as having + * lost a guard it never lost. + * + * **A floor, not a complete set.** Membership is by name, and this list only names framework + * tools — a target's own self-guarding tools cannot be enumerated here even when they meet the + * criterion above. Read a `false` [isConditionallyGuarded] as "no *enumerated* guard", and any + * conditional count derived from it as a lower bound. Making this complete needs the property to + * travel as tool metadata rather than a name list; see #5269. + */ + val CONDITIONAL_TOOL_NAMES = setOf("block_runIf", "runIf", "block_dismissIfPresent") } } @@ -107,6 +124,16 @@ data class TrailRecordingResolution( * imperatively, and missed a quarter of the steps that are provably conditional. A sibling * device's own recording is evidence instead of a guess. * + * **Read this as an upper bound, not a defect count.** A sibling's guard proves the step is + * *conditional*; it does not prove this device is *missing* a guard. Two legitimate shapes land + * here: a per-device flow difference that moves the guard to an adjacent step, and a dialog that + * only exists on one platform (an iOS-only promo, a tablet-only side menu), where the other + * devices correctly have no guard because the dialog never appears. Both are topologically + * indistinguishable from a dropped guard — the discriminating information is the step's intent, + * not the shape of the recordings. Every candidate examined so far turned out to be legitimate + * divergence rather than a defect. Use this to *list* candidates for a human to read; do not + * gate on it. + * * @param siblings the same trail's resolution for other devices. */ fun lostGuardsVersus(siblings: List): List { @@ -115,25 +142,49 @@ data class TrailRecordingResolution( .flatMap { sibling -> sibling.conditionallyGuarded.map { it.stepIndex } } .toSet() return steps.filter { - it.resolvedClassifier != null && !it.isConditionallyGuarded && it.stepIndex in guardedElsewhere + // A matched-EMPTY recording replays nothing, so it has no guard to have lost. Including it + // would be the same null/empty conflation this file exists to prevent, one level up. + it.toolNames?.isNotEmpty() == true && + !it.isConditionallyGuarded && + it.stepIndex in guardedElsewhere } } /** * One-line census for a log or report column. Named counts rather than a bare total, because the * total is the number that hid all four shapes in the first place. + * + * The outcome counts **partition** the steps — each step lands in exactly one of exact / + * family-alias / zero-tool no-op / unmatched / never-recorded, so they sum to the step total. They + * used to overlap: a matched-empty exact key was counted as both `exact` and `zero-tool no-op`, so + * a 5-step trail printed 6 labels and anyone adding up the line got a wrong number. `conditional` + * is reported separately in parentheses because it is a property *of* the matched steps, not a + * sixth bucket. + * + * The step total counts `trail:` steps only; the trailhead is called out by name so the count + * lines up with the step numbering every other artifact uses. */ fun summarize(): String = buildString { - append("${steps.size} step(s)") - val exact = steps.count { it.resolvedClassifier != null && it.resolvedClassifier == deviceClassifier } + append("${steps.count { it.stepIndex != null }} step(s)") + if (steps.any { it.stepIndex == null }) append(" + trailhead") + val exact = + steps.count { + // The null guard matters for an empty classifier list, where deviceClassifier is also null + // and an unmatched step would otherwise read as an exact match. + it.resolvedClassifier != null && + it.resolvedClassifier == deviceClassifier && + it.toolCount != 0 + } if (exact > 0) append(", $exact exact") - familyAliased.groupingBy { it.resolvedClassifier }.eachCount().forEach { (key, n) -> - append(", $n via family alias '$key'") - } + familyAliased + .filter { it.toolCount != 0 } + .groupingBy { it.resolvedClassifier } + .eachCount() + .forEach { (key, n) -> append(", $n via family alias '$key'") } if (deterministicNoOps.isNotEmpty()) append(", ${deterministicNoOps.size} zero-tool no-op") - if (conditionallyGuarded.isNotEmpty()) append(", ${conditionallyGuarded.size} conditional") if (unresolvedDeclared.isNotEmpty()) append(", ${unresolvedDeclared.size} unmatched -> LLM") val never = steps.count { it.declaredClassifiers.isEmpty() } if (never > 0) append(", $never never recorded") + if (conditionallyGuarded.isNotEmpty()) append(" (${conditionallyGuarded.size} conditional)") } } diff --git a/trailblaze-models/src/commonMain/resources/trails/config/trailmaps/trailblaze/toolsets/core_interaction.yaml b/trailblaze-models/src/commonMain/resources/trails/config/trailmaps/trailblaze/toolsets/core_interaction.yaml index b80625f3f..4a8386ab0 100644 --- a/trailblaze-models/src/commonMain/resources/trails/config/trailmaps/trailblaze/toolsets/core_interaction.yaml +++ b/trailblaze-models/src/commonMain/resources/trails/config/trailmaps/trailblaze/toolsets/core_interaction.yaml @@ -26,6 +26,7 @@ tools: - pressKey - scrollUntilTextIsVisible - mobile_setClipboard + - sleep - swipe - takeSnapshot - tap diff --git a/trailblaze-models/src/jvmTest/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolutionTest.kt b/trailblaze-models/src/jvmTest/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolutionTest.kt index 939f151b2..924698e64 100644 --- a/trailblaze-models/src/jvmTest/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolutionTest.kt +++ b/trailblaze-models/src/jvmTest/kotlin/xyz/block/trailblaze/yaml/unified/RecordingResolutionTest.kt @@ -34,6 +34,17 @@ class RecordingResolutionTest { ), ) + /** + * The same four outcomes plus a trailhead, which lowers through its own path + * ([TrailheadDefinition.tools], not [DirectionStep.recording]). Its `block_runIf` also makes it the + * fixture where a conditional is present. + */ + private val fourFacesWithTrailhead = + fourFaces.copy( + trailhead = + UnifiedTrailStep(step = "boot", recordings = mapOf("android" to listOf(tool("block_runIf")))) + ) + @Test fun `each of the four outcomes is distinguishable`() { val r = UnifiedTrailAdapter.describeRecordingResolution(fourFaces, androidPhone) @@ -110,40 +121,92 @@ class RecordingResolutionTest { // Counts, not wording — the wording is a log line, the counts are the contract. assertTrue(summary.contains("5 step"), summary) - assertTrue(summary.contains("2 exact"), summary) + assertTrue(summary.contains("1 exact"), summary) assertTrue(summary.contains("1 via family alias 'android'"), summary) assertTrue(summary.contains("1 zero-tool no-op"), summary) assertTrue(summary.contains("1 unmatched"), summary) assertTrue(summary.contains("1 never recorded"), summary) } + @Test + fun `the summary's outcome counts partition the steps`() { + // The census is only readable if the buckets sum to what the line says it counted. They didn't: + // a matched-empty exact key counted as both `exact` and `zero-tool no-op`, so this 5-step trail + // printed 6 labels. Summing the numbers out of the rendered line is what a reader does, so the + // test does the same rather than re-deriving from the model. + // Both fixtures matter: the trailhead one also carries a conditional, which must NOT read as a + // sixth bucket. + for (unified in listOf(fourFaces, fourFacesWithTrailhead)) { + val summary = UnifiedTrailAdapter.describeRecordingResolution(unified, androidPhone).summarize() + + val trailSteps = Regex("""^(\d+) step""").find(summary)!!.groupValues[1].toInt() + val counted = trailSteps + if (summary.contains("+ trailhead")) 1 else 0 + // Buckets are comma-separated; the `conditional` sub-count is parenthesised precisely so it + // isn't one of them. + val buckets = Regex(""", (\d+) """).findAll(summary).map { it.groupValues[1].toInt() }.toList() + + assertEquals(5, trailSteps, summary) + assertEquals(counted, buckets.sum(), "outcome buckets must sum to what the line counted: $summary") + } + } + + @Test + fun `the summary counts trail steps and names the trailhead separately`() { + // steps.size includes the trailhead, but every other artifact numbers steps from `trail:` — a + // trail with 5 steps plus a trailhead reading "6 step(s)" makes the log disagree with the + // numbering a reader is holding. + val withTrailhead = + UnifiedTrailAdapter.describeRecordingResolution(fourFacesWithTrailhead, androidPhone) + .summarize() + val without = + UnifiedTrailAdapter.describeRecordingResolution(fourFaces, androidPhone).summarize() + + assertTrue(withTrailhead.startsWith("5 step(s) + trailhead"), withTrailhead) + assertTrue(without.startsWith("5 step(s),"), without) + assertTrue(withTrailhead.contains("(1 conditional)"), withTrailhead) + } + @Test fun `the description agrees with what the executor actually does`() { // The property that makes this reportable: for every step, "described as matched" must equal // "lowered with a non-null recording", and any disagreement with hasRecordingForDevice would // mean the report and the runtime had two different opinions about the same trail. This is the // parallel-implementation failure mode, asserted away. - for (device in listOf(androidPhone, androidTablet, iosIphone)) { - val described = UnifiedTrailAdapter.describeRecordingResolution(fourFaces, device) - val lowered = UnifiedTrailAdapter.lowerToTrailItems(fourFaces, device) - .filterIsInstance() - .single().promptSteps.map { (it as DirectionStep).recording } - - assertEquals( - lowered.map { it != null }, - described.steps.map { it.resolvedClassifier != null }, - "described match must equal lowered recording presence for $device", - ) - assertEquals( - lowered.map { it?.tools?.size }, - described.steps.map { it.toolCount }, - "described toolCount must equal the tools actually lowered for $device", - ) - assertEquals( - described.steps.any { it.resolvedClassifier != null }, - UnifiedTrailAdapter.hasRecordingForDevice(fourFaces, device), - "description and the requireRecordings gate must not disagree for $device", - ) + // + // Run over the trailhead-bearing fixture too. The trailhead lowers through TrailheadDefinition + // .tools rather than DirectionStep.recording, so it is a second implementation of the same + // null-vs-empty decision — and it is the step whose silent guard loss the class doc calls the + // worst case. They share resolveClosestKey today; an `.orEmpty()` on either path would break the + // agreement for exactly one of them. + for (unified in listOf(fourFaces, fourFacesWithTrailhead)) { + for (device in listOf(androidPhone, androidTablet, iosIphone)) { + val described = UnifiedTrailAdapter.describeRecordingResolution(unified, device) + val lowered = UnifiedTrailAdapter.lowerToTrailItems(unified, device) + // Trailhead first, then the prompt steps — the same order describeRecordingResolution emits. + val loweredTools = + lowered.filterIsInstance().map { it.trailhead.tools } + + lowered + .filterIsInstance() + .single() + .promptSteps + .map { (it as DirectionStep).recording?.tools } + + assertEquals( + loweredTools.map { it != null }, + described.steps.map { it.resolvedClassifier != null }, + "described match must equal lowered recording presence for $device", + ) + assertEquals( + loweredTools.map { it?.size }, + described.steps.map { it.toolCount }, + "described toolCount must equal the tools actually lowered for $device", + ) + assertEquals( + described.steps.any { it.resolvedClassifier != null }, + UnifiedTrailAdapter.hasRecordingForDevice(unified, device), + "description and the requireRecordings gate must not disagree for $device", + ) + } } } @@ -189,6 +252,55 @@ class RecordingResolutionTest { assertTrue(tablet.lostGuardsVersus(listOf(phone)).isEmpty(), "the guarded device has lost nothing") } + @Test + fun `a matched-empty step is not reported as a lost guard`() { + // A zero-tool no-op replays nothing, so there is no guard for it to have lost. Found by + // reconciling two independent counts over the same trails: including these over-reported the + // device cells, and the whole residual disagreement between the two counts WAS those cells — + // the null/empty conflation this file exists to prevent, one level up. + val unified = UnifiedTrail( + config = UnifiedTrailConfig(id = "x", target = "y"), + trail = listOf( + UnifiedTrailStep( + step = "Dismiss the popup if it is visible", + recordings = mapOf( + "android-tablet" to listOf(tool("block_runIf")), + "android-phone" to emptyList(), + ), + ), + ), + ) + val tablet = UnifiedTrailAdapter.describeRecordingResolution(unified, androidTablet) + val phone = UnifiedTrailAdapter.describeRecordingResolution(unified, androidPhone) + + assertEquals("android-phone", phone.steps.single().resolvedClassifier, "it did match, with zero tools") + assertTrue(phone.lostGuardsVersus(listOf(tablet)).isEmpty(), "a no-op has no guard to lose") + } + + @Test + fun `a self-guarding tool counts as conditional, not as a lost guard`() { + // block_dismissIfPresent probes for its dialog and no-ops when absent, so a device recorded with + // it never fires blind — it just spells the condition differently than the block_runIf wrapper. + // Treating only wrappers as conditional would report this device as having lost a guard it has. + val unified = UnifiedTrail( + config = UnifiedTrailConfig(id = "x", target = "y"), + trail = listOf( + UnifiedTrailStep( + step = "Dismiss the Updates to Orders pop up if it is visible", + recordings = mapOf( + "android-tablet" to listOf(tool("block_runIf")), + "android-phone" to listOf(tool("block_dismissIfPresent")), + ), + ), + ), + ) + val tablet = UnifiedTrailAdapter.describeRecordingResolution(unified, androidTablet) + val phone = UnifiedTrailAdapter.describeRecordingResolution(unified, androidPhone) + + assertTrue(phone.steps.single().isConditionallyGuarded, "it re-evaluates at replay") + assertTrue(phone.lostGuardsVersus(listOf(tablet)).isEmpty()) + } + @Test fun `an unmatched step is not reported as a lost guard`() { // A step with no recording on this device runs via the LLM, which branches natively — it has no diff --git a/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-core.test.ts b/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-core.test.ts index 0d836f48e..448845dde 100644 --- a/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-core.test.ts +++ b/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-core.test.ts @@ -472,6 +472,214 @@ describe("extractTrace", () => { expect(last.screenshotFile).toBe("final.png"); expect(String(last.label)).toContain("Final"); }); + + test("surfaces the tool calls the traceId fold merged in as children", () => { + // A traceId is allocated per LLM request (one turn's tool batch), not per tool call, so a turn's + // whole batch shares one traceId and folds onto its first tool. Without children, the other calls + // are absent from the payload entirely and the fold increments no count to reveal it. + const tool = (name: string, raw: Record, s: number) => ({ + class: `${T}.TrailblazeToolLog`, toolName: name, traceId: "obj8", successful: true, + durationMs: 10, trailblazeTool: { raw }, timestamp: `2024-01-01T00:00:0${s}Z`, + }); + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Edit the end time" }, timestamp: "2024-01-01T00:00:00Z" }, + tool("assertVisibleBySelector", { selector: { text: "End time" } }, 1), + { class: `${T}.MaestroDriverLog`, traceId: "obj8", action: { class: "xyz.AgentDriverAction.TapPoint", x: 1, y: 2 }, deviceWidth: 10, deviceHeight: 20, timestamp: "2024-01-01T00:00:02Z" }, + tool("tapOnElementBySelector", { selector: { text: "End time" } }, 3), + tool("swipe", { swipeOnElementText: "00 minutes" }, 4), + tool("mobile_maestro", { commands: "tapOn 50%,91%" }, 5), + ]; + const trace = core.extractTrace(logs); + // Still one folded row per traceId — this fix adds detail, it does not split the row. + const row = trace.find((r) => r.label === "assertVisibleBySelector"); + expect(trace.filter((r) => !r.objective).length).toBe(1); + // The three calls that actually did the work are now followable. + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["tapOnElementBySelector", "swipe", "mobile_maestro"]); + // Device actions stay folded: the row already names the action, so they are not children. + expect((row.children as unknown[]).length).toBe(3); + // And they survive the share slimming — the standalone report renders from the slimmed shape. + const slim = (core as any).slimTraceForShare(trace); + expect(slim.find((r: any) => r.label === "assertVisibleBySelector").children.map((c: any) => c.label)) + .toEqual(["tapOnElementBySelector", "swipe", "mobile_maestro"]); + }); + + test("a delegating tool's executor is one child, not one per source", () => { + // On-device instrumentation logs the DelegatingTrailblazeToolLog and, under the same traceId, + // the executor's own TrailblazeToolLog (TrailCommand.kt:1836) — so it arrives twice. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Tap the row" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tapOnElementWithNodeId", traceId: "objD", + trailblazeTool: { toolName: "tapOnElementWithNodeId", raw: { nodeId: 7 } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Row" } } }], + timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.TrailblazeToolLog`, toolName: "tapOnElementBySelector", traceId: "objD", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "Row" } } }, timestamp: "2024-01-01T00:00:02Z", + }, + { + class: `${T}.TrailblazeToolLog`, toolName: "swipe", traceId: "objD", successful: true, + durationMs: 10, trailblazeTool: { raw: { swipeOnElementText: "list" } }, timestamp: "2024-01-01T00:00:03Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "tapOnElementWithNodeId"); + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["tapOnElementBySelector", "swipe"]); + }); + + test("a delegating wrapper folded mid-objective is not a child alongside its executor", () => { + // The wrapper can arrive at any position in the batch, not just first. It is a dispatch record, + // not a step — SessionCombinedView.kt:893 and TrailblazeRecordingGenerator.kt:211 both skip it. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Check then tap" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.TrailblazeToolLog`, toolName: "assertVisibleBySelector", traceId: "objM", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "Row" } } }, timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tapOnElementWithNodeId", traceId: "objM", + trailblazeTool: { toolName: "tapOnElementWithNodeId", raw: { nodeId: 7 } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Row" } } }], + timestamp: "2024-01-01T00:00:02Z", + }, + { + class: `${T}.TrailblazeToolLog`, toolName: "tapOnElementBySelector", traceId: "objM", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "Row" } } }, timestamp: "2024-01-01T00:00:03Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "assertVisibleBySelector"); + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["tapOnElementBySelector"]); + }); + + test("a delegating tool whose executor never logged still shows what it dispatched", () => { + // The fallback that keeps the dedupe from hiding work: some tools route around the device's + // tool-log emit site (HostOnDeviceRpcTrailblazeAgent.kt:743), so only the declaration exists. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Tap by ref" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.TrailblazeToolLog`, toolName: "assertVisibleBySelector", traceId: "objF", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "Row" } } }, timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tap", traceId: "objF", + trailblazeTool: { toolName: "tap", raw: { ref: "z639" } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Row" } } }], + timestamp: "2024-01-01T00:00:02Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "assertVisibleBySelector"); + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["tapOnElementBySelector"]); + }); + + test("repeated polls keep their ×N count instead of becoming N children", () => { + // The assertion fold already annotates the row, so expanding it would trade a readable count + // for noise. Only the silent tool-into-tool fold gets children. + const poll = (s: number) => ({ + class: `${T}.MaestroDriverLog`, durationMs: 5, deviceWidth: 10, deviceHeight: 20, + action: { class: "xyz.AgentDriverAction.AssertCondition", conditionDescription: "shows 5:00 PM", succeeded: true, x: 1, y: 1 }, + timestamp: `2024-01-01T00:00:${String(s).padStart(2, "0")}Z`, + }); + const trace = core.extractTrace([poll(1), poll(2), poll(3)]); + expect(trace.length).toBe(1); + expect(trace[0].note).toBe("×3"); + expect(trace[0].children).toBeUndefined(); + }); + + test("an MCP tool's response log is not a child of itself", () => { + // McpToolCallRequestLog / McpToolCallResponseLog share one traceId and the same toolName + // (TrailblazeMcpServer.kt:1615), so folding on "anything with a toolName" would nest the row's + // own tool under itself. Only a TrailblazeToolLog is an executed child. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Connect the device" }, timestamp: "2024-01-01T00:00:00Z" }, + { class: `${T}.McpToolCallRequestLog`, toolName: "trailblaze_connect_device", traceId: "mcp1", timestamp: "2024-01-01T00:00:01Z" }, + { class: `${T}.McpToolCallResponseLog`, toolName: "trailblaze_connect_device", traceId: "mcp1", timestamp: "2024-01-01T00:00:02Z" }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "trailblaze_connect_device"); + expect(row).toBeDefined(); + expect(row.children).toBeUndefined(); + }); + + test("a repeated primitive with one unlogged dispatch still shows the dispatched call", () => { + // One tapOnElementBySelector logged its executor; a second (different selector) was dispatched + // via a delegating wrapper whose executor never logged. A name-only dedupe drops the second as + // "already ran"; matching on name AND args keeps it, so the dispatched-but-unlogged call shows. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Tap two rows" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.TrailblazeToolLog`, toolName: "assertVisibleBySelector", traceId: "objP", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "Header" } } }, timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.TrailblazeToolLog`, toolName: "tapOnElementBySelector", traceId: "objP", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "First" } } }, timestamp: "2024-01-01T00:00:02Z", + }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tap", traceId: "objP", + trailblazeTool: { toolName: "tap", raw: { ref: "z2" } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Second" } } }], + timestamp: "2024-01-01T00:00:03Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "assertVisibleBySelector"); + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["tapOnElementBySelector", "tapOnElementBySelector"]); + // The args distinguish them: both dispatches survive, not just the one that logged. + expect((row.children as Array>).map((c) => c.tool)) + .toEqual(["text: First", "text: Second"]); + }); + + test("children render in dispatch order, not declarations-first", () => { + // swipe ran and logged first; a later delegating wrapper dispatched tapOnElementBySelector whose + // executor never logged. Concatenating declarations ahead of executions would list the tap first + // even though the swipe happened first — order children by log position instead. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Swipe then tap by ref" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.TrailblazeToolLog`, toolName: "assertVisibleBySelector", traceId: "objO", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "List" } } }, timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.TrailblazeToolLog`, toolName: "swipe", traceId: "objO", successful: true, + durationMs: 10, trailblazeTool: { raw: { swipeOnElementText: "list" } }, timestamp: "2024-01-01T00:00:02Z", + }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tap", traceId: "objO", + trailblazeTool: { toolName: "tap", raw: { ref: "z3" } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Row" } } }], + timestamp: "2024-01-01T00:00:03Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "assertVisibleBySelector"); + expect((row.children as Array>).map((c) => c.label)) + .toEqual(["swipe", "tapOnElementBySelector"]); + }); + + test("a ref dispatch that reuses the row's own primitive name is not filtered as self", () => { + // logs[0] is a directly-invoked tapOnElementBySelector, so it labels the row. A later ref-based + // tap resolves to the same primitive with a DIFFERENT selector and its executor never logged. + // Filtering every declaration named like the row would drop this genuine second call; the + // self-filter must key on the row's own name AND args, not the name alone. + const logs = [ + { class: `${T}.ObjectiveStartLog`, promptStep: { step: "Tap one directly, one by ref" }, timestamp: "2024-01-01T00:00:00Z" }, + { + class: `${T}.TrailblazeToolLog`, toolName: "tapOnElementBySelector", traceId: "objS", successful: true, + durationMs: 10, trailblazeTool: { raw: { selector: { text: "First" } } }, timestamp: "2024-01-01T00:00:01Z", + }, + { + class: `${T}.DelegatingTrailblazeToolLog`, toolName: "tap", traceId: "objS", + trailblazeTool: { toolName: "tap", raw: { ref: "z9" } }, + executableTools: [{ toolName: "tapOnElementBySelector", raw: { selector: { text: "Second" } } }], + timestamp: "2024-01-01T00:00:02Z", + }, + ]; + const row = core.extractTrace(logs).find((r) => r.label === "tapOnElementBySelector"); + expect((row.children as Array>).map((c) => c.label)).toEqual(["tapOnElementBySelector"]); + expect((row.children as Array>).map((c) => c.tool)).toEqual(["text: Second"]); + }); }); describe("shotForStep (timeline preview image)", () => { diff --git a/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-extract.ts b/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-extract.ts index 234f2fc1d..77139e72e 100644 --- a/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-extract.ts +++ b/trailblaze-report/src/main/resources/xyz/block/trailblaze/trailrunner/web/app/run-report-extract.ts @@ -218,20 +218,47 @@ function extractTrace(logs: TrailblazeLogRecord[]): RawTraceRow[] { }); } -// The sub-tools an outer tool delegated to. A high-level tool the agent calls (e.g. -// `tap` on a ref) is logged as a DelegatingTrailblazeToolLog carrying `executableTools` -// — the concrete executor tool(s) it expanded into (e.g. `tapOnElementBySelector` with a -// resolved selector). They share the outer tool's traceId, so they're already folded into -// this one row; we surface them as expandable children so the "this tool ran those tools" -// hierarchy is visible. Returns null when the row didn't delegate to a distinct inner tool -// (primitives, scripted host-side tools that call backend APIs directly, raw actions). +// Every tool call this row stands for besides the one it is labelled with, from two sources: +// the `executableTools` a DelegatingTrailblazeToolLog expanded into (e.g. `tap` on a ref +// resolving to `tapOnElementBySelector`), and the sibling tool logs the traceId fold merged in. +// Both are already collapsed into this single row, so surfacing them as expandable children is +// what makes "this step ran those tools" followable. Returns null for a row that really did stand +// for one tool (primitives, scripted host-side tools calling backend APIs directly, raw actions). function toolChildren(r: any): TraceChild[] | null { - const first = r._logs && r._logs[0]; - const exec = first && Array.isArray(first.executableTools) ? first.executableTools : null; - if (!exec || !exec.length) return null; - const kids = exec - .map((e) => ({ label: e.toolName || '', tool: summarizeToolArgs((e && e.raw) || {}, {}) })) - .filter((c) => c.label && c.label !== r.label); + const logs: any[] = r._logs || []; + const isDelegating = (l: any) => logClass(l) === 'DelegatingTrailblazeToolLog'; + // A traceId is allocated per LLM request (one turn's tool batch), not per objective, so an + // objective spanning several turns folds into several of these rows — each row is one turn. + // Only a TrailblazeToolLog is an executed tool: MCP request/response and agent-iteration logs + // share the row's id and name, so keying off "anything with a toolName" nests the row under itself. + const isExecuted = (l: any) => logClass(l) === 'TrailblazeToolLog'; + const executed = logs + .map((l, i) => ({ l, i })) + .filter(({ l, i }) => i > 0 && l && isExecuted(l)) + .map(({ l, i }) => ({ i, label: String(l.toolName), tool: toolDetail(l).summary })); + // A delegating log is a dispatch wrapper, not a step: it declares executors the device then logs + // itself under the same traceId. Keep executed records; surface a declaration only to fill in an + // executor that never logged — matched to its executor by name AND args (not name alone) and by + // remaining count, so a repeated primitive with one unlogged dispatch still shows the missing call. + const key = (c: { label: string; tool: string }) => JSON.stringify([c.label, c.tool]); + const unmatched = new Map(); + // Seed logs[0]'s own identity (excluded from `executed` by the i>0 filter) so only a wrapper + // re-declaring exactly it is absorbed — a separate same-named dispatch with other args still shows. + unmatched.set(key(r), (unmatched.get(key(r)) || 0) + 1); + for (const c of executed) unmatched.set(key(c), (unmatched.get(key(c)) || 0) + 1); + const declared: Array<{ i: number; label: string; tool: string }> = []; + logs.forEach((l, i) => { + if (!isDelegating(l)) return; + for (const e of (Array.isArray(l.executableTools) ? l.executableTools : [])) { + const c = { i, label: (e && e.toolName) || '', tool: summarizeToolArgs((e && e.raw) || {}, {}) }; + if (!c.label) continue; + const n = unmatched.get(key(c)) || 0; + if (n > 0) { unmatched.set(key(c), n - 1); continue; } + declared.push(c); + } + }); + // Order by log position so children read in dispatch order, not declarations-first. + const kids = [...executed, ...declared].sort((a, b) => a.i - b.i).map((c) => ({ label: c.label, tool: c.tool })); return kids.length ? kids : null; }