From 352d9f5bc06b9b9d97b5e2316055bb88745afd2b Mon Sep 17 00:00:00 2001 From: Bulat Galeev Date: Fri, 2 Oct 2026 08:03:49 +0400 Subject: [PATCH 1/5] chore(uiautomator2): remove escapeUIAutomatorString, which nothing calls any more 30257df (Android device queries match the whole text and id) took out the last caller of this helper in the uiautomator2 driver. The unused linter has flagged it since, so Lint has failed on every push to main, and Build, which needs Lint, has been skipped each time. The same helper in the appium and devicelab drivers is untouched. --- pkg/driver/uiautomator2/driver.go | 6 ------ 1 file changed, 6 deletions(-) diff --git a/pkg/driver/uiautomator2/driver.go b/pkg/driver/uiautomator2/driver.go index baad23df..d34f3f76 100644 --- a/pkg/driver/uiautomator2/driver.go +++ b/pkg/driver/uiautomator2/driver.go @@ -1280,12 +1280,6 @@ func looksLikeRegex(text string) bool { return false } -// escapeUIAutomatorString escapes only the double quotes for UiAutomator string. -// Used when the text is already a regex pattern. -func escapeUIAutomatorString(s string) string { - return strings.ReplaceAll(s, `"`, `\"`) -} - // buildStateFilters returns UiSelector chain for state filters. // e.g., ".enabled(true).checked(false)" func buildStateFilters(sel flow.Selector) string { From a289cc7cd8e429a1fc3f8ffa151cc136668a3466 Mon Sep 17 00:00:00 2001 From: Bulat Galeev Date: Mon, 28 Sep 2026 09:37:11 +0400 Subject: [PATCH 2/5] fix(runscript): run a script file as written Maestro runs a runScript file as plain JavaScript. It reads the file and evaluates ${...} only in the step's env, when: condition and label; the script text goes to the engine as it is (YamlFluentCommand.kt:409-424, Commands.kt:1029-1035, Orchestra.kt:723-737). The runner expanded ${...} and $VAR across the whole file before running it. A template literal that used the script's own variables was replaced ahead of the script, against variables that did not exist yet: `/v1/x?email=${encodeURIComponent(who)}&state=${state}` came out as `/v1/x?email=undefined&state=`. A script file now runs as written. Inline script text, which Maestro has no equivalent of, keeps the expansion. --- CHANGELOG.md | 1 + pkg/executor/scripting.go | 19 +++++++++++++++---- pkg/executor/scripting_test.go | 23 +++++++++++++++++++++++ 3 files changed, 39 insertions(+), 4 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index ddfda590..05497ce1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **WDA `launchApp` restarts a running app unless `stopApp: false`, as Maestro does.** It only activated the running app, so a relaunch left the app on the screen it was already on, and a flow checking what survives a restart restarted nothing. - **WDA `notVisible` passes only when a lookup finds the element absent.** `assertNotVisible` and `extendedWaitUntil: notVisible` treated any failed lookup, such as an unreadable page source or a dropped connection, as the element being gone, so they could pass without the screen being looked at. Other errors are now retried until the timeout, and then fail the step. - **`checked` selectors work on iOS.** The iOS drivers dropped `checked` with a warning, so `checked: true` matched a switch in either state. WDA now derives checked from a CheckBox, Switch or Toggle whose value is 1, as Maestro does, and filters on it on every path (tap, assert, relative). +- **`runScript` runs a script file as written, as Maestro does.** The runner expanded `${...}` across the whole file before running it, so a template literal that used the script's own variables, such as `${encodeURIComponent(email)}`, was replaced ahead of the script, against variables that did not exist yet, and came out as `undefined`. A script file now runs as plain JavaScript. Inline script text keeps its `${...}` expansion. ## [1.1.28] - 2026-09-30 diff --git a/pkg/executor/scripting.go b/pkg/executor/scripting.go index d453cb89..0804fa7d 100644 --- a/pkg/executor/scripting.go +++ b/pkg/executor/scripting.go @@ -251,8 +251,18 @@ func expandDollarVar(text, name, value string) string { // outlive a single runScript call still goes through the global `output` // bag, exactly as documented. func (se *ScriptEngine) RunScript(script string, env map[string]string) error { - // Expand variables in script - script = se.ExpandVariables(script) + return se.runScript(script, env, true) +} + +// runScript runs a script with its env. expandBody expands ${...} and $VAR in the script text +// first, which suits inline script text. A script file is plain JavaScript and runs as written, +// as in Maestro: expanding it first replaced the file's own template literals (`${localVar}`) +// ahead of the script, against variables that did not exist yet. +func (se *ScriptEngine) runScript(script string, env map[string]string, expandBody bool) error { + if expandBody { + // Expand variables in script + script = se.ExpandVariables(script) + } // Apply env variables for the duration of THIS script only, expanded so // values like "mockoon-cli start --port ${output.port}" resolve before the @@ -422,7 +432,8 @@ func (se *ScriptEngine) ExecuteRunScript(step *flow.RunScriptStep) *core.Command script := step.ScriptPath() // Check if it's a file path (ends with .js) - if strings.HasSuffix(script, ".js") { + isFile := strings.HasSuffix(script, ".js") + if isFile { filePath := se.ResolvePath(script) content, err := os.ReadFile(filePath) if err != nil { @@ -435,7 +446,7 @@ func (se *ScriptEngine) ExecuteRunScript(step *flow.RunScriptStep) *core.Command script = string(content) } - if err := se.RunScript(script, step.Env); err != nil { + if err := se.runScript(script, step.Env, !isFile); err != nil { return &core.CommandResult{ Success: false, Error: err, diff --git a/pkg/executor/scripting_test.go b/pkg/executor/scripting_test.go index 5e4eaf71..82d5a96f 100644 --- a/pkg/executor/scripting_test.go +++ b/pkg/executor/scripting_test.go @@ -792,6 +792,29 @@ func TestScriptEngine_ExecuteRunScript_File(t *testing.T) { } } +// A script file's own template literals are plain JavaScript: they must see the script's local +// variables, not be expanded ahead of the script against the flow's variables. +func TestScriptEngine_ExecuteRunScript_FileTemplateLiteral(t *testing.T) { + se := NewScriptEngine() + defer se.Close() + + tmpDir := t.TempDir() + src := "const who = EMAIL;\nconst state = 'onboarded';\n" + + "output.url = `/v1/x?email=${encodeURIComponent(who)}&state=${state}`;\n" + if err := os.WriteFile(filepath.Join(tmpDir, "tl.js"), []byte(src), 0o644); err != nil { + t.Fatalf("Failed to create test script: %v", err) + } + se.SetFlowDir(tmpDir) + + step := &flow.RunScriptStep{Script: "tl.js", Env: map[string]string{"EMAIL": "a+b@x.io"}} + if result := se.ExecuteRunScript(step); !result.Success { + t.Fatalf("ExecuteRunScript() success = false, error = %v", result.Error) + } + if got, want := se.GetVariable("url"), "/v1/x?email=a%2Bb%40x.io&state=onboarded"; got != want { + t.Errorf("url = %q, want %q", got, want) + } +} + func TestScriptEngine_ExecuteRunScript_FileNotFound(t *testing.T) { se := NewScriptEngine() defer se.Close() From df20b1b5aa0263b93e309e19be710629803bff12 Mon Sep 17 00:00:00 2001 From: Bulat Galeev Date: Mon, 28 Sep 2026 19:35:05 +0400 Subject: [PATCH 3/5] fix(executor): remove the env keys a runFlow or retry added when it ends Maestro gives a sub-flow its own env scope: enterEnvScope saves the env and leaveEnvScope puts that copy back, so a key the sub-flow added is gone when it returns (GraalJsEngine.kt:223-238, around runSubFlow at Orchestra.kt:1159-1197, which repeat, retry and runFlow all go through). The runner's withEnvVars restored each key to the value it had before, and a key that had none was set to "" rather than removed. After a runFlow, retry or sub-flow with `env: {KEY: ...}`, KEY stayed defined: typeof KEY was "string", `$KEY` expanded to nothing, and runShell saw KEY="" in its environment. withEnvVars now uses applyScopedEnv, which runScript's env already used: a key is restored when it existed and removed when it did not. --- CHANGELOG.md | 1 + pkg/executor/scoped_env_test.go | 53 +++++++++++++++++++++++++++++++++ pkg/executor/scripting.go | 14 +++------ 3 files changed, 58 insertions(+), 10 deletions(-) create mode 100644 pkg/executor/scoped_env_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index 05497ce1..b1c10c8e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **WDA `notVisible` passes only when a lookup finds the element absent.** `assertNotVisible` and `extendedWaitUntil: notVisible` treated any failed lookup, such as an unreadable page source or a dropped connection, as the element being gone, so they could pass without the screen being looked at. Other errors are now retried until the timeout, and then fail the step. - **`checked` selectors work on iOS.** The iOS drivers dropped `checked` with a warning, so `checked: true` matched a switch in either state. WDA now derives checked from a CheckBox, Switch or Toggle whose value is 1, as Maestro does, and filters on it on every path (tap, assert, relative). - **`runScript` runs a script file as written, as Maestro does.** The runner expanded `${...}` across the whole file before running it, so a template literal that used the script's own variables, such as `${encodeURIComponent(email)}`, was replaced ahead of the script, against variables that did not exist yet, and came out as `undefined`. A script file now runs as plain JavaScript. Inline script text keeps its `${...}` expansion. +- **A `runFlow`, `retry` or sub-flow `env` no longer leaves its keys behind, as in Maestro.** The runner put each key back to its old value, but a key that had none was set to an empty string instead of being removed, so after `runFlow` with `env: {KEY: ...}` the name stayed defined: `typeof KEY` was `"string"`, `$KEY` expanded to nothing, and `runShell` saw `KEY=""`. A key the block added is now removed when it ends. ## [1.1.28] - 2026-09-30 diff --git a/pkg/executor/scoped_env_test.go b/pkg/executor/scoped_env_test.go new file mode 100644 index 00000000..7b495bb6 --- /dev/null +++ b/pkg/executor/scoped_env_test.go @@ -0,0 +1,53 @@ +package executor + +import ( + "testing" + + "github.com/devicelab-dev/maestro-runner/pkg/flow" + "github.com/devicelab-dev/maestro-runner/pkg/report" +) + +// A key a runFlow, retry or sub-flow env added is gone when it returns, as in +// Maestro, whose leaveEnvScope restores the env as it was (GraalJsEngine.kt: +// 223-238). It used to stay behind set to "". +func TestWithEnvVars_RestoreRemovesAddedKeys(t *testing.T) { + se := NewScriptEngine() + defer se.Close() + se.SetVariable("KEPT", "before") + + restore := se.withEnvVars(map[string]string{"KEPT": "inside", "ADDED": "inside"}) + if se.GetVariable("ADDED") != "inside" || se.GetVariable("KEPT") != "inside" { + t.Fatalf("env not applied: ADDED=%q KEPT=%q", se.GetVariable("ADDED"), se.GetVariable("KEPT")) + } + restore() + + if got := se.GetVariable("KEPT"); got != "before" { + t.Errorf("KEPT = %q after restore, want its old value", got) + } + if _, ok := se.Variables()["ADDED"]; ok { + t.Error("ADDED is still a variable after restore, want it removed") + } + if got, err := se.js.Eval("typeof ADDED"); err != nil || got != "undefined" { + t.Errorf("typeof ADDED = %v (%v) after restore, want undefined", got, err) + } +} + +func TestRunFlowEnv_IsGoneAfterTheRunFlow(t *testing.T) { + result := runOneFlow(t, &mockDriver{}, flow.Flow{ + SourcePath: "test.yaml", + Config: flow.Config{Name: "scoped env"}, + Steps: []flow.Step{ + &flow.RunFlowStep{ + BaseStep: flow.BaseStep{StepType: flow.StepRunFlow}, + Env: map[string]string{"SCOPED": "1"}, + Steps: []flow.Step{ + &flow.AssertTrueStep{BaseStep: flow.BaseStep{StepType: flow.StepAssertTrue}, Script: "${SCOPED === '1'}"}, + }, + }, + &flow.AssertTrueStep{BaseStep: flow.BaseStep{StepType: flow.StepAssertTrue}, Script: "${typeof SCOPED === 'undefined'}"}, + }, + }) + if result.Status != report.StatusPassed { + t.Errorf("status = %v, want passed: SCOPED should be set inside the runFlow and undefined after it", result.Status) + } +} diff --git a/pkg/executor/scripting.go b/pkg/executor/scripting.go index 0804fa7d..05fac506 100644 --- a/pkg/executor/scripting.go +++ b/pkg/executor/scripting.go @@ -667,17 +667,11 @@ func conditionTimeout(cond flow.Condition, sel *flow.Selector, fallback int) int // withEnvVars applies environment variables and returns a restore function. // Values are expanded through ExpandVariables to support ${VAR || "default"} syntax. +// The restore puts back what each key held and removes a key that was not set +// before, as Maestro's leaveEnvScope does (GraalJsEngine.kt:223-238), rather +// than leaving it set to "". func (se *ScriptEngine) withEnvVars(env map[string]string) func() { - oldVars := make(map[string]string) - for k, v := range env { - oldVars[k] = se.GetVariable(k) - se.SetVariable(k, se.ExpandVariables(v)) - } - return func() { - for k, v := range oldVars { - se.SetVariable(k, v) - } - } + return se.applyScopedEnv(env) } // parseBoolExpr converts the resolved value of an `enabled:` argument into a From 33e4e376d1853a91ed1225187da80c39eeccd91a Mon Sep 17 00:00:00 2001 From: Bulat Galeev Date: Mon, 28 Sep 2026 19:38:26 +0400 Subject: [PATCH 4/5] fix(jsengine): give a script's http call Maestro's 5 minutes Maestro builds its script http client with 5-minute read, write and call timeouts (GraalJsEngine.kt:28-34), and the CLI passes no client of its own (Orchestra.kt:138 and 161), so every call gets them. The runner's http.* gave a call 30 s unless the call set `timeout`, so a script that calls a slow endpoint (seeding test data, waiting on a server-side job) failed with "HTTP request failed" where Maestro waits. A local server that answered after 32 s failed the call at 30 s. A call without a timeout option now gets 5 minutes. The option still wins. --- CHANGELOG.md | 1 + pkg/jsengine/http.go | 7 ++++- pkg/jsengine/http_timeout_test.go | 48 +++++++++++++++++++++++++++++++ 3 files changed, 55 insertions(+), 1 deletion(-) create mode 100644 pkg/jsengine/http_timeout_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index b1c10c8e..f6353120 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **`checked` selectors work on iOS.** The iOS drivers dropped `checked` with a warning, so `checked: true` matched a switch in either state. WDA now derives checked from a CheckBox, Switch or Toggle whose value is 1, as Maestro does, and filters on it on every path (tap, assert, relative). - **`runScript` runs a script file as written, as Maestro does.** The runner expanded `${...}` across the whole file before running it, so a template literal that used the script's own variables, such as `${encodeURIComponent(email)}`, was replaced ahead of the script, against variables that did not exist yet, and came out as `undefined`. A script file now runs as plain JavaScript. Inline script text keeps its `${...}` expansion. - **A `runFlow`, `retry` or sub-flow `env` no longer leaves its keys behind, as in Maestro.** The runner put each key back to its old value, but a key that had none was set to an empty string instead of being removed, so after `runFlow` with `env: {KEY: ...}` the name stayed defined: `typeof KEY` was `"string"`, `$KEY` expanded to nothing, and `runShell` saw `KEY=""`. A key the block added is now removed when it ends. +- **A script's `http` call waits up to 5 minutes, as in Maestro.** Maestro's script client allows a call 5 minutes. The runner gave up after 30 seconds unless the call set `timeout`, so a script that calls a slow endpoint, such as one that seeds test data, failed with `HTTP request failed` where Maestro waits. A call without a `timeout` option now gets 5 minutes, and the option still wins. ## [1.1.28] - 2026-09-30 diff --git a/pkg/jsengine/http.go b/pkg/jsengine/http.go index d986d121..4b6f0342 100644 --- a/pkg/jsengine/http.go +++ b/pkg/jsengine/http.go @@ -12,6 +12,11 @@ import ( "github.com/dop251/goja" ) +// defaultHTTPTimeout bounds an http.* call that sets no timeout of its own: +// the 5 minutes Maestro's script client allows a call (GraalJsEngine.kt:28-34). +// A variable so tests can shorten it. +var defaultHTTPTimeout = 5 * time.Minute + // httpModule returns the http object with get, post, put, delete methods func (e *Engine) httpModule() *goja.Object { obj := e.runtime.NewObject() @@ -84,7 +89,7 @@ func (e *Engine) doHTTPRequest(method string, call goja.FunctionCall) goja.Value // Parse options if provided var body io.Reader headers := make(map[string]string) - timeout := 30 * time.Second + timeout := defaultHTTPTimeout insecure := e.insecureHTTP if len(call.Arguments) > 1 && !goja.IsUndefined(call.Arguments[1]) { diff --git a/pkg/jsengine/http_timeout_test.go b/pkg/jsengine/http_timeout_test.go new file mode 100644 index 00000000..c4ed08f0 --- /dev/null +++ b/pkg/jsengine/http_timeout_test.go @@ -0,0 +1,48 @@ +package jsengine + +import ( + "net/http" + "net/http/httptest" + "strings" + "testing" + "time" +) + +// Maestro's script client allows a call 5 minutes (GraalJsEngine.kt:28-34). +// The runner's gave up after 30 s, so a slow test-data endpoint that works +// under Maestro failed the script. +func TestDefaultHTTPTimeoutIsMaestros(t *testing.T) { + if defaultHTTPTimeout != 5*time.Minute { + t.Errorf("default http timeout = %v, want 5m", defaultHTTPTimeout) + } +} + +// A call with no timeout option waits for the default, and the option still +// wins over it. +func TestHTTPRequestWithoutATimeoutUsesTheDefault(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + time.Sleep(300 * time.Millisecond) + _, _ = w.Write([]byte(`ok`)) + })) + defer srv.Close() + + saved := defaultHTTPTimeout + defaultHTTPTimeout = 50 * time.Millisecond + defer func() { defaultHTTPTimeout = saved }() + + e := New() + defer e.Close() + + _, err := e.Eval(`http.get(` + jsString(srv.URL) + `).status`) + if err == nil || !strings.Contains(err.Error(), "HTTP request failed") { + t.Errorf("a call slower than the default timeout returned err = %v, want it to time out", err) + } + + v, err := e.Eval(`http.get(` + jsString(srv.URL) + `, { timeout: 5000 }).status`) + if err != nil { + t.Fatalf("a call with its own longer timeout failed: %v", err) + } + if n, _ := v.(int64); n != 200 { + t.Errorf("status = %v, want 200", v) + } +} From 1bac95a66b018e18b9c03e469d6f6099dd44570d Mon Sep 17 00:00:00 2001 From: Bulat Galeev Date: Mon, 28 Sep 2026 17:46:41 +0400 Subject: [PATCH 5/5] fix(wda): send a read or a lookup again when its connection drops On a physical iPhone reached through usbmux and an SSH tunnel, WDA began dropping connections 90 minutes into a run: about one request in fourteen came back as EOF within about 10 ms, nearly all of them element reads sent in parallel (displayed, text, rect, name). Most were harmless, but a dropped text read made a copyTextFrom come back empty and failed the flow. A fresh WDA dropped none, in seven other runs. net/http does not help here. It sends a request again by itself only when it is a GET on a connection that had been used before (shouldRetryRequest), so a fresh connection that is hung up on, and any POST, come back as errors. A GET, or a POST that only finds elements, whose connection dies before any response (EOF, reset, broken pipe) is now sent once more, with a warning in the log. An action (a tap, typing, a swipe, launching an app) is never repeated: it may have reached WDA before the connection went. One more try, not a loop. The changelog entry for keeping idle connections said those requests are sent again. That is only true with this change, so the entry is reworded. --- CHANGELOG.md | 3 +- pkg/driver/wda/client.go | 47 ++++++++- pkg/driver/wda/dropped_connection_test.go | 115 ++++++++++++++++++++++ 3 files changed, 160 insertions(+), 5 deletions(-) create mode 100644 pkg/driver/wda/dropped_connection_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index f6353120..39684d3e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,7 +8,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] ### Fixed -- **WDA keeps enough idle connections for its own parallel reads.** The driver reads an element's name, rect, text and displayed at once, and a tap looks an element up four ways at once, but Go's default transport keeps two idle connections per host, so every burst closed two connections and opened two new ones. Through a forwarded port to a physical iPhone, new connections opened together fail with EOF and are sent again, which costs time on every step. The WDA client now keeps up to eight. +- **WDA keeps enough idle connections for its own parallel reads.** The driver reads an element's name, rect, text and displayed at once, and a tap looks an element up four ways at once, but Go's default transport keeps two idle connections per host, so every burst closed two connections and opened two new ones. Through a forwarded port to a physical iPhone, new connections opened together fail with EOF, which costs time on every step. The WDA client now keeps up to eight. - **`retry` counts retries, not attempts, as Maestro does.** `maxRetries: 1` now runs the commands twice (once, then one retry), an unset `maxRetries` means one retry, and the value is capped at 3. The runner ran exactly `maxRetries` attempts, three when unset and with no cap, so `maxRetries: 1` never retried. A value that is not an integer is logged and read as 1 instead of failing the step. - **WDA `launchApp` restarts a running app unless `stopApp: false`, as Maestro does.** It only activated the running app, so a relaunch left the app on the screen it was already on, and a flow checking what survives a restart restarted nothing. - **WDA `notVisible` passes only when a lookup finds the element absent.** `assertNotVisible` and `extendedWaitUntil: notVisible` treated any failed lookup, such as an unreadable page source or a dropped connection, as the element being gone, so they could pass without the screen being looked at. Other errors are now retried until the timeout, and then fail the step. @@ -16,6 +16,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **`runScript` runs a script file as written, as Maestro does.** The runner expanded `${...}` across the whole file before running it, so a template literal that used the script's own variables, such as `${encodeURIComponent(email)}`, was replaced ahead of the script, against variables that did not exist yet, and came out as `undefined`. A script file now runs as plain JavaScript. Inline script text keeps its `${...}` expansion. - **A `runFlow`, `retry` or sub-flow `env` no longer leaves its keys behind, as in Maestro.** The runner put each key back to its old value, but a key that had none was set to an empty string instead of being removed, so after `runFlow` with `env: {KEY: ...}` the name stayed defined: `typeof KEY` was `"string"`, `$KEY` expanded to nothing, and `runShell` saw `KEY=""`. A key the block added is now removed when it ends. - **A script's `http` call waits up to 5 minutes, as in Maestro.** Maestro's script client allows a call 5 minutes. The runner gave up after 30 seconds unless the call set `timeout`, so a script that calls a slow endpoint, such as one that seeds test data, failed with `HTTP request failed` where Maestro waits. A call without a `timeout` option now gets 5 minutes, and the option still wins. +- **WDA sends a read or a lookup again when its connection drops.** Through a forwarded port to a physical iPhone, WDA sometimes closes a connection before it answers, and the request came back as EOF; one dropped text read made `copyTextFrom` copy an empty string. net/http does not send these again (it only repeats a GET on a connection it had used before). A GET, or a POST that only finds elements, is now sent once more, with a warning in the log. An action (a tap, typing, a swipe, launching an app) is never repeated, because it may have reached WDA before the connection went. ## [1.1.28] - 2026-09-30 diff --git a/pkg/driver/wda/client.go b/pkg/driver/wda/client.go index 5078bc4e..d000568f 100644 --- a/pkg/driver/wda/client.go +++ b/pkg/driver/wda/client.go @@ -5,12 +5,14 @@ import ( "bytes" "encoding/base64" "encoding/json" + "errors" "fmt" "io" "net/http" "os" "strconv" "strings" + "syscall" "time" "github.com/devicelab-dev/maestro-runner/pkg/core" @@ -313,6 +315,26 @@ func (c *Client) ElementSendKeys(elementID, text string, frequency int) error { return err } +// isDroppedConnection reports a request that died on its connection before any +// response came back: an EOF, a reset or a broken pipe. Over a forwarded WDA port +// this happens. On a physical iPhone reached through usbmux and an SSH tunnel, WDA +// began dropping about one request in fourteen, 90 minutes into a run, each +// within about 10 ms and nearly all of them element reads sent in parallel; one +// such dropped text read made a copyTextFrom come back empty. net/http sends a +// request again by itself only when it is a GET on a connection that had been +// used before, so a fresh connection that is hung up on, and a POST, are not. +func isDroppedConnection(err error) bool { + return errors.Is(err, io.EOF) || errors.Is(err, io.ErrUnexpectedEOF) || + errors.Is(err, syscall.ECONNRESET) || errors.Is(err, syscall.EPIPE) +} + +// isLookupPath reports a POST that only finds elements, from the root or from an +// element (/element, /elements, /element/{id}/element(s)), so repeating it changes +// nothing on the device. +func isLookupPath(path string) bool { + return strings.HasSuffix(path, "/element") || strings.HasSuffix(path, "/elements") +} + // ElementClear clears an element's text. func (c *Client) ElementClear(elementID string) error { _, err := c.post(c.sessionPath(fmt.Sprintf("/element/%s/clear", elementID)), nil) @@ -631,6 +653,11 @@ func (c *Client) get(path string) (map[string]interface{}, error) { logger.Debug("WDA GET %s", path) resp, err := c.httpClient.Get(c.baseURL + path) + if err != nil && isDroppedConnection(err) { + // A read is safe to send twice. + logger.Warn("WDA GET %s: the connection dropped before a response (%v), sending it again", path, err) + resp, err = c.httpClient.Get(c.baseURL + path) + } duration := time.Since(start).Milliseconds() if err != nil { @@ -649,23 +676,35 @@ func (c *Client) get(path string) (map[string]interface{}, error) { func (c *Client) post(path string, body interface{}) (map[string]interface{}, error) { start := time.Now() - var reqBody io.Reader + var data []byte bodyStr := "" if body != nil { - data, err := json.Marshal(body) + var err error + data, err = json.Marshal(body) if err != nil { return nil, err } - reqBody = bytes.NewReader(data) bodyStr = string(data) if len(bodyStr) > 100 { bodyStr = bodyStr[:100] + "..." } } + newBody := func() io.Reader { + if data == nil { + return nil + } + return bytes.NewReader(data) + } logger.Debug("WDA POST %s body=%s", path, core.RedactTypedText(path, bodyStr)) - resp, err := c.httpClient.Post(c.baseURL+path, "application/json", reqBody) + resp, err := c.httpClient.Post(c.baseURL+path, "application/json", newBody()) + if err != nil && isDroppedConnection(err) && isLookupPath(path) { + // A lookup changes nothing, so it is as safe to repeat as a GET. An action is + // not sent twice: it may have reached WDA before the connection went. + logger.Warn("WDA POST %s: the connection dropped before a response (%v), sending it again", path, err) + resp, err = c.httpClient.Post(c.baseURL+path, "application/json", newBody()) + } duration := time.Since(start).Milliseconds() if err != nil { diff --git a/pkg/driver/wda/dropped_connection_test.go b/pkg/driver/wda/dropped_connection_test.go new file mode 100644 index 00000000..638f31eb --- /dev/null +++ b/pkg/driver/wda/dropped_connection_test.go @@ -0,0 +1,115 @@ +package wda + +import ( + "net/http" + "net/http/httptest" + "strings" + "sync" + "testing" +) + +// droppingServer closes the connection, with no response, on the first request to +// each path in drop; every later request is answered. +func droppingServer(t *testing.T, drop ...string) (*httptest.Server, func(string) int) { + t.Helper() + var mu sync.Mutex + seen := map[string]int{} + dropFirst := map[string]bool{} + for _, p := range drop { + dropFirst[p] = true + } + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + mu.Lock() + seen[r.URL.Path]++ + n := seen[r.URL.Path] + mu.Unlock() + if dropFirst[r.URL.Path] && n == 1 { + conn, _, err := w.(http.Hijacker).Hijack() + if err != nil { + t.Fatalf("hijack: %v", err) + } + _ = conn.Close() + return + } + w.Header().Set("Content-Type", "application/json") + switch { + case strings.HasSuffix(r.URL.Path, "/text"): + jsonResponse(w, map[string]interface{}{"value": "72.4"}) + case strings.HasSuffix(r.URL.Path, "/elements"): + jsonResponse(w, map[string]interface{}{"value": []interface{}{map[string]interface{}{"ELEMENT": "e1"}}}) + default: + jsonResponse(w, map[string]interface{}{"value": nil}) + } + })) + count := func(path string) int { + mu.Lock() + defer mu.Unlock() + return seen[path] + } + return server, count +} + +func testClient(server *httptest.Server) *Client { + return &Client{baseURL: server.URL, httpClient: http.DefaultClient, sessionID: "s"} +} + +// The measured failure: a text read whose connection dropped left copyTextFrom +// with an empty string. The read is now sent once more and gets its answer. +func TestGetIsSentAgainWhenItsConnectionDrops(t *testing.T) { + server, count := droppingServer(t, "/session/s/element/e1/text") + defer server.Close() + text, err := testClient(server).ElementText("e1") + if err != nil || text != "72.4" { + t.Fatalf("got %q, %v; want the text after one more try", text, err) + } + if n := count("/session/s/element/e1/text"); n != 2 { + t.Errorf("WDA saw the read %d times, want 2", n) + } +} + +func TestLookupIsSentAgainWhenItsConnectionDrops(t *testing.T) { + server, count := droppingServer(t, "/session/s/elements") + defer server.Close() + ids, err := testClient(server).FindElements("class chain", "**/XCUIElementTypeAny") + if err != nil || len(ids) != 1 { + t.Fatalf("got %v, %v; want the element after one more try", ids, err) + } + if n := count("/session/s/elements"); n != 2 { + t.Errorf("WDA saw the lookup %d times, want 2", n) + } +} + +// A tap may have reached WDA before the connection went, so it is never repeated: +// the error comes back and WDA saw it exactly once. +func TestActionIsNotSentAgainWhenItsConnectionDrops(t *testing.T) { + server, count := droppingServer(t, "/session/s/element/e1/click") + defer server.Close() + if err := testClient(server).ElementClick("e1"); err == nil { + t.Fatal("the tap reported success over a dropped connection") + } + if n := count("/session/s/element/e1/click"); n != 1 { + t.Errorf("WDA saw the tap %d times, want 1", n) + } +} + +// A request that fails twice fails: one more try, not a loop. +func TestGetIsTriedOnlyOnceMore(t *testing.T) { + var mu sync.Mutex + hits := 0 + server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + mu.Lock() + hits++ + mu.Unlock() + conn, _, _ := w.(http.Hijacker).Hijack() + _ = conn.Close() + })) + defer server.Close() + if _, err := testClient(server).ElementText("e1"); err == nil { + t.Fatal("a read that dropped twice reported success") + } + mu.Lock() + defer mu.Unlock() + if hits != 2 { + t.Errorf("WDA saw the read %d times, want 2", hits) + } +}