Files
Sylpheed/tools/re-capture/wave7_probe.py
Sylpheed RE agent d4f6b7bf03 re: freezes are stochastic, not eliminated; calibration vectorised
Correcting the previous iteration's wording. It claimed on n=1 that disabling
the periodic rescan "removes the freeze". With more runs that is too strong: the
configuration is now clean at 210, 240 and 300 seconds and frozen at 60 on a
fourth run.

The tally across configurations: the heavy probe froze at 27, 45, 83, 183 and
255 seconds; the cheap probe with a 90 s rescan froze at 183; the cheap probe
with no rescan is clean in three runs of four past 200 s. That is a real and
large improvement in survival, but it is a change in probability rather than a
fix, and the documentation now says so.

The witness handled the frozen run correctly -- losses stop at t=45 and stalls
are flagged from t=60 onward, with no contradiction between them.

Separately, the candidate search was the last Python loop over eight million
words and most of the remaining startup cost. Replaced with two numpy vector
operations; 7250 candidates found and startup is no longer the bottleneck. Boot
now dominates: about 190 s of title movie plus 35 s to flight against a 595 s
turn cap leaves roughly 350 s of observation, so boot is the only remaining
lever if longer windows are needed.

Practical rule recorded: do not treat a single frozen run as evidence. Run,
check the witness, discard the frozen ones and keep the clean ones -- about
three in four are usable now, which is workable where it previously was not.
2026-08-24 19:13:06 +00:00

214 lines
11 KiB
Python
Executable File

#!/usr/bin/env python3
"""Cheap per-record watch: the heavy rescan was stalling the guest.
A no-probe control ran 300 s clean while probed runs stalled at 27-255 s
(guest-stalls.md), so the 32 MB rescan every 12 s has to go. After one full
enumeration the craft bases and their roster links are known, and a sample only
needs the hull word at each base -- about 1.2 KB instead of 32 MB. A full rescan
runs only every RESCAN seconds to catch anything genuinely new.
"""
import os, sys, time, struct, collections, importlib.util
SD = __file__.rsplit('/', 1)[0]
sys.path.insert(0, SD)
import gmem, gworld, entities2
_w3 = importlib.util.spec_from_file_location('w3', SD + '/wave3_probe.py')
wave3 = importlib.util.module_from_spec(_w3); _w3.loader.exec_module(wave3)
ROSTER_VT = struct.pack('>I', 0x820AF030)
DELTA, WIN, LINK, HULL = 0x130, 0x400, 0x08, 0x154
BASELINE = 116
# Periodic rescan DISABLED. It was a 32 MB read every 90-180 s, the only
# recurring heavy cost left, and it exists to catch craft that appear from
# nowhere -- which the roster work already showed does not happen: every
# participant is allocated at mission load, so an arrival is a state change on
# an existing craft, not a new allocation. Set >0 to re-enable.
RESCAN = 0
def scan_vt(fd, size, vt):
out = []
for a, b in gmem.extents(fd, size):
pos = a
while pos < b:
m = min(1 << 24, b - pos)
blob = os.pread(fd, m, pos)
i = blob.find(vt)
while i != -1:
if (pos + i) % 4 == 0: out.append(pos + i)
i = blob.find(vt, i + 1)
pos += m
return sorted(out)
def enumerate_craft(fd, defs, want):
"""Full heap scan. Returns [(base, unit, roster_off)].
Was iterating every 4-byte word of 32 MB in Python -- 8 million steps -- and
the startup cost worked out at roughly 100 s of wall-clock, which is a third
of the observation window a turn can afford. Each definition VA is a fixed
4-byte needle, so bytes.find() does the same search at C speed.
"""
lo, hi = gmem.va_to_off(entities2.ENT_VA_LO), gmem.va_to_off(entities2.ENT_VA_HI)
out, pos = [], lo
while pos < hi:
m = min(1 << 24, hi - pos)
blob = os.pread(fd, m, pos)
for needle, nm in defs.items():
i = blob.find(needle)
while i != -1:
if (pos + i) % 4 == 0:
base = pos + i - DELTA
head = os.pread(fd, WIN, base)
own = None
for j in range(0, len(head) - 3, 4):
(p,) = struct.unpack_from('>I', head, j)
if p in want: own = want[p]; break
out.append((base, nm, own))
i = blob.find(needle, i + 1)
pos += m
return sorted(out)
def alive(fd, base):
try: return struct.unpack('>f', os.pread(fd, 4, base + HULL))[0] > 0
except Exception: return False
def main():
secs = int(sys.argv[1]) if len(sys.argv) > 1 else 300
every = int(sys.argv[2]) if len(sys.argv) > 2 else 15
w = gworld.World(); fd = w.fd
defs = entities2.definitions(w)
if not defs: print('NOT IN A MISSION'); return 2
# The 42-instead-of-116 anomaly has now happened twice. Rather than discard
# immediately, rescan a few times: if the count CLIMBS toward 116 the roster
# is being built progressively and the probe simply started too early, which
# is a fact worth having. If it sits at 42 it is something else.
roster = scan_vt(fd, w.size, ROSTER_VT)
print('roster records: %d (baseline %d)' % (len(roster), BASELINE))
for attempt in range(1, 6):
if len(roster) == BASELINE: break
time.sleep(10)
roster = scan_vt(fd, w.size, ROSTER_VT)
print(' rescan %d: %d records' % (attempt, len(roster)), flush=True)
if len(roster) != BASELINE:
print('DISCARD: settled at %d, not the reproduced baseline %d'
% (len(roster), BASELINE)); return 3
f = os.fdopen(os.dup(fd), 'rb')
label, want = {}, {}
for o in roster:
va = gmem.primary_va(o)
if va is None: continue
label[o] = wave3.resolve_id(f, w.size, o)[0] or '?'
want[va + LINK] = o
# A 1 MB window was too narrow and found nothing, yet the summary still
# printed "stalled samples=0" -- a witness that does not exist cannot report
# zero stalls, and that is false reassurance, not a clean run. Search wider,
# and if there is still no witness say the run is UNVALIDATED.
# Taking the FIRST word that advances was wrong: it flagged 13 samples as
# stalled in a run that was recording losses in those same samples, which a
# frozen guest cannot do. Some counters simply advance intermittently. Use
# timer_probe's approach instead -- collect every candidate, keep the modal
# rate cluster, and call a stall only when a MAJORITY of that cluster fails
# to advance.
# 4 MB was too narrow: it yielded 5 candidates at a nominal 24/s that then
# failed to advance in 15 s windows where craft were being destroyed, i.e.
# they are bursty, not frame counters. timer_probe searched the WHOLE 32 MB
# region and found 286 with a clean cluster at ~17/s. Pay the one-off cost.
# REVERTED to the full-region calibration. Trimming it to 8 spread 512 KB
# windows to save I/O found only 17 candidates, none of them frame counters,
# and the witness then reported 0/17 stalled on EVERY sample of a run that
# recorded 13 losses -- a total contradiction. The frame-rate cluster is
# sparse and spread sampling misses it. Two 32 MB reads once at startup is
# the price of a witness that works; the recurring cost was the periodic
# rescan, and that is what has been cut instead.
lo, hiw = gmem.va_to_off(0xBC000000), gmem.va_to_off(0xBE000000)
def grab():
out, pos = bytearray(), lo
while pos < hiw:
n = min(1 << 24, hiw - pos); out += os.pread(fd, n, pos); pos += n
return bytes(out)
a = grab(); time.sleep(3.0); b = grab()
# The candidate search was the last Python loop over 8 million words and cost
# most of the remaining startup time. numpy does the same comparison as two
# vector ops. (AGENT.md: numpy is installed; its absence used to look like a
# logic bug.)
import numpy as np
n4 = min(len(a), len(b)) // 4 * 4
A = np.frombuffer(a[:n4], dtype='>u4').astype(np.int64)
B = np.frombuffer(b[:n4], dtype='>u4').astype(np.int64)
d = B - A
rate = d / 3.0
idx = np.nonzero((d > 0) & (rate > 5) & (rate < 200))[0]
cands = [(lo + int(i) * 4, int(round(float(rate[i])))) for i in idx]
# The MODAL cluster is not the frame counter. One run picked a modal rate of
# 93/s, and only 11 of 31 of those advanced during active combat -- they are
# subsystem counters that tick in bursts. timer_probe measured the frame-rate
# cluster at ~17/s, matching Canary's 14-19 fps on this box, so prefer a
# cluster in that band and fall back to modal only if none exists.
rates = collections.Counter(r for _, r in cands)
band = [r for r in rates if 8 <= r <= 40]
pick = max(band, key=lambda r: rates[r]) if band else (
rates.most_common(1)[0][0] if rates else None)
ticks = [o for o, r in cands if r == pick][:32]
if len(ticks) < 8:
print('WARNING: only %d witnesses; stall detection is weak' % len(ticks))
print('tick witnesses: %d candidates, using %d at %s/s (frame-rate band)'
% (len(cands), len(ticks), pick)
if ticks else 'tick witnesses: NONE -- RUN UNVALIDATED')
last_ticks = [struct.unpack('>I', os.pread(fd, 4, o))[0] for o in ticks]
craft = enumerate_craft(fd, defs, want)
print('craft %d, linked %d' % (len(craft), sum(1 for c in craft if c[2])))
prev = collections.Counter(c[2] for c in craft if c[2] and alive(fd, c[0]))
print('t= 0s deployed=%d strengths %s'
% (len(prev), sorted(collections.Counter(prev.values()).items())), flush=True)
t0 = time.time(); last_rescan = t0; arr = los = 0; stalls = 0
pending, confirmed = {}, 0
while time.time() - t0 < secs:
time.sleep(every)
el = round(time.time() - t0)
if RESCAN and time.time() - last_rescan > RESCAN:
craft = enumerate_craft(fd, defs, want); last_rescan = time.time()
cur = collections.Counter(c[2] for c in craft if c[2] and alive(fd, c[0]))
st = ''
if ticks:
now = [struct.unpack('>I', os.pread(fd, 4, o))[0] for o in ticks]
moved = sum(1 for x, y in zip(last_ticks, now) if y > x)
# "Fewer than half" was too strict: 11 of 31 advanced while craft
# were being destroyed. The unambiguous signal in that run was
# 0 of 31, which coincided exactly with losses stopping.
if moved == 0:
st = ' *** GUEST STALLED (%d/%d witnesses moved) ***' % (moved, len(ticks))
stalls += 1
last_ticks = now
# Report EVERY increase, not just 0 -> n. The first run logged a record
# reading 13 then 14 with no event printed, which is how flicker in the
# hull-based liveness read hides: only decreases were being surfaced, so
# a spurious 0 -> 2 looked like an arrival while 13 -> 14 looked like
# nothing. An arrival must also PERSIST to count.
a_ = [(o, prev.get(o, 0), cur[o]) for o in cur if cur[o] > prev.get(o, 0)]
l_ = [(o, prev[o], cur.get(o, 0)) for o in prev if cur.get(o, 0) < prev[o]]
for o, x, y in a_:
if x == 0: pending[o] = pending.get(o, 0) + 1
for o in list(pending):
if cur.get(o, 0) == 0: pending.pop(o, None) # vanished: flicker
elif pending[o] == 2:
confirmed += 1
print(' *** CONFIRMED ARRIVAL %-26s now %d (persisted 2 samples)'
% (label.get(o, '?'), cur[o]), flush=True)
pending[o] = 3
arr += sum(1 for x in a_ if x[1] == 0); los += len(l_)
print('t=%4ds deployed=%d up=%d down=%d (cum up %d / down %d, confirmed %d)%s'
% (el, len(cur), len(a_), len(l_), arr, los, confirmed, st), flush=True)
for o, x, y in a_:
print(' up %-30s %d -> %d%s' % (label.get(o, '?'), x, y,
' <- candidate arrival' if x == 0 else ''), flush=True)
for o, x, y in l_: print(' loss %-30s %d -> %d' % (label.get(o, '?'), x, y), flush=True)
prev = cur
if not ticks:
print('\nRUN UNVALIDATED: no tick witness, so flat samples prove nothing.')
print('\nTOTAL candidate-up=%d down=%d CONFIRMED arrivals=%d stalled samples=%s'
% (arr, los, confirmed, stalls if ticks else 'UNKNOWN'))
return 0
if __name__ == '__main__':
sys.exit(main())