#!/usr/bin/env python3 # SPDX-License-Identifier: BSD-3-Clause # Copyright (c) 2026 Open-IOV contributors # semfix_uvmt.py - single-QMP tracking-semaphore/resolution watcher. # # One QMP client does everything semfix_watch.py and uvmt_poll.py did, because # QEMU's QMP socket accepts a single client: running the two tools side by side # silently broke semfix's pinning. # # Jobs: # 1. keep the client's tracking-semaphore pool pages and push-buffer pages # pinned with fresh guest truth (semfix_watch.py, imported); # 2. poll every tracking semaphore seen in the guest trace and print the exact # word the client's wait polls: pool GPU VA (gpu_base + idx*4), its guest PA # (gva2gpa of the CPU mapping), the payload value and the +0x14/+0x28 # fields. Every change is appended to a timeline file, so the last wait # before a failure and the release that should clear it are both visible; # 3. mirror the host's decoded releases (dmesg `sema-push ... rel=... pay=...`) # into the same timeline, so a wait can be matched to the channel/push that # releases its word. # # Usage: tools/guest-diag/semfix_uvmt.py [interval-seconds] # Env: TIMELINE=/tmp/opencode/uvmt_timeline.log # UVMT_HEARTBEAT=30 (seconds between unchanged-state heartbeats) import os import re import subprocess import sys import time HERE = os.path.dirname(os.path.abspath(__file__)) sys.path.insert(0, HERE) from semfix_watch import ( # noqa: E402 Qmp, QMP_SOCK, is_kern, is_gpu, diag_str, guest_trace, resolve_sem_pool, pin, pin_bulk, resolve_from_channel, resolve_from_pushbuffer, resolve_from_sem, resolve_pushbuffer_wide, pin_pushbuffer, PUSHBUF_MAX_PAGES, ) TIMELINE = os.environ.get("TIMELINE", "/tmp/opencode/uvmt_timeline.log") HEARTBEAT = float(os.environ.get("UVMT_HEARTBEAT", "30")) DLOG = os.environ.get("UVMT_DMESG", "1") == "1" VMEXEC = os.path.normpath(os.path.join(HERE, "..", "..", "scripts", "vgpu_vm.py")) COUNTER_LO = int(os.environ.get("COUNTER_LO", "0x20400f000"), 16) COUNTER_HI = int(os.environ.get("COUNTER_HI", "0x204010000"), 16) SEMSTREAM = os.environ.get("SEM_STREAM_FILE", "/tmp/opencode/sem_stream.txt") TRACE_EVERY = int(os.environ.get("UVMT_TRACE_EVERY", "5")) # The push-buffer resolution walks the channel/pool/manager chain with many # QMP reads and can block the poller for tens of seconds. When the GR window # stream (pin_gr_stream.py) already supplies the push-buffer pages, skip it so # the tracking-sem poller stays live during the client's deadline window. SKIP_PB = os.environ.get("SEMFIX_SKIP_PB", "0") == "1" # Seconds between counter-page pin attempts (the guest-agent exec blocks for # its full timeout when the client saturates the guest). COUNTER_RETRY_S = float(os.environ.get("SEMFIX_COUNTER_RETRY", "10")) # Liveness file checked by pin_supervisor.sh (mtime must stay < 75 s; the # supervisor grants a 120 s startup grace on top). SEMFIX_HB_FILE = os.environ.get("SEMFIX_HEARTBEAT_FILE", "/tmp/opencode/semfix_heartbeat") # Dead-pid/stall watchdog tuning (seconds). The tracked client is probed in # the guest only when it has been idle this long, on a cadence, so live # clients are never probed and a killed client is detected within ~1 min. LIVENESS_IDLE_S = float(os.environ.get("SEMFIX_LIVENESS_IDLE", "15")) LIVENESS_EVERY_S = float(os.environ.get("SEMFIX_LIVENESS_EVERY", "25")) # Pre-capture stall: client alive, counter page not pinned, no progress for # this long -> recovery attempt; escalate loudly if it persists. STALL_PRECAP_S = float(os.environ.get("SEMFIX_STALL_PRECAP", "60")) STALL_RETRY_S = float(os.environ.get("SEMFIX_STALL_RETRY", "30")) STALL_ESCALATE_S = float(os.environ.get("SEMFIX_STALL_ESCALATE", "180")) # Inter-tool re-assert request: written here, consumed by pin_gr_stream.py # (full ping re-assert of every pair it has ever pinned). REASSERT_REQ = os.environ.get("PIN_REASSERT_FILE", "/tmp/opencode/pin_reassert_request") def _hb(): try: with open(SEMFIX_HB_FILE, "w") as f: f.write("%.3f\n" % time.time()) except OSError: pass class Stream: """Tail the guest scanner's control lines mirrored by pin_gr_stream.py. The guest emits "#pid [starttime]" and "#sem 0x" over vsock; the listener appends them here. This replaces per-loop guest-agent trace reads, which were too slow to catch short-lived tracking semaphores. Replay safety (the m178 regression): the file persists across tool restarts, so a fresh process re-reads the whole history. Lines written before this process started (byte offset < init_size) are absorbed as HISTORY - they seed the dedupe/identity state and the sem/pb lists but can never trigger a per-client reset. Only lines appended afterwards are live. This makes a supervisor restart mid-run harmless. """ def __init__(self, path): self.path = path self.off = 0 self.sems = [] self.pids = [] self.pbs = [] self.new_pbs = [] self.new_nopids = [] self.history_pids = [] # (pid, start) identities from history self.pid_keys = set() # (pid, start) dedupe, per generation try: # Everything already in the file when this process starts is # history (a restart replays it); never reset on it. self._init_size = os.path.getsize(path) except OSError: self._init_size = 0 def reset(self): """Forget everything learned about the previous client. A new client allocates its own channel pools; keeping the old sems/seen-pin marks makes the watcher chase stale kernel pointers and pin the previous client's (freed) pool pages - the stale-translation trap.""" self.sems = [] self.pbs = [] self.pids = [] self.new_pbs = [] self.new_nopids = [] self.pid_keys = set() @staticmethod def _ident(line): """Parse '#pid 1234' or '#pid 1234 5678900' -> (pid, start|None).""" nums = re.findall(r"\d+", line) if not nums: return None, None return int(nums[0]), (int(nums[1]) if len(nums) > 1 else None) def poll(self): try: with open(self.path) as f: f.seek(0, os.SEEK_END) size = f.tell() if size < self.off: self.off = 0 f.seek(self.off) data = f.read() base = self.off self.off = f.tell() except OSError: return [], [], [] new_sems, new_pids = [], [] self.new_pbs = [] self.new_nopids = [] pos = base for line in data.splitlines(): # A line is live when it ends past the startup boundary; history # lines are absorbed (identity/dedupe) but never emitted as live. live = pos + len(line) + 1 > self._init_size pos += len(line) + 1 if line.startswith("#sem"): m = re.search(r"0x([0-9a-fA-F]+)", line) if m: v = int(m.group(1), 16) if v not in self.sems: self.sems.append(v) new_sems.append(v) elif line.startswith("#pb"): m = re.search(r"0x([0-9a-fA-F]+)", line) if m: v = int(m.group(1), 16) if v not in self.pbs: self.pbs.append(v) self.new_pbs.append(v) elif line.startswith("#pid"): pid, start = self._ident(line) if pid is not None and (pid, start) not in self.pid_keys: self.pid_keys.add((pid, start)) self.pids.append(pid) if live: new_pids.append((pid, start)) else: self.history_pids.append((pid, start)) elif line.startswith("#nopid"): # In-band client-death signal (new guest scanner; older ones # simply never send it and the host probe covers the case). pid, start = self._ident(line) if live and pid is not None: self.new_nopids.append((pid, start)) return new_sems, new_pids, self.new_nopids class ClientTracker: """Monotonic, replay-proof client-identity tracking. A client's identity is (pid, starttime). Rules, in priority order: * an identity adopted once is never reset a second time (duplicate lines, trace/stream replays, supervisor restarts); * a backwards pid, or the same pid with an older starttime, is a replay - never reset; * a pid recycled with a NEWER starttime is a real new client - reset immediately (the previous holder is definitionally gone); * a newer unseen identity only resets the per-client state once the CURRENT client is CONFIRMED gone - a reset fired while the previous client was still active is the m178 third-client hang regression. Pure logic: the caller feeds guest liveness results in and performs the actual state purge when an action says so. """ def __init__(self): self.seen = set() self.current = None self.pending = None self.dead = set() @staticmethod def _start_match(a, b): # Unknown starttimes match conservatively (legacy scanner lines). return a[1] == b[1] or a[1] is None or b[1] is None def observe_history(self, pid, start): """Absorb an identity found in pre-restart history: the process has no per-client state yet, so history only seeds identity tracking and the freshest identity becomes current - no reset is ever requested for history lines.""" key = (pid, start) if key in self.seen: return self.seen.add(key) self.current = key def note_dead(self, pid, start): """A #nopid or a successful dead probe: identity is gone.""" key = (pid, start) self.dead.add(key) if self.current and self.current[0] == pid \ and self._start_match(self.current, key): self.current = None if self.pending and self.pending[0] == pid \ and self._start_match(self.pending, key): self.pending = None def is_current(self, pid, start): """True when (pid, start) is the currently tracked identity (used to decide whether a death signal may purge - a stale #nopid for a recycled pid must never purge the new holder).""" return self.current is not None and self.current[0] == pid \ and self._start_match(self.current, (pid, start)) def decide(self, pid, start): """Classify a live #pid line: adopt | skip | skip_backwards | maybe_reset | reset.""" key = (pid, start) if key in self.seen: return "skip" self.seen.add(key) cur = self.current if cur is None: self.current = key return "adopt" if pid == cur[0] and self._start_match(cur, key): return "skip" if pid == cur[0] and start is not None and cur[1] is not None \ and start > cur[1]: # Recycled pid, newer process: safe to reset now. self.current = key return "reset" if pid < cur[0] or (pid == cur[0] and start is not None and cur[1] is not None and start < cur[1]): return "skip_backwards" self.pending = key return "maybe_reset" def resolve(self, old_dead): """Caller learned whether the CURRENT client is dead. Returns 'reset' (purge + adopt the pending client) or 'defer'.""" if self.pending is None: return None if old_dead: key = self.pending self.pending = None self.current = key return "reset" return "defer" def log(msg): line = "[%s] %s" % (time.strftime("%H:%M:%S"), msg) print(line, flush=True) try: with open(TIMELINE, "a") as f: f.write(line + "\n") except OSError: pass def uvmt_state(q, sem): """Read one tracking semaphore; returns a dict or None. Layout (uvm 570.144, verified by probe): sem+0 = tracking semaphore page object, sem+4 low u16 = pool index; page+0 = uvm_rm_mem; mem+0x10 = vas[]; the payload the client's update_completed_value polls is the u32 at cpu_va + idx*4 (its GPU alias is gpu_va + idx*4, the VA the releasing push writes). """ vals = q.read64(sem, 12, cache=False) if len(vals) < 2 or not is_kern(vals[0]): return None pv = q.read64(vals[0], cache=False) if not pv or not is_kern(pv[0]): return None mem = pv[0] vas = q.read64(mem + 0x10, 16, cache=False) cpu = next((v for v in vas if is_kern(v)), None) gpu = [v for v in vas if is_gpu(v)] idx = vals[1] & 0xffff payload = None word_pa = None if cpu is not None: w = q.read64(cpu + idx * 4, cache=False) payload = w[0] if w else None word_pa = q.gva2gpa(cpu + idx * 4) word_va = (gpu[0] + idx * 4) if gpu else None return { "page": vals[0], "mem": mem, "idx": idx, "gpu": gpu, "cpu": cpu, "payload": payload, "word_va": word_va, "word_pa": word_pa, "w14": vals[5] if len(vals) > 5 else 0, "w28": vals[10] if len(vals) > 10 else 0, } def state_key(st): if not st: return None return (st["idx"], st["payload"], st["w14"], st["w28"], st["word_pa"], tuple(st["gpu"])) def state_str(sem, st): if not st: return "sem=0x%x unreadable" % sem return ("sem=0x%x idx=%d word_va=%s word_pa=%s payload=%s " "+14=0x%x +28=0x%x gpu=%s" % (sem, st["idx"], "0x%x" % st["word_va"] if st["word_va"] is not None else "?", "0x%x" % st["word_pa"] if st["word_pa"] is not None else "?", "0x%x" % st["payload"] if st["payload"] is not None else "?", st["w14"], st["w28"], ",".join("0x%x" % v for v in st["gpu"]))) def dmesg_releases(seen): """Print/append new host-decoded releases (sema-push lines). Only lines after the last "sema-svc: thread started" marker count: dmesg keeps the previous module load's lines and the old client's releases. Returns the number of newly printed lines (used as watchdog progress). """ n = 0 try: r = subprocess.run( ["sudo", "-n", "sh", "-c", "dmesg -T | awk '/sema-svc: thread started/{n=NR} " "{l[NR]=$0} END{for(i=n+1;i<=NR;i++) print l[i]}' " "| grep 'sema-push' | tail -300"], capture_output=True, text=True, timeout=10) except Exception: return 0 for line in r.stdout.splitlines(): line = line.strip() if not line or line in seen: continue seen.add(line) n += 1 log("push: %s" % line.replace("vgsp: ", "")) return n def cdt_pid(): try: r = subprocess.run([VMEXEC, "exec", "pgrep -x cdt | head -1"], capture_output=True, text=True, timeout=30) except Exception: return None pids = re.findall(r"(?m)^(\d+)\s*$", r.stdout) return int(pids[-1]) if pids else None def _pid_alive_cmd(pid): """Guest shell that reports ALIVE / DEAD for a pid. Zombie-aware: a killed (SIGKILLed) client lingers as a defunct /proc entry, and a plain `test -d /proc/` would latch it as alive forever (the m178 dead-pid latch).""" return ("f=/proc/%d/stat; if [ -r \"$f\" ]; then " "s=$(sed -e 's/^[^)]*) //' -e 's/ .*//' \"$f\"); " "if [ \"$s\" = Z ] || [ -z \"$s\" ]; then echo DEAD; " "else echo ALIVE; fi; else echo DEAD; fi" % pid) def pid_alive(pid): """Guest liveness of a client pid: True alive, False dead/zombie/gone, None unknown (agent error). Callers must treat None as alive (never purge a client on an inconclusive probe).""" try: r = subprocess.run([VMEXEC, "exec", _pid_alive_cmd(pid)], capture_output=True, text=True, timeout=20) except Exception: return None out = r.stdout or "" if "ALIVE" in out: return True if "DEAD" in out: return False return None def pin_counter_page(pid, pinned_pids): """Pin the client's completion-counter page from its own pagemap. The GR channels release the counter page VA range (0x20400fec0..0x20400fff0 observed); translating it from fresh guest truth before the first releases decode is what lets those releases land on the slots the client polls. """ cmd = ("sudo python3 /tmp/guest_pmap_win.py %d 0x%x 0x%x 64" % (pid, COUNTER_LO, COUNTER_HI)) try: r = subprocess.run([VMEXEC, "exec", cmd], capture_output=True, text=True, timeout=25) except Exception: return False n = 0 for m in re.finditer(r"^(0x[0-9a-f]+),(0x[0-9a-f]+),(\d+)$", r.stdout, re.M): va, pa, pages = int(m.group(1), 16), int(m.group(2), 16), int(m.group(3)) if pin_bulk(va, pa, pages * 0x1000): n += pages if n: pinned_pids.add(pid) log("counter: pinned %d page(s) at pid %d (0x%x..0x%x)" % (n, pid, COUNTER_LO, COUNTER_HI)) return n > 0 def main(): interval = float(sys.argv[1]) if len(sys.argv) > 1 else 2.0 os.environ.setdefault("KEEP_TRACE", "1") q = Qmp(QMP_SOCK) os.makedirs(os.path.dirname(TIMELINE), exist_ok=True) log("semfix_uvmt: watching (interval %.1fs, qmp %s)" % (interval, QMP_SOCK)) known_sems = set() seen_sem_pin = set() seen_pb = set() seen_ch = set() pinned_ranges = {} last_state = {} last_seen_t = {} dseen = set() counter_pids = set() counter_next_try = {} # Current client pid/starttime, mirrored from the tracker (starttime # disambiguates recycled pids). last_pid = None last_start = None # Stale-sem tracking: consecutive unreadable reads, first-unreadable time, # and the per-sem read skip deadline once a sem has failed 3 times. unread_count = {} first_unreadable_t = {} skip_until = {} # Failed pool-pin tracking: retry with a 15 s backoff after 2 failures. sem_pin_fail = {} sem_pin_skip_until = {} qmp_next_try = 0.0 stream = Stream(SEMSTREAM) tracker = ClientTracker() # Dead-pid/backwards-transition proofing and the stall watchdog. history_absorbed = False adopted_from_history = False probe_next = 0.0 # next allowed idle-liveness probe recover_next = 0.0 # next watchdog recovery attempt stall_since = None # first observation of the pre-capture stall escalated = False progress_t = time.time() # last host-side progress for the client loop = 0 def _clear_client_state(): """Purge every per-client latch. ONLY valid when the previous client is CONFIRMED dead (or at fresh process start): the m178 third-client hang came from wiping the state of an ACTIVE client on a replayed (#pid) identity.""" stream.reset() known_sems.clear() seen_sem_pin.clear() last_state.clear() last_seen_t.clear() pinned_ranges.clear() seen_ch.clear() seen_pb.clear() counter_pids.clear() counter_next_try.clear() sem_pin_fail.clear() sem_pin_skip_until.clear() unread_count.clear() first_unreadable_t.clear() skip_until.clear() def _adopt(pid, start, why): nonlocal last_pid, last_start, progress_t, adopted_from_history nonlocal stall_since, escalated last_pid, last_start = pid, start progress_t = time.time() adopted_from_history = False stall_since = None escalated = False log("semfix: tracking client pid %d%s (%s)" % (pid, " start=%s" % start if start is not None else "", why)) def _watchdog_reset(): nonlocal stall_since, escalated stall_since = None escalated = False def _watchdog_recover(): """Idempotent pre-capture stall recovery: re-arm every sem latch so the next loop re-resolves and re-pins, force an immediate counter retry, and request a full pin re-assert from pin_gr_stream.""" for sem in set(known_sems) | set(stream.sems): skip_until.pop(sem, None) sem_pin_skip_until.pop(sem, None) sem_pin_fail.pop(sem, None) unread_count.pop(sem, None) first_unreadable_t.pop(sem, None) seen_sem_pin.discard(sem) if last_pid is not None: counter_next_try[last_pid] = 0.0 try: with open(REASSERT_REQ, "w") as f: f.write("%.3f\n" % time.time()) except OSError: pass def pin_range_once(gpu_vas, cpu, gpa, size=0): key = tuple(gpu_vas), cpu, size st = pinned_ranges.get(key) if st is None: st = pinned_ranges[key] = {"tries": 0, "done": False, "args": (gpu_vas, cpu, gpa, size)} if st["done"]: return st["tries"] += 1 pinned = pin_pushbuffer(q, gpu_vas, cpu, gpa, size) expected = min(max(size >> 12, 1) if size else PUSHBUF_MAX_PAGES, PUSHBUF_MAX_PAGES) if pinned >= expected: st["done"] = True elif st["tries"] >= 12: st["done"] = True log("semfix: pushbuf pin incomplete after %d tries: %d/%d pages" % (st["tries"], pinned, expected)) while True: loop += 1 _hb() sems = set() pbs = set() chans = set() new_sems, new_pids, new_nopids = stream.poll() for s in new_sems: log("stream: new uvmt sem 0x%x" % s) if new_sems and last_pid is not None: progress_t = time.time() # In-band client-death signals (new guest scanner): purge the dead # client's per-client state immediately so the NEXT client works # without a VM cycle (the kill cascade). for p, st in new_nopids: log("stream: client gone (%d%s)" % (p, " start=%s" % st if st is not None else "")) was_current = tracker.is_current(p, st) tracker.note_dead(p, st) if was_current and last_pid == p: _clear_client_state() last_pid = last_start = None _watchdog_reset() log("semfix: purged per-client state of exited pid %d" % p) # The old client is gone: adopt any client whose reset was deferred # while it was still (assumed) alive. if last_pid is None and tracker.pending is not None \ and tracker.current is None: if tracker.resolve(old_dead=True) == "reset": p, st = tracker.current _clear_client_state() _adopt(p, st, "deferred reset") # Pre-restart history (a supervisor restart re-reads the file): absorb # identities WITHOUT any reset - the fresh process already has empty # state; the freshest identity is the client that was running. if stream.history_pids and not history_absorbed: for p, st in stream.history_pids: tracker.observe_history(p, st) history_absorbed = True if tracker.current is not None and last_pid is None: p, st = tracker.current _adopt(p, st, "resumed from pre-restart history") adopted_from_history = True for p, st in new_pids: cur_before = tracker.current action = tracker.decide(p, st) tag = " start=%s" % st if st is not None else "" if action == "skip": log("stream: client pid %d%s seen before - no reset" % (p, tag)) elif action == "skip_backwards": log("semfix: client pid %d%s backwards/replay - no reset" % (p, tag)) elif action == "adopt": log("stream: client pid %d%s" % (p, tag)) _adopt(p, st, "new client") elif action == "reset": # Recycled pid, newer starttime: the previous holder of this # pid is definitionally gone, safe to reset now. log("semfix: pid %d recycled (start=%s) - reset per-client " "pin state" % (p, st)) _clear_client_state() _adopt(p, st, "pid recycled") elif action == "maybe_reset": old = cur_before alive = pid_alive(old[0]) if old else False if alive is False: log("semfix: new client pid %d%s (pid %d gone) - reset " "per-client pin state" % (p, tag, old[0] if old else -1)) _clear_client_state() tracker.resolve(old_dead=True) _adopt(p, st, "client switch") else: # NEVER clear the active client's state on the account of # a newer pid: the m178 hang. Deferred until the old pid # is confirmed gone (periodic idle probe below). log("semfix: client pid %d%s appeared while pid %s is " "alive%s - reset deferred" % (p, tag, old[0] if old else "?", "" if alive else " (probe unknown)")) for pb in getattr(stream, "new_pbs", []): log("stream: new pushbuffer 0x%x" % pb) pbs.add(pb) if getattr(stream, "new_pbs", []) and last_pid is not None: progress_t = time.time() sems.update(stream.sems) # The guest-agent trace read is slow under client load; use it only # as a fallback for channel/pushbuffer discovery and to recover sems # the scanner may have missed. if loop % TRACE_EVERY == 0: _hb() try: t_sems, t_pbs, t_chans = guest_trace() except Exception: t_sems, t_pbs, t_chans = set(), set(), set() _hb() sems.update(t_sems) pbs.update(t_pbs) chans.update(t_chans) # Poll every sem ever seen: the client's final wait may only appear in # the trace once, and the trace ring wraps while it spins. for sem in sorted(sems - known_sems): known_sems.add(sem) for hb_i, sem in enumerate(sorted(known_sems)): if hb_i % 16 == 0: # A full pass can run 60-90 s (thousands of QMP reads); keep # the heartbeat fresh inside it (r203: 79 s gap -> supervisor # restarted the tool mid-pass). _hb() now = time.time() if now < skip_until.get(sem, 0): continue try: st = uvmt_state(q, sem) except Exception: st = None if st is None: # Stale-sem hygiene: the trace ring replays dead clients' # kernel pointers forever; without eviction every loop burns # QMP reads on them and the log floods with "unreadable". cnt = unread_count.get(sem, 0) + 1 unread_count[sem] = cnt first_unreadable_t.setdefault(sem, now) if cnt >= 3: skip_until[sem] = now + 30.0 if cnt == 3: log("semfix: sem=0x%x unreadable x3 - retrying every " "30s" % sem) age = now - first_unreadable_t[sem] if age >= 60.0 and sem not in stream.sems: known_sems.discard(sem) unread_count.pop(sem, None) first_unreadable_t.pop(sem, None) skip_until.pop(sem, None) last_state.pop(sem, None) last_seen_t.pop(sem, None) seen_sem_pin.discard(sem) sem_pin_fail.pop(sem, None) sem_pin_skip_until.pop(sem, None) log("semfix: evicting stale sem=0x%x (unreadable %.0fs, " "absent from stream)" % (sem, age)) continue else: unread_count.pop(sem, None) first_unreadable_t.pop(sem, None) skip_until.pop(sem, None) key = state_key(st) if key != last_state.get(sem): last_state[sem] = key last_seen_t[sem] = now progress_t = time.time() log("uvmt %s" % state_str(sem, st)) elif now - last_seen_t.get(sem, 0) >= HEARTBEAT: last_seen_t[sem] = now log("uvmt(hb) %s" % state_str(sem, st)) # Pin the pool page once per (sem, word) resolution. The payload # word is what the releasing push writes; pinning the page makes # the host able to apply that release. if (st and sem not in seen_sem_pin and now >= sem_pin_skip_until.get(sem, 0)): try: pairs = resolve_sem_pool(q, sem) except Exception as e: pairs = [] log("semfix: sem=0x%x resolve failed: %s" % (sem, e)) if pairs: ok_any = False for gv, gpa in pairs: ok = pin(gv, gpa) ok_any = ok_any or ok log("semfix: sem=0x%x pool va=0x%x -> gpa=0x%x pin=%s" % (sem, gv, gpa, "ok" if ok else "FAILED")) if not ok_any: # Mark pinned only after a successful pin(): a failed # pin used to be recorded as done and never retried. fails = sem_pin_fail.get(sem, 0) + 1 sem_pin_fail[sem] = fails if fails >= 2: sem_pin_skip_until[sem] = now + 15.0 log("semfix: sem=0x%x pool pin failed x%d - retry " "in 15s" % (sem, fails)) continue seen_sem_pin.add(sem) sem_pin_fail.pop(sem, None) sem_pin_skip_until.pop(sem, None) progress_t = time.time() if SKIP_PB: continue d = {} try: res = resolve_from_sem(q, sem, d) except Exception as e: res = None d["exception"] = str(e)[:40] if not res: for k in ("chunks", "words", "cands", "stop_pool", "no_gpuva", "no_vmalloc", "empty_vas"): d.pop(k, None) try: res = resolve_pushbuffer_wide(q, sem, d) except Exception as e: res = None d["exception"] = str(e)[:40] if res: pin_range_once(*res) progress_t = time.time() log("semfix: sem=0x%x pushbuf -> %s" % (sem, diag_str(d))) else: log("semfix: sem=0x%x pushbuf not found [%s]" % (sem, diag_str(d))) else: log("semfix: sem=0x%x pool unresolved (retry)" % sem) if getattr(q, "_fails", 0) >= 5: # QMP went away (QEMU restart, monitor died): all reads have been # empty for 5 consecutive replies. Recreate the client loudly # instead of reading empty forever ("uvmt(hb) ... unreadable"). now = time.time() if now >= qmp_next_try: log("semfix: QMP unreadable (%d consecutive empty replies) - " "recreating connection" % q._fails) try: q = Qmp(QMP_SOCK) except Exception as e: log("semfix: QMP recreate failed: %s" % e) qmp_next_try = now + 5.0 for ch in sorted(chans - seen_ch): _hb() # a resolve can block for tens of seconds d = {} try: res = resolve_from_channel(q, ch, d) except Exception as e: res = None d["exception"] = str(e)[:40] if res: seen_ch.add(ch) pin_range_once(*res) progress_t = time.time() log("semfix: ch=0x%x -> %s" % (ch, diag_str(d))) else: log("semfix: ch=0x%x pushbuf miss [%s]" % (ch, diag_str(d))) for pb in sorted(pbs - seen_pb): _hb() # a resolve can block for tens of seconds d = {} try: res = resolve_from_pushbuffer(q, pb, d) except Exception as e: res = None d["exception"] = str(e)[:40] if res: seen_pb.add(pb) pin_range_once(*res) progress_t = time.time() log("semfix: pb=0x%x -> %s" % (pb, diag_str(d))) else: log("semfix: pb=0x%x pushbuf miss [%s]" % (pb, diag_str(d))) if DLOG: if dmesg_releases(dseen): progress_t = time.time() _hb() # Retry incomplete push-buffer pins: gva2gpa of the kernel vmalloc # alias fails while the sampled vCPU runs in user mode (PTI), so a # pass can miss a run of pages that resolves a moment later. Only # every 8th loop - a full pass costs thousands of QMP reads. if loop % 8 == 0: for st in list(pinned_ranges.values()): if not st["done"] and st["tries"] > 0: _hb() # pin_range_once can walk thousands of QMP reads pin_range_once(*st["args"]) # Dead-pid detection and the pre-capture stall watchdog. The guest is # probed ONLY when the tracked client has been quiet for a while (a # live, pushing client is never probed), so the agent is not burdened # during healthy runs. A confirmed-dead client is purged immediately: # the NEXT client then starts with clean state - no VM cycle needed # (the kill cascade). now = time.time() if adopted_from_history and last_pid is not None: # The client resumed from pre-restart history may have died while # this process was down; do not latch a dead pid into the counter # retries. alive = pid_alive(last_pid) adopted_from_history = False if alive is False: log("semfix: resumed pid %d already gone - dropping" % last_pid) tracker.note_dead(last_pid, last_start) last_pid = last_start = None _watchdog_reset() if last_pid is not None and now >= probe_next \ and now - progress_t >= LIVENESS_IDLE_S: probe_next = now + LIVENESS_EVERY_S alive = pid_alive(last_pid) if alive is False: log("semfix: client pid %d gone (probe) - purging per-client " "state" % last_pid) tracker.note_dead(last_pid, last_start) _clear_client_state() last_pid = last_start = None _watchdog_reset() if tracker.pending is not None and tracker.current is None \ and tracker.resolve(old_dead=True) == "reset": p, st = tracker.current log("semfix: adopting deferred client pid %d" % p) _adopt(p, st, "deferred reset") elif alive is True and last_pid not in counter_pids: # Pre-capture stall: the client is alive but has no pinned # counter page and nothing progressed. Recover (idempotent), # then escalate loudly if the stall persists - the goal is # that a first cudaMalloc / first GR capture never stalls # silently. idle = now - progress_t if idle >= STALL_PRECAP_S: if stall_since is None: stall_since = now if now >= recover_next: recover_next = now + STALL_RETRY_S log("STALL WATCHDOG: client pid %d alive, no " "pre-capture progress for %.0fs - recovery " "attempt (re-arm sems, re-pin counter, request " "pin re-assert)" % (last_pid, idle)) _watchdog_recover() if not escalated and now - stall_since >= STALL_ESCALATE_S: escalated = True log("STALL WATCHDOG: recovery FAILED for pid %d " "after %.0fs (alive, counter page not pinned) - " "pre-capture hang persists, needs manual " "attention" % (last_pid, now - stall_since)) # Pin the completion-counter page of a newly started client, before its # first GR pushes decode their releases. The pid comes from the guest # scanner; the guest-agent fallback is only a safety net. The exec can # block for its whole timeout under client load, so retry on a slow # cadence: hammering the agent here starves it and wedges the run. if last_pid is None and loop % TRACE_EVERY == 0: p = cdt_pid() _hb() if p: if tracker.current is None and (p, None) not in tracker.seen: tracker.observe_history(p, None) last_pid, last_start = p, None log("counter: client pid %d (agent)" % p) if last_pid and last_pid not in counter_pids: now = time.time() if now >= counter_next_try.get(last_pid, 0): try: if pin_counter_page(last_pid, counter_pids): progress_t = time.time() except Exception as e: log("counter: pin failed: %s" % e) _hb() counter_next_try[last_pid] = now + COUNTER_RETRY_S time.sleep(interval) if __name__ == "__main__": main()