From 746672250ec3c3910c7dfd05102fd361c5c34070 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 17:52:09 +0200 Subject: [PATCH 1/8] docs: record post-merge simulator connection evidence --- docs/BUILD_INCIDENT_2026-10.md | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/docs/BUILD_INCIDENT_2026-10.md b/docs/BUILD_INCIDENT_2026-10.md index a3cd67b..4a79182 100644 --- a/docs/BUILD_INCIDENT_2026-10.md +++ b/docs/BUILD_INCIDENT_2026-10.md @@ -62,3 +62,24 @@ reported error. Build failures, nonzero driver exits, test failures and timeouts after the driver begins remain failures. Recovery does not rebuild the APP or retry failed assertions. The exact underlying failure in the original silent launch remains unknown; new verbose attempt evidence makes recurrence diagnosable. + +## 11 October: retained evidence identifies missed VM-service discovery + +The complete PR verification passed, but the subsequent [main run +38142017784](https://github.com/getbible/app/actions/runs/38142017784) failed both +iOS runtime jobs. All seven package builds and the other platform checks passed. +The new watchdog retained evidence and stopped each unsuccessful launch attempt +after three minutes; it did not resolve the underlying connection problem. + +On the first attempt, both apps actually started. The iPhone unified log records +the Dart VM service at 13:19:29 UTC; the iPad records it at 13:18:46 UTC. Flutter +continued waiting for that service in both cases and never invoked the host test +driver. The second attempts stalled inside `simctl launch`. No application test +assertion ran or failed in these jobs. Increasing the discovery timeout alone +does not address a service announcement missed by the live log listener. + +Flutter 3.44.6 provides `drive --use-existing-app=` to attach directly to an +already-running application. The repair must discover the authenticated service +URL from retained unified logs scoped to the current launch, then use this +supported connection path while preserving all six acceptance tests and their +failure semantics. The already-published alpha 5 assets remain unchanged. From 05b0f53dd9eb2bddf6634e5e675780d796b5d412 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 17:55:23 +0200 Subject: [PATCH 2/8] fix(ci): attach iOS acceptance through persisted VM service discovery --- scripts/testing/run_ios_acceptance.py | 179 +++++++++++++---- scripts/tests/test_ios_simulator.py | 272 ++++++++++++++++++-------- 2 files changed, 326 insertions(+), 125 deletions(-) diff --git a/scripts/testing/run_ios_acceptance.py b/scripts/testing/run_ios_acceptance.py index 6015d0a..dab03c1 100644 --- a/scripts/testing/run_ios_acceptance.py +++ b/scripts/testing/run_ios_acceptance.py @@ -1,21 +1,24 @@ #!/usr/bin/env python3 """Build once and run iOS acceptance with bounded, diagnosable simulator waits. -Flutter 3.44.6 waits without a deadline for the simulator's VM service. Its -``drive --timeout`` starts only after launch, so it cannot cover that wait. -Only an observed pre-driver install/launch/VM wait may receive one reboot. Build -failures, driver failures and started test journeys are never retried. +Flutter's live simulator log stream can miss the VM service announcement. +Install and launch the built app paused, discover its authenticated VM URI from +the durable system log, then attach the unchanged Flutter test driver. Only a +pre-driver startup timeout may receive one reboot; failed tests are not retried. """ import codecs +from datetime import datetime, timezone import json import os from pathlib import Path +import plistlib import re import signal import subprocess import sys import time +from urllib.parse import urlsplit OUTPUT = Path('build/runtime-evidence') @@ -29,6 +32,7 @@ BOOT_SECONDS = 3 * 60 ATTACH_SECONDS = 3 * 60 TEST_SECONDS = 12 * 60 +LOG_QUERY_SECONDS = 30 class CommandFailure(RuntimeError): @@ -44,27 +48,15 @@ def __init__(self, stage, *, session_expired=False): class DriverProgress: - """Conservative recovery boundary tied to the pinned Flutter SDK's output. - - Drive starts paused. Once its host driver is invoked it can resume the app; - treat even its *connecting* message as started and never retry after it. - Keep a small rolling tail so markers split across OS writes are recognized. - """ + """Recognize the host driver, including markers split across output writes.""" def __init__(self, clock=time.monotonic): self.clock = clock - self.launch_observed = False self.driver_started_at = None - self.saw_failure = False self.tail = '' def observe(self, text): observed = self.tail + text - self.launch_observed |= ( - 'Waiting for VM Service port to be available' in observed - or bool(re.search(r'executing: [^\n]*\bxcrun\b[^\n]*\bsimctl ' - r'(?:install|launch) ', observed)) - ) started = ( 'Connecting to Flutter application at' in observed or 'Attempting to resume isolate' in observed @@ -75,19 +67,60 @@ def observe(self, text): ) if started and self.driver_started_at is None: self.driver_started_at = self.clock() - self.saw_failure |= bool(re.search( - r'Unhandled exception|EXCEPTION CAUGHT|\[E\]|Some tests failed|' - r'Error waiting for a debug connection|Application failed to start|' - r'EXC_BAD_ACCESS|EXC_CRASH|Fatal signal|Lost connection to device|' - r'Unable to (?:install|launch)|ProcessException|\b(?:Error|Exception):', - observed, - )) self.tail = observed[-8192:] - @property - def retryable(self): - return (self.launch_observed and self.driver_started_at is None - and not self.saw_failure) + +class VmServiceDiscovery: + """Read only this launch's authenticated loopback endpoint from Apple logs. + + Persisted logs avoid the race between app startup and ``log stream`` becoming + ready. PID, executable and launch time prevent attaching to an earlier app. + Authentication remains enabled, and the URL may never leave this host. + """ + + def __init__(self, pid, executable, started): + self.pid, self.executable, self.started = pid, executable, started + + def find(self, text): + # simctl can emit a getpwuid_r warning on stderr before the JSON array. + # Keep that evidence, but parse the complete structured stdout payload. + beginning = re.search(r'^\s*\[', text, flags=re.MULTILINE) + if beginning is None: + raise ValueError('Simulator log query did not return a JSON array.') + records = json.loads(text[beginning.start():]) + if not isinstance(records, list): + raise ValueError('Simulator log query must return an array.') + for record in reversed(records): + if (not isinstance(record, dict) or record.get('processID') != self.pid + or not isinstance(record.get('processImagePath'), str) + or Path(record['processImagePath']).name != self.executable): + continue + try: + timestamp = datetime.fromisoformat(record.get('timestamp', '')) + except (TypeError, ValueError): + continue + if timestamp.tzinfo is None or timestamp < self.started: + continue + message = record.get('eventMessage', '') + if not isinstance(message, str): + continue + match = re.search(r'The Dart VM service is listening on (\S+)', message) + if match is None: + continue + uri = match[1] + try: + parsed = urlsplit(uri) + valid = (parsed.scheme == 'http' and parsed.hostname in ('127.0.0.1', '::1') + and parsed.port is not None and 0 < parsed.port < 65536 + and parsed.username is None and parsed.password is None + and not parsed.query and not parsed.fragment + and re.fullmatch(r'/[A-Za-z0-9_=-]+/', parsed.path)) + except ValueError: + valid = False + if not valid: + raise ValueError('Simulator announced an invalid authenticated loopback VM URI.') + return uri + return None class ProcessRunner: @@ -181,9 +214,7 @@ def run(self, command, stage, timeout, *, progress=None): self.event(stage=stage, status='failed', reason=str(error), elapsed_seconds=round(self.clock() - started, 2), **({} if progress is None else { - 'launch_observed': progress.launch_observed, 'driver_started': progress.driver_started_at is not None, - 'failure_observed': progress.saw_failure, })) raise finally: @@ -192,11 +223,68 @@ def run(self, command, stage, timeout, *, progress=None): class SimulatorAcceptance: - def __init__(self, runner): + def __init__(self, runner, *, application=APPLICATION, + utc_now=lambda: datetime.now(timezone.utc)): self.runner = runner + self.application = Path(application) + self.utc_now = utc_now self.identifier = None self.attempt = 0 + def application_identity(self): + with (self.application / 'Info.plist').open('rb') as source: + metadata = plistlib.load(source) + bundle = metadata.get('CFBundleIdentifier') + executable = metadata.get('CFBundleExecutable') + if (not isinstance(bundle, str) or not re.fullmatch(r'[A-Za-z0-9.-]+', bundle) + or not isinstance(executable, str) + or not re.fullmatch(r'[A-Za-z0-9_.-]+', executable)): + raise ValueError('Built iOS app has an invalid bundle identifier or executable.') + return bundle, executable + + def start_application(self, bundle, executable): + prefix = f'attempt-{self.attempt}' + deadline = min(self.runner.clock() + ATTACH_SECONDS, self.runner.deadline) + + def startup(command, stage, limit=ATTACH_SECONDS): + remaining = deadline - self.runner.clock() + if remaining <= 0: + raise StageTimeout(stage, session_expired=self.runner.clock() >= self.runner.deadline) + self.required(command, stage, min(limit, remaining)) + + startup(['xcrun', 'simctl', 'install', self.identifier, str(self.application)], + f'{prefix}/install') + # Apple log dates have subsecond precision. Filter the retained records + # at this second boundary and the exact PID returned by this launch. + started = self.utc_now().replace(microsecond=0) + startup(['xcrun', 'simctl', 'launch', self.identifier, bundle, + '--enable-dart-profiling', '--disable-vm-service-publication', + '--start-paused', '--enable-checked-mode', '--verify-entry-points'], + f'{prefix}/launch') + output = (self.runner.output / f'{prefix}/launch.log').read_text() + match = re.search(r'^' + re.escape(bundle) + r': ([1-9][0-9]*)\s*$', output, re.MULTILINE) + if match is None: + raise ValueError('simctl launch did not identify the started application process.') + discovery = VmServiceDiscovery(int(match[1]), executable, started) + query = 0 + self.runner.event(stage=f'{prefix}/discovery', status='started', pid=discovery.pid) + while self.runner.clock() < deadline: + query += 1 + stage = f'{prefix}/vm-service/{query:03d}' + startup(['xcrun', 'simctl', 'spawn', self.identifier, 'log', 'show', + '--last', '5m', + '--style', 'json', '--predicate', f'process == "{executable}"'], + stage, LOG_QUERY_SECONDS) + uri = discovery.find((self.runner.output / f'{stage}.log').read_text()) + if uri is not None: + self.runner.event(stage=f'{prefix}/discovery', status='ready', pid=discovery.pid) + return uri + remaining = deadline - self.runner.clock() + if remaining > 0: + self.runner.pause(min(1, remaining)) + raise StageTimeout(f'{prefix}/discovery', + session_expired=self.runner.clock() >= self.runner.deadline) + def required(self, command, stage, timeout): code = self.runner.run(command, stage, timeout) if code: @@ -253,32 +341,37 @@ def run(self, family): # the integration target. Drive then reuses exactly this built APP. self.required(['flutter', 'build', 'ios', '--simulator', '--debug', f'--target={TARGET}'], 'build', BUILD_SECONDS) + bundle, executable = self.application_identity() for attempt in (1, 2): self.attempt = attempt if attempt == 1 and device['state'] == 'Booted': self.ready() else: self.boot() - progress = DriverProgress(self.runner.clock) try: - code = self.runner.run([ - 'flutter', 'drive', '--verbose', '--no-pub', '--start-paused', - f'--driver={DRIVER}', f'--target={TARGET}', - f'--use-application-binary={APPLICATION}', '-d', self.identifier, - ], f'attempt-{attempt}/driver', ATTACH_SECONDS, progress=progress) - if code: - raise CommandFailure(f'attempt-{attempt}/driver', code) - if progress.driver_started_at is None: - raise RuntimeError('Flutter exited without evidence of a test driver.') - return 0 + uri = self.start_application(bundle, executable) except StageTimeout as error: - if attempt != 1 or error.session_expired or not progress.retryable: + if attempt != 1 or error.session_expired: raise self.runner.event(stage='recovery', status='rebooting', reason='Simulator install/launch/VM wait expired before test driver started') self.capture() self.required(['xcrun', 'simctl', 'shutdown', self.identifier], 'recovery/shutdown', 30) + continue + # This command may resume the paused app: no exception from + # attachment or the test journey is eligible for a new attempt. + progress = DriverProgress(self.runner.clock) + code = self.runner.run([ + 'flutter', 'drive', '--verbose', '--no-pub', + f'--driver={DRIVER}', f'--target={TARGET}', + f'--use-existing-app={uri}', '-d', self.identifier, + ], f'attempt-{attempt}/driver', ATTACH_SECONDS, progress=progress) + if code: + raise CommandFailure(f'attempt-{attempt}/driver', code) + if progress.driver_started_at is None: + raise RuntimeError('Flutter exited without evidence of a test driver.') + return 0 raise RuntimeError('Simulator attempts exhausted.') finally: # Separate bounded cleanup reserve, including failure during boot or diff --git a/scripts/tests/test_ios_simulator.py b/scripts/tests/test_ios_simulator.py index 08eb0de..42d6c0d 100644 --- a/scripts/tests/test_ios_simulator.py +++ b/scripts/tests/test_ios_simulator.py @@ -1,11 +1,13 @@ """Keep iOS infrastructure recovery bounded without retrying failed journeys.""" import contextlib +from datetime import datetime, timezone import importlib.util import io import json import os from pathlib import Path +import plistlib import signal import subprocess import tempfile @@ -17,7 +19,21 @@ SPEC = importlib.util.spec_from_file_location('ios_acceptance', SOURCE) ios = importlib.util.module_from_spec(SPEC) SPEC.loader.exec_module(ios) -VM_WAIT = 'Waiting for VM Service port to be available...\n' +VM_URI = 'http://127.0.0.1:50145/xHtX2JUvNj8=/' +STARTED = datetime(2026, 10, 11, 13, 18, 0, tzinfo=timezone.utc) +BUNDLE = 'life.getbible.acceptance' + + +def vm_record(**changes): + return { + 'processID': 10439, + 'processImagePath': '/Simulator/Containers/Runner.app/Runner', + 'timestamp': '2026-10-11 13:18:46.226000+0000', + 'eventMessage': f'flutter: The Dart VM service is listening on {VM_URI}', + **changes, + } + + DRIVER_START = 'VMServiceFlutterDriver: Connecting to Flutter application at http://127.0.0.1:1234\n' @@ -120,7 +136,6 @@ def test_driver_start_changes_to_test_budget_without_resetting_on_each_line(self with self.assertRaises(ios.StageTimeout): runner.run(['flutter', 'drive'], 'driver', 1, progress=progress) self.assertEqual(self.clock(), progress.driver_started_at + ios.TEST_SECONDS) - self.assertFalse(progress.retryable) def test_global_deadline_wins_even_after_driver_starts(self): runner = self.runner(events=[(0, DRIVER_START.encode())]) @@ -152,12 +167,19 @@ def missing(*args, **kwargs): class FakeRunner: - def __init__(self, output, outcomes=None): + def __init__(self, output, outcomes=None, *, query_records=None, delays=None): self.output = output self.clock = FakeClock() + self.pause = self.clock.pause self.deadline = ios.SESSION_SECONDS self.calls, self.events = [], [] self.outcomes = outcomes or {} + self.delays = delays or {} + self.query_records = [vm_record()] if query_records is None else query_records + self.application = self.output / 'Runner.app' + self.application.mkdir() + with (self.application / 'Info.plist').open('wb') as destination: + plistlib.dump({'CFBundleIdentifier': BUNDLE, 'CFBundleExecutable': 'Runner'}, destination) def event(self, **record): self.events.append(record) @@ -166,20 +188,32 @@ def run(self, command, stage, timeout, *, progress=None): self.calls.append((command, stage, timeout, self.deadline)) path = self.output / f'{stage}.log' path.parent.mkdir(parents=True, exist_ok=True) + message = '' if stage == 'available-devices': - path.write_text(json.dumps({'devices': { + message = json.dumps({'devices': { 'com.apple.CoreSimulator.SimRuntime.iOS-18-5': [ {'name': 'iPad Pro', 'udid': 'old', 'state': 'Shutdown', 'isAvailable': True}], 'com.apple.CoreSimulator.SimRuntime.iOS-26-2': [ {'name': 'iPhone 17', 'udid': 'phone', 'state': 'Shutdown', 'isAvailable': True}, {'name': 'iPad mini (A17 Pro)', 'udid': 'tablet', 'state': 'Shutdown', 'isAvailable': True}, - ]}})) + ]}}) + elif stage.endswith('/launch'): + message = f'{BUNDLE}: 10439\n' + elif '/vm-service/' in stage: + message = ('getpwuid_r did not find a match for uid 501\n' + + json.dumps(self.query_records)) + elif stage.endswith('/driver'): + message = DRIVER_START action = self.outcomes.get(stage, 0) if isinstance(action, tuple): message, action = action + path.write_text(message) + if progress is not None: progress.observe(message) - elif progress is not None: - progress.observe(DRIVER_START) + delay = self.delays.get(stage, 0) + self.pause(min(delay, timeout)) + if delay >= timeout: + raise ios.StageTimeout(stage, session_expired=self.clock() >= self.deadline) if isinstance(action, BaseException): raise action return action @@ -194,79 +228,130 @@ def setUp(self): self.directory = tempfile.TemporaryDirectory() self.addCleanup(self.directory.cleanup) self.output = Path(self.directory.name) + self.runner_count = 0 - def runner(self, outcomes=None): - return FakeRunner(self.output, outcomes) + def runner(self, outcomes=None, **options): + self.runner_count += 1 + output = self.output / str(self.runner_count) + output.mkdir() + return FakeRunner(output, outcomes, **options) - def test_build_once_then_use_exact_binary_on_selected_family(self): + def acceptance(self, runner): + return ios.SimulatorAcceptance(runner, application=runner.application, utc_now=lambda: STARTED) + + def test_build_once_install_exact_binary_and_attach_to_durable_vm_announcement(self): runner = self.runner() - self.assertEqual(ios.SimulatorAcceptance(runner).run('iPad'), 0) + self.assertEqual(self.acceptance(runner).run('iPad'), 0) self.assertEqual(runner.stages.count('build'), 1) - build = next(command for command, stage, _, _ in runner.calls if stage == 'build') - self.assertNotIn('--no-pub', build) - drive = next(command for command, stage, _, _ in runner.calls if stage.endswith('/driver')) - self.assertIn(f'--use-application-binary={ios.APPLICATION}', drive) + commands = {stage: command for command, stage, _, _ in runner.calls} + self.assertNotIn('--no-pub', commands['build']) + self.assertEqual(commands['attempt-1/install'], + ['xcrun', 'simctl', 'install', 'tablet', str(runner.application)]) + launch = commands['attempt-1/launch'] + self.assertEqual(launch[:5], ['xcrun', 'simctl', 'launch', 'tablet', BUNDLE]) + for flag in ('--start-paused', '--disable-vm-service-publication', + '--enable-checked-mode', '--verify-entry-points'): + self.assertIn(flag, launch) + self.assertNotIn('--disable-service-auth-codes', launch) + query = commands['attempt-1/vm-service/001'] + self.assertIn('show', query) + self.assertIn('--last', query) + self.assertIn('5m', query) + drive = commands['attempt-1/driver'] + self.assertIn(f'--use-existing-app={VM_URI}', drive) self.assertIn('--no-pub', drive) - self.assertIn('--start-paused', drive) + self.assertFalse(any(arg.startswith('--use-application-binary') for arg in drive)) self.assertEqual(drive[-1], 'tablet') - self.assertEqual(json.loads((self.output / 'device.json').read_text())['udid'], 'tablet') + self.assertEqual(json.loads((runner.output / 'device.json').read_text())['udid'], 'tablet') self.assertEqual(runner.stages[-1], 'cleanup/shutdown') - def test_only_observed_vm_stall_reboots_once_and_reuses_build(self): - runner = self.runner({'attempt-1/driver': (VM_WAIT, ios.StageTimeout('driver'))}) - self.assertEqual(ios.SimulatorAcceptance(runner).run('iPad'), 0) - self.assertEqual(runner.stages.count('build'), 1) - self.assertEqual(runner.stages.count('recovery/shutdown'), 1) - self.assertLess(runner.stages.index('attempt-1/screenshot'), - runner.stages.index('recovery/shutdown')) - self.assertLess(runner.stages.index('recovery/shutdown'), runner.stages.index('attempt-2/boot')) - self.assertIn('attempt-2/driver', runner.stages) - self.assertIn('attempt-2/screenshot', runner.stages) - - def test_second_vm_stall_fails_and_cleanup_still_runs(self): - runner = self.runner({f'attempt-{number}/driver': (VM_WAIT, ios.StageTimeout('driver')) + def test_pre_driver_startup_stall_reboots_once_and_reuses_build(self): + for failed_stage in ('install', 'launch', 'vm-service/001'): + with self.subTest(stage=failed_stage): + runner = self.runner({f'attempt-1/{failed_stage}': ios.StageTimeout(failed_stage)}) + self.assertEqual(self.acceptance(runner).run('iPad'), 0) + self.assertEqual(runner.stages.count('build'), 1) + self.assertEqual(runner.stages.count('recovery/shutdown'), 1) + self.assertLess(runner.stages.index('attempt-1/screenshot'), + runner.stages.index('recovery/shutdown')) + self.assertNotIn('attempt-1/driver', runner.stages) + self.assertIn('attempt-2/driver', runner.stages) + + def test_second_startup_stall_fails_and_cleanup_still_runs(self): + runner = self.runner({f'attempt-{number}/launch': ios.StageTimeout('launch') for number in (1, 2)}) with self.assertRaises(ios.StageTimeout): - ios.SimulatorAcceptance(runner).run('iPhone') + self.acceptance(runner).run('iPhone') self.assertEqual(runner.stages.count('recovery/shutdown'), 1) self.assertNotIn('attempt-3/driver', runner.stages) self.assertEqual(runner.stages[-1], 'cleanup/shutdown') - def test_test_failure_is_never_retried(self): - runner = self.runner({'attempt-1/driver': (VM_WAIT + DRIVER_START + 'Some tests failed', 7)}) - with self.assertRaises(ios.CommandFailure) as caught: - ios.SimulatorAcceptance(runner).run('iPad') - self.assertEqual(caught.exception.returncode, 7) - self.assertNotIn('recovery/shutdown', runner.stages) - self.assertEqual(runner.stages[-1], 'cleanup/shutdown') + def test_nonzero_stage_failures_are_never_retried(self): + for stage in ('build', 'attempt-1/boot', 'attempt-1/bootstatus', + 'attempt-1/install', 'attempt-1/launch', + 'attempt-1/vm-service/001', 'attempt-1/driver'): + with self.subTest(stage=stage): + runner = self.runner({stage: 7}) + with self.assertRaises(ios.CommandFailure) as caught: + self.acceptance(runner).run('iPad') + self.assertEqual(caught.exception.returncode, 7) + self.assertNotIn('recovery/shutdown', runner.stages) + self.assertEqual(runner.stages[-1], 'cleanup/shutdown') - def test_no_retry_on_started_unknown_or_error_launch_timeouts(self): - for message in (VM_WAIT + DRIVER_START, '', VM_WAIT + 'Unhandled exception: crash', - VM_WAIT + 'EXC_BAD_ACCESS', VM_WAIT + '00:01 +0: test started'): + def test_driver_timeout_is_never_retried_even_before_host_driver_output(self): + for message in (DRIVER_START, '', 'Unhandled exception: crash', '00:01 +0: test started'): with self.subTest(message=message): runner = self.runner({'attempt-1/driver': (message, ios.StageTimeout('driver'))}) with self.assertRaises(ios.StageTimeout): - ios.SimulatorAcceptance(runner).run('iPad') + self.acceptance(runner).run('iPad') self.assertNotIn('recovery/shutdown', runner.stages) self.assertEqual(runner.stages[-1], 'cleanup/shutdown') def test_session_budget_expiry_never_starts_recovery(self): - runner = self.runner({'attempt-1/driver': ( - VM_WAIT, ios.StageTimeout('driver', session_expired=True))}) + runner = self.runner({'attempt-1/launch': ios.StageTimeout('launch', session_expired=True)}) with self.assertRaises(ios.StageTimeout): - ios.SimulatorAcceptance(runner).run('iPad') + self.acceptance(runner).run('iPad') self.assertNotIn('recovery/shutdown', runner.stages) self.assertEqual(runner.stages[-1], 'cleanup/shutdown') - def test_build_and_boot_failures_are_not_retried_and_always_cleanup(self): - for stage in ('build', 'attempt-1/boot', 'attempt-1/bootstatus'): - with self.subTest(stage=stage): - runner = self.runner({stage: 5}) - with self.assertRaises(ios.CommandFailure): - ios.SimulatorAcceptance(runner).run('iPhone') - self.assertNotIn('attempt-1/driver', runner.stages) + def test_discovery_polling_shares_startup_budget_and_never_resets_deadline(self): + runner = self.runner(query_records=[], delays={ + 'attempt-1/install': 60, 'attempt-1/launch': 60, + 'attempt-2/install': 60, 'attempt-2/launch': 60}) + with self.assertRaisesRegex(ios.StageTimeout, 'discovery'): + self.acceptance(runner).run('iPad') + self.assertEqual(runner.clock(), 2 * ios.ATTACH_SECONDS) + self.assertNotIn('attempt-1/driver', runner.stages) + queries = [call for call in runner.calls if '/vm-service/' in call[1]] + self.assertTrue(queries) + self.assertLessEqual(max(call[2] for call in queries), ios.LOG_QUERY_SECONDS) + self.assertEqual(queries[-1][2], 1) + + def test_discovery_polling_respects_global_budget(self): + runner = self.runner(query_records=[]) + runner.deadline = 2.5 + with self.assertRaises(ios.StageTimeout) as caught: + self.acceptance(runner).run('iPad') + self.assertTrue(caught.exception.session_expired) + self.assertEqual(runner.clock(), 2.5) + self.assertNotIn('recovery/shutdown', runner.stages) + + def test_malformed_identity_launch_or_log_output_fails_without_retry(self): + for stage, output in (('attempt-1/launch', 'other.bundle: 123\n'), + ('attempt-1/launch', f'{BUNDLE}: 0\n'), + ('attempt-1/vm-service/001', 'not JSON')): + with self.subTest(stage=stage, output=output): + runner = self.runner({stage: (output, 0)}) + with self.assertRaises(ValueError): + self.acceptance(runner).run('iPad') self.assertNotIn('recovery/shutdown', runner.stages) - self.assertEqual(runner.stages[-1], 'cleanup/shutdown') + self.assertNotIn('attempt-1/driver', runner.stages) + runner = self.runner() + with (runner.application / 'Info.plist').open('wb') as target: + plistlib.dump({'CFBundleIdentifier': BUNDLE, 'CFBundleExecutable': '../Runner'}, target) + with self.assertRaises(ValueError): + self.acceptance(runner).run('iPad') + self.assertNotIn('attempt-1/install', runner.stages) def test_cleanup_failures_preserve_test_failure_and_shutdown_is_attempted(self): runner = self.runner({'attempt-1/driver': 9, @@ -274,7 +359,7 @@ def test_cleanup_failures_preserve_test_failure_and_shutdown_is_attempted(self): 'attempt-1/simulator-console': OSError('simctl hung'), 'cleanup/shutdown': ios.StageTimeout('shutdown')}) with self.assertRaises(ios.CommandFailure) as caught: - ios.SimulatorAcceptance(runner).run('iPad') + self.acceptance(runner).run('iPad') self.assertEqual(caught.exception.returncode, 9) self.assertEqual(runner.stages[-1], 'cleanup/shutdown') self.assertEqual(len([event for event in runner.events @@ -285,16 +370,58 @@ def test_cleanup_failures_preserve_test_failure_and_shutdown_is_attempted(self): def test_zero_exit_without_driver_evidence_fails_closed(self): runner = self.runner({'attempt-1/driver': ('', 0)}) with self.assertRaisesRegex(RuntimeError, 'without evidence'): - ios.SimulatorAcceptance(runner).run('iPad') + self.acceptance(runner).run('iPad') self.assertNotIn('recovery/shutdown', runner.stages) def test_invalid_family_does_not_invoke_platform_tools(self): runner = self.runner() with self.assertRaises(ValueError): - ios.SimulatorAcceptance(runner).run('watch') + self.acceptance(runner).run('watch') self.assertEqual(runner.calls, []) +class VmServiceDiscoveryTests(unittest.TestCase): + def setUp(self): + self.discovery = ios.VmServiceDiscovery(10439, 'Runner', STARTED) + + def test_persisted_announcement_with_simctl_warning_needs_no_live_stream(self): + output = 'getpwuid_r did not find a match for uid 501\n' + json.dumps([vm_record()]) + self.assertEqual(self.discovery.find(output), VM_URI) + + def test_ignores_other_pids_executables_stale_records_and_malformed_metadata(self): + for changes in ({'processID': 10440}, {'processID': '10439'}, + {'processImagePath': '/another/App'}, {'processImagePath': None}, + {'timestamp': '2026-10-11 13:17:59.999+0000'}, + {'timestamp': '2026-10-11 13:18:46'}, {'timestamp': 'invalid'}, + {'eventMessage': None}): + with self.subTest(changes=changes): + self.assertIsNone(self.discovery.find(json.dumps([vm_record(**changes)]))) + self.assertEqual(self.discovery.find(json.dumps([vm_record(processID=9), vm_record()])), VM_URI) + + def test_rejects_nonlocal_unauthenticated_and_malformed_announcements(self): + for uri in ('https://example.com:1234/auth=/', 'http://example.com:1234/auth=/', + 'http://127.0.0.1:1234/', 'http://127.0.0.1:0/auth=/', + 'http://127.0.0.1:99999/auth=/', 'http://127.0.0.1:port/auth=/', + 'http://127.0.0.1/auth=/', 'http://user@127.0.0.1:1234/auth=/', + 'http://127.0.0.1:1234/auth=/?redirect=1', + 'http://127.0.0.1:1234/auth=/#fragment', 'http://[::1'): + with self.subTest(uri=uri): + record = vm_record(eventMessage=f'The Dart VM service is listening on {uri}') + with self.assertRaises(ValueError): + self.discovery.find(json.dumps([record])) + + def test_accepts_authenticated_ipv6_loopback(self): + uri = 'http://[::1]:50145/a_token-=/' + record = vm_record(eventMessage=f'The Dart VM service is listening on {uri}') + self.assertEqual(self.discovery.find(json.dumps([record])), uri) + + def test_malformed_structured_output_fails_explicitly(self): + for output in ('not json', '{}', '[broken]', '[] trailing failure'): + with self.subTest(output=output): + with self.assertRaises(ValueError): + self.discovery.find(output) + + class PortabilityTests(unittest.TestCase): def test_import_without_killpg_preserves_pure_checks_and_rejects_native_execution(self): spec = importlib.util.spec_from_file_location('ios_acceptance_without_posix', SOURCE) @@ -302,45 +429,26 @@ def test_import_without_killpg_preserves_pure_checks_and_rejects_native_executio with patch.dict(os.__dict__): os.__dict__.pop('killpg', None) spec.loader.exec_module(module) - progress = module.DriverProgress() - progress.observe(VM_WAIT) - self.assertTrue(progress.retryable) + discovery = module.VmServiceDiscovery(10439, 'Runner', STARTED) + self.assertEqual(discovery.find(json.dumps([vm_record()])), VM_URI) with tempfile.TemporaryDirectory() as directory: with self.assertRaisesRegex(RuntimeError, 'POSIX host with Xcode'): module.ProcessRunner(Path(directory)) class DriverProgressTests(unittest.TestCase): - def test_large_output_chunk_cannot_hide_prior_driver_start_or_failure(self): - for prefix in (DRIVER_START, 'Unhandled exception: test failure\n'): - with self.subTest(prefix=prefix): - progress = ios.DriverProgress() - progress.observe(prefix + 'output\n' * 10000 + VM_WAIT) - self.assertFalse(progress.retryable) - self.assertLessEqual(len(progress.tail), 8192) - - def test_only_observed_install_launch_or_vm_wait_allows_recovery(self): - for command in ('/usr/bin/xcrun simctl install tablet Runner.app', - '/usr/bin/xcrun simctl launch tablet life.getbible.mobile --start-paused'): - with self.subTest(command=command): - progress = ios.DriverProgress() - progress.observe('[+5 ms] executing: ' + command + '\n') - self.assertTrue(progress.retryable) - progress.observe('Unable to launch life.getbible.mobile') - self.assertFalse(progress.retryable) + def test_large_output_chunk_cannot_hide_prior_driver_start(self): progress = ios.DriverProgress() - progress.observe('Waiting for another flutter command to release the startup lock') - self.assertFalse(progress.retryable) + progress.observe(DRIVER_START + 'output\n' * 10000) + self.assertIsNotNone(progress.driver_started_at) + self.assertLessEqual(len(progress.tail), 8192) def test_split_markers_and_verbose_host_driver_execution(self): progress = ios.DriverProgress() - progress.observe(VM_WAIT[:10]) - progress.observe(VM_WAIT[10:]) - self.assertTrue(progress.retryable) progress.observe('[+4 ms] executing: /opt/flutter/bin/cache/dart-sdk/bin/dart ' '--packages=.dart_tool/package_config.json test_driver/platform_') + self.assertIsNone(progress.driver_started_at) progress.observe('acceptance.dart\n') - self.assertFalse(progress.retryable) self.assertIsNotNone(progress.driver_started_at) From 13cf38da242dbbba85cff7c038755a4cb49e212f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 17:55:24 +0200 Subject: [PATCH 3/8] docs: explain deterministic iOS acceptance attachment --- docs/BUILD_INCIDENT_2026-10.md | 11 +++++++---- docs/TESTING.md | 26 ++++++++++++++++++-------- 2 files changed, 25 insertions(+), 12 deletions(-) diff --git a/docs/BUILD_INCIDENT_2026-10.md b/docs/BUILD_INCIDENT_2026-10.md index 4a79182..52384a1 100644 --- a/docs/BUILD_INCIDENT_2026-10.md +++ b/docs/BUILD_INCIDENT_2026-10.md @@ -79,7 +79,10 @@ assertion ran or failed in these jobs. Increasing the discovery timeout alone does not address a service announcement missed by the live log listener. Flutter 3.44.6 provides `drive --use-existing-app=` to attach directly to an -already-running application. The repair must discover the authenticated service -URL from retained unified logs scoped to the current launch, then use this -supported connection path while preserving all six acceptance tests and their -failure semantics. The already-published alpha 5 assets remain unchanged. +already-running application. The launcher now installs and launches the built +APP paused, obtains its process ID, and discovers the authenticated service URL +from retained unified logs scoped to that process, executable and launch time. +It uses the supported explicit connection path to run the same six acceptance +tests. Install, launch and discovery share one three-minute startup budget; +driver attachment and test failures never enter the reboot path. The published +alpha 5 assets remain unchanged. diff --git a/docs/TESTING.md b/docs/TESTING.md index 10a7a89..666729f 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -440,20 +440,30 @@ window/activity/power state, all-buffer logcat and a native screenshot. Syntheti widget focus alone does not establish Android clipboard permission. The iOS acceptance launcher builds the integration APP once and reuses it for -bounded launch attempts. It permits one simulator reboot only for an observed -install/launch/VM-service stall before the host test driver starts; reported -errors, failed tests and post-start timeouts are never retried. Build, boot, -attachment and test phases have separate limits inside a 38-minute session, -followed by a bounded cleanup reserve. Attempt logs go directly to disk, with -flushed stage events and simulator diagnostics. This prevents a silent launch -from consuming the whole 50-minute job and losing its evidence. +bounded launch attempts. It installs and launches the APP paused through +`simctl`, obtains the launched process ID, and discovers its authenticated Dart +VM-service URL from retained unified logs. Discovery checks the current process +and launch time; an old application instance cannot satisfy it. The URL must be +local to the simulator host. `flutter drive --use-existing-app` then connects +the same host driver and resumes the paused integration journey. VM-service +authentication remains enabled. This avoids depending on a live log listener +being ready when the app announces its service. + +One simulator reboot is permitted only for a bounded startup timeout before +driver attachment. Reported command errors, driver connection failures, failed +tests and post-start timeouts are never retried. Build, boot, attachment and test +phases have separate limits inside a 38-minute session, followed by a bounded +cleanup reserve. Attempt logs go directly to disk, with flushed stage events +and simulator diagnostics. This prevents a silent launch from consuming the +whole 50-minute job and losing its evidence. Initial device discovery receives the same three-minute startup allowance as boot: its first `simctl` invocation also initializes CoreSimulator on a cold host. `scripts/tests/test_ios_simulator.py` covers timeout boundaries, child-process termination, partial output, split/large log markers, one-time recovery and failure preservation. These Python checks complement actual iPhone/iPad CI execution; they do not establish native runtime acceptance by themselves. See -the [alpha 5 incident](BUILD_INCIDENT_2026-10.md#10-october-ipad-runtime-timeout-blocked-alpha-5-publication). +the [alpha 5 incident](BUILD_INCIDENT_2026-10.md#10-october-ipad-runtime-timeout-blocked-alpha-5-publication) +and the [post-merge discovery evidence](BUILD_INCIDENT_2026-10.md#11-october-retained-evidence-identifies-missed-vm-service-discovery). The production Web build uses bundled rendering resources, generated static shell inventory and Chromium, Firefox and WebKit runtime journeys under plain From e498d58ca07db2cea823b13b12416bc698bb18ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 18:16:18 +0200 Subject: [PATCH 4/8] fix(ci): preserve completed iOS results during process cleanup --- docs/BUILD_INCIDENT_2026-10.md | 9 ++++++ docs/TESTING.md | 7 +++++ scripts/testing/run_ios_acceptance.py | 31 ++++++++++++++------ scripts/tests/test_ios_simulator.py | 41 +++++++++++++++++++++++++++ 4 files changed, 79 insertions(+), 9 deletions(-) diff --git a/docs/BUILD_INCIDENT_2026-10.md b/docs/BUILD_INCIDENT_2026-10.md index 52384a1..c28a7f1 100644 --- a/docs/BUILD_INCIDENT_2026-10.md +++ b/docs/BUILD_INCIDENT_2026-10.md @@ -86,3 +86,12 @@ It uses the supported explicit connection path to run the same six acceptance tests. Install, launch and discovery share one three-minute startup budget; driver attachment and test failures never enter the reboot path. The published alpha 5 assets remain unchanged. + +Native verification of this connection path succeeded on iPhone on its first +attempt: retained-log discovery took 9.29 seconds and all six tests passed. It +also exposed a separate post-exit cleanup error: macOS rejected a process-group +signal after the driver had exited successfully. The existing-app command now +explicitly requests Flutter's application/device cleanup. A denied group signal +is recorded as a warning only when the command has already exited; it cannot +replace a completed command's result. Denied signals for running commands remain +errors, and the final simulator shutdown is still attempted. diff --git a/docs/TESTING.md b/docs/TESTING.md index 666729f..a2e66e1 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -449,6 +449,13 @@ the same host driver and resumes the paused integration journey. VM-service authentication remains enabled. This avoids depending on a live log listener being ready when the app announces its service. +The existing-app driver explicitly uses `--no-keep-app-running`, so Flutter +stops the application and disposes its device log readers after the journey. +If macOS refuses a process-group cleanup signal after the command has already +exited, the runner records that cleanup warning and preserves the command's +result. A signal failure while the command is still running remains fatal. +Simulator shutdown still runs within the separate cleanup reserve. + One simulator reboot is permitted only for a bounded startup timeout before driver attachment. Reported command errors, driver connection failures, failed tests and post-start timeouts are never retried. Build, boot, attachment and test diff --git a/scripts/testing/run_ios_acceptance.py b/scripts/testing/run_ios_acceptance.py index dab03c1..efacfd3 100644 --- a/scripts/testing/run_ios_acceptance.py +++ b/scripts/testing/run_ios_acceptance.py @@ -157,10 +157,8 @@ def stop(self, process): # Signal the group even if its leader exited: xcrun/Dart may leave a # descendant holding resources. Never kill unrelated runner processes. for sig, seconds in ((signal.SIGTERM, 10), (signal.SIGKILL, 5)): - try: - self.kill_group(process.pid, sig) - except ProcessLookupError: - pass + if not self.signal_group(process, sig): + return try: process.wait(timeout=seconds) except subprocess.TimeoutExpired: @@ -168,12 +166,27 @@ def stop(self, process): # A dead leader does not prove its descendants exited. SIGKILL the # remaining group after graceful shutdown without an unbounded wait. if sig == signal.SIGTERM: - try: - self.kill_group(process.pid, signal.SIGKILL) - except ProcessLookupError: - pass + self.signal_group(process, signal.SIGKILL) return + def signal_group(self, process, sig): + try: + self.kill_group(process.pid, sig) + except ProcessLookupError: + pass + except PermissionError: + code = process.poll() + if code is None: + # An owned command that is still running must remain a failure. + raise + # macOS may retain protected simulator descendants after the owned + # command exits. Record the denied cleanup without replacing that + # command's known result, and never escalate the denied signal. + self.event(stage='process-cleanup', status='permission_denied_after_exit', + pid=process.pid, returncode=code, signal=sig.name) + return False + return True + def run(self, command, stage, timeout, *, progress=None): started = self.clock() stage_deadline = started + timeout @@ -363,7 +376,7 @@ def run(self, family): # attachment or the test journey is eligible for a new attempt. progress = DriverProgress(self.runner.clock) code = self.runner.run([ - 'flutter', 'drive', '--verbose', '--no-pub', + 'flutter', 'drive', '--verbose', '--no-pub', '--no-keep-app-running', f'--driver={DRIVER}', f'--target={TARGET}', f'--use-existing-app={uri}', '-d', self.identifier, ], f'attempt-{attempt}/driver', ATTACH_SECONDS, progress=progress) diff --git a/scripts/tests/test_ios_simulator.py b/scripts/tests/test_ios_simulator.py index 42d6c0d..04e20b3 100644 --- a/scripts/tests/test_ios_simulator.py +++ b/scripts/tests/test_ios_simulator.py @@ -130,6 +130,46 @@ def test_actual_nonzero_status_is_preserved(self): runner = self.runner(end=0, code=17) self.assertEqual(runner.run(['command'], 'failed-test', 2), 17) + def test_denied_cleanup_after_exit_retains_success_or_failure_without_escalation(self): + for code in (0, 17): + for denied_signal in (signal.SIGTERM, signal.SIGKILL): + with self.subTest(code=code, denied_signal=denied_signal): + runner = self.runner(end=0, code=code) + signals = [] + + def signal_group(pid, sig): + signals.append(sig) + if sig == denied_signal: + raise PermissionError('protected simulator descendant') + + runner.kill_group = signal_group + self.assertEqual(runner.run(['command'], 'completed', 2), code) + expected = ([signal.SIGTERM] if denied_signal == signal.SIGTERM + else [signal.SIGTERM, signal.SIGKILL]) + self.assertEqual(signals, expected) + event = json.loads((self.output / 'stages.jsonl').read_text().splitlines()[-1]) + self.assertEqual(event['status'], 'permission_denied_after_exit') + self.assertEqual(event['pid'], self.child.pid) + self.assertEqual(event['returncode'], code) + self.assertEqual(event['signal'], denied_signal.name) + + def test_denied_cleanup_of_running_command_remains_fatal(self): + for denied_signal in (signal.SIGTERM, signal.SIGKILL): + with self.subTest(denied_signal=denied_signal): + runner = self.runner(ignore_term=True) + + def denied(pid, sig): + if sig == denied_signal: + raise PermissionError('running process cannot be terminated') + self.child.kill_group(pid, sig) + + runner.kill_group = denied + with self.assertRaisesRegex(PermissionError, 'running process'): + runner.run(['command'], 'running', 1) + self.assertIsNone(self.child.poll()) + self.assertNotIn('permission_denied_after_exit', + (self.output / 'stages.jsonl').read_text()) + def test_driver_start_changes_to_test_budget_without_resetting_on_each_line(self): runner = self.runner(events=[(0, DRIVER_START.encode()), (10, b'still working\n')]) progress = ios.DriverProgress(self.clock) @@ -260,6 +300,7 @@ def test_build_once_install_exact_binary_and_attach_to_durable_vm_announcement(s drive = commands['attempt-1/driver'] self.assertIn(f'--use-existing-app={VM_URI}', drive) self.assertIn('--no-pub', drive) + self.assertIn('--no-keep-app-running', drive) self.assertFalse(any(arg.startswith('--use-application-binary') for arg in drive)) self.assertEqual(drive[-1], 'tablet') self.assertEqual(json.loads((runner.output / 'device.json').read_text())['udid'], 'tablet') From 717c83b6475259669264f4c1d58a64cef1bbca4f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 18:16:24 +0200 Subject: [PATCH 5/8] fix(ci): preserve simulator services after normal command exit --- scripts/testing/run_ios_acceptance.py | 8 +++++++- scripts/tests/test_ios_simulator.py | 16 ++++++++++++++-- 2 files changed, 21 insertions(+), 3 deletions(-) diff --git a/scripts/testing/run_ios_acceptance.py b/scripts/testing/run_ios_acceptance.py index efacfd3..545009f 100644 --- a/scripts/testing/run_ios_acceptance.py +++ b/scripts/testing/run_ios_acceptance.py @@ -197,6 +197,7 @@ def run(self, command, stage, timeout, *, progress=None): self.event(stage=stage, status='started', command=command, timeout_seconds=min(timeout, self.deadline - started)) process = None + completed = False try: with path.open('wb', buffering=0) as destination, path.open('rb') as source: process = self.popen(command, stdout=destination, @@ -215,6 +216,7 @@ def run(self, command, stage, timeout, *, progress=None): if code is not None and not chunk: self.event(stage=stage, status='exited', returncode=code, elapsed_seconds=round(self.clock() - started, 2)) + completed = True return code if progress is not None and progress.driver_started_at is not None: stage_deadline = progress.driver_started_at + TEST_SECONDS @@ -231,7 +233,11 @@ def run(self, command, stage, timeout, *, progress=None): })) raise finally: - if process is not None: + # A completed simctl command can leave persistent CoreSimulator + # services in its process group. Normal exit is not permission to + # terminate those services. Only aborts require forced cleanup; + # Flutter's --no-keep-app-running owns its normal driver shutdown. + if process is not None and not completed: self.stop(process) diff --git a/scripts/tests/test_ios_simulator.py b/scripts/tests/test_ios_simulator.py index 04e20b3..db75be5 100644 --- a/scripts/tests/test_ios_simulator.py +++ b/scripts/tests/test_ios_simulator.py @@ -119,16 +119,24 @@ def test_silent_wait_preserves_partial_output_and_escalates_own_group(self): events = [json.loads(line) for line in (self.output / 'stages.jsonl').read_text().splitlines()] self.assertEqual([event['status'] for event in events], ['started', 'failed']) - def test_success_drains_output_and_still_cleans_remaining_descendants(self): + def test_success_drains_output_without_signaling_completed_native_command(self): runner = self.runner(events=[(0, b'one\n'), (0.5, b'two\n')], end=0.5) self.assertEqual(runner.run(['command'], 'success', 2), 0) self.assertEqual((self.output / 'success.log').read_text(), 'one\ntwo\n') self.assertIn('two\n', self.console.getvalue()) - self.assertEqual(self.child.signals, [signal.SIGTERM, signal.SIGKILL]) + self.assertEqual(self.child.signals, []) def test_actual_nonzero_status_is_preserved(self): runner = self.runner(end=0, code=17) self.assertEqual(runner.run(['command'], 'failed-test', 2), 17) + self.assertEqual(self.child.signals, []) + + def test_abort_while_draining_exited_leader_still_cleans_its_group(self): + runner = self.runner(events=[(0, b'last output')], end=0) + with self.assertRaises(ios.StageTimeout): + runner.run(['command'], 'expired-during-drain', 0) + self.assertEqual((self.output / 'expired-during-drain.log').read_bytes(), b'last output') + self.assertEqual(self.child.signals, [signal.SIGTERM, signal.SIGKILL]) def test_denied_cleanup_after_exit_retains_success_or_failure_without_escalation(self): for code in (0, 17): @@ -144,6 +152,10 @@ def signal_group(pid, sig): runner.kill_group = signal_group self.assertEqual(runner.run(['command'], 'completed', 2), code) + self.assertEqual(signals, []) + # An abort can race with leader exit. Directly exercise + # its cleanup path after the command has been reaped. + runner.stop(self.child) expected = ([signal.SIGTERM] if denied_signal == signal.SIGTERM else [signal.SIGTERM, signal.SIGKILL]) self.assertEqual(signals, expected) From b7ddffe13628e4050fca800736861c4612f09138 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 18:16:26 +0200 Subject: [PATCH 6/8] docs: explain completed-command lifecycle and iPad launch evidence --- docs/BUILD_INCIDENT_2026-10.md | 18 ++++++++++++++++++ docs/TESTING.md | 11 +++++++---- 2 files changed, 25 insertions(+), 4 deletions(-) diff --git a/docs/BUILD_INCIDENT_2026-10.md b/docs/BUILD_INCIDENT_2026-10.md index c28a7f1..77cf541 100644 --- a/docs/BUILD_INCIDENT_2026-10.md +++ b/docs/BUILD_INCIDENT_2026-10.md @@ -95,3 +95,21 @@ explicitly requests Flutter's application/device cleanup. A denied group signal is recorded as a warning only when the command has already exited; it cannot replace a completed command's result. Denied signals for running commands remain errors, and the final simulator shutdown is still attempted. + +The same [verification run +38153311245](https://github.com/getbible/app/actions/runs/38153311245) retained a +different iPad failure: installation and boot completed, but both `simctl launch` +attempts timed out without a process ID, Runner log or VM-service announcement. +The simulator screenshots show an unlocked home screen and the installed app. +This establishes a failure before application execution; it does not identify +the underlying CoreSimulator cause. + +Review also found that the runner sent TERM/KILL to every command's process +group after normal exit, including simulator discovery, boot and installation. +Normal command completion does not authorize terminating persistent platform +services initialized by that command. The runner now reaps naturally completed +commands without signalling their groups, regardless of exit code. Bounded +group termination still runs after timeouts or interruptions. Regression tests +cover both natural completion and aborted-command cleanup. Native CI is needed +to determine whether this lifecycle correction also resolves the iPad launch +stall; the recorded iPad evidence alone cannot prove that causal connection. diff --git a/docs/TESTING.md b/docs/TESTING.md index a2e66e1..6b72795 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -451,10 +451,13 @@ being ready when the app announces its service. The existing-app driver explicitly uses `--no-keep-app-running`, so Flutter stops the application and disposes its device log readers after the journey. -If macOS refuses a process-group cleanup signal after the command has already -exited, the runner records that cleanup warning and preserves the command's -result. A signal failure while the command is still running remains fatal. -Simulator shutdown still runs within the separate cleanup reserve. +Naturally completed commands are reaped without signalling their process +groups: a completed `simctl` command can leave platform services running that +later stages need. Group termination is reserved for interrupted or timed-out +commands. If a command exits during that termination and macOS refuses a group +signal, the runner records the warning without replacing the original failure. +A denied signal while the command is still running remains fatal. Simulator +shutdown still runs within the separate cleanup reserve. One simulator reboot is permitted only for a bounded startup timeout before driver attachment. Reported command errors, driver connection failures, failed From b33b66e62c07a38d53731bfa0956aab58d78cc9e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 18:33:23 +0200 Subject: [PATCH 7/8] fix(ci): share startup budget with durable VM log queries --- scripts/testing/run_ios_acceptance.py | 7 +++-- scripts/tests/test_ios_simulator.py | 37 ++++++++++++++++++++++++++- 2 files changed, 39 insertions(+), 5 deletions(-) diff --git a/scripts/testing/run_ios_acceptance.py b/scripts/testing/run_ios_acceptance.py index 545009f..a22c120 100644 --- a/scripts/testing/run_ios_acceptance.py +++ b/scripts/testing/run_ios_acceptance.py @@ -32,7 +32,6 @@ BOOT_SECONDS = 3 * 60 ATTACH_SECONDS = 3 * 60 TEST_SECONDS = 12 * 60 -LOG_QUERY_SECONDS = 30 class CommandFailure(RuntimeError): @@ -265,11 +264,11 @@ def start_application(self, bundle, executable): prefix = f'attempt-{self.attempt}' deadline = min(self.runner.clock() + ATTACH_SECONDS, self.runner.deadline) - def startup(command, stage, limit=ATTACH_SECONDS): + def startup(command, stage): remaining = deadline - self.runner.clock() if remaining <= 0: raise StageTimeout(stage, session_expired=self.runner.clock() >= self.runner.deadline) - self.required(command, stage, min(limit, remaining)) + self.required(command, stage, remaining) startup(['xcrun', 'simctl', 'install', self.identifier, str(self.application)], f'{prefix}/install') @@ -293,7 +292,7 @@ def startup(command, stage, limit=ATTACH_SECONDS): startup(['xcrun', 'simctl', 'spawn', self.identifier, 'log', 'show', '--last', '5m', '--style', 'json', '--predicate', f'process == "{executable}"'], - stage, LOG_QUERY_SECONDS) + stage) uri = discovery.find((self.runner.output / f'{stage}.log').read_text()) if uri is not None: self.runner.event(stage=f'{prefix}/discovery', status='ready', pid=discovery.pid) diff --git a/scripts/tests/test_ios_simulator.py b/scripts/tests/test_ios_simulator.py index db75be5..3696907 100644 --- a/scripts/tests/test_ios_simulator.py +++ b/scripts/tests/test_ios_simulator.py @@ -377,9 +377,44 @@ def test_discovery_polling_shares_startup_budget_and_never_resets_deadline(self) self.assertNotIn('attempt-1/driver', runner.stages) queries = [call for call in runner.calls if '/vm-service/' in call[1]] self.assertTrue(queries) - self.assertLessEqual(max(call[2] for call in queries), ios.LOG_QUERY_SECONDS) + self.assertEqual(queries[0][2], 60) + self.assertLessEqual(max(call[2] for call in queries), 60) self.assertEqual(queries[-1][2], 1) + def test_slow_log_query_uses_remaining_startup_budget_without_unnecessary_reboot(self): + runner = self.runner(delays={'attempt-1/install': 24, 'attempt-1/launch': 31, + 'attempt-1/vm-service/001': 45}) + self.assertEqual(self.acceptance(runner).run('iPhone'), 0) + query = next(call for call in runner.calls if call[1] == 'attempt-1/vm-service/001') + self.assertEqual(query[2], ios.ATTACH_SECONDS - 24 - 31) + self.assertEqual(runner.clock(), 100) + self.assertNotIn('recovery/shutdown', runner.stages) + self.assertIn('attempt-1/driver', runner.stages) + + def test_slow_log_query_cannot_exceed_remaining_startup_budget(self): + runner = self.runner(delays={ + f'attempt-{attempt}/{stage}': delay + for attempt in (1, 2) + for stage, delay in (('install', 60), ('launch', 60), ('vm-service/001', 70))}) + with self.assertRaises(ios.StageTimeout): + self.acceptance(runner).run('iPad') + self.assertEqual(runner.clock(), 2 * ios.ATTACH_SECONDS) + queries = [call for call in runner.calls if '/vm-service/' in call[1]] + self.assertEqual([call[2] for call in queries], [60, 60]) + self.assertNotIn('attempt-1/driver', runner.stages) + self.assertNotIn('attempt-2/driver', runner.stages) + + def test_slow_log_query_cannot_exceed_global_deadline_or_start_recovery(self): + runner = self.runner(delays={'attempt-1/vm-service/001': 20}) + runner.deadline = 10 + with self.assertRaises(ios.StageTimeout) as caught: + self.acceptance(runner).run('iPad') + self.assertTrue(caught.exception.session_expired) + self.assertEqual(runner.clock(), 10) + query = next(call for call in runner.calls if '/vm-service/' in call[1]) + self.assertEqual(query[2], 10) + self.assertNotIn('recovery/shutdown', runner.stages) + def test_discovery_polling_respects_global_budget(self): runner = self.runner(query_records=[]) runner.deadline = 2.5 From 32e8991a0ad4fbef070598aaf176fac78aee8d46 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?eW=C9=98yn?= <5607939+Llewellynvdm@users.noreply.github.com> Date: Sun, 11 Oct 2026 18:33:25 +0200 Subject: [PATCH 8/8] docs: record slow simulator log query evidence --- docs/BUILD_INCIDENT_2026-10.md | 12 ++++++++++++ docs/TESTING.md | 2 ++ 2 files changed, 14 insertions(+) diff --git a/docs/BUILD_INCIDENT_2026-10.md b/docs/BUILD_INCIDENT_2026-10.md index 77cf541..dbd9d16 100644 --- a/docs/BUILD_INCIDENT_2026-10.md +++ b/docs/BUILD_INCIDENT_2026-10.md @@ -113,3 +113,15 @@ group termination still runs after timeouts or interruptions. Regression tests cover both natural completion and aborted-command cleanup. Native CI is needed to determine whether this lifecycle correction also resolves the iPad launch stall; the recorded iPad evidence alone cannot prove that causal connection. + +The next [verification run +38154773547](https://github.com/getbible/app/actions/runs/38154773547) passed iPad +acceptance on its first attempt, including all six tests and shutdown. The iPhone +launched PID 9094 and announced its VM service at 16:25:36.991 UTC. Its first +retained-log query was then aborted by an independent 30-second query limit, +while about 90 seconds remained in the shared startup budget. That premature +timeout triggered a reboot; the second launch stalled before application startup. +Log discovery now uses the remaining shared budget, just like install and +launch. The overall three-minute startup bound is unchanged. Regressions cover +a log query taking more than 30 seconds, shared-deadline exhaustion and the +shorter overall session deadline. diff --git a/docs/TESTING.md b/docs/TESTING.md index 6b72795..f0062fd 100644 --- a/docs/TESTING.md +++ b/docs/TESTING.md @@ -448,6 +448,8 @@ local to the simulator host. `flutter drive --use-existing-app` then connects the same host driver and resumes the paused integration journey. VM-service authentication remains enabled. This avoids depending on a live log listener being ready when the app announces its service. +Log reads share the remaining install/launch/discovery budget; a separate short +query timeout must not reboot a running app while that startup budget remains. The existing-app driver explicitly uses `--no-keep-app-running`, so Flutter stops the application and disposes its device log readers after the journey.