Skip to content

Commit 65ce65b

Browse files
authored
fix(ci): Android e2e flakes, shell Terminated sent before output (#3672)
* fix(ci): Android e2e flakes, shell `Terminated` sent before output - close "isn't responding" system dialogs before each spec and hide error dialogs on the CI emulator: a launcher ANR dialog takes input focus from the app, and Android then denies clipboard reads - retry switching to the webview context until it succeeds instead of running the spec in the native context when the first switch fails with "No such context found" - save the focused window, a screenshot and logcat when an Android test fails - shell: wait for the pipe readers to finish before emitting `Terminated`; the readers took their read lock on their own thread, so a child exiting quickly could have `close` emitted before its output * Apply suggestion from @lucasfernog
1 parent cbd691b commit 65ce65b

4 files changed

Lines changed: 134 additions & 51 deletions

File tree

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
---
2+
shell: patch
3+
shell-js: patch
4+
---
5+
6+
Fix `Command::spawn` (and the JavaScript `Command` API) sometimes emitting the `Terminated` (`close`) event before the child's `stdout`/`stderr` output when the process exits quickly.

‎.github/workflows/test-api-e2e-mobile.yml‎

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -159,7 +159,13 @@ jobs:
159159
profile: pixel_6
160160
emulator-options: -no-window -gpu swiftshader_indirect -noaudio -no-boot-anim -camera-back none
161161
disable-animations: true
162-
script: E2E_SKIP_BUILD=1 E2E_SPEC_RETRIES=1 pnpm test:api-e2e:android
162+
# The slow emulator regularly has the launcher hit an ANR, and the "isn't responding"
163+
# dialog takes input focus from the app under test (failing focus-gated APIs such as
164+
# clipboard reads). With error dialogs hidden the system kills the unresponsive process
165+
# instead; one that is already up is closed before each spec (see wdio.mobile.ts).
166+
script: |
167+
adb shell settings put global hide_error_dialogs 1
168+
E2E_SKIP_BUILD=1 E2E_SPEC_RETRIES=1 pnpm test:api-e2e:android
163169
164170
- name: upload appium logs
165171
if: failure()

‎packages/api-e2e/wdio.mobile.ts‎

Lines changed: 99 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -197,6 +197,9 @@ export function mobileConfig(platform: MobilePlatform): WebdriverIO.Config {
197197
// because Appium may only have booted the emulator with the first
198198
// session.
199199
adbReverse(FIXTURE_SERVER_PORT)
200+
// Still in the native context here, where UiAutomator2 sees system
201+
// windows.
202+
await dismissAnrDialogs(browser)
200203
}
201204

202205
let webview: string | undefined
@@ -216,7 +219,20 @@ export function mobileConfig(platform: MobilePlatform): WebdriverIO.Config {
216219
?? (platform === 'ios'
217220
? contexts.find((name) => name.startsWith('WEBVIEW_'))
218221
: undefined)
219-
return webview !== undefined
222+
if (webview === undefined) {
223+
return false
224+
}
225+
try {
226+
await browser.switchAppiumContext(webview)
227+
return true
228+
} catch {
229+
// On Android the context is listed as soon as the WebView's
230+
// devtools socket exists, but switching to it fails with "No such
231+
// context found" until the page is attachable. The suite would
232+
// otherwise carry on in the native context, where every script
233+
// fails with "Method has not yet been implemented".
234+
return false
235+
}
220236
},
221237
{
222238
// Covers a cold app start plus, on Android, the on-demand chromedriver
@@ -227,7 +243,6 @@ export function mobileConfig(platform: MobilePlatform): WebdriverIO.Config {
227243
'no WEBVIEW context appeared — is the app a debug build (webview debugging enabled)?'
228244
}
229245
)
230-
await browser.switchAppiumContext(webview!)
231246
// The specs run the page through `executeAsync`, and the XCUITest driver
232247
// starts with a script timeout of 0 (every async script times out at
233248
// once) rather than the 30s the other drivers default to.
@@ -255,6 +270,16 @@ export function mobileConfig(platform: MobilePlatform): WebdriverIO.Config {
255270
)
256271
},
257272

273+
// On Android, a failure is often down to the device rather than the app
274+
// (e.g. a system dialog holding input focus), which the webview-side
275+
// error alone does not show. Save what the device looked like next to the
276+
// Appium log, which CI uploads on failure.
277+
afterTest: (test, _context, { passed }) => {
278+
if (platform === 'android' && !passed) {
279+
androidDiagnostics(`${test.parent} ${test.title}`)
280+
}
281+
},
282+
258283
onComplete: () => {
259284
closeFixtureServer()
260285
}
@@ -313,18 +338,22 @@ function androidBuildEnv(): NodeJS.ProcessEnv {
313338

314339
/** `adb` from the Android SDK, else whatever is on `PATH`. */
315340
function adb(args: string[]): SpawnSyncReturns<string> {
341+
return spawnSync(adbBinary(), [...adbDeviceArgs(), ...args], {
342+
encoding: 'utf8',
343+
timeout: 20_000,
344+
maxBuffer: 64 * 1024 * 1024
345+
})
346+
}
347+
348+
function adbBinary(): string {
316349
const sdk = process.env.ANDROID_HOME ?? process.env.ANDROID_SDK_ROOT
317-
const binary = sdk ? path.join(sdk, 'platform-tools', 'adb') : 'adb'
318-
return spawnSync(
319-
binary,
320-
[
321-
...(process.env.E2E_ANDROID_DEVICE
322-
? ['-s', process.env.E2E_ANDROID_DEVICE]
323-
: []),
324-
...args
325-
],
326-
{ encoding: 'utf8', timeout: 20_000 }
327-
)
350+
return sdk ? path.join(sdk, 'platform-tools', 'adb') : 'adb'
351+
}
352+
353+
function adbDeviceArgs(): string[] {
354+
return process.env.E2E_ANDROID_DEVICE
355+
? ['-s', process.env.E2E_ANDROID_DEVICE]
356+
: []
328357
}
329358

330359
function adbReverse(port: number): void {
@@ -336,6 +365,63 @@ function adbReverse(port: number): void {
336365
}
337366
}
338367

368+
/**
369+
* Closes any "<app> isn't responding" dialog. On a slow emulator the launcher
370+
* or System UI regularly hits an ANR, and the dialog that follows holds input
371+
* focus over the app under test until someone answers it, failing anything
372+
* that needs focus (Android denies clipboard reads to apps without it) for
373+
* the rest of the run, retries included. "Close app" kills the unresponsive
374+
* process, so it does not come straight back like "Wait" could.
375+
*/
376+
async function dismissAnrDialogs(browser: WebdriverIO.Browser): Promise<void> {
377+
// More than one process can be stuck (e.g. launcher and System UI).
378+
for (let attempt = 0; attempt < 5; attempt++) {
379+
const close = browser.$('id=android:id/aerr_close')
380+
if (!(await close.isExisting())) {
381+
return
382+
}
383+
console.warn('[android] closing an "isn\'t responding" system dialog')
384+
await close.click()
385+
await browser.pause(500)
386+
}
387+
}
388+
389+
/**
390+
* Writes the focused window, a screenshot and the recent logcat for a failed
391+
* test to `logs/android-diagnostics/`.
392+
*/
393+
function androidDiagnostics(name: string): void {
394+
const dir = path.join(dirname, 'logs', 'android-diagnostics')
395+
const base = path.join(
396+
dir,
397+
`${new Date().toISOString().replace(/[:.]/g, '-')}-${name.replace(/[^\w-]+/g, '_').slice(0, 80)}`
398+
)
399+
fs.mkdirSync(dir, { recursive: true })
400+
401+
const focus = adb(['shell', 'dumpsys', 'window'])
402+
const focusLines = (focus.stdout ?? '')
403+
.split('\n')
404+
.filter((line) => /mCurrentFocus|mFocusedApp|mFocusedWindow/.test(line))
405+
.map((line) => line.trim())
406+
console.warn(`[android diagnostics] ${name}\n ${focusLines.join('\n ')}`)
407+
// eslint-disable-next-line security/detect-non-literal-fs-filename
408+
fs.writeFileSync(`${base}.window.txt`, focus.stdout ?? '')
409+
410+
const screenshot = spawnSync(
411+
adbBinary(),
412+
[...adbDeviceArgs(), 'exec-out', 'screencap', '-p'],
413+
{ timeout: 20_000 }
414+
)
415+
if (screenshot.status === 0) {
416+
// eslint-disable-next-line security/detect-non-literal-fs-filename
417+
fs.writeFileSync(`${base}.png`, screenshot.stdout)
418+
}
419+
420+
const logcat = adb(['logcat', '-d', '-t', '20000'])
421+
// eslint-disable-next-line security/detect-non-literal-fs-filename
422+
fs.writeFileSync(`${base}.logcat.txt`, logcat.stdout ?? '')
423+
}
424+
339425
function androidCapabilities(app: string): WebdriverIO.Capabilities {
340426
return {
341427
platformName: 'Android',

‎plugins/shell/src/process/mod.rs‎

Lines changed: 22 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -7,8 +7,8 @@ use std::{
77
io::{BufRead, BufReader, Write},
88
path::{Path, PathBuf},
99
process::{Command as StdCommand, Stdio},
10-
sync::{Arc, RwLock},
11-
thread::spawn,
10+
sync::Arc,
11+
thread::{JoinHandle, spawn},
1212
};
1313

1414
#[cfg(unix)]
@@ -315,42 +315,29 @@ impl Command {
315315
let shared_child = SharedChild::spawn(&mut command)?;
316316
let child = Arc::new(shared_child);
317317
let child_ = child.clone();
318-
let guard = Arc::new(RwLock::new(()));
319-
320318
let (tx, rx) = channel(1);
321319

322-
spawn_pipe_reader(
323-
tx.clone(),
324-
guard.clone(),
325-
stdout_reader,
326-
CommandEvent::Stdout,
327-
raw,
328-
);
329-
spawn_pipe_reader(
330-
tx.clone(),
331-
guard.clone(),
332-
stderr_reader,
333-
CommandEvent::Stderr,
334-
raw,
335-
);
320+
let stdout_thread = spawn_pipe_reader(tx.clone(), stdout_reader, CommandEvent::Stdout, raw);
321+
let stderr_thread = spawn_pipe_reader(tx.clone(), stderr_reader, CommandEvent::Stderr, raw);
336322

337323
spawn(move || {
338-
let _ = match child_.wait() {
339-
Ok(status) => {
340-
let _l = guard.write().unwrap();
341-
block_on_task(async move {
342-
tx.send(CommandEvent::Terminated(TerminatedPayload {
343-
code: status.code(),
344-
#[cfg(windows)]
345-
signal: None,
346-
#[cfg(unix)]
347-
signal: status.signal(),
348-
}))
349-
.await
350-
})
351-
}
324+
let status = child_.wait();
325+
// `Terminated` must be the last event: wait for the readers to drain the pipes,
326+
// since a short-lived child can exit before they have read anything.
327+
let _ = stdout_thread.join();
328+
let _ = stderr_thread.join();
329+
let _ = match status {
330+
Ok(status) => block_on_task(async move {
331+
tx.send(CommandEvent::Terminated(TerminatedPayload {
332+
code: status.code(),
333+
#[cfg(windows)]
334+
signal: None,
335+
#[cfg(unix)]
336+
signal: status.signal(),
337+
}))
338+
.await
339+
}),
352340
Err(e) => {
353-
let _l = guard.write().unwrap();
354341
block_on_task(async move { tx.send(CommandEvent::Error(e.to_string())).await })
355342
}
356343
};
@@ -489,21 +476,19 @@ fn read_line<F: Fn(Vec<u8>) -> CommandEvent + Send + Copy + 'static>(
489476

490477
fn spawn_pipe_reader<F: Fn(Vec<u8>) -> CommandEvent + Send + Copy + 'static>(
491478
tx: Sender<CommandEvent>,
492-
guard: Arc<RwLock<()>>,
493479
pipe_reader: PipeReader,
494480
wrapper: F,
495481
raw_out: bool,
496-
) {
482+
) -> JoinHandle<()> {
497483
spawn(move || {
498-
let _lock = guard.read().unwrap();
499484
let reader = BufReader::new(pipe_reader);
500485

501486
if raw_out {
502487
read_raw_bytes(reader, tx, wrapper);
503488
} else {
504489
read_line(reader, tx, wrapper);
505490
}
506-
});
491+
})
507492
}
508493

509494
// tests for the commands functions.

0 commit comments

Comments
 (0)