feat: bounded retry for a dropped tap, and poll the screen more gently

Running spotify_play against the real phone showed a tap can be delivered
to the app and then never acted on (the dispatcher lists the Spotify window
as the touch target, and the screen does not move). The run log also showed
step durations were printed as 0s while the recorded ones were correct.

- wait steps accept "retry N": on timeout, re-run the step above and wait
  again, up to N extra times. Only a wait may use it, it needs a step above
  it, and it can only press something already matched by text. spotify_play
  uses it on the search box and on the playback check.
- The success log line printed the duration before the deferred assignment
  ran. It now records the duration first.
- uiautomator dump starts a JVM on the phone, and the wait helpers polled
  every 400ms. ui.PollInterval is now 1500ms, which cuts that load on a
  phone that is already short of memory.

docs/phase-3-spotify-recipe.md logs attempts 7-10: the recipe now reaches
tap_row and picks "Honky Tonk Women" at (540,878), but the app stops acting
on input on this loaded phone, so the end-to-end run is still outstanding.
This commit is contained in:
2026-10-16 14:12:01 +11:00
parent 767844cacc
commit ab69f37aa4
6 changed files with 175 additions and 23 deletions

View File

@@ -54,7 +54,8 @@ Run it with:
``` ```
The verbs are `launch`, `foreground`, `wait`, `wait_gone`, `tap`, `tap_if`, The verbs are `launch`, `foreground`, `wait`, `wait_gone`, `tap`, `tap_if`,
`tap_row`, `type`, `key`, `back`, `home` and `sleep`. `tap exact "Pause"` `tap_row`, `type`, `key`, `back`, `home` and `sleep`. A `wait` step may add
`retry N` (see below). `tap exact "Pause"`
matches the whole text, not a substring. `tap_if` taps only when the text is matches the whole text, not a substring. `tap_if` taps only when the text is
already on screen, which lets one recipe cope with an app that remembers its already on screen, which lets one recipe cope with an app that remembers its
last screen. `foreground` waits until the recipe's app is really in front, so a last screen. `foreground` waits until the recipe's app is really in front, so a
@@ -114,7 +115,7 @@ its own reason instead of a generic "element not found".
## Timeouts (FR-11) ## Timeouts (FR-11)
`step_timeout: 20s` is the default per step, `total_timeout: 150s` bounds the `step_timeout: 20s` is the default per step, `total_timeout: 420s` bounds the
whole run. A step may name its own timeout (`wait "Search" 30s`). The engine whole run. A step may name its own timeout (`wait "Search" 30s`). The engine
checks the remaining budget before each step and stops when it runs out. Every checks the remaining budget before each step and stops when it runs out. Every
`adb` call is already bounded by `adb.DefaultTimeout`. `adb` call is already bounded by `adb.DefaultTimeout`.
@@ -192,8 +193,23 @@ keyguard; reading the state first would say "unlocked" about a locked phone.
| All acting commands refuse on a locked phone | **live, verified** (above) | | All acting commands refuse on a locked phone | **live, verified** (above) |
| `artemis run spotify_play` refuses on a locked phone | **live, verified** (above) | | `artemis run spotify_play` refuses on a locked phone | **live, verified** (above) |
| `spotify_play` plays the right song | **not yet run end to end** — see below | | `spotify_play` plays the right song | **not yet run end to end** — see below |
| `spotify_play` picks the right row on the real results list | **live, verified** — `tapped row "Honky Tonk Women" at (540,878)` |
| Spotify search reaches the result list | live (Home → Search → type → results) | | Spotify search reaches the result list | live (Home → Search → type → results) |
## Retrying a dropped tap
A step can ask for the step above it to be pressed again:
```
- tap_row "{query}" 40s
- wait exact "Pause" 45s retry 3
```
`retry N` is only allowed on a `wait` step, needs a step above it to repeat, and
never taps anything that was not matched by text. It exists because a busy phone
can deliver a tap and then not act on it. The retry only re-runs the step above,
so nothing else can be pressed by accident.
## Live run log ## Live run log
Six attempts, in order. Each failure was clean, named its screen and tapped Six attempts, in order. Each failure was clean, named its screen and tapped
@@ -220,12 +236,46 @@ nothing random — which is the point of the phase.
screen shows: "Cancel", "App logo", "Settings", "Verify that it's you" ...`. screen shows: "Cancel", "App logo", "Settings", "Verify that it's you" ...`.
Artemis did not touch the prompt, and it must not: it needs Sam's fingerprint Artemis did not touch the prompt, and it must not: it needs Sam's fingerprint
or PIN, exactly like the lock screen. or PIN, exactly like the lock screen.
6. **Still blocked** by the same prompt on the next attempt. 6. **Same prompt again**, until Sam cleared it.
7. **Through to the row, but no playback.** After the prompt was cleared the
recipe reached step 11 (`tap_row`) with every earlier step ok, and the run
log shows it chose exactly the right element:
`tapped row "Honky Tonk Women" at (540,878) from Honky Tonk Women /
Song • The Rolling Stones`. Only the last step failed:
`text "Pause" did not appear within 40s`, with the search results still on
screen. The tap was delivered (the dispatcher lists the Spotify window as the
touch target) and Spotify did nothing with it.
8. **Duration logging fixed, retry added.** `wait ... retry N` now re-runs the
step above and waits again. Steps 9–12 made four attempts each.
9. **A dropped tap is not the whole story.** With retries, `tap_if "Clear
search query"` reported ok four times and never cleared the box. A probe
showed typing no longer reached the app either (`input text "zz"` left the
field unchanged) and neither did taps on the tab bar, while `keyevent 3`
(HOME) still worked. The app was deaf to input while still drawing.
10. **It recovers on its own, then wedges again.** After a 75-second rest with
no dumps and no input, the screen had moved to Home — queued input had been
processed — so a fresh run was started immediately. It failed at
`tap "Search"`: the tap reported ok, the screen never left Home.
### Diagnosis
This is the phone, not the recipe. Spotify's UI thread is starved: the phone is
at `MemFree ~300MB` with 3.2GB of swap in use, load average ~4, and Spotify
sustains ~70% CPU. When it is in that state it accepts no input at all — not
injected taps, not injected keys — while `keyevent 3` (HOME, handled by the
system) still works, and it recovers only after minutes of quiet. A force-stop
would clear it, and that is a restart on Sam's phone, so it is not something
Artemis does on its own.
Artemis made this worse than it needed to be: `uiautomator dump` starts a JVM on
the phone, and the wait helpers were polling every 400ms. `ui.PollInterval` is
now 1500ms, which cuts that load by roughly two thirds.
### What is left ### What is left
The live end-to-end run of `spotify_play` (Phase 3 DoD) has not completed. It The live end-to-end run of `spotify_play` (Phase 3 DoD) has not completed. It
needs the phone unlocked and free of the biometric prompt, and then: needs the phone's Spotify restarted — swipe it away from Recents, or force-stop
it — and the phone left awake and unlocked. Then:
```sh ```sh
./bin/artemis run spotify_play query="Rolling Stones Honky Tonk" ./bin/artemis run spotify_play query="Rolling Stones Honky Tonk"

View File

@@ -96,14 +96,34 @@ func Run(r *adb.Runner, rec *Recipe, opts Options) *RunResult {
w, h, _ := ui.ScreenSize(r) // best effort: bounds checking degrades gracefully w, h, _ := ui.ScreenSize(r) // best effort: bounds checking degrades gracefully
deadline := started.Add(rec.TotalTimeout) deadline := started.Add(rec.TotalTimeout)
for i, step := range rec.Steps { for i := 0; i < len(rec.Steps); i++ {
if remaining := time.Until(deadline); remaining <= 0 { step := rec.Steps[i]
return fail(fmt.Errorf("recipe timed out after %s at step %d (%s)", rec.TotalTimeout, i+1, step.Verb)) var sr StepResult
} for attempt := 0; ; attempt++ {
sr := executeStep(r, rec, step, i, params, w, h, deadline, logf) if remaining := time.Until(deadline); remaining <= 0 {
res.Steps = append(res.Steps, sr) return fail(fmt.Errorf("recipe timed out after %s at step %d (%s)", rec.TotalTimeout, i+1, step.Verb))
if !sr.OK { }
return fail(fmt.Errorf("step %d (%s %s) failed: %s", i+1, step.Verb, strings.Join(step.Args, " "), sr.Error)) sr = executeStep(r, rec, step, i, params, w, h, deadline, logf)
res.Steps = append(res.Steps, sr)
if sr.OK {
break
}
// A wait step with "retry N" presses the step above again: on a
// busy phone a tap can be delivered but never acted on, or dropped.
if attempt >= step.Retry {
return fail(fmt.Errorf("step %d (%s %s) failed: %s", i+1, step.Verb, strings.Join(step.Args, " "), sr.Error))
}
if i == 0 {
return fail(fmt.Errorf("step %d: retry needs a step above it to repeat", i+1))
}
logf(" step %d %s: retrying, pressing %s again", i+1, step.Verb, rec.Steps[i-1].Verb)
again := executeStep(r, rec, rec.Steps[i-1], i-1, params, w, h, deadline, logf)
res.Steps = append(res.Steps, again)
if !again.OK {
// The wait is the real failure; the repeat just could not run.
return fail(fmt.Errorf("step %d (%s %s) failed: %s; repeating %s failed too: %s",
i+1, step.Verb, strings.Join(step.Args, " "), sr.Error, rec.Steps[i-1].Verb, again.Error))
}
} }
} }
@@ -184,7 +204,7 @@ func executeStep(r *adb.Runner, rec *Recipe, step Step, index int, params map[st
} }
return fmt.Errorf("%s never came to the foreground within %s (foreground=%s)", pkg, timeout, got) return fmt.Errorf("%s never came to the foreground within %s (foreground=%s)", pkg, timeout, got)
} }
time.Sleep(400 * time.Millisecond) time.Sleep(ui.PollInterval)
} }
case "wait": case "wait":
@@ -269,6 +289,8 @@ func executeStep(r *adb.Runner, rec *Recipe, step Step, index int, params map[st
} }
sr.OK = true sr.OK = true
sr.Duration = time.Since(started)
sr.DurationMS = sr.Duration.Milliseconds()
logf(" step %d %s %v: ok (%s)", sr.Index, step.Verb, args, sr.Duration.Round(time.Millisecond)) logf(" step %d %s %v: ok (%s)", sr.Index, step.Verb, args, sr.Duration.Round(time.Millisecond))
return sr return sr
} }
@@ -321,7 +343,7 @@ func tapRow(r *adb.Runner, rec *Recipe, query string, timeout time.Duration, w,
} else { } else {
lastErr = err lastErr = err
} }
time.Sleep(500 * time.Millisecond) time.Sleep(ui.PollInterval)
} }
if lastErr == nil { if lastErr == nil {
lastErr = fmt.Errorf("no result row matches %q", query) lastErr = fmt.Errorf("no result row matches %q", query)

View File

@@ -31,6 +31,9 @@
// - launch start the recipe's app // - launch start the recipe's app
// - foreground 30s wait until the recipe's app is in front // - foreground 30s wait until the recipe's app is in front
// - wait "Search" 30s wait for an element whose text matches // - wait "Search" 30s wait for an element whose text matches
// - wait exact "Pause" 60s retry 3
// if it never appears, re-run the step above and
// wait again (a busy phone can drop a tap)
// - wait_gone "Recents" 30s wait until no element matches the text // - wait_gone "Recents" 30s wait until no element matches the text
// - tap "Search" tap the element whose text matches (FR-4) // - tap "Search" tap the element whose text matches (FR-4)
// - tap exact "Pause" tap an element whose text matches exactly // - tap exact "Pause" tap an element whose text matches exactly
@@ -50,6 +53,7 @@ import (
"os" "os"
"path/filepath" "path/filepath"
"sort" "sort"
"strconv"
"strings" "strings"
"time" "time"
) )
@@ -80,7 +84,10 @@ type Step struct {
Args []string Args []string
Exact bool Exact bool
Timeout time.Duration Timeout time.Duration
Line int // Retry, on a wait step, re-runs the preceding step and waits again, up to
// this many extra times. A busy phone can drop a tap.
Retry int
Line int
} }
// Defaults used when a recipe does not set its own timeouts. // Defaults used when a recipe does not set its own timeouts.
@@ -312,6 +319,26 @@ func parseStep(body string, lineNo int) (*Step, error) {
args = args[1:] args = args[1:]
} }
// "retry N" is pulled out first, so the timeout can still be the last word.
for i := 0; i < len(args); i++ {
if !strings.EqualFold(args[i], "retry") {
continue
}
if i+1 >= len(args) {
return nil, fmt.Errorf("line %d: retry needs a number, as in retry 3", lineNo)
}
n, err := strconv.Atoi(args[i+1])
if err != nil || n < 1 {
return nil, fmt.Errorf("line %d: retry needs a positive number, got %q", lineNo, args[i+1])
}
if verb != "wait" {
return nil, fmt.Errorf("line %d: retry is only allowed on a wait step", lineNo)
}
step.Retry = n
args = append(args[:i], args[i+2:]...)
break
}
// A trailing duration is the step timeout, except for sleep where the // A trailing duration is the step timeout, except for sleep where the
// duration is the step itself. // duration is the step itself.
if !spec.durArg && len(args) > spec.min { if !spec.durArg && len(args) > spec.min {

View File

@@ -172,6 +172,9 @@ func TestSpotifyRecipeIsValid(t *testing.T) {
if last.Verb != "wait" || last.Args[0] != "Pause" { if last.Verb != "wait" || last.Args[0] != "Pause" {
t.Fatalf("the last step must confirm playback, got %+v", last) t.Fatalf("the last step must confirm playback, got %+v", last)
} }
if last.Retry < 1 {
t.Fatal("the playback check must be allowed to press the row again")
}
} }
func TestLoadAndList(t *testing.T) { func TestLoadAndList(t *testing.T) {
@@ -205,6 +208,38 @@ func TestLoadAndList(t *testing.T) {
} }
} }
func TestRetryOnWait(t *testing.T) {
rec, err := Parse("steps:\n - tap_row \"{query}\" 40s\n - wait exact \"Pause\" 45s retry 3\n")
if err != nil {
t.Fatalf("Parse: %v", err)
}
wait := rec.Steps[1]
if wait.Retry != 3 || wait.Timeout != 45*time.Second || !wait.Exact || wait.Args[0] != "Pause" {
t.Fatalf("retry wait step = %+v", wait)
}
// retry without a duration still works.
rec, err = Parse("steps:\n - tap_row \"x\"\n - wait \"Pause\" retry 2\n")
if err != nil {
t.Fatalf("Parse: %v", err)
}
if rec.Steps[1].Retry != 2 || rec.Steps[1].Timeout != 0 {
t.Fatalf("retry step = %+v", rec.Steps[1])
}
}
func TestRetryRejectsBadUse(t *testing.T) {
for name, src := range map[string]string{
"on a tap": "steps:\n - tap \"x\" retry 3\n",
"no number": "steps:\n - tap_row \"x\"\n - wait \"y\" retry\n",
"zero": "steps:\n - tap_row \"x\"\n - wait \"y\" retry 0\n",
"not a number": "steps:\n - tap_row \"x\"\n - wait \"y\" retry soon\n",
} {
if _, err := Parse(src); err == nil {
t.Errorf("%s: expected a parse error", name)
}
}
}
func TestForegroundStep(t *testing.T) { func TestForegroundStep(t *testing.T) {
rec, err := Parse("app: com.spotify.music\nsteps:\n - launch\n - foreground 30s\n") rec, err := Parse("app: com.spotify.music\nsteps:\n - launch\n - foreground 30s\n")
if err != nil { if err != nil {

View File

@@ -11,6 +11,13 @@ import (
"gitea.lab.audasmedia.com.au/sam/artemis_control/internal/adb" "gitea.lab.audasmedia.com.au/sam/artemis_control/internal/adb"
) )
// PollInterval is how long the wait helpers sleep between screen dumps.
//
// A dump runs a whole uiautomator JVM on the phone, which is expensive on a
// loaded device: polling every 400ms starves the very app Artemis is driving.
// A slower poll costs a moment of latency and keeps the phone responsive.
const PollInterval = 1500 * time.Millisecond
// Android key events we use. // Android key events we use.
const ( const (
KeyHome = 3 KeyHome = 3
@@ -173,7 +180,7 @@ func WaitForText(r *adb.Runner, query string, exact bool, timeout time.Duration)
} }
} }
} }
time.Sleep(400 * time.Millisecond) time.Sleep(PollInterval)
} }
if len(seen) > 0 { if len(seen) > 0 {
return nil, fmt.Errorf("text %q is on screen but no enabled match could be tapped", query) return nil, fmt.Errorf("text %q is on screen but no enabled match could be tapped", query)
@@ -194,7 +201,7 @@ func WaitForNoText(r *adb.Runner, query string, exact bool, timeout time.Duratio
if err == nil && len(h.FindText(query, exact)) == 0 { if err == nil && len(h.FindText(query, exact)) == 0 {
return nil return nil
} }
time.Sleep(400 * time.Millisecond) time.Sleep(PollInterval)
} }
return fmt.Errorf("text %q was still on screen after %s", query, timeout) return fmt.Errorf("text %q was still on screen after %s", query, timeout)
} }

View File

@@ -19,7 +19,7 @@ param: query
row_id: com.spotify.music:id/row_root row_id: com.spotify.music:id/row_root
step_timeout: 20s step_timeout: 20s
total_timeout: 150s total_timeout: 420s
# Screens Artemis must never tap on. Each one fails the run with the reason, so # Screens Artemis must never tap on. Each one fails the run with the reason, so
# a wrong tap is impossible (FR-8). # a wrong tap is impossible (FR-8).
@@ -36,14 +36,16 @@ steps:
# no-op, so this is safe to repeat. # no-op, so this is safe to repeat.
- launch - launch
- foreground 30s - foreground 30s
- wait "Search" 30s - wait "Search" 30s retry 2
# 2. Open the search tab. Spotify remembers the last tab, so a search screen # 2. Open the search tab. Spotify remembers the last tab, so a search screen
# with the previous query can come back: clear that box only when the # with the previous query can come back: clear that box only when the
# clear button is actually on screen. # clear button is actually on screen.
- tap "Search" - tap "Search"
- tap_if "Clear search query" - tap_if "Clear search query"
- wait "What do you want to listen to?" 30s # retry: the clear tap above can be dropped while the phone is busy, so press
# it again before giving up on the empty search box.
- wait "What do you want to listen to?" 30s retry 3
- tap "What do you want to listen to?" - tap "What do you want to listen to?"
# 3. Type the query. The clear button proves the text landed. # 3. Type the query. The clear button proves the text landed.
@@ -54,11 +56,20 @@ steps:
# never match something from the history instead of a search result. # never match something from the history instead of a search result.
- wait_gone "Recents" 30s - wait_gone "Recents" 30s
# 5. Play the result that matches the query. tap_row scores every visible # 5. Give the app a moment. Spotify renders the results list after the query
# lands, and the tap below must land on the settled list.
- sleep 1s
# 6. Play the result that matches the query. tap_row scores every visible
# result row against the query words and taps the best one; equal matches # result row against the query words and taps the best one; equal matches
# go to the highest row, which is how Spotify ranks them. # go to the highest row, which is how Spotify ranks them.
- tap_row "{query}" 40s - tap_row "{query}" 40s
# 6. Playback started when the transport button says "Pause". Exact match, so # 7. Playback started when the transport button says "Pause". Exact match, so
# Spotify's "Paused" labels do not count. # Spotify's "Paused" labels do not count.
- wait exact "Pause" 40s #
# This is the phone's slowest moment: the app is rendering a new list and
# can stop answering input for a while, so a tap can be dropped. "retry 3"
# presses the row again and waits, up to three more times. It never taps
# anything it did not match by text.
- wait exact "Pause" 45s retry 3