From 69002b07b11a93e3dd0f0d72fc9f968d658aa6a9 Mon Sep 17 00:00:00 2001 From: pjay Date: Sat, 18 Apr 2026 18:48:25 +0700 Subject: [PATCH] fix(runner,sample-app): surface silent errors and demo a failing property (#15) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * fix(runner): surface non-deadline WaitForIdle errors Previously the WaitForIdle return value was discarded entirely, hiding real driver failures (gRPC transport errors, sidecar crashes) behind the expected deadline-exceeded case. Log non-deadline errors so they are visible without changing control flow. * chore(sample-app): drop unused uptime_millis extractor Registered in SampleApplication but never consumed by spec.ts. * fix(sample-app): drop trivial appIsRunning property app_state was hardcoded to 'running' so the property was a tautology that could never fail. Removing both the extractor and the property is the simplest fix; demo-grade properties that can fail land next. * feat(sample-app): add Reset button that zeroes clickCount Pairs with the next commit's tap-reset action so the fuzzer can violate clickCountNeverDecreases and demonstrate uatu actually finding a property violation. * feat(sample-app): add tap-reset action to exercise Reset button Weighted at 10/122, fuzzer reaches it within a short run. Pairs with the Reset button to demonstrate uatu detecting the clickCountNeverDecreases violation. * fix(runner): filter WaitForIdle errors via context state, not errors.Is errors.Is(err, context.DeadlineExceeded) misses gRPC's wrapped status.DeadlineExceeded, so every step under the maestro driver logged a spurious warning. Check idleCtx.Err() instead — captures both deadline-fired and parent-canceled cases regardless of how the driver wraps them. * chore(sample-app): tune action weights so demo violates in ~30s Prior weights left tap-reset rare enough that short demo runs missed the violation by chance. Bumped to 30/107, with typeUsername reduced since username noise doesn't help exercise clickCount. * refactor(runner): route warnings through slog Adds Options.Logger (defaults to slog.Default()) and converts the three warning sites that were using fmt.Printf. Progress line stays on Printf since it's user-facing UI, not a log. Makes the warnings testable via a capturing handler. * test(runner): assert WaitForIdle driver errors are logged Captures slog output via TextHandler into a buffer and asserts the warning message + injected error text appear when the mock driver returns a non-context error from WaitForIdle. Guards against a regression of the silent-error swallow. --- .../kotlin/dev/uatu/sample/MainActivity.kt | 10 +++++ .../dev/uatu/sample/SampleApplication.kt | 4 -- examples/sample-app/spec.ts | 14 ++++--- internal/runner/runner.go | 15 ++++++-- internal/runner/runner_test.go | 37 +++++++++++++++++++ 5 files changed, 67 insertions(+), 13 deletions(-) diff --git a/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/MainActivity.kt b/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/MainActivity.kt index d59f691..414cddb 100644 --- a/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/MainActivity.kt +++ b/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/MainActivity.kt @@ -47,6 +47,16 @@ class MainActivity : Activity() { } layout.addView(button) + val resetButton = Button(this).apply { + text = "Reset" + textSize = 18f + setOnClickListener { + clickCount = 0 + label.text = "Clicks: $clickCount" + } + } + layout.addView(resetButton) + val usernameLabel = TextView(this).apply { text = "Username: " textSize = 20f diff --git a/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/SampleApplication.kt b/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/SampleApplication.kt index be66cb9..784df4d 100644 --- a/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/SampleApplication.kt +++ b/examples/sample-app/android/src/main/kotlin/dev/uatu/sample/SampleApplication.kt @@ -7,11 +7,7 @@ class SampleApplication : Application() { override fun onCreate() { super.onCreate() Uatu.start(this) - Uatu.extract("app_state") { "running" } Uatu.extract("click_count") { MainActivity.clickCount } Uatu.extract("username") { MainActivity.username } - Uatu.extract("uptime_millis") { System.currentTimeMillis() - startedAt } } - - private val startedAt: Long = System.currentTimeMillis() } diff --git a/examples/sample-app/spec.ts b/examples/sample-app/spec.ts index 52c20af..4da93d8 100644 --- a/examples/sample-app/spec.ts +++ b/examples/sample-app/spec.ts @@ -11,9 +11,6 @@ import { // ── Snapshot extractors (fed by SampleApplication.kt) ────────── // See ./android/src/main/kotlin/dev/uatu/sample/SampleApplication.kt -const appState = extract( - (state) => (state.snapshots.app_state as string) ?? "", -); const clickCount = extract( (state) => (state.snapshots.click_count as number) ?? 0, ); @@ -23,11 +20,11 @@ const username = extract( // ── UI elements ──────────────────────────────────────────────── const clickButton = extract((state) => state.ax.find("text:Click me")); +const resetButton = extract((state) => state.ax.find("text:Reset")); const usernameField = extract((state) => state.ax.find("desc:username_field")); // ── Properties ───────────────────────────────────────────────── export const properties = { - appIsRunning: always(() => appState.current === "running"), clickCountNonNegative: always(() => clickCount.current >= 0), clickCountNeverDecreases: always(() => { const previous = clickCount.previous; @@ -50,10 +47,15 @@ const typeUsername = actions(() => { : []; }); +const tapReset = actions(() => { + return resetButton.current ? [Tap({ on: resetButton.current })] : []; +}); + export const actionsRoot = weighted( [50, tapClickMe], - [50, typeUsername], - [10, taps], + [20, typeUsername], + [30, tapReset], + [5, taps], [2, swipes], ); diff --git a/internal/runner/runner.go b/internal/runner/runner.go index 4da598a..ead0141 100644 --- a/internal/runner/runner.go +++ b/internal/runner/runner.go @@ -5,6 +5,7 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "time" "github.com/priyanshujain/uatu/internal/agent" @@ -24,6 +25,7 @@ type Options struct { Driver driver.Driver Verifier *verifier.Verifier TraceWriter *trace.Writer + Logger *slog.Logger } type Summary struct { @@ -46,6 +48,10 @@ func Run(ctx context.Context, options Options) (Summary, error) { if err := validate(options); err != nil { return Summary{}, err } + logger := options.Logger + if logger == nil { + logger = slog.Default() + } summary := Summary{StartTime: time.Now()} deadline := summary.StartTime.Add(options.Duration) @@ -64,7 +70,7 @@ func Run(ctx context.Context, options Options) (Summary, error) { // a hierarchy that matches the snapshots captured a moment later. tree, hierarchyErr := fetchHierarchy(ctx, options.Driver) if hierarchyErr != nil { - fmt.Printf("warning: step %d hierarchy: %v\n", stepIndex, hierarchyErr) + logger.Warn("hierarchy fetch failed", "step", stepIndex, "err", hierarchyErr) } treeSize := 0 if tree != nil { @@ -81,7 +87,7 @@ func Run(ctx context.Context, options Options) (Summary, error) { } screen, screenErr := screenFromSnapshot(snapshot.Snapshots) if screenErr != nil { - fmt.Printf("warning: step %d screen: %v\n", stepIndex, screenErr) + logger.Warn("screen snapshot decode failed", "step", stepIndex, "err", screenErr) } fmt.Printf("step %d: screen=%q hierarchy=%d nodes\n", stepIndex, screen, treeSize) @@ -126,7 +132,10 @@ func Run(ctx context.Context, options Options) (Summary, error) { } idleCtx, idleCancel := context.WithTimeout(ctx, options.IdleTimeout) - _ = options.Driver.WaitForIdle(idleCtx, options.IdleTimeout) + idleErr := options.Driver.WaitForIdle(idleCtx, options.IdleTimeout) + if idleErr != nil && idleCtx.Err() == nil { + logger.Warn("wait_for_idle failed", "step", stepIndex, "err", idleErr) + } idleCancel() } diff --git a/internal/runner/runner_test.go b/internal/runner/runner_test.go index e5cf9d5..bf00f16 100644 --- a/internal/runner/runner_test.go +++ b/internal/runner/runner_test.go @@ -1,9 +1,11 @@ package runner import ( + "bytes" "context" "encoding/json" "errors" + "log/slog" "net" "os" "path/filepath" @@ -267,6 +269,41 @@ func TestScreenFromSnapshot(t *testing.T) { }) } +func TestRunner_LogsWaitForIdleDriverErrors(t *testing.T) { + snapshots := []map[string]json.RawMessage{ + {"balance": json.RawMessage(`100`)}, + } + state := newHarness(t, snapshots) + state.startSDK(t) + state.acceptConnection(t) + state.mock.Failures[mockdriver.ActionWaitForIdle] = errors.New("sidecar lost gRPC stream") + + var logBuf bytes.Buffer + logger := slog.New(slog.NewTextHandler(&logBuf, &slog.HandlerOptions{Level: slog.LevelWarn})) + + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if _, err := Run(ctx, Options{ + Duration: 100 * time.Millisecond, + SnapshotTimeout: 2 * time.Second, + IdleTimeout: 50 * time.Millisecond, + Connection: state.conn, + Driver: state.mock, + Verifier: state.verifier, + TraceWriter: state.writer, + Logger: logger, + }); err != nil { + t.Fatalf("Run: %v", err) + } + output := logBuf.String() + if !strings.Contains(output, "wait_for_idle failed") { + t.Errorf("expected wait_for_idle warning, got: %q", output) + } + if !strings.Contains(output, "sidecar lost gRPC stream") { + t.Errorf("expected driver error message in warning, got: %q", output) + } +} + func TestApplyAction_InputTextSurfacesFocusTapError(t *testing.T) { t.Run("selector focus tap fails", func(t *testing.T) { driverMock := mockdriver.New()