diff options
| -rw-r--r-- | test/hil/helper/hil_health.py | 3 | ||||
| -rw-r--r-- | test/hil/helper/hil_pool_check.py | 8 | ||||
| -rw-r--r-- | test/hil/helper/hil_report.py | 32 | ||||
| -rw-r--r-- | test/hil/helper/hil_util.py | 20 | ||||
| -rwxr-xr-x | test/hil/hil_test.py | 356 | ||||
| -rw-r--r-- | test/hil/test/test_hil_bounded.py | 31 |
6 files changed, 287 insertions, 163 deletions
diff --git a/test/hil/helper/hil_health.py b/test/hil/helper/hil_health.py index aa811eeb4..b9c05c236 100644 --- a/test/hil/helper/hil_health.py +++ b/test/hil/helper/hil_health.py @@ -214,9 +214,6 @@ def _kill_kids(kids: dict, seen: set) -> int: own = os.getpgid(0) except OSError: own = None # cannot tell our own group apart: never killpg, signal pids only - # One list: every pid here is a DESCENDANT of one of our own workers, so it is ours by - # construction -- no argv identity check needed, because we never signal anything we - # did not discover through our own ppid tree. touched: list = [] for children in kids.values(): for cpid, cpgid in children: diff --git a/test/hil/helper/hil_pool_check.py b/test/hil/helper/hil_pool_check.py index 179a417ed..b92f0aee0 100644 --- a/test/hil/helper/hil_pool_check.py +++ b/test/hil/helper/hil_pool_check.py @@ -983,9 +983,13 @@ def main() -> None: headers = ['Board', 'Probe', 'Flash', 'Device', 'Status', 'Note'] cells = [[r['name'], r['probe'], r['flash'], r['device'], status_mark.get(r['status'], r['status']), '; '.join(r['note'])] for r in rows] - widths = [max(len(h), *(len(c[i]) for c in cells)) if cells else len(h) + # display_width, not len(): ✅ / ❌ / 🔒 / ⚠ are one character and two columns, so + # len() pads every row holding one a column short of the header rule + _w = hil_util.display_width + widths = [max(_w(h), *(_w(c[i]) for c in cells)) if cells else _w(h) for i, h in enumerate(headers)] - line = lambda vals: '| ' + ' | '.join(v.ljust(w) for v, w in zip(vals, widths)) + ' |' + line = lambda vals: ('| ' + ' | '.join(hil_util.pad(v, w) + for v, w in zip(vals, widths)) + ' |') print() print(line(headers)) print('|' + '|'.join('-' * (w + 2) for w in widths) + '|') diff --git a/test/hil/helper/hil_report.py b/test/hil/helper/hil_report.py index b73c030a9..d059c62c9 100644 --- a/test/hil/helper/hil_report.py +++ b/test/hil/helper/hil_report.py @@ -9,14 +9,36 @@ writers, and the fold to one machine-readable verdict per board. Dual-mode by design: imported as `helper.hil_report` by hil_test.py, and run as a script by the operator (see .claude/agents/hil-operator.md). A script run puts test/hil/helper on -sys.path rather than test/hil, hence the guarded hil_health import below. +sys.path rather than test/hil, so this module imports no sibling helper at all -- +_p and the width helpers below are defined locally for that reason. """ import argparse import json import sys +import unicodedata from pathlib import Path +def _w(s: str) -> int: + """Terminal COLUMNS, not characters. Every status mark in REPORT_CELL is one Python + character and TWO columns wide, so len() pads a cell holding one a column short and + the pipes drift out of line with the header rule for the whole table. + + Local, like _p above and for the same reason: this module is also run as a script, and + under PYTHONSAFEPATH=1 a sibling import dies before argparse runs. hil_util carries the + same pair for callers that can import it. + """ + return sum(2 if unicodedata.east_asian_width(c) in 'WF' else 1 for c in s) + + +def _pad(s: str, width: int, center: bool = False) -> str: + """str.ljust/center, measured in display columns. See _w.""" + room = max(0, width - _w(s)) + if not center: + return s + ' ' * room + left = room // 2 + return ' ' * left + s + ' ' * (room - left) + def _p(*args, **kwargs) -> None: """Print that cannot raise. Defined here rather than imported from hil_health: this @@ -136,12 +158,14 @@ def render_matrix(rows_all: list) -> str: rows_vals = [(lbl, [cell(cells, c) for c in columns] + [dur or '']) for lbl, cells, dur in rows_all] board_hdr = 'Board' - board_w = max([len(board_hdr)] + [len(lbl) for lbl, _ in rows_vals]) - col_w = [max([len(h)] + [len(vals[i]) for _, vals in rows_vals]) + # display_width, not len(): the ✅/❌/⚪ marks are one character and two columns + board_w = max([_w(board_hdr)] + [_w(lbl) for lbl, _ in rows_vals]) + col_w = [max([_w(h)] + [_w(vals[i]) for _, vals in rows_vals]) for i, h in enumerate(headers)] def line(label, values): - padded = [label.ljust(board_w)] + [v.center(w) for v, w in zip(values, col_w)] + padded = [_pad(label, board_w)] + [_pad(v, w, center=True) + for v, w in zip(values, col_w)] return '| ' + ' | '.join(padded) + ' |' header = line(board_hdr, headers) diff --git a/test/hil/helper/hil_util.py b/test/hil/helper/hil_util.py index 0a2a13fca..dfd37467a 100644 --- a/test/hil/helper/hil_util.py +++ b/test/hil/helper/hil_util.py @@ -11,6 +11,7 @@ import glob import os import signal import subprocess +import unicodedata import threading import sys from pathlib import Path @@ -92,6 +93,25 @@ CMD_TIMEOUT = pos_int_env('HIL_CMD_TIMEOUT', 180) TINYUSB_ROOT = Path(__file__).resolve().parents[3] # test/hil/helper/ -> repo root +def display_width(s: str) -> int: + """Terminal COLUMNS, not characters. + + The status marks the reports use -- ✅ ❌ ⚪ ⚠ 🔒 -- are one Python character and TWO + columns wide. Measuring with len() pads every cell containing one a column short, so + the pipes drift out of line against the header rule for the whole table. + """ + return sum(2 if unicodedata.east_asian_width(c) in 'WF' else 1 for c in s) + + +def pad(s: str, width: int, center: bool = False) -> str: + """str.ljust/center, measured in display columns. See display_width.""" + room = max(0, width - display_width(s)) + if not center: + return s + ' ' * room + left = room // 2 + return ' ' * left + s + ' ' * (room - left) + + def cmd_stdout_text(out: Any) -> str: if out is None: return '' diff --git a/test/hil/hil_test.py b/test/hil/hil_test.py index 83e5082d4..140860677 100755 --- a/test/hil/hil_test.py +++ b/test/hil/hil_test.py @@ -238,6 +238,9 @@ USBTEST_BATTERY_BUDGET = hil_util.pos_int_env('HIL_USBTEST_BATTERY_BUDGET', 260) # timeout paths = 95s. 120 leaves a margin; 75 (my first estimate, taken before checking # dmesg_tail) was 20s SHORT and would have killed the battery mid-print. USBTEST_OVERSHOOT = 120 +# Named, not a literal, so the unit tests can zero it: every test that drives +# test_device_usbtest against a fake rig otherwise pays a real 3s (ten of them, 30s a run). +USBTEST_SETTLE = 3 SERIAL_READ_TIMEOUT = hil_util.pos_float_env('HIL_SERIAL_READ_TIMEOUT', 5) SERIAL_WRITE_TIMEOUT = hil_util.pos_float_env('HIL_SERIAL_WRITE_TIMEOUT', 10) @@ -1066,8 +1069,13 @@ def test_device_printer_to_cdc(board): ready.unlink(missing_ok=True) # stderr, not stdout: run_alongside keeps the payload stream clean, so a traceback # from the reader now arrives on its own pipe - assert r.returncode == 0, (f'CDC->Printer reader failed ({size} bytes, rc ' - f'{r.returncode}): {hil_util.cmd_stdout_text(r.stderr)[:200]}') + # rc 124 is run_alongside's kill -- a blocked usblp_open leaves stderr EMPTY, so + # without the fallback this renders as 'failed (32 bytes, rc 124):' and nothing + rdetail = hil_util.cmd_stdout_text(r.stderr).strip()[:200] + assert r.returncode == 0, ( + f'CDC->Printer reader failed ({size} bytes): {rdetail}' if rdetail else + f'printer: reading {lp_dev} blocked (device wedged): the reader was killed on ' + f'its bound (rc {r.returncode})') assert r.stdout == test_data, (f'CDC->Printer wrong data ({size} bytes):\n' f' expected: {test_data[:64]}\n received: {r.stdout[:64]}') time.sleep(0.2) @@ -1365,7 +1373,7 @@ def test_device_usbtest(board): # settle: right after flashing the enumeration can bounce once (and on dual-port parts # the other port's stale node — same serial and PID — lingers), and testusb run into # that gap sees the device drop mid-case - time.sleep(3) + time.sleep(USBTEST_SETTLE) # --keep-binding is required for concurrent batteries: usbtest.py's cleanup unbinds # EVERY usbtest-bound interface, killing a peer battery under USBTEST_PARALLEL > 1, and @@ -1453,6 +1461,20 @@ def test_device_usbtest(board): raise TestFail(f'usbtest did not run: {detail}', metric=f'{hil_report.REPORT_CELL["fail"]} 0/30') + return _usbtest_verdict(board, data, out, passed, failed, recovery, + _rec_flasher) + + +def _usbtest_verdict(board: Board, data: dict, out: str, passed: int, failed: int, + recovery: bool, rec_flasher: dict) -> str: + """The report cell for a battery that produced JSON, or a TestFail carrying one. + + Also latches board_wedged, which stops the REST of this board's examples: each would + flash THROUGH the poisoned usbfs node, block, survive SIGKILL and add another stray -- + one wedge becoming one stray per remaining example, which is the convoy this whole + containment path exists to prevent. + """ + global board_wedged # A HUNG case that recovery could not clear leaves a D-state holder on this board's # usbfs node. Latch it: the remaining examples would each flash THROUGH that node, # block, survive SIGKILL and add another stray -- turning one wedge into one stray per @@ -1461,15 +1483,15 @@ def test_device_usbtest(board): # the reflash worked, so a convoy-safe board whose recovery failed used to come back # unlatched and flash every remaining example through the poisoned node. if data.get('wedged') or (not recovery and 'HUNG' in out): - # _rec_flasher, NOT board['flasher']: recovery was decided against recover_flasher() - # at the top of this function, and the two diverge as soon as a roster carries the + # rec_flasher, NOT board['flasher']: recovery was decided against recover_flasher() + # in the caller, and the two diverge as soon as a roster carries the # optional `flasher_recover` key -- naming the wrong one sends the operator to the # wrong probe. The wording stays on what usbtest actually reported ("still wedged"), # because unrecovered_hang is also set by the ambiguous/inconclusive aborts, where # nothing hung and the old text was false on both clauses. board_wedged = (f'{board["name"]}: usbtest reports the device still wedged ' - + (f'after a recovery reflash via {_rec_flasher["name"]}' if recovery - else f'and {_rec_flasher["name"]} cannot deliver a recovery reflash')) + + (f'after a recovery reflash via {rec_flasher["name"]}' if recovery + else f'and {rec_flasher["name"]} cannot deliver a recovery reflash')) # notrun counts toward the denominator but is NOT a failure: listing cases that never # ran as failures sends a maintainer bisecting one of them. @@ -1702,7 +1724,49 @@ def build_board(board: Board) -> tuple[str, int]: return name, failed -def test_board(board: Board) -> tuple[str, int, list[str], list, float]: +def _tests_for(board: Board) -> list: + """Which examples this board runs, in roster order. + + Three sources, most specific first: an explicit -bt list for this board, a global -t + list filtered against what the board can actually do, or the roster's own capability + flags. The -t filter is not cosmetic -- without it a device-only board runs host/dual + tests whose `dev_attached` roster entry does not exist. + """ + name = board['name'] + if name in board_test: + return list(board_test[name]) + + board_tests = board.get('tests', {}) + if test_only: + if 'only' in board_tests: + allowed = set(board_tests['only']) + return [t for t in test_only if t in allowed] + return [t for t in test_only + if board_tests.get(t.split('/', 1)[0]) is True] + + if 'tests' not in board: + return [] + test_list: list = [] + if board_tests.get('device') is True: + test_list += list(device_tests) + if board_tests.get('dual') is True: + test_list += dual_tests + if board_tests.get('host') is True: + test_list += host_test + if 'only' in board_tests: + test_list = list(board_tests['only']) + for skip in board_tests.get('skip', []): + if skip in test_list: + test_list.remove(skip) + log_line(f'{name:25} {skip:30} ... Skip') + return test_list + + +def test_board(board: Board) -> tuple: + # (name, err_count, failed_tests, rows, duration[, blind, strays]) -- the board-LOCKED + # early return is 5 wide, the normal one 7. _blind_note and _stray_note index 5 and 6 + # behind a len() guard, so a field inserted before them reads a WRONG SLOT rather than + # raising: a duration would report as a stray count. swept = False name = board['name'] flasher = board['flasher'] @@ -1719,38 +1783,7 @@ def test_board(board: Board) -> tuple[str, int, list[str], list, float]: # after the lock: flock wait behind a concurrent run is not board cost t_board = time.monotonic() try: - test_list = [] - - if name in board_test: - test_list = board_test[name] - elif len(test_only) > 0: - # Explicit -t: filter against the board's capabilities, or a device-only board - # runs host/dual tests whose `dev_attached` config entry does not exist. - board_tests = board.get('tests', {}) - if 'only' in board_tests: - allowed = set(board_tests['only']) - test_list = [t for t in test_only if t in allowed] - else: - for t in test_only: - category = t.split('/', 1)[0] - if board_tests.get(category) is True: - test_list.append(t) - else: - if 'tests' in board: - board_tests = board['tests'] - if board_tests.get('device') is True: - test_list += list(device_tests) - if board_tests.get('dual') is True: - test_list += dual_tests - if board_tests.get('host') is True: - test_list += host_test - if 'only' in board_tests: - test_list = board_tests['only'] - if 'skip' in board_tests: - for skip in board_tests['skip']: - if skip in test_list: - test_list.remove(skip) - log_line(f'{name:25} {skip:30} ... Skip') + test_list = _tests_for(board) err_count = 0 failed_tests = [] @@ -2070,6 +2103,127 @@ def _abandon_exit(pool, mgr, abandoned: bool, err_count: int, os._exit(min(err_count, 125) if err_count else 1) +def _load_controller_hints() -> tuple[dict, dict]: + """The uid -> {name, pci, duration} cache, plus the uid -> pci view scheduling wants. + + Best effort throughout: a missing, hand-edited or torn cache costs dispatch ORDER, + never the run. + """ + hints: dict = {} + try: + with CONTROLLER_CACHE.open() as f: + loaded = json.load(f) + if isinstance(loaded, dict): # keep only the expected uid -> dict shape + hints = {k: v for k, v in loaded.items() if isinstance(v, dict)} + except (OSError, ValueError): + pass + return hints, {uid: h['pci'] for uid, h in hints.items() if h.get('pci')} + + +def _save_controller_hints(hints: dict, mret: list, uid_of: dict, cmap) -> None: + """Fold this run's PCI resolutions and durations back into the cache, atomically. + + Merge-on-write: another HIL job (the esp split) may have finished since our startup + read, so overlay only this run's boards rather than publishing our whole view. + """ + for name, _, _, _, dur, *_ in mret: + uid = uid_of.get(name) + if uid is None: + continue + h = dict(hints.get(uid) or {}) + h['name'] = name # informational: the cache is keyed by uid + h['pci'] = cmap.get(f'uid:{uid}') or h.get('pci') + if dur > 0: # test_board reports 0.0 for filtered (partial) runs + h['duration'] = round(dur, 1) + hints[uid] = h + merged: dict = {} + try: + with CONTROLLER_CACHE.open() as f: + cur = json.load(f) + if isinstance(cur, dict): + merged = {k: v for k, v in cur.items() if isinstance(v, dict)} + except (OSError, ValueError): + pass + # onto what the CACHE now holds, not onto our startup snapshot: another HIL job may + # have written a newer duration/pci for these boards since we read it + for name, *_ in mret: + uid = uid_of.get(name) + if uid is not None and uid in hints: + merged[uid] = {**merged.get(uid, {}), **hints[uid]} + CONTROLLER_CACHE.parent.mkdir(parents=True, exist_ok=True) + tmp = CONTROLLER_CACHE.with_suffix('.json.tmp') + with tmp.open('w') as f: + json.dump(merged, f, indent=1, sort_keys=True) + tmp.replace(CONTROLLER_CACHE) + + +def _abort_report(reason: str, mret: list, config_boards: list, failed_fname: Path, + report_dir: Path, fresh: bool, health_banner: str, + timeout_secs: int | None = None) -> None: + """Keep what finished, name what did not, and get a report on disk. Never raises. + + Both abort paths -- the pool guard expiring and a worker raising -- need exactly this, + and in this order. The re-run spec goes FIRST: a fresh run already unlinked it, and + leaving it unwritten is what made a GitHub re-run repeat the whole fleet. Only the + boards that never reported go in it. + + The report follows, before anything that can block, and the caller raises afterwards + into the one containment path. `timeout_secs` adds the pool-guard fallback: when + accumulate_report itself fails -- an unwritable report dir, a torn JSON -- + _abandon_exit can only stamp a report that EXISTS, so without it the artifact upload + finds nothing and the sticky PR comment keeps the previous push's green table under a + red job. + """ + stuck = [b['name'] for b in config_boards if b['name'] not in {r[0] for r in mret}] + try: + _write_failed_spec(failed_fname, report_dir, + [(n, 1, [], None, 0) for n in stuck] + + [r for r in mret if r[1] > 0]) + except Exception as werr: # noqa: BLE001 - it mkdir()s and open()s the report dir + # letting it raise here REPLACES the caller's RuntimeError, so the operator never + # sees the 'pool timed out' line and no report is written at all + print(f'warning: re-run spec failed: {type(werr).__name__}: {werr}', flush=True) + banner = (f"**HIL run {reason}.** {len(mret)} board(s) below finished and are this " + f"run's; {len(stuck)} never reported and are NOT in the table: " + f"{', '.join(stuck)}. The re-run spec covers those.\n") + try: + hil_report.accumulate_report(mret, report_dir, fresh, '', + health_banner + _blind_note(mret) + + _stray_note(mret), caveat=banner) + return + except Exception as rerr: # noqa: BLE001 - the caller's raise must still happen + print(f'warning: partial report failed: {type(rerr).__name__}: {rerr}' + + ('; falling back to the board list' if timeout_secs else ''), flush=True) + if timeout_secs is None: + return + try: + hil_report.write_timeout_report( + report_dir, [b for b in config_boards if b['name'] in stuck], + timeout_secs, prefix=health_banner) + except Exception as re2: # noqa: BLE001 + print(f'warning: fallback report failed too: {type(re2).__name__}: {re2}', + flush=True) + + +def _start_pool(seed: str, hints_by_uid: dict): + """(mgr, cmap, pool). Split out so main()'s try/finally reads as one shape. + + maxtasksperchild=1: a fresh worker per board makes cross-board contamination + structural rather than dependent on every module global being reset by hand + (board_wedged, _current_fw, hil_flash's warn-once sets). The extra fork is noise + against a flash+test cycle. + """ + mgr = Manager() + cmap = mgr.dict() + initargs = (Lock(), seed, + hil_lock.make_permit_sems(Semaphore, hil_lock.USBTEST_PARALLEL), + hil_lock.make_permit_sems(Semaphore, hil_lock.FLASH_PARALLEL), + cmap, Lock(), hints_by_uid) + pool = Pool(processes=os.cpu_count() or 1, initializer=init_worker, + initargs=initargs, maxtasksperchild=1) + return mgr, cmap, pool + + def main() -> None: """ Hardware test on specified boards @@ -2188,9 +2342,6 @@ def main() -> None: report_dir = Path(os.environ.get('HIL_REPORT_DIR', '.')) failed_fname = report_dir / (config_file.name + '.failed') fresh = not args.accumulate - # The unlink is DEFERRED to inside the pool try/except below: wiping here leaves - # Manager() and Pool() running with the old report gone and no report-writing path - # armed, so an EAGAIN/ENOMEM on fork gives CI an EMPTY report dir with no reason. seed = os.getenv('HIL_SHUFFLE_SEED') or str(int(time.time())) log_line(f'test-order shuffle seed: {seed} (HIL_SHUFFLE_SEED={seed} to replay); ' @@ -2200,16 +2351,7 @@ def main() -> None: # unattributable from the log alone f'pool guard: {POOL_TIMEOUT}s') - hints = {} - try: - with CONTROLLER_CACHE.open() as f: - loaded = json.load(f) - # tolerate a hand-edited/torn cache: keep only the expected uid -> dict shape - if isinstance(loaded, dict): - hints = {k: v for k, v in loaded.items() if isinstance(v, dict)} - except (OSError, ValueError): - pass - hints_by_uid = {uid: h['pci'] for uid, h in hints.items() if h.get('pci')} + hints, hints_by_uid = _load_controller_hints() config_boards = schedule_boards(config_boards, hints_by_uid) log_line('dispatch order: ' + ', '.join(b['name'] for b in config_boards)) @@ -2240,20 +2382,7 @@ def main() -> None: (report_dir / f).unlink(missing_ok=True) failed_fname.unlink(missing_ok=True) try: - mgr = Manager() - cmap = mgr.dict() - initargs = (Lock(), seed, - hil_lock.make_permit_sems(Semaphore, hil_lock.USBTEST_PARALLEL), - hil_lock.make_permit_sems(Semaphore, hil_lock.FLASH_PARALLEL), - cmap, Lock(), hints_by_uid) - # maxtasksperchild=1: the sysfs blindness latch is process-global and permanent - # (no decrement anywhere -- see hil_util.SYSFS_STUCK_MAX), so a worker that goes - # blind on ONE wedged board would report 0/30 and "probe missing" for the 2-3 - # healthy boards it picked up afterwards. A fresh worker per board confines the - # damage to the board that caused it; the extra fork is noise against a - # flash+test cycle. - pool = Pool(processes=os.cpu_count() or 1, initializer=init_worker, - initargs=initargs, maxtasksperchild=1) + mgr, cmap, pool = _start_pool(seed, hints_by_uid) # OUTER: encloses the pool block too, not just the reporting below. An exception # escaping async_ret.get() (a worker exception, a Ctrl-C) runs the pool finally and # then propagates straight out of main(); with _abandon_exit in a sibling try it @@ -2270,43 +2399,13 @@ def main() -> None: try: mret = drain_pool(it, config_boards, deadline, out=mret) except MpTimeoutError as te: - mret = te.finished - stuck = [b['name'] for b in config_boards - if b['name'] not in {r[0] for r in mret}] - # The re-run spec FIRST and before the raise: a fresh run already unlinked - # it, so leaving it unwritten is what made the GitHub re-run repeat the - # whole fleet. Only the boards that never reported go in it. - _write_failed_spec(failed_fname, report_dir, - [(n, 1, [], None, 0) for n in stuck] - + [r for r in mret if r[1] > 0]) - # Then the report, with the rows that DID finish, before anything that can - # block. Then RAISE into the ONE containment path: the inner finally runs + # RAISE afterwards into the ONE containment path: the inner finally runs # the ordered sweep (kill_worker_children BEFORE terminate, or a reaped # worker's flasher reparents out of reach), the outer one os._exit's. - banner = (f'**HIL run abandoned: worker pool timed out after ' - f'{POOL_TIMEOUT}s.** {len(mret)} board(s) below finished and ' - f'are this run\'s; {len(stuck)} never reported and are NOT in ' - f'the table: {", ".join(stuck)}. Re-run covers those.\n') - try: - hil_report.accumulate_report(mret, report_dir, fresh, '', - health_banner + _blind_note(mret) - + _stray_note(mret), caveat=banner) - except Exception as rerr: # noqa: BLE001 - the raise below must still happen - # FALL BACK, do not just warn: accumulate_report can raise on an - # unwritable/root-owned report dir or a torn JSON, and _abandon_exit - # only PREPENDS to a report that exists. Without this the artifact - # upload finds nothing (if-no-files-found: ignore) and the sticky PR - # comment keeps the previous push's green table under a red job. - print(f'warning: partial report failed: {type(rerr).__name__}: {rerr}; ' - f'falling back to the board list', flush=True) - try: - hil_report.write_timeout_report( - report_dir, [b for b in config_boards - if b['name'] in stuck], POOL_TIMEOUT, - prefix=health_banner) - except Exception as re2: # noqa: BLE001 - print(f'warning: fallback report failed too: ' - f'{type(re2).__name__}: {re2}', flush=True) + mret = te.finished + _abort_report(f'abandoned: worker pool timed out after {POOL_TIMEOUT}s', + mret, config_boards, failed_fname, report_dir, fresh, + health_banner, timeout_secs=POOL_TIMEOUT) _p(f'HIL worker pool timed out after {POOL_TIMEOUT}s; sweeping and ' f'shutting it down (abandoning it if a worker is unkillable)', flush=True) @@ -2314,25 +2413,11 @@ def main() -> None: except Exception as e: # A worker RAISED -- e.g. a flasher adapter dropping off the bus makes # get_serial_dev raise in the worker's flash section, which no per-test - # handler guards. Same treatment as the timeout path: the drain means - # `mret` already holds every board that finished, so keep those rows and - # name only the ones still in flight. (Under map_async they were all lost, - # which is what the old banner here claimed.) - done = {r[0] for r in mret} - stuck = [b['name'] for b in config_boards if b['name'] not in done] - _write_failed_spec(failed_fname, report_dir, - [(n, 1, [], None, 0) for n in stuck] - + [r for r in mret if r[1] > 0]) - banner = (f'**HIL run aborted: a worker raised {type(e).__name__}: {e}.** ' - f'{len(mret)} board(s) below finished and are this run\'s; ' - f'{len(stuck)} did not report: {", ".join(stuck)}.\n') - try: - hil_report.accumulate_report(mret, report_dir, fresh, '', - health_banner + _blind_note(mret) - + _stray_note(mret), caveat=banner) - except Exception as re2: # noqa: BLE001 - the raise below must still happen - print(f'warning: partial report failed: {type(re2).__name__}: {re2}', - flush=True) + # handler guards. The drain means `mret` already holds every board that + # finished, so keep those rows and name only the ones still in flight. + _abort_report(f'aborted: a worker raised {type(e).__name__}: {e}', + mret, config_boards, failed_fname, report_dir, fresh, + health_banner) raise err_count = build_err + sum(e[1] for e in mret) @@ -2379,33 +2464,8 @@ def main() -> None: report_dir.mkdir(parents=True, exist_ok=True) with (report_dir / 'hil_profile_ctrl.json').open('w') as f: json.dump(dict(cmap), f, indent=1, sort_keys=True) - uid_of = {b['name']: b['uid'] for b in config['boards']} - for name, _, _, _, dur, *_ in mret: - uid = uid_of.get(name) - if uid is None: - continue - h = dict(hints.get(uid) or {}) - h['name'] = name # informational: cache is keyed by uid - h['pci'] = cmap.get(f'uid:{uid}') or h.get('pci') - if dur > 0: # test_board reports 0.0 for filtered (partial) runs - h['duration'] = round(dur, 1) - hints[uid] = h - # merge-on-write: another HIL job (e.g. the esp split) may have finished since - # our startup read, so overlay only this run's boards and replace atomically - merged = {} - try: - with CONTROLLER_CACHE.open() as f: - cur = json.load(f) - if isinstance(cur, dict): - merged = {k: v for k, v in cur.items() if isinstance(v, dict)} - except (OSError, ValueError): - pass - merged.update({uid_of[n]: hints[uid_of[n]] for n, *_ in mret if n in uid_of}) - CONTROLLER_CACHE.parent.mkdir(parents=True, exist_ok=True) - tmp = CONTROLLER_CACHE.with_suffix('.json.tmp') - with tmp.open('w') as f: - json.dump(merged, f, indent=1, sort_keys=True) - tmp.replace(CONTROLLER_CACHE) + _save_controller_hints( + hints, mret, {b['name']: b['uid'] for b in config['boards']}, cmap) except Exception as e: # Deliberately broad, and it must stay that way: this best-effort refresh makes # Manager proxy RPCs that raise EOFError / BrokenPipeError / RemoteError when diff --git a/test/hil/test/test_hil_bounded.py b/test/hil/test/test_hil_bounded.py index 715d520db..2230ef422 100644 --- a/test/hil/test/test_hil_bounded.py +++ b/test/hil/test/test_hil_bounded.py @@ -47,6 +47,17 @@ def write_script(path: Path, body: str) -> None: path.chmod(path.stat().st_mode | stat.S_IEXEC) +def no_settle(case): + """Zero test_device_usbtest's post-flash settle for one test. + + Real hardware needs it -- the enumeration can bounce once after a flash, and on + dual-port parts the stale same-serial node lingers. A fake rig has neither, and ten + tests drive that path, so leaving it real cost 30s of every suite run. + """ + case.addCleanup(setattr, hil_test, 'USBTEST_SETTLE', hil_test.USBTEST_SETTLE) + hil_test.USBTEST_SETTLE = 0 + + def run_bounded(fn, timeout: float): """Run fn in a daemon thread; return (finished, exception). A still-running thread is the hang under test — leave it to die with the interpreter.""" @@ -78,7 +89,7 @@ class ReadDiskFile(unittest.TestCase): for name in ('get_disk_dev', '_enum_timeout', 'MTYPE_TIMEOUT'): self.addCleanup(setattr, hil_test, name, getattr(hil_test, name)) hil_test.get_disk_dev = lambda uid, vendor, lun: str(self.dev) - hil_test._enum_timeout = 2 + hil_test._enum_timeout = 1 # the wait these tests must outlast; keep it small self.bin = tmp / 'bin' self.bin.mkdir() self.addCleanup(os.environ.__setitem__, 'PATH', os.environ['PATH']) @@ -113,7 +124,11 @@ class ReadDiskFile(unittest.TestCase): t0 = time.monotonic() with self.assertRaises(AssertionError) as cm: hil_test.read_disk_file('uid0', 0, 'README.TXT') - self.assertLess(time.monotonic() - t0, 1.5) + # BELOW one full _enum_timeout wait, not above it: "fails immediately" is the + # claim, and a bound of 1.5 against a 1s budget passes for code that spun the + # whole budget -- which is the regression this test exists to catch. + self.assertLess(time.monotonic() - t0, hil_test._enum_timeout, + 'read_disk_file spun the enumeration budget on a real answer') self.assertIn('README.TXT', str(cm.exception)) def test_hung_mtype_cannot_hang_the_worker(self): @@ -314,7 +329,7 @@ class _MtpFakeRig: os.environ['PYTHONSAFEPATH'] = '1' for name in ('_enum_timeout', 'MTP_SESSION_MARGIN'): self.addCleanup(setattr, hil_test, name, getattr(hil_test, name)) - hil_test._enum_timeout = 2 + hil_test._enum_timeout = 1 # the wait these tests must outlast; keep it small # the session scratch files land in cwd self.addCleanup(os.chdir, os.getcwd()) os.chdir(tmp) @@ -900,16 +915,16 @@ class MtpGioFallthrough(unittest.TestCase): t0 = time.monotonic() r = subprocess.run([sys.executable, str(Path(TEST_DIR).parents[0] / 'mtp_test.py'), - '--uid', 'CAFE01', '--timeout', '3'], + '--uid', 'CAFE01', '--timeout', '1'], capture_output=True, text=True, timeout=60, env=env) elapsed = time.monotonic() - t0 - self.assertLess(elapsed, 30, f'did not honour --timeout 3 ({elapsed:.1f}s)') + self.assertLess(elapsed, 30, f'did not honour --timeout 1 ({elapsed:.1f}s)') self.assertNotEqual(r.returncode, 0) # The assertions above are satisfied by an immediate CRASH, which is exactly what # shipped through this test once: `pass` left gio unbound and the next line # dereferenced it. Assert the behaviour the docstring names -- it POLLED for the # device (so it spent its budget) and did not die on a traceback. - self.assertGreater(elapsed, 2.0, + self.assertGreater(elapsed, 0.8, f'exited without polling ({elapsed:.1f}s) -- it crashed') self.assertNotIn('Traceback', r.stderr) self.assertIn('MTP device not found', r.stdout + r.stderr) @@ -1226,6 +1241,7 @@ class UsbtestOuterBoundIsOneValue(unittest.TestCase): # wedged-FIFO test would otherwise make every read here answer SYSFS_UNKNOWN patch(_hu, '_sysfs_stuck', 0) patch(_hu, '_sysfs_stranded', {}) + patch(hil_test, 'USBTEST_SETTLE', 0) # see no_settle patch(hil_lock, 'usbtest_permit', contextmanager(_permit)) patch(hil_test, 'skip_flash', skip_flash) patch(hil_test, '_current_fw', '/tmp/fw.elf') @@ -1333,6 +1349,7 @@ class UsbtestOuterKillStaysRetryable(unittest.TestCase): from helper import hil_util as _hu patch(_hu, 'glob', types.SimpleNamespace(glob=lambda p: [str(dev)])) + patch(hil_test, 'USBTEST_SETTLE', 0) # see no_settle def _permit(uid): # a real generator: a lambda returning an iterator has yield # no .throw(), so any raise inside the `with` would # surface as an AttributeError from contextlib instead @@ -1827,6 +1844,7 @@ class WedgeVerdictReachesTheLatch(unittest.TestCase): def setUp(self): self.addCleanup(setattr, hil_test, 'board_wedged', hil_test.board_wedged) hil_test.board_wedged = '' + no_settle(self) def _run(self, stdout, rc=0): from helper import hil_lock, hil_util @@ -1875,6 +1893,7 @@ class WedgedBoardCannotReportAPass(unittest.TestCase): def setUp(self): self.addCleanup(setattr, hil_test, 'board_wedged', hil_test.board_wedged) hil_test.board_wedged = '' + no_settle(self) def _cell(self, js): """Returns ('pass', cell) or ('fail', message).""" |