Skip to content

Commit c97b2df

Browse files
authored
feat(runner): real-time step feedback — pre-step indicator, progress ticker, timeout warning (#100)
Three-layer feedback system so test runs no longer look stale: Layer 1 — Pre-step indicator (verbose mode) Prints '→ step description' immediately before each step runs. On TTY: result line (✓/✗) overwrites the arrow line in place via ANSI cursor-up + erase (clean single-line-per-step output). On non-TTY: both lines appended (CI-friendly, nothing hidden). Layer 2 — Progress ticker (all modes) runStepTicker goroutine fires every 5s while a step is running. Prints '⏱ step... (Ns)' so the user knows something is happening. Goroutine exits immediately when step finishes; fast steps (< 5s) produce no ticker output. Layer 3 — 80% timeout warning (all modes) One-time '⚠ step still running — Ns elapsed, Ns timeout' warning when elapsed >= 80% of the step's context deadline. Gives time to react before a timeout occurs. Non-verbose TTY status line Without --verbose: a faint \r-overwriting status shows the current step while it runs, then is cleared. No output on non-TTY (CI clean). Implementation: reporter.go: isTTY detection via os.ModeCharDevice (no new deps), 6 testable helpers (printStep*W accept io.Writer + bool), 6 public wrappers (PrintStep*) called from executor.go executor.go: runStep now calls PrintStepBefore/PrintCurrentStep before the dispatch switch, spawns runStepTicker goroutine, stops it via close(stop)+<-done after the switch, then calls PrintStepAfterN Goroutine sync: close(stopTicker) → <-tickerDone guarantees ticker has exited before extraLines.Load() or result print runs (no race) Tests: 21 new tests in step_feedback_test.go (package runner, internal) covering TTY detection, all print helpers, ticker no-output-for-fast- steps, tick-after-interval, 80%-warning, ctx-cancel exit, warning-once
1 parent 528db6d commit c97b2df

9 files changed

Lines changed: 523 additions & 11 deletions

File tree

CHANGELOG.md

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,15 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/).
66

77
## [Unreleased]
88

9+
## [0.9.2] - 2026-05-09
10+
11+
### Added
12+
- **Real-time step feedback** — the runner now emits progress during test execution instead of staying silent until a step completes:
13+
- **Pre-step indicator** (verbose mode): prints `→ step description` immediately before each step runs. On a TTY the line is overwritten in place by the `✓/✗` result when the step finishes (clean single-line-per-step output). On non-TTY (CI) both lines are appended.
14+
- **Progress ticker** (all modes): a goroutine fires every 5 seconds while a step is still running and prints `⏱ step... (Ns)`. Stops immediately when the step completes — fast steps produce no ticker output.
15+
- **Timeout warning** (all modes): when a step has consumed ≥ 80% of its context deadline, a one-time `⚠ step still running — Ns elapsed, Ns timeout` warning is printed. Gives time to react before the step times out.
16+
- **Non-verbose TTY status line**: even without `--verbose`, a faint `\r`-overwriting status line shows the current step name while it runs and is cleared when it finishes. No output on non-TTY so CI logs stay clean.
17+
918
## [0.9.1] - 2026-05-09
1019

1120
### Added

docs/wiki/Home.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@ Welcome to the FlutterProbe wiki. This documentation covers architecture details
1818

1919
## Project Status
2020

21-
FlutterProbe is in active development. Current version: **0.9.1**.
21+
FlutterProbe is in active development. Current version: **0.9.2**.
2222

2323
### Repository Structure
2424

internal/runner/executor.go

Lines changed: 84 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -124,8 +124,28 @@ func (e *Executor) runStep(ctx context.Context, step parser.Step) error {
124124

125125
start := time.Now()
126126
desc := e.stepDescription(step)
127-
var err error
128127

128+
// Real-time feedback: print the step description before it runs.
129+
if desc != "" {
130+
if e.verbose {
131+
PrintStepBefore(e.depth, desc)
132+
} else {
133+
PrintCurrentStep(desc)
134+
}
135+
}
136+
137+
// Launch a ticker goroutine that prints progress lines every 5 seconds for
138+
// slow steps. It also emits a one-time warning at 80% of the step timeout.
139+
// The goroutine is always started when there's a description — it exits
140+
// immediately via <-stopTicker if the step finishes fast (< 5s).
141+
var extraLines atomic.Int32
142+
stopTicker := make(chan struct{})
143+
tickerDone := make(chan struct{})
144+
if desc != "" {
145+
go runStepTicker(stepCtx, desc, e.depth, 5*time.Second, stopTicker, tickerDone, &extraLines)
146+
}
147+
148+
var err error
129149
switch s := step.(type) {
130150
case parser.ActionStep:
131151
err = e.runAction(stepCtx, s)
@@ -181,19 +201,76 @@ func (e *Executor) runStep(ctx context.Context, step parser.Step) error {
181201
}
182202
}
183203

184-
if e.verbose && desc != "" {
204+
// Stop the ticker goroutine and wait for it to fully exit before reading
205+
// extraLines or printing the result — this eliminates any output race.
206+
if desc != "" {
207+
close(stopTicker)
208+
<-tickerDone
209+
}
210+
211+
if desc != "" {
185212
elapsed := time.Since(start)
186-
indent := strings.Repeat(" ", e.depth)
187-
status := "\033[32m✓\033[0m"
188-
if err != nil {
189-
status = "\033[31m✗\033[0m"
213+
if e.verbose {
214+
PrintStepAfterN(e.depth, desc, elapsed, err, int(extraLines.Load()))
215+
} else {
216+
ClearCurrentStep()
190217
}
191-
fmt.Printf(" %s%s %s \033[2m(%.1fs)\033[0m\n", indent, status, desc, elapsed.Seconds())
192218
}
193219

194220
return err
195221
}
196222

223+
// runStepTicker is run in a goroutine by runStep. It emits ⏱ progress lines
224+
// every tickInterval for slow steps and a one-time ⚠ warning at 80% of the
225+
// step's context deadline. It exits when stop is closed or ctx is cancelled.
226+
func runStepTicker(
227+
ctx context.Context,
228+
desc string,
229+
depth int,
230+
tickInterval time.Duration,
231+
stop <-chan struct{},
232+
done chan<- struct{},
233+
extraLines *atomic.Int32,
234+
) {
235+
defer close(done)
236+
237+
ticker := time.NewTicker(tickInterval)
238+
defer ticker.Stop()
239+
240+
goroutineStart := time.Now()
241+
warnPrinted := false
242+
243+
// Derive the total step timeout from the context deadline so we can emit
244+
// the 80% warning at the right moment.
245+
var timeoutDur time.Duration
246+
if deadline, ok := ctx.Deadline(); ok {
247+
timeoutDur = deadline.Sub(goroutineStart)
248+
}
249+
250+
for {
251+
select {
252+
case <-stop:
253+
return
254+
case <-ctx.Done():
255+
return
256+
case t := <-ticker.C:
257+
elapsed := t.Sub(goroutineStart)
258+
PrintStepTick(depth, desc, elapsed)
259+
extraLines.Add(1)
260+
261+
// Emit the 80% warning exactly once, after the threshold is crossed.
262+
if !warnPrinted && timeoutDur > 0 {
263+
threshold := time.Duration(float64(timeoutDur) * 0.80)
264+
if elapsed >= threshold {
265+
PrintStepWarning(depth, desc, elapsed, timeoutDur)
266+
extraLines.Add(1)
267+
warnPrinted = true
268+
}
269+
}
270+
}
271+
}
272+
}
273+
197274
// stepDescription returns a human-readable description of the step.
198275
func (e *Executor) stepDescription(step parser.Step) string {
199276
switch s := step.(type) {

internal/runner/reporter.go

Lines changed: 116 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88
"os"
99
"path/filepath"
1010
"strings"
11+
"sync"
1112
"time"
1213
)
1314

@@ -357,3 +358,118 @@ func AllPassed(results []TestResult) bool {
357358
}
358359
return true
359360
}
361+
362+
// ---- Real-time step feedback ----
363+
364+
// isTTY reports whether os.Stdout is an interactive terminal. The result is
365+
// computed once (via sync.OnceValue) and cached — no repeated syscalls.
366+
// Returns false in CI pipes, when stdout is redirected to a file, etc.
367+
var isTTY = sync.OnceValue(func() bool {
368+
fi, err := os.Stdout.Stat()
369+
if err != nil {
370+
return false
371+
}
372+
return fi.Mode()&os.ModeCharDevice != 0
373+
})
374+
375+
// printStepBeforeW writes the "→ desc" pre-step line to w.
376+
// On a TTY the line will be overwritten by printStepAfterNW (when tickLines==0).
377+
func printStepBeforeW(w io.Writer, _ bool, depth int, desc string) {
378+
if desc == "" {
379+
return
380+
}
381+
indent := strings.Repeat(" ", depth)
382+
fmt.Fprintf(w, " %s\033[2m→\033[0m %s\n", indent, desc)
383+
}
384+
385+
// printStepAfterNW writes the ✓/✗ result line.
386+
// On a TTY with no tick lines printed below the "→" line, it moves the cursor
387+
// up one line and overwrites in place (clean single-line-per-step output).
388+
// When tickLines > 0 the "→" line has scrolled above the tick lines, so we
389+
// just append — attempting to erase N lines is more fragile than helpful.
390+
// On non-TTY output is always appended.
391+
func printStepAfterNW(w io.Writer, tty bool, depth int, desc string, elapsed time.Duration, err error, tickLines int) {
392+
if desc == "" {
393+
return
394+
}
395+
indent := strings.Repeat(" ", depth)
396+
status := "\033[32m✓\033[0m"
397+
if err != nil {
398+
status = "\033[31m✗\033[0m"
399+
}
400+
line := fmt.Sprintf(" %s%s %s \033[2m(%.1fs)\033[0m", indent, status, desc, elapsed.Seconds())
401+
if tty && tickLines == 0 {
402+
// Cursor up one line, carriage return, erase to EOL, then print result.
403+
fmt.Fprintf(w, "\033[1A\r\033[K%s\n", line)
404+
} else {
405+
fmt.Fprintln(w, line)
406+
}
407+
}
408+
409+
// printStepTickW writes a ⏱ progress line showing elapsed time.
410+
func printStepTickW(w io.Writer, depth int, desc string, elapsed time.Duration) {
411+
indent := strings.Repeat(" ", depth)
412+
fmt.Fprintf(w, " %s\033[33m⏱\033[0m %s... \033[2m(%ds)\033[0m\n",
413+
indent, desc, int(elapsed.Seconds()))
414+
}
415+
416+
// printStepWarningW writes a one-time ⚠ warning when a step is near its timeout.
417+
func printStepWarningW(w io.Writer, depth int, desc string, elapsed, timeout time.Duration) {
418+
indent := strings.Repeat(" ", depth)
419+
fmt.Fprintf(w, " %s\033[33m⚠\033[0m %s still running — %ds elapsed, %ds timeout\n",
420+
indent, desc, int(elapsed.Seconds()), int(timeout.Seconds()))
421+
}
422+
423+
// printCurrentStepW writes a transient \r-overwriting status line in non-verbose
424+
// mode. On non-TTY this is a no-op so CI output stays clean.
425+
func printCurrentStepW(w io.Writer, tty bool, desc string) {
426+
if !tty || desc == "" {
427+
return
428+
}
429+
const maxW = 80
430+
label := " \033[2m" + desc + "\033[0m"
431+
// Pad to maxW so previous (longer) status is fully erased.
432+
fmt.Fprintf(w, "\r%-*s", maxW, label)
433+
}
434+
435+
// clearCurrentStepW erases the transient status line written by printCurrentStepW.
436+
func clearCurrentStepW(w io.Writer, tty bool) {
437+
if !tty {
438+
return
439+
}
440+
fmt.Fprintf(w, "\r%*s\r", 80, "")
441+
}
442+
443+
// Public wrappers — called from executor.go. Each delegates to the testable
444+
// helper with os.Stdout and the cached isTTY result.
445+
446+
// PrintStepBefore prints the "→ desc" line before a step runs (verbose mode).
447+
func PrintStepBefore(depth int, desc string) {
448+
printStepBeforeW(os.Stdout, isTTY(), depth, desc)
449+
}
450+
451+
// PrintStepAfterN prints the ✓/✗ result line after a step finishes.
452+
// tickLines is the number of ⏱/⚠ lines printed below the "→" line.
453+
func PrintStepAfterN(depth int, desc string, elapsed time.Duration, err error, tickLines int) {
454+
printStepAfterNW(os.Stdout, isTTY(), depth, desc, elapsed, err, tickLines)
455+
}
456+
457+
// PrintStepTick prints a ⏱ progress line during a long-running step.
458+
func PrintStepTick(depth int, desc string, elapsed time.Duration) {
459+
printStepTickW(os.Stdout, depth, desc, elapsed)
460+
}
461+
462+
// PrintStepWarning prints a one-time ⚠ warning when a step is near its timeout.
463+
func PrintStepWarning(depth int, desc string, elapsed, timeout time.Duration) {
464+
printStepWarningW(os.Stdout, depth, desc, elapsed, timeout)
465+
}
466+
467+
// PrintCurrentStep prints a transient \r-based status line (non-verbose, TTY only).
468+
func PrintCurrentStep(desc string) {
469+
printCurrentStepW(os.Stdout, isTTY(), desc)
470+
}
471+
472+
// ClearCurrentStep erases the transient status line (non-verbose, TTY only).
473+
func ClearCurrentStep() {
474+
clearCurrentStepW(os.Stdout, isTTY())
475+
}

0 commit comments

Comments
 (0)