Skip to content

Commit 437465f

Browse files
authored
ci(1874): declare the diagnose lane and read its iterations honestly (#2059)
The loop that #1874 is investigated with could not tell the truth about itself. It classified every non-`passed` iteration as a stall, which after #2035 gave the looped test an XCTSkipIf meant an environment flip would report a 100% stall rate; it captured cadence only for failures, though an absorbed episode now passes; and it read its logs with shell pipelines whose exit status means "did this match", so an iteration that legitimately matched nothing killed the job before it could be summarized. scripts/diagnose-1874-iteration.ts reads one iteration: xcodebuild's own verdict, the `type-all` duration, and the cadence worth keeping. A nonzero exit outranks a green measured test — in `pair` mode the neighbour or the runner can fail while the measured test passes — and a run that produced no verdict is named as ours rather than counted as a stall. The workflow gains the #1781 lane declaration it never had. Its kill criterion names #2080, which the loop can now serve rather than merely claim to: the looped test is a dispatch input, so the fill route that #2080 traces loops the same way. One test pins the contract the script cannot check about itself — that the workflow hands it the status xcodebuild returned rather than a literal. Closes #1874. Both filed symptoms are resolved. `smoke:form-input` was root-caused and fixed in #2035: the fixture's placeholder was identical to the value every suite filled, so `fill` could never be verified on the penalized route — deterministic, not a flake, and only visible under load because that route is gated on a penalized XCTest channel. The targeted XCTest is mitigated by the progress-aware commit budget, with 200 consecutive green loop iterations across two dispatches. The issue's remaining question — why the input pipeline throttles — is answered by the second dispatch, and the premise was wrong: it does not. Posting 17 characters took 484 ms and the commit was observed on the first poll, inside an iteration whose `type-all` measured 14334 ms. The ~12.6 s went to accessibility round-trips before any character was posted, which is #1105's path, not the input pipeline's.
1 parent 5e30451 commit 437465f

4 files changed

Lines changed: 274 additions & 17 deletions

File tree

.github/workflows/1874-diagnose.yml

Lines changed: 36 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -1,12 +1,29 @@
11
name: 1874 Diagnose
22

3+
# Under the lane rule in #1781:
4+
#
5+
# - Catches: iOS text-entry commit episodes on CI hardware — the dispatched test looped on both
6+
# arches, with and without the neighbour test that shares the simulator. An absorbed episode
7+
# surfaces as a slow pass, so the cadence is kept for passes too.
8+
# - Evidence: the 2026-08-21 dispatch passed 50/50 and still caught an episode (`type-all`
9+
# 2487 ms across 5 polls) that no PR lane would report; it does not reproduce locally.
10+
# - Cost: manual dispatch and the `diagnose/1874-commit-stall` branch only — never a PR or `main`.
11+
# One dispatch is four macOS slots, each a runner build plus `iterations` iterations of
12+
# simulator time.
13+
# - Kill criterion: delete when #2080 closes. It is the last open text-entry question this loop
14+
# is the CI reproduction path for, and nothing else reads these artifacts.
15+
316
on:
417
workflow_dispatch:
518
inputs:
619
iterations:
720
description: 'Loop iterations per job'
821
required: false
922
default: '25'
23+
test:
24+
description: 'RunnerTests method to loop'
25+
required: false
26+
default: testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden
1027
push:
1128
branches:
1229
- diagnose/1874-commit-stall
@@ -57,12 +74,17 @@ jobs:
5774
preferred-device-name: iPhone 17 Pro
5875

5976
- name: Stall loop
77+
env:
78+
ITERATIONS_INPUT: ${{ github.event.inputs.iterations }}
79+
TEST_INPUT: ${{ github.event.inputs.test }}
6080
run: |
6181
set -euo pipefail
6282
XCTESTRUN_PATH="$(find "$AGENT_DEVICE_IOS_RUNNER_DERIVED_PATH/Build/Products" -maxdepth 1 -name '*.xctestrun' -print -quit)"
6383
test -n "$XCTESTRUN_PATH"
6484
UDID="${{ steps.ios-simulator.outputs.simulator-udid }}"
65-
ITER="${{ github.event.inputs.iterations || '25' }}"
85+
ITER="${ITERATIONS_INPUT:-25}"
86+
TEST_NAME="${TEST_INPUT:-testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden}"
87+
mkdir -p .tmp
6688
6789
if [ "${{ matrix.mode }}" = "pair" ]; then
6890
EXTRA_ONLY_TESTING=(-only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareDelayedTypeFailsWhenTappedInputDisappearsMidCommand)
@@ -73,33 +95,30 @@ jobs:
7395
sys_prof="$(system_profiler SPHardwareDataType 2>/dev/null | grep -E 'Chip|Cores|Memory' || true)"
7496
echo "HOST: $sys_prof" | tee stall-summary.txt
7597
76-
pass=0; fail=0
98+
pass=0; skipped=0; failed=0; noresult=0; runfailed=0
7799
for i in $(seq 1 "$ITER"); do
78100
LOG=".tmp/stall-run-$i.log"
79101
set +e
80102
xcodebuild test-without-building \
81103
-xctestrun "$XCTESTRUN_PATH" \
82104
-destination "platform=iOS Simulator,id=$UDID" \
83-
-only-testing:AgentDeviceRunnerUITests/RunnerTests/testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden \
105+
-only-testing:"AgentDeviceRunnerUITests/RunnerTests/$TEST_NAME" \
84106
${EXTRA_ONLY_TESTING[@]+"${EXTRA_ONLY_TESTING[@]}"} \
85107
> "$LOG" 2>&1
86108
rc=$?
87109
set -e
88-
if grep -q "testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden]' passed" "$LOG"; then
89-
pass=$((pass+1)); verdict=pass
90-
else
91-
fail=$((fail+1)); verdict=STALL
92-
fi
93-
phase="$(grep -o 'phase=type-all durationMs=[0-9.]*' "$LOG" | tail -1)"
94-
polls="$(grep -c 'DEBUG-1874] poll' "$LOG" || true)"
95-
echo "iter=$i verdict=$verdict rc=$rc $phase polls=$polls" | tee -a stall-summary.txt
96-
if [ "$verdict" = "STALL" ]; then
97-
grep 'DEBUG-1874' "$LOG" | head -40 | tee -a stall-summary.txt
98-
cp "$LOG" ".tmp/stall-failure-$i.log"
99-
fi
110+
verdict="$(node --experimental-strip-types scripts/diagnose-1874-iteration.ts \
111+
"$LOG" "$TEST_NAME" "$i" "$rc")"
112+
case "$verdict" in
113+
passed) pass=$((pass+1)) ;;
114+
skipped) skipped=$((skipped+1)) ;;
115+
no-result) noresult=$((noresult+1)) ;;
116+
run-failed) runfailed=$((runfailed+1)) ;;
117+
*) failed=$((failed+1)) ;;
118+
esac
100119
done
101120
102-
echo "RESULT arch=${{ matrix.arch }} mode=${{ matrix.mode }}: $pass passed, $fail stalled of $ITER" | tee -a stall-summary.txt
121+
echo "RESULT arch=${{ matrix.arch }} mode=${{ matrix.mode }}: $pass passed, $skipped skipped, $failed failed, $noresult no-result, $runfailed run-failed of $ITER" | tee -a stall-summary.txt
103122
104123
- name: Upload stall evidence
105124
if: always()
@@ -109,5 +128,5 @@ jobs:
109128
include-hidden-files: true
110129
path: |
111130
stall-summary.txt
112-
.tmp/stall-failure-*.log
131+
.tmp/stall-evidence-*.log
113132
if-no-files-found: ignore
Lines changed: 157 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,157 @@
1+
import { execFileSync } from 'node:child_process';
2+
import fs from 'node:fs';
3+
import os from 'node:os';
4+
import path from 'node:path';
5+
import { fileURLToPath } from 'node:url';
6+
import { expect, test } from 'vitest';
7+
import { readIteration, type IterationReport } from '../diagnose-1874-iteration.ts';
8+
9+
const root = path.join(path.dirname(fileURLToPath(import.meta.url)), '../..');
10+
const script = path.join(root, 'scripts/diagnose-1874-iteration.ts');
11+
const WORKFLOW = path.join(root, '.github/workflows/1874-diagnose.yml');
12+
const NAME = 'testBareTypeUsesTappedInputWhenSoftwareKeyboardIsHidden';
13+
const POLL = '[DEBUG-1874] poll t=1ms observedLen=0 expectedPrefixLen=0';
14+
const CADENCE = [
15+
'[DEBUG-1874] wait start expectedLen=17',
16+
POLL,
17+
'[DEBUG-1874] wait outcome=settled',
18+
];
19+
20+
const verdictLine = (test: string, word: string) =>
21+
`Test Case '-[X.RunnerTests ${test}]' ${word} (1.0 seconds).`;
22+
const phases = (typeAllMs: string) =>
23+
[
24+
`phase=focus durationMs=644.6`,
25+
`phase=type-all durationMs=${typeAllMs}`,
26+
`phase=total durationMs=7379.7`,
27+
].map((phase) => `AGENT_DEVICE_RUNNER_TEXT_ENTRY_PHASE commandId=c ${phase} chars=17`);
28+
29+
const SHAPES: readonly (Partial<IterationReport> & { name: string; log: string[]; rc?: number })[] =
30+
[
31+
{
32+
name: 'healthy pass',
33+
log: [verdictLine(NAME, 'passed'), ...phases('796.1'), ...CADENCE],
34+
verdict: 'passed',
35+
keepEvidence: false,
36+
lines: ['iter=1 verdict=passed rc=0 durationMs=796.1 polls=1'],
37+
},
38+
{
39+
name: 'slow pass — an absorbed episode, which is the evidence #1874 wants',
40+
log: [verdictLine(NAME, 'passed'), ...phases('14146.4'), ...CADENCE],
41+
verdict: 'passed',
42+
keepEvidence: true,
43+
lines: ['iter=1 verdict=passed rc=0 durationMs=14146.4 polls=1', ...CADENCE],
44+
},
45+
{
46+
name: 'a pass a tenth of a millisecond over the slow threshold is still slow',
47+
log: [verdictLine(NAME, 'passed'), ...phases('2000.1'), ...CADENCE],
48+
verdict: 'passed',
49+
keepEvidence: true,
50+
},
51+
{
52+
name: 'skipped — an environment flip, not a stall',
53+
log: [verdictLine(NAME, 'skipped')],
54+
verdict: 'skipped',
55+
keepEvidence: true,
56+
lines: ['iter=1 verdict=skipped rc=0 durationMs=0 polls=0'],
57+
},
58+
{
59+
name: 'no verdict at all — ours to own, not the product’s',
60+
log: ['Executed 0 tests, with 0 failures (0 unexpected) in 0.000 seconds'],
61+
verdict: 'no-result',
62+
keepEvidence: true,
63+
},
64+
{
65+
name: 'a verdict word this loop does not model is not a stall either',
66+
log: [verdictLine(NAME, 'errored')],
67+
verdict: 'no-result',
68+
},
69+
{
70+
name: 'pair mode — the neighbour test logs first',
71+
log: [
72+
verdictLine('testBareDelayedTypeFailsWhenTappedInputDisappearsMidCommand', 'passed'),
73+
'AGENT_DEVICE_RUNNER_TEXT_ENTRY_PHASE commandId=n phase=type-all durationMs=5000.0 chars=17',
74+
verdictLine(NAME, 'passed'),
75+
...phases('812.0'),
76+
],
77+
verdict: 'passed',
78+
keepEvidence: false,
79+
},
80+
{
81+
name: 'restarted — the final word is the outcome',
82+
log: [verdictLine(NAME, 'failed'), ...phases('900.0'), verdictLine(NAME, 'passed')],
83+
verdict: 'passed',
84+
keepEvidence: false,
85+
},
86+
{
87+
name: 'measured test passed, xcodebuild did not',
88+
log: [verdictLine(NAME, 'passed'), ...phases('796.1'), ...CADENCE],
89+
rc: 65,
90+
verdict: 'run-failed',
91+
keepEvidence: true,
92+
},
93+
{
94+
name: 'louder than the cadence cap',
95+
log: [verdictLine(NAME, 'failed'), ...Array.from({ length: 45 }, () => POLL)],
96+
verdict: 'failed',
97+
keepEvidence: true,
98+
lines: [
99+
'iter=1 verdict=failed rc=0 durationMs=0 polls=45',
100+
...Array.from({ length: 40 }, () => POLL),
101+
'… 5 more DEBUG-1874 lines (full log in the artifact)',
102+
],
103+
},
104+
];
105+
106+
test.each(SHAPES)('reads a $name iteration', (shape) => {
107+
const report = readIteration(shape.log.join('\n'), NAME, 1, shape.rc ?? 0);
108+
expect(report.verdict).toBe(shape.verdict);
109+
if (shape.keepEvidence !== undefined) expect(report.keepEvidence).toBe(shape.keepEvidence);
110+
if (shape.lines) expect(report.lines).toEqual(shape.lines);
111+
});
112+
113+
test('the workflow forwards the exit status xcodebuild actually returned', () => {
114+
const workflow = fs.readFileSync(WORKFLOW, 'utf8');
115+
expect(workflow).toContain('rc=$?');
116+
expect(workflow).toMatch(/diagnose-1874-iteration\.ts \\\n\s*"\$LOG" "\$TEST_NAME" "\$i" "\$rc"/);
117+
});
118+
119+
test('the test name is matched literally, not as a pattern', () => {
120+
const log = verdictLine('testAXB', 'passed');
121+
expect(readIteration(log, 'testA.B', 1, 0).verdict).toBe('no-result');
122+
expect(readIteration(log, 'testAXB', 1, 0).verdict).toBe('passed');
123+
});
124+
125+
test.each([
126+
{ label: 'slow pass', rc: 0, verdict: 'passed' },
127+
{ label: 'nonzero exit over a green measured test', rc: 65, verdict: 'run-failed' },
128+
])(
129+
'the entry point writes, keeps evidence and prints the verdict for a $label',
130+
({ rc, verdict }) => {
131+
const cwd = fs.mkdtempSync(path.join(os.tmpdir(), 'diagnose-1874-'));
132+
try {
133+
fs.mkdirSync(path.join(cwd, '.tmp'));
134+
const log = path.join(cwd, 'iteration.log');
135+
fs.writeFileSync(
136+
log,
137+
[verdictLine(NAME, 'passed'), ...phases('14146.4'), ...CADENCE].join('\n'),
138+
);
139+
140+
const printed = execFileSync(
141+
process.execPath,
142+
['--experimental-strip-types', script, log, NAME, '7', `${rc}`],
143+
{ cwd, encoding: 'utf8' },
144+
);
145+
146+
expect(printed).toBe(verdict);
147+
expect(fs.readFileSync(path.join(cwd, 'stall-summary.txt'), 'utf8')).toBe(
148+
[`iter=7 verdict=${verdict} rc=${rc} durationMs=14146.4 polls=1`, ...CADENCE, ''].join(
149+
'\n',
150+
),
151+
);
152+
expect(fs.existsSync(path.join(cwd, '.tmp', 'stall-evidence-7.log'))).toBe(true);
153+
} finally {
154+
fs.rmSync(cwd, { recursive: true, force: true });
155+
}
156+
},
157+
);

scripts/diagnose-1874-iteration.ts

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
import fs from 'node:fs';
2+
import path from 'node:path';
3+
import { pathToFileURL } from 'node:url';
4+
5+
const SLOW_PASS_MS = 2000;
6+
const CADENCE_LIMIT = 40;
7+
const SUMMARY = 'stall-summary.txt';
8+
const EVIDENCE_DIR = '.tmp';
9+
10+
type MeasuredVerdict = 'passed' | 'skipped' | 'failed';
11+
12+
export type IterationReport = {
13+
readonly verdict: MeasuredVerdict | 'no-result' | 'run-failed';
14+
readonly keepEvidence: boolean;
15+
readonly lines: readonly string[];
16+
};
17+
18+
export function readIteration(
19+
log: string,
20+
testName: string,
21+
iteration: number,
22+
rc: number,
23+
): IterationReport {
24+
const lines = log.split('\n');
25+
const marker = `${testName}]' `;
26+
const word = lines
27+
.filter((line) => line.includes(marker))
28+
.map((line) => line.slice(line.indexOf(marker) + marker.length).split(' ')[0])
29+
.at(-1);
30+
const measured = isMeasuredVerdict(word) ? word : 'no-result';
31+
const exitContradictsMeasured = rc !== 0 && measured !== 'failed' && measured !== 'no-result';
32+
const verdict = exitContradictsMeasured ? 'run-failed' : measured;
33+
const durationMs = Number(
34+
lines
35+
.flatMap((line) => /phase=type-all durationMs=(\d+(?:\.\d+)?)/.exec(line)?.[1] ?? [])
36+
.at(-1) ?? 0,
37+
);
38+
const cadence = lines.filter((line) => line.includes('[DEBUG-1874]'));
39+
const keepEvidence = verdict !== 'passed' || durationMs > SLOW_PASS_MS;
40+
41+
const polls = cadence.filter((line) => line.includes('] poll')).length;
42+
const summary = `iter=${iteration} verdict=${verdict} rc=${rc} durationMs=${durationMs} polls=${polls}`;
43+
const dropped = cadence.length - CADENCE_LIMIT;
44+
return {
45+
verdict,
46+
keepEvidence,
47+
lines: !keepEvidence
48+
? [summary]
49+
: [
50+
summary,
51+
...cadence.slice(0, CADENCE_LIMIT),
52+
...(dropped > 0 ? [`… ${dropped} more DEBUG-1874 lines (full log in the artifact)`] : []),
53+
],
54+
};
55+
}
56+
57+
function isMeasuredVerdict(word: string | undefined): word is MeasuredVerdict {
58+
return word === 'passed' || word === 'skipped' || word === 'failed';
59+
}
60+
61+
function main(): number {
62+
const [logPath, testName, iteration, rc] = process.argv.slice(2);
63+
if (!logPath || !testName || !iteration || !rc) {
64+
throw new Error('usage: diagnose-1874-iteration.ts <log> <testName> <iteration> <rc>');
65+
}
66+
const report = readIteration(
67+
fs.readFileSync(logPath, 'utf8'),
68+
testName,
69+
Number(iteration),
70+
Number(rc),
71+
);
72+
fs.appendFileSync(SUMMARY, `${report.lines.join('\n')}\n`);
73+
if (report.keepEvidence) {
74+
fs.copyFileSync(logPath, path.join(EVIDENCE_DIR, `stall-evidence-${iteration}.log`));
75+
}
76+
process.stdout.write(report.verdict);
77+
return 0;
78+
}
79+
80+
if (import.meta.url === pathToFileURL(process.argv[1] ?? '').href) process.exit(main());

vitest.config.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -153,6 +153,7 @@ export default defineConfig({
153153
// Parses CI configuration only, so this action guard needs no device or subprocess lane.
154154
'test/ci/upload-agent-device-artifacts.test.ts',
155155
'test/ci/upload-artifact-hidden-paths.test.ts',
156+
'scripts/__tests__/diagnose-1874-iteration.test.ts',
156157
// The size reporter is preserved across a base checkout; its entrypoint and imported
157158
// modules must move as one directory or the Bundle Size lane fails before measuring.
158159
'test/ci/size-workflow.test.ts',

0 commit comments

Comments
 (0)