diff options
| author | hathach <[email protected]> | 2026-08-27 15:26:43 +0700 |
|---|---|---|
| committer | hathach <[email protected]> | 2026-08-28 14:18:41 +0700 |
| commit | b190840e1d85f806575f58635827502d714febcf (patch) | |
| tree | 76c6abf45f3670313d5812f3c453d849a98371f9 /test/hil/helper | |
| parent | a5938f71fbc704c85979121bb9e37d5d636ef20d (diff) | |
test/hil: drop the sysfs blindness subsystem and derive the recovery reserve
Two layers whose cost was a contract to reason about rather than an outcome.
SYSFS_UNKNOWN was a three-valued return five files had to keep apart, and
misreading unknown as absence was silent: a healthy board reported as a firmware
regression. What it guarded is real -- `serial` is served by usb_string_attr,
which takes usb_lock_device_interruptible (v6.12.96 sysfs.c:141-143), the same
lock a wedged usbfs ioctl holds -- so the BOUND stays, on every caller by
default. usb_scan reads `serial` on every device matching the VID, and hil_lock's
controller_of does that on essentially every board, so one wedged DUT would
otherwise stall every worker, not one. What goes is the third value.
read_sysfs now returns str or None, and the question the third value existed to
answer is asked directly instead, by two predicates that say which question they
answer: sysfs_stranded() is process-wide and sticky, for hil_pool_check's footer
("could anything here be the tool losing sight of healthy hardware?"), and
path_stranded(path) is per-device, which is what usbtest needs to tell a DUT
whose `serial` is held under device_lock from one that genuinely left the bus --
that difference decides whether it performs driver-registry writes that take the
uninterruptible device_lock.
Gone: _SysfsUnknown, SYSFS_UNKNOWN, sysfs_blind, sysfs_blind_note,
note_sysfs_strand, the cross-process blindness publishing and its report banner,
usb_scan's (list, bool) return, usbtest's inconclusive abort, _blind_note's slot
in the result tuple, and bounded_open, whose last caller went in the previous
commit.
The strand memo is rewritten around the one invariant that makes it safe to
reuse: it is keyed by the path's kernfs inode, captured BEFORE the read. A
busport does not change when a board returns to the same physical port, so a
path-only blacklist outlives the wedge and hil_pool_check's own recovery flow --
reset, reflash, wait_device polling that busport -- would never look at the
board again. A re-enumeration destroys the kernfs node and makes a new one, so a
changed inode is the all-clear. Two ceilings bound different things: per path
(_PATH_STRAND_MAX) for a board that flaps while still wedged, and per process
(_STRAND_MAX) as a backstop against RLIMIT_NOFILE, counted per PATH rather than
per reader because hil_pool_check runs four poll threads over one bus.
A board the pool guard never reached is now reported as run-aborted rather than
pool-timed-out, and outranks a stale board-locked cell for the same reason the
pool-timeout cell does.
Both predicates answer conservatively where they are consulted before something
irreversible. path_stranded() covers the paths read_sysfs answered None for
WITHOUT reading -- past _STRAND_MAX it declines to start another reader, and
vouching for a path nobody looked at hands usbtest's fail-CLOSED guard a
fabricated all-clear, running remove_id/unbind against a wedged device. usbtest's
startup lookup carries the same caveat hil_test's absent arm already did, because
its stderr is relayed verbatim into the report cell.
strand_note() survives the removal for the same reason master had it: every
caller that can say "not found" needs the same sentence, and the one site left to
re-invent it got missed -- a wedged-but-enumerated printer was reported as an
enumeration failure, sending a maintainer after firmware.
The two predicates are not interchangeable, and usbtest needs both. Its per-case
verdict is per-DUT -- a peer that stranded at case 2 must not make our board
report wedged at case 29 -- but the finally block's cleanup is process-wide:
remove_id plus an unbind of EVERY interface under the driver, including that
peer's, each taking the uninterruptible device_lock. So the verdict uses
path_stranded() and the global cleanup stays gated on sysfs_stranded().
USBTEST_RECOVERY_BUDGET was an independent 250s that could not actually contain
the ladder it reserved for, which is why usbtest.py carried a _time_left() gate
re-deciding before every step -- with a bare '- 35' for costs paid downstream
that nobody could re-derive. Between them the two produced a recovery that
skipped its own steps for most real hangs.
The reserve is now derived from the bounds usbtest itself declares, per flasher
and per target: a probe reset, a reflash, and the Rescue-DP POR plus retry a
wedged RP DAP needs, plus the settles and hil_util.REAP_GRACE for each bounded
step. The Rescue-DP legs are openocd-only and gated on the RP target cfg, and
a stub reset is screened out, so the reserve tracks each board's real ladder
instead of one fleet number: 390s for the two RP boards -- whose ladder the old
250 could not contain, which is exactly why the gates skipped their steps --
190s for the other seventeen probe-reset boards, and 150s for esptool and
lm4flash, whose reset is a no-op. Changing a bound in usbtest moves the
reserve with it, and a unit test asserts it covers the ladder.
With the room actually reserved, the child runs the ladder straight through:
recovery_steps, _time_left, the three per-step gates and the parsed-but-unused
--outer-timeout are gone. What stays is what decides outcomes -- the convoy_safe
gate, reset-before-reflash, the no_op screen so a stub that resets nothing is not
claimed, and wedged_pids() as the arbiter, because a clean flash only proves the
probe wrote the MCU.
hil_util.py 616 -> 514 lines.
Diffstat (limited to 'test/hil/helper')
| -rwxr-xr-x | test/hil/helper/hil_lock.py | 15 | ||||
| -rw-r--r-- | test/hil/helper/hil_pool_check.py | 51 | ||||
| -rw-r--r-- | test/hil/helper/hil_report.py | 22 | ||||
| -rw-r--r-- | test/hil/helper/hil_util.py | 363 |
4 files changed, 195 insertions, 256 deletions
diff --git a/test/hil/helper/hil_lock.py b/test/hil/helper/hil_lock.py index 7757ef17d..91f05ca86 100755 --- a/test/hil/helper/hil_lock.py +++ b/test/hil/helper/hil_lock.py @@ -175,13 +175,12 @@ def controller_of(uid: str): if cached: return cached # vid='cafe' first: the target is always a TinyUSB DUT, and the VID is a lock-free - # descriptor field. Without it this read every probe's and hub's `serial` -- the - # attribute served under device_lock -- so a HEALTHY peer mid-usbtest would strand a - # reader here and spend one of this worker's four blindness credits. - devs, _ = hil_util.usb_scan(vid='cafe', serial=uid) + # descriptor field. Without it this reads every probe's and hub's `serial` -- the one + # attribute served under device_lock -- so a wedged peer would block us here. + devs = hil_util.usb_scan(vid='cafe', serial=uid) for dev in devs: busnum = hil_util.read_sysfs(os.path.join(dev['dir'], 'busnum')) - if busnum is None or busnum is hil_util.SYSFS_UNKNOWN: + if busnum is None: continue try: root = os.path.realpath(f'/sys/bus/usb/devices/usb{int(busnum)}') @@ -212,7 +211,7 @@ def controller_slot(pci: str) -> int: # Unresolved boards budget in a slot of their OWN, one past the real ones, and that slot # holds exactly ONE permit whatever the per-controller width is. Neither neighbour works: # a permit on every slot (the old fail-closed rule) serialized the whole fleet the moment -# a worker went blind, while a full private budget let unknown boards run a second +# one board could not be resolved, while a full private budget let unknown boards run a second # controller's worth of batteries on top of the resolved ones -- doubling the load on # whichever physical controller they actually sit on, which is the saturation the # uPD720201 deaths above are attributed to. Width 1 caps the over-subscription at +1. @@ -252,8 +251,8 @@ class controller_permit: if pci is None: pci = controller_of(uid) if pci is None and warn_unknown: - log(f'warning: cannot resolve {uid} to a host controller' - f'{hil_util.sysfs_blind_note()}; budgeting it in the unknown bucket') + log(f'warning: cannot resolve {uid} to a host controller; ' + f'budgeting it in the unknown bucket') self.slots = [controller_slot(pci) if pci else UNKNOWN_SLOT] def __enter__(self): diff --git a/test/hil/helper/hil_pool_check.py b/test/hil/helper/hil_pool_check.py index 4623ce45f..d98b92bd4 100644 --- a/test/hil/helper/hil_pool_check.py +++ b/test/hil/helper/hil_pool_check.py @@ -54,7 +54,7 @@ ENUM_WAIT_RETRY = 8 # s, uid wait after a recovery reset/re-flash SERIAL_WAIT = 6 # s, host-board serial-output wait print_mutex = threading.Lock() -_UNKNOWN_WARNED = False # scan_usb's caveat: once per process, not once per poll +_STRANDED_WARNED = False # scan_usb's caveat: once per process, not once per poll t0 = time.monotonic() @@ -72,20 +72,20 @@ def scan_usb() -> dict: USB-Serial-JTAG bridge and the cafe device it flashes both derive it from the same MAC), and one dict slot would silently drop whichever lost the race.""" found = {} - # `unknown` matters BEFORE the blindness latch trips: one wedged device is the normal - # reason this tool is run, and its serial read stranding makes it absent from `devs`. - # Reported as fact, that is "probe MISSING" for hardware that is physically present. - devs, unknown = hil_util.usb_scan() - # ONCE per process: this is called from 0.5s poll loops across 4 worker threads and - # ~26 boards, so warning per call buried the table it exists to qualify under 600+ - # identical lines. The memo in read_sysfs makes the condition sticky, so one line is - # as true as six hundred. - global _UNKNOWN_WARNED - if unknown and not _UNKNOWN_WARNED: - _UNKNOWN_WARNED = True - say('WARNING: at least one device did not answer a bounded read; rows below that ' - 'say a probe or board is missing may be this scan losing sight of healthy ' - 'hardware. Find the wedged device (usb-kernel-recover) and re-run.') + # usb_scan's `serial` read is bounded by default (see hil_util.read_sysfs) -- this tool + # has no pool guard behind it and is run exactly when a device is suspected wedged. A + # device that will not answer is simply absent from the table; the footer says so. + devs = hil_util.usb_scan() + # ONCE per process, at SCAN time, not only in the footer: this tool prints rows as it + # goes over minutes, so a board dropped from the scan says "probe MISSING" within + # seconds while the only qualification would arrive after the final counts -- and an + # operator acting on the streaming output, or a run cut short by ^C, never sees it. + global _STRANDED_WARNED + if hil_util.sysfs_stranded() and not _STRANDED_WARNED: + _STRANDED_WARNED = True + say('WARNING: a bounded sysfs read gave up; rows below that say a probe or board ' + 'is missing may be this scan losing sight of healthy hardware. Find the ' + 'wedged device (usb-kernel-recover) and re-run.') for dev in devs: try: found[dev['busport']] = { @@ -1045,17 +1045,16 @@ def main() -> None: counts[r.get('status', 'failed')] += 1 print(f'\n{counts["ok"]} ok · {counts["flash-failed"]} flash-failed · {counts["failed"]} failed ' f'· {counts["locked"]} locked · in {time.monotonic() - t0:.0f}s') - if hil_util.sysfs_blind(): - # Without this the table is the worst kind of wrong: once the process latches - # blind, every read answers SYSFS_UNKNOWN, scan_usb() returns {}, and EVERY board - # prints "probe MISSING"/"off bus" -- a clean-looking report declaring the whole - # fleet dead, produced during exactly the incident this tool is run to diagnose, - # and it sends the operator to power-cycle a rig where one device is wedged. - print('WARNING: this scan lost sight of the bus' - f'{hil_util.sysfs_blind_note()}. Rows above that say a probe or board is ' - f'missing may be this tool losing sight of healthy hardware, not absent ' - f'hardware. Find the wedged device (see the usb-kernel-recover skill) and ' - f're-run before acting on the table.') + if hil_util.sysfs_stranded(): + # Without this the table is the worst kind of wrong: a device whose `serial` never + # answered is absent from the scan, which prints as "probe MISSING"/"off bus" for + # hardware that is physically present -- during exactly the incident this tool is + # run to diagnose, and it sends the operator to power-cycle a healthy rig. + print('WARNING: at least one sysfs read did not answer within ' + f'{hil_util.SYSFS_READ_GRACE:.0f}s, so rows above that say a probe or board ' + f'is missing may be this tool losing sight of healthy hardware rather than ' + f'absent hardware. Find the wedged device (see the usb-kernel-recover ' + f'skill) and re-run before acting on the table.') sys.exit(min(counts['flash-failed'] + counts['failed'], 125)) diff --git a/test/hil/helper/hil_report.py b/test/hil/helper/hil_report.py index d059c62c9..c93c8e6a1 100644 --- a/test/hil/helper/hil_report.py +++ b/test/hil/helper/hil_report.py @@ -63,6 +63,10 @@ LOCKED_CELL = 'board-locked' # A pseudo-test column, not a real one: write_timeout_report marks the boards that were # still dispatched when the pool guard fired. accumulate_report clears it on a retry. POOL_TIMEOUT_CELL = 'pool-timeout' +# The other way a board can fail to report: the pool did not expire, a worker RAISED. Same +# shape, different cause, and naming the cause is the whole point of the column -- a board +# marked pool-timeout by an abort that never timed out sends the reader after the guard. +RUN_ABORTED_CELL = 'run-aborted' def _load(report_dir: Path) -> tuple: @@ -352,6 +356,7 @@ def accumulate_report(mret: list, report_dir: Path, fresh: bool, scope: str = '' # never reported, and update() below MERGES, so without this a board that # passed clean on the retry kept a red cell for ever. stale[0].pop(POOL_TIMEOUT_CELL, None) + stale[0].pop(RUN_ABORTED_CELL, None) if not stale[0]: # variant-keyed boards never repopulate the board-name row, so drop it # or it renders as a blank ghost row @@ -360,6 +365,7 @@ def accumulate_report(mret: list, report_dir: Path, fresh: bool, scope: str = '' row = acc.setdefault(row_label, [{}, None]) # a row that ran is no longer pool-timed-out, whatever it is keyed by row[0].pop(POOL_TIMEOUT_CELL, None) + row[0].pop(RUN_ABORTED_CELL, None) # the boundary cell is only ever written on failure, so a re-run of this # variant that cleared the boundary must drop the previous attempt's ❌ if BOUNDARY_CELL not in cells: @@ -409,7 +415,8 @@ def _write_stuck_over_prior_md(report_dir: Path, doc: dict) -> None: def write_timeout_report(report_dir: Path, boards, secs: int, - banner: str = '', prefix: str = '') -> None: + banner: str = '', prefix: str = '', + cell: str = POOL_TIMEOUT_CELL) -> None: """Leave a report behind when the worker pool has to be abandoned. map_async is all-or-nothing, so a timeout loses every per-board result and the report @@ -427,7 +434,7 @@ def write_timeout_report(report_dir: Path, boards, secs: int, caveat = banner or ( f'**HIL run abandoned: worker pool timed out after {secs}s.**\n\n' f'No per-board results could be collected for this attempt. Rows other than ' - f'the {POOL_TIMEOUT_CELL} cells below are from an earlier attempt. Boards ' + f'the {cell} cells below are from an earlier attempt. Boards ' f'dispatched:\n\n' + '\n'.join(f'- {n}' for n in names) + '\n') doc, readable = _load(report_dir) rows = doc['rows'] @@ -435,13 +442,13 @@ def write_timeout_report(report_dir: Path, boards, secs: int, for name in names: row = by_board.get(name) if row is None: - rows.append({'board': name, 'cells': {POOL_TIMEOUT_CELL: 'fail'}, + rows.append({'board': name, 'cells': {cell: 'fail'}, 'duration': None}) else: # _load guarantees `cells` is a dict, so a null-cells row from an uploaded # sidecar can no longer send this down the fallback and publish a board # that ate the whole pool guard as a pass. - row['cells'][POOL_TIMEOUT_CELL] = 'fail' + row['cells'][cell] = 'fail' out = {'rows': rows, 'scope': doc['scope'], 'caveat': caveat, 'banner': ((doc['banner'] + prefix) if prefix not in doc['banner'] else doc['banner'])} @@ -517,8 +524,11 @@ def summarize(cfg: dict, boards: list, report: dict) -> dict: # a wedge outranks lock contention: `locked` short-circuits `detail` below, so a # stale board-locked cell from an earlier attempt used to mask the pool-timeout # cell the retry added -- publishing a board that hung the rig as LOCKED, which - # hil-validate.js then RE-RUNS, paying another pool guard on it. - wedged = any(POOL_TIMEOUT_CELL in cells for cells in mine.values()) + # hil-validate.js then RE-RUNS, paying another pool guard on it. RUN_ABORTED_CELL + # is written by the same _abort_report path for a board the guard never reached, + # and must outrank it for the same reason. + wedged = any(POOL_TIMEOUT_CELL in cells or RUN_ABORTED_CELL in cells + for cells in mine.values()) locked = not wedged and any(LOCKED_CELL in cells for cells in mine.values()) bad = [] for vname, cells in sorted(mine.items()): diff --git a/test/hil/helper/hil_util.py b/test/hil/helper/hil_util.py index f279cfa77..b2c233cf3 100644 --- a/test/hil/helper/hil_util.py +++ b/test/hil/helper/hil_util.py @@ -90,6 +90,10 @@ def pos_float_env(name: str, default: float) -> float: CMD_TIMEOUT = pos_int_env('HIL_CMD_TIMEOUT', 180) +# Post-SIGKILL reap, spent ON TOP of a run_cmd timeout whenever the child has to be killed. +# A caller budgeting several bounded steps must add one of these PER STEP, or its own outer +# bound fires mid-step -- for a flasher, orphaning it on the probe. +REAP_GRACE = 10 TINYUSB_ROOT = Path(__file__).resolve().parents[3] # test/hil/helper/ -> repo root @@ -158,74 +162,119 @@ def _print_banner(title: str, out: Any, err: Any) -> None: print(_banner_body(out, err)) -SYSFS_READ_GRACE = 2.0 # bound on one attribute read of a possibly-wedged device -SYSFS_STUCK_MAX = 4 # stranded readers tolerated before read_sysfs goes blind -_sysfs_stuck = 0 # each costs a thread + an fd for the life of the process -_sysfs_stuck_lock = threading.Lock() -_sysfs_blind_logged = False +SYSFS_READ_GRACE = 2.0 # default bound on one attribute read; see read_sysfs +# path -> the kernfs inode the node had when its bounded read gave up. Keyed by INODE, not +# by path alone: a busport does not change when a board returns to the same physical port, +# so a path-only blacklist outlives the wedge -- hil_pool_check resets or reflashes the +# board, wait_device polls that busport for the new inode, and the scan it polls through +# would never look at the device again. A re-enumeration destroys the kernfs node and makes +# a new one, so a CHANGED inode is the all-clear. os.stat is safe on a wedged device: it +# does not call ->show(), so it cannot block on the lock the reader is stuck behind. +_stranded: dict = {} +_strand_hits: dict = {} # path -> how many times it has stranded, ever +_refused: set = set() # paths answered None WITHOUT reading, once past _STRAND_MAX +_strand_lock = threading.Lock() +_ever_stranded = False -class _SysfsUnknown: - """Sentinel: the read did not answer. NOT "the attribute is absent" -- reading it as - absence turns a healthy board into a firmware regression in the report.""" - __slots__ = () +# Each strand costs a thread AND an fd for the life of the process -- on sysfs the open() +# SUCCEEDS and only the read blocks. Two ceilings, because they bound different things: +# +# _PATH_STRAND_MAX -- a device that FLAPS while still wedged re-enumerates, clears the +# inode memo, and strands again. Per path, so one sick board cannot leak without bound. +# After this many it stays memoised whatever its inode says. +# _STRAND_MAX -- a whole-process backstop against RLIMIT_NOFILE or the thread ceiling, +# which would raise inside a worker and lose every board's result. Counted PER PATH, not +# per reader: hil_pool_check runs four poll threads over one bus, and counting each +# reader let four threads on ONE wedged device spend four credits between them. With +# per-path counting a 27-board rig cannot approach this. +_PATH_STRAND_MAX = 4 +_STRAND_MAX = 64 - def __bool__(self) -> bool: - return False - def __repr__(self) -> str: - return 'SYSFS_UNKNOWN' +def sysfs_stranded() -> bool: + """True once any bounded read has given up, and it STAYS true. + A sticky, process-wide fact, so it answers exactly one question: "could anything in + this process's output be the tool losing sight of healthy hardware?" -- which is what + hil_pool_check's footer needs. It canNOT answer "is THIS device unreadable" for a + caller deciding what a single missing device means; use path_stranded() for that. + """ + return _ever_stranded -SYSFS_UNKNOWN = _SysfsUnknown() +def strand_note() -> str: + """Suffix for an absence claim, so "not found" never reads as proven absence. -def sysfs_blind() -> bool: - """True once this process has stranded SYSFS_STUCK_MAX readers: every later read - answers SYSFS_UNKNOWN, so nothing it reports about a device is a fact any more.""" - return _sysfs_stuck >= SYSFS_STUCK_MAX + Lives here because every caller that can say "not found" needs the same sentence, and + the one that had to re-invent it got missed: a wedged-but-enumerated printer was + reported as an enumeration failure, sending a maintainer after firmware. + """ + return (' (a bounded sysfs read gave up, so "not found" here means "could not tell"' + ' -- see the usb-kernel-recover skill)') if sysfs_stranded() else '' -def sysfs_blind_note() -> str: - """Suffix for a failure message, so a blind worker's verdict never reads as hardware.""" - return (f' (this worker is blind: {SYSFS_STUCK_MAX} sysfs reads stranded on a wedged ' - f'device, so the check could not see the bus)') if sysfs_blind() else '' +def path_stranded(path: str) -> bool: + """Whether THIS attribute is currently memoised as unreadable. + The per-device question sysfs_stranded() cannot answer. usbtest uses it to tell a DUT + whose `serial` is held under device_lock from one that genuinely left the bus, because + the difference decides whether it performs driver-registry writes that take the + UNINTERRUPTIBLE device_lock. + """ + with _strand_lock: + return path in _stranded or path in _refused -def read_sysfs(path: str, grace: float = SYSFS_READ_GRACE) -> str | None | _SysfsUnknown: - """Read a sysfs attribute with a WALL-CLOCK bound. - The value, None when the attribute is genuinely unreadable (OSError), or SYSFS_UNKNOWN - when the read did not answer -- it timed out, or this process is already blind. Callers - MUST keep those apart: absence is a fact, unknown is not. +def read_sysfs(path: str, timeout: float = SYSFS_READ_GRACE) -> str | None: + """A sysfs attribute's value, or None when it did not answer. - usb_string_attr (serial/product/manufacturer) is served under the device lock a wedged - usbfs ioctl holds, so a plain open().read() blocks for as long as the wedge lasts, on - exactly the board an incident is about. The reader sleeps INTERRUPTIBLY (every read - takes usb_lock_device_interruptible, v6.12.96 sysfs.c:124-139 -- uninterruptible is the - ioctl holder, not us), so it dies with a SIGKILLed worker; what it costs meanwhile is a - thread and an fd for this process's life, because on sysfs the open() SUCCEEDS and only - the read blocks. Measured: 20 blocking reads leave 20 live threads. + BOUNDED BY DEFAULT, and it has to be. `serial` is served by usb_string_attr, which + takes usb_lock_device_interruptible (v6.12.96 sysfs.c:141-143) -- the same lock a + wedged usbfs ioctl holds. Every OTHER attribute the harness reads (idVendor, idProduct, + bcdDevice, busnum, devnum, speed) is a lock-free sysfs_emit from a cached field and + cannot block. - Hence the cap: callers rescan (hil_lock's controller_of re-reads every unresolved - device on EVERY permit), and hitting RLIMIT_NOFILE or the thread ceiling raises inside - the worker and loses every board's result -- worse than the hang this prevents. + "Only the wedged board's own worker pays" is FALSE, which is why the bound is not + opt-in: usb_scan reads `serial` on every device matching the VID to find the one it + wants, so resolving MY board touches every peer's locked attribute. hil_lock's + controller_of does that from controller_permit, on essentially every board -- one + wedged DUT would stall every worker, not one. hil_pool_check has no guard at all. + + A give-up reads as None, the same as unreadable: there is no third value and no + per-attribute blindness. The memo is keyed by inode so the cost stays on the device + that is actually wedged; path_stranded() tells a caller which device that was. """ - if sysfs_blind(): - return SYSFS_UNKNOWN - # Known-stranded? Re-reading costs another permanent thread+fd and a blindness credit - # to learn what we already know. Lives HERE, not at the call sites: a call-site memo - # has to be remembered by every new scanner, and twice it was not. - was = _sysfs_stranded.get(path, _STRAND_MISS) - if was is not _STRAND_MISS: - if was is None: - return SYSFS_UNKNOWN # stranded, inode unknown: never re-read it + with _strand_lock: + was = _stranded.get(path) + stuck_for_good = _strand_hits.get(path, 0) >= _PATH_STRAND_MAX + budget_spent = len(_stranded) >= _STRAND_MAX + if was is not None: try: if os.stat(path).st_ino == was: - return SYSFS_UNKNOWN # same node, still wedged + return None # same kernfs node, still wedged except OSError: - pass # gone: fall through, the read reports it - _sysfs_stranded.pop(path, None) # replaced or gone -> re-read it + pass # gone: let the read below report it + if stuck_for_good: + return None # flapped too many times; see _PATH_STRAND_MAX + with _strand_lock: + _stranded.pop(path, None) # a different inode is the all-clear + elif budget_spent: + # see _STRAND_MAX. Recorded, not just returned: usbtest fails CLOSED on + # path_stranded() before the lock-taking cleanup, and a path we declined to read + # is exactly the case it must not be told is readable-and-absent. + with _strand_lock: + _refused.add(path) + return None + + # BEFORE the read, not after: a node that re-enumerates DURING the grace would + # otherwise have its brand-new HEALTHY inode recorded as the wedged one, and only a + # second re-enumeration could ever clear it. If it cannot be stat'd there is no key to + # memoise against, so the path is simply re-read next time -- the open fails fast. + try: + ino = os.stat(path).st_ino + except OSError: + ino = None out: dict = {} def _read(): @@ -233,92 +282,66 @@ def read_sysfs(path: str, grace: float = SYSFS_READ_GRACE) -> str | None | _Sysf with open(path) as f: out['v'] = f.read().strip() except (OSError, ValueError): - pass # no such attribute, or not text: unreadable, and that IS a fact + pass t = threading.Thread(target=_read, daemon=True) t.start() - t.join(grace) - # `out` FIRST, not is_alive() alone: a reader can deposit its value and still be alive - # for a moment afterwards, and counting that as a strand memoises a healthy attribute as - # unreadable and spends one of four blindness credits. bounded_open has always checked - # its box for the same reason. + t.join(timeout) + # `out` FIRST: a reader can deposit its value and still be alive for a moment + # afterwards, and counting that as a strand blacklists a healthy attribute forever + if 'v' in out: + # a path that answered is not refused any more: _refused feeds path_stranded(), + # and a stale entry makes usbtest read a LATER genuine disconnect as "cannot tell" + with _strand_lock: + _refused.discard(path) if t.is_alive() and 'v' not in out: - # Count the PATH once, not once per reader. hil_pool_check runs -j4 by default, - # which equals SYSFS_STUCK_MAX, so four threads hitting ONE wedged device used to - # spend the entire blindness budget between them -- latching blind on the single - # wedge the tool was run to find. The strand is real for each thread, but the - # DEVICE is what the cap is about. - # Under the SAME lock as the counter: check-then-act here is a race, and - # hil_pool_check runs a ThreadPoolExecutor of exactly SYSFS_STUCK_MAX workers in - # ONE process, so four threads on one wedged path could each see `first` before any - # of them recorded it -- spending the whole blindness budget on a single device, - # which is what this memo exists to prevent. note_sysfs_strand takes the lock - # itself, so call it after releasing. - with _sysfs_stuck_lock: - first = path not in _sysfs_stranded - if first: - try: - # stat, never the thread's own open(): stat does not call ->show(), so - # it cannot block on the device lock the reader is stuck behind - _sysfs_stranded[path] = os.stat(path).st_ino - except OSError: - _sysfs_stranded[path] = None # unstattable, but still known-stranded - if first: - note_sysfs_strand() - return SYSFS_UNKNOWN + global _ever_stranded + announce = False + if ino is None: + # the pre-read stat lost a race the open then won -- the node was replaced + # between them. Re-stat now: the reader is blocked on whatever node exists, + # so this is the key it is stuck on. Without a key nothing is memoised and + # every later poll starts another permanent thread and fd for this path. + try: + ino = os.stat(path).st_ino + except OSError: + pass + with _strand_lock: + _ever_stranded = True + if ino is not None: + first = path not in _stranded # count the PATH once, not each reader + _stranded[path] = ino + if first: + _strand_hits[path] = _strand_hits.get(path, 0) + 1 + announce = len(_stranded) == _STRAND_MAX + else: + _refused.add(path) # unkeyable: at least do not vouch for it + if announce: + print(f'warning: {_STRAND_MAX} devices have unreadable sysfs attributes; ' + f'refusing to start more bounded readers, so later reads answer None ' + f'without looking. Find the wedged device (usb-kernel-recover skill).', + file=sys.stderr, flush=True) + return None return out.get('v') -def note_sysfs_strand() -> None: - """Record ONE stranded sysfs reader. Shared by read_sysfs and bounded_open so both - account against a single counter -- the report caveat keys off it.""" - global _sysfs_stuck, _sysfs_blind_logged - with _sysfs_stuck_lock: - _sysfs_stuck += 1 - announce = sysfs_blind() and not _sysfs_blind_logged - _sysfs_blind_logged = _sysfs_blind_logged or announce - if announce: - # once per process, on stderr: a worker's stdout is compacted into one report - # row, where this would be lost among the test output - print(f'warning: {SYSFS_STUCK_MAX} sysfs reads stranded on a wedged device; ' - f'this process is now blind and answers SYSFS_UNKNOWN for every ' - f'attribute -- its verdicts about device presence are not evidence', - file=sys.stderr, flush=True) - - -# path -> the inode it had when its read stranded. A stranded attribute stays -# stranded until the DEVICE is replaced, and a re-enumeration destroys the kernfs -# node and makes a new one -- so a changed inode is the all-clear. Keyed by path -# alone it would outlive the wedge: a busport does not change when a board comes -# back on the same port, so the HUNG reflash this branch performs would recover a -# board the harness could then never see again. -_sysfs_stranded: dict = {} -# A stranded path whose inode could not be read is stored as None, so a plain .get() cannot -# tell 'known stranded, inode unknown' from 'never seen' -- and treating the first as the -# second re-reads it, stranding another permanent thread and fd every call. Distinct miss -# sentinel, so None keeps its own meaning. -_STRAND_MISS = object() - - -def usb_scan(vid_pid=None, serial=None, vid=None) -> tuple[list, bool]: - """Enumerated USB devices matching the filters, and whether anything is unknown. - - Returns ([{busport, dir, vid, pid, serial}], unknown). `unknown` True means a bounded - read did not answer, so absence is NOT proven -- the same contract as read_sysfs. +def usb_scan(vid_pid=None, serial=None, vid=None, timeout=SYSFS_READ_GRACE) -> list: + """Enumerated USB devices matching the filters: [{busport, dir, vid, pid, serial}]. Three rules, one implementation for every caller: * Root hubs excluded (glob `*-*`): no DUT is one, and scans including them measured seconds slower (observation, no mechanism -- the "autosuspend wake" explanation was - wrong; usb_string_attr reads a cached string, sysfs.c:124-139). + wrong; usb_string_attr reads a cached string, sysfs.c:141-143). * idVendor/idProduct first: lock-free `sysfs_emit` from udev->descriptor (sysfs.c:688-705), so they rule out nearly every device for free. - * `serial` last and bounded: it is served under the lock a wedged ioctl holds, and a - path that already stranded is never re-read (each strand costs a thread and an fd - for this process's life). + * `serial` LAST and BOUNDED: it is the only attribute here served under the device + lock, so it is the only one that can block. Filtering on the lock-free pair first + keeps most devices out of it, but a scan for ONE board still reads the serial of + every peer that shares its VID -- so the bound is what stops one wedged DUT from + stalling every caller (see read_sysfs). """ out = [] - unknown = False for d in glob.glob('/sys/bus/usb/devices/*-*'): # Interfaces are '<busport>:<cfg>.<ifnum>' (e.g. 2-4:1.0) -- they CONTAIN the # colon, they do not end with it, so the original endswith() never fired and every @@ -336,106 +359,14 @@ def usb_scan(vid_pid=None, serial=None, vid=None) -> tuple[list, bool]: continue # ruled out for free, without touching the locked attribute if vid is not None and dev_vid != vid: continue # same, for callers that know the VID but not the PID - sn = read_sysfs(os.path.join(d, 'serial')) - if sn is SYSFS_UNKNOWN: - unknown = True # read_sysfs memoises it; a repeat scan costs nothing - continue + sn = read_sysfs(os.path.join(d, 'serial'), timeout) if sn is None: - continue # no serial attribute: a fact + continue # no serial attribute if serial is not None and sn.lower() != serial.lower(): continue out.append({'busport': os.path.basename(d), 'dir': d, 'vid': dev_vid, 'pid': dev_pid, 'serial': sn}) - return out, unknown - - -def bounded_open(path: str, flags: int, timeout: float = SYSFS_READ_GRACE): - """os.open() with a wall-clock bound. - - The fd, None when the open genuinely FAILED (OSError: EBUSY, ENOENT, EACCES), or - SYSFS_UNKNOWN when it did not answer -- the same three-valued contract as read_sysfs, - and for the same reason: folding a fact into an unknown made an ordinary EBUSY read as - a wedged device and sent the operator hunting hardware that is healthy. - - An open CAN block on a wedged device -- not on O_NONBLOCK, which usblp_open never - consults, but on usb_autopm_get_interface(), a runtime-PM resume that does I/O - (v6.12.96 drivers/usb/class/usblp.c). It holds usblp_mutex while it waits, and that - mutex is driver-GLOBAL, so one wedged printer blocks opens of every usblp node. - - Unlike read_sysfs the stranded thread cleans up after itself: if we have given up it - closes the fd it eventually got, so only the thread leaks. Both sides take `handoff` - -- "store or close" and "abandon and drain" are a check-then-act pair that can - interleave into an fd stored after the box was drained, which would leak it into a - node that allows a SINGLE opener (usblp_open returns -EBUSY when usblp->used). - """ - # Same short-circuit as read_sysfs: once blind, another stranded thread buys nothing - # and the cap exists precisely to stop them accumulating. - if sysfs_blind(): - return SYSFS_UNKNOWN - # Known-stranded? Re-opening costs another thread, another fd and another blindness - # credit to learn what we already know -- and the printer test re-opens ONE lp node on - # every retry. Same memo and same inode check as read_sysfs. - was = _sysfs_stranded.get(path, _STRAND_MISS) - if was is not _STRAND_MISS: - if was is None: - return SYSFS_UNKNOWN # stranded, inode unknown: never re-read it - try: - if os.stat(path).st_ino == was: - return SYSFS_UNKNOWN - except OSError: - pass - _sysfs_stranded.pop(path, None) - box: dict = {} - done, abandoned = threading.Event(), threading.Event() - handoff = threading.Lock() - - def _open(): - try: - fd = os.open(path, flags) - except OSError: - done.set() - return - with handoff: - stored = not abandoned.is_set() - if stored: - box['fd'] = fd - if not stored: - try: - os.close(fd) - except OSError: - pass - done.set() - - threading.Thread(target=_open, daemon=True).start() - if not done.wait(timeout): - with handoff: - abandoned.set() - fd = box.pop('fd', None) # completed in the gap between timeout and flag - if fd is not None: - # It DID open, just after our deadline -- the thread finished, so nothing is - # stranded. Report unknown (we already gave up on it) but do not spend a - # blindness credit, and do not call a merely-slow node wedged. - try: - os.close(fd) - except OSError: - pass - return SYSFS_UNKNOWN - # counted like a stranded read_sysfs: the thread and (eventually) its fd are gone - # for the life of the process, and the cap exists to stop that reaching the - # thread/fd ceiling -- an exception there escapes the worker and loses every board. - # Memoised by inode so a retry of the same node does not pay again. - # same lock as read_sysfs, same reason - with _sysfs_stuck_lock: - first = path not in _sysfs_stranded - if first: - try: - _sysfs_stranded[path] = os.stat(path).st_ino - except OSError: - _sysfs_stranded[path] = None - if first: - note_sysfs_strand() - return SYSFS_UNKNOWN - return box.get('fd') + return out def _close_pipes(p: subprocess.Popen) -> None: @@ -478,7 +409,7 @@ def run_alongside(argv: list, work, timeout: int) -> subprocess.CompletedProcess except OSError: p.kill() try: - out, err = p.communicate(timeout=5) + out, err = p.communicate(timeout=REAP_GRACE) except subprocess.TimeoutExpired: # Outlasted SIGKILL: uninterruptible, still holding whatever it opened. # Abandoned like any other stray -- but as a real child in its own @@ -575,7 +506,7 @@ def run_cmd(cmd: str | list, cwd: str | None = None, timeout: int | None = None, # close and the rc-124 return this handler exists for. pass try: - out, err = p.communicate(timeout=10) + out, err = p.communicate(timeout=REAP_GRACE) except subprocess.TimeoutExpired: # Something in the group outlived SIGKILL: D state (truly unkillable), or # root-owned because sudo FORKS rather than execs, so the wrapper dies and its |
