test+refactor: real sidecar test, deterministic test sleeps, slog step line (#22)

* test(sidecar): replace assertTrue(true) placeholder with real server test

MainTest.mainExists() always passed and inflated the green-check count.
DriverServiceTest covers RPCs, but SidecarServer start/stop had no
coverage. Drop the placeholder and add SidecarServerTest that binds to
port 0, asserts a real ephemeral port, and stops cleanly.

* test(agent): drop 50ms sleep before cancel in TestServer_AcceptCancelsOnContext

Accept's closeListenerOnCancel watcher closes the listener as soon as
ctx fires, regardless of whether the outer Accept has reached
listener.Accept() yet. The sleep was a CI-flake surface (50ms is not
enough on a slow runner), and dropping it still exercises the same
outcome — Accept returns with ctx.Err() after cancellation.

Stable across 50x -count runs.

* test(agent): replace 2s sleep with done-chan in TestConn_SnapshotTimesOutIfSDKSilent

The silent-SDK fake held the connection open via time.Sleep(2s), which
coupled the test's wall clock to the server's 200ms snapshot-timeout
assertion. Swap for a done channel closed by t.Cleanup — the goroutine
exits when the test ends, independent of timing.

* test(maestro): make WaitForHealth_PollsUntilReady deterministic

Replace the 50ms wall-clock sleep that flipped healthReady with a
healthReadyAfterCall counter in the fake server. The handler returns
ready=true once healthCalls reaches the threshold, so the test's
"at least 2 polls before ready" assertion is satisfied by call
count rather than a race between the flip goroutine and the 25ms
poll loop.

* refactor(runner): route per-step progress through slog instead of fmt.Printf

The runner already carries a *slog.Logger for warnings (logger.Warn on
decode failures, predicate errors). The per-step status line was the
outlier — a bare fmt.Printf that wrote to os.Stdout unconditionally,
bypassing both the injected logger and any caller-configured writer.

Switch it to logger.Info("step", "index", ..., "screen", ..., "nodes", ...).
The caller (cmd/uatu) is responsible for wiring a logger whose handler
renders to the right stream; the next commit adds that wiring.

* feat(cli): render runner progress via a thin slog handler on stdout

progressHandler writes Info records as "msg key=value ..." and prefixes
warnings/errors with their level, matching the prose style of the
surrounding CLI status prints. Wired into the runner via
runner.Options.Logger so the per-step status line still lands on stdout
without slog's default time= / level= framing.

cmd/uatu/progress_logger.go

@@ -0,0 +1,52 @@
+package main
+
+import (
+	"context"
+	"fmt"
+	"io"
+	"log/slog"
+	"strings"
+)
+
+// newProgressLogger wires a slog.Logger that prints user-facing progress
+// lines to the CLI's stdout stream. Info messages render as
+// "msg key=value ..." to match the prose style of other CLI prints;
+// warnings and errors get a "warn:" / "error:" prefix so they stand
+// out in the same stream.
+func newProgressLogger(writer io.Writer) *slog.Logger {
+	return slog.New(&progressHandler{writer: writer, level: slog.LevelInfo})
+}
+
+type progressHandler struct {
+	writer io.Writer
+	level  slog.Level
+}
+
+func (h *progressHandler) Enabled(_ context.Context, level slog.Level) bool {
+	return level >= h.level
+}
+
+func (h *progressHandler) Handle(_ context.Context, record slog.Record) error {
+	var builder strings.Builder
+	if record.Level >= slog.LevelWarn {
+		fmt.Fprintf(&builder, "%s: ", strings.ToLower(record.Level.String()))
+	}
+	builder.WriteString(record.Message)
+	record.Attrs(func(attr slog.Attr) bool {
+		fmt.Fprintf(&builder, " %s=%s", attr.Key, formatAttrValue(attr.Value))
+		return true
+	})
+	builder.WriteByte('\n')
+	_, err := io.WriteString(h.writer, builder.String())
+	return err
+}
+
+func (h *progressHandler) WithAttrs(_ []slog.Attr) slog.Handler { return h }
+func (h *progressHandler) WithGroup(_ string) slog.Handler      { return h }
+
+func formatAttrValue(value slog.Value) string {
+	if value.Kind() == slog.KindString {
+		return fmt.Sprintf("%q", value.String())
+	}
+	return value.String()
+}

cmd/uatu/test_run.go

@@ -181,6 +181,7 @@ func runTestPipeline(ctx context.Context, options testOptions, stdout io.Writer)
 		Driver:          driverClient,
 		Verifier:        verifierInstance,
 		TraceWriter:     traceWriter,
+		Logger:          newProgressLogger(stdout),
 	})
 
 	terminateCtx, terminateCancel := context.WithTimeout(context.Background(), 5*time.Second)

internal/agent/server_test.go

@@ -191,7 +191,6 @@ func TestServer_AcceptCancelsOnContext(t *testing.T) {
 	acceptErr := make(chan error, 1)
 	go func() { _, err := server.Accept(ctx); acceptErr <- err }()
 
-	time.Sleep(50 * time.Millisecond)
 	cancel()
 
 	select {
@@ -321,12 +320,14 @@ func TestConn_SnapshotAfterAcceptContextCancel(t *testing.T) {
 func TestConn_SnapshotTimesOutIfSDKSilent(t *testing.T) {
 	server := newLoopbackServer(t)
 
+	done := make(chan struct{})
+	t.Cleanup(func() { close(done) })
 	go func() {
 		client, _ := net.Dial("tcp", server.Addr().String())
 		defer client.Close()
 		_ = WriteMessage(client, Hello("0.0.1", "android", "com.x"))
-		// Never respond to PAUSE.
+		// Never respond to PAUSE; stay alive until the test ends.
-		time.Sleep(2 * time.Second)
+		<-done
 	}()
 
 	ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)

internal/driver/maestro/client_test.go

@@ -19,6 +19,7 @@ type fakeServer struct {
 
 	healthReady          bool
 	healthCalls          int
+	healthReadyAfterCall int
 
 	launchedBundleID string
 	launcherActivity string
@@ -43,7 +44,11 @@ func (s *fakeServer) Health(_ context.Context, _ *driverpb.Empty) (*driverpb.Hea
 	if s.healthError != nil {
 		return nil, s.healthError
 	}
-	return &driverpb.HealthStatus{Ready: s.healthReady, Version: "test", Platform: "android"}, nil
+	ready := s.healthReady
+	if s.healthReadyAfterCall > 0 && s.healthCalls >= s.healthReadyAfterCall {
+		ready = true
+	}
+	return &driverpb.HealthStatus{Ready: ready, Version: "test", Platform: "android"}, nil
 }
 
 func (s *fakeServer) Launch(_ context.Context, request *driverpb.LaunchRequest) (*driverpb.Empty, error) {
@@ -144,25 +149,23 @@ func TestClient_HealthRoundTrip(t *testing.T) {
 
 func TestClient_WaitForHealth_PollsUntilReady(t *testing.T) {
 	state := newHarness(t)
+	state.fake.mutex.Lock()
 	state.fake.healthReady = false
+	state.fake.healthReadyAfterCall = 2
+	state.fake.mutex.Unlock()
 	client, err := Dial(state.address)
 	if err != nil {
 		t.Fatal(err)
 	}
 	defer client.Close()
 
-	go func() {
-		time.Sleep(50 * time.Millisecond)
-		state.fake.mutex.Lock()
-		state.fake.healthReady = true
-		state.fake.mutex.Unlock()
-	}()
-
 	ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
 	defer cancel()
 	if err := client.WaitForHealth(ctx, 25*time.Millisecond); err != nil {
 		t.Fatalf("WaitForHealth: %v", err)
 	}
+	state.fake.mutex.Lock()
+	defer state.fake.mutex.Unlock()
 	if state.fake.healthCalls < 2 {
 		t.Errorf("expected at least 2 health polls, got %d", state.fake.healthCalls)
 	}

internal/runner/runner.go

@@ -104,8 +104,7 @@ func Run(ctx context.Context, options Options) (Summary, error) {
 		if screenErr != nil {
 			logger.Warn("screen snapshot decode failed", "step", stepIndex, "err", screenErr)
 		}
-		fmt.Printf("step %d: screen=%q hierarchy=%d nodes\n",
+		logger.Info("step", "index", stepIndex, "screen", screen, "nodes", treeSize)
-			stepIndex, screen, treeSize)
 		verdicts := options.Verifier.EvaluateProperties()
 		violations := violationNames(verdicts)
 		for _, name := range violations {

sidecar/src/test/kotlin/dev/uatu/sidecar/MainTest.kt

@@ -1,11 +0,0 @@
-package dev.uatu.sidecar
-
-import kotlin.test.Test
-import kotlin.test.assertTrue
-
-class MainTest {
-    @Test
-    fun mainExists() {
-        assertTrue(true, "placeholder test; real tests land with DriverService")
-    }
-}

sidecar/src/test/kotlin/dev/uatu/sidecar/SidecarServerTest.kt

@@ -0,0 +1,17 @@
+package dev.uatu.sidecar
+
+import kotlin.test.Test
+import kotlin.test.assertTrue
+
+class SidecarServerTest {
+    @Test
+    fun startBindsEphemeralPortAndStopReleasesIt() {
+        val server = SidecarServer(port = 0, service = DriverService())
+        val boundPort = server.start()
+        try {
+            assertTrue(boundPort > 0, "expected ephemeral port, got $boundPort")
+        } finally {
+            server.stop()
+        }
+    }
+}