0b7fd59489
Caught the freeze by waiting for the event (frozen.py + in_flight) instead of sleeping a guessed interval; freeze_waitobj.sh splits into boot/watch so the wait is not capped by one Bash call. Verified hard: a frame minutes later is byte-identical to the capture. Healthy vs frozen, same run: 20 -> 24 wait frames, XEvent 19 -> 23, XSemaphore 8 -> 7. The signature is per-thread -- 17 of 24 threads sit on the exact object they were on, four previously-running threads park, and T74/T75 move off a semaphore onto an event. So the freeze is not a whole-emulator stall. Also corrects the previous entry's test: screen_id reads 'flight' during a freeze by design, which is why frozen.py exists. Re-testing the saved frames says that run was genuinely healthy, but it was right by luck. heavy_read.py added to test whether the instrument provokes the freeze: I/O is free (371 MB in 0.1s, page cache), the cost is Python-level CPU. One data point -- 670s clean, then frozen 54s after the inducer started -- recorded as n=1, not as causation.
86 lines
3.2 KiB
Python
Executable File
86 lines
3.2 KiB
Python
Executable File
#!/usr/bin/env python3
|
|
"""Reproduce the EXPENSIVE part of the old probes: full-region guest scans.
|
|
|
|
Not a probe -- it computes nothing. It exists to test whether the in-mission
|
|
freeze is caused by the instrument rather than by the game. The tally in
|
|
BACKLOG.md is suggestive but only correlational: the heavy probe (32 MB at
|
|
startup + 32 MB every 90 s + two more for calibration) froze at 27/45/83/183/255
|
|
s, while the cheap probe with the periodic rescan removed was clean past 200 s
|
|
on 3 of 4 runs. This makes the comparison causal by adding the reads BACK to a
|
|
run that is otherwise identical and demonstrably clean.
|
|
|
|
MEASURED FIRST: the reads themselves are not the cost. A full uncapped walk of
|
|
every allocated extent moves 371 MB in 0.1 s -- it is all page cache. What the
|
|
old probes actually spent was CPU, unpacking and comparing every 4-byte word of
|
|
that region in Python to build the witness candidate list. So `cpu` mode does
|
|
that, and it is the mode that tests the hypothesis; `read` mode is kept only as
|
|
the control that shows I/O is free.
|
|
|
|
Usage: heavy_read.py [secs] [period_s] [read|cpu]
|
|
"""
|
|
import os, sys, time
|
|
|
|
def shm():
|
|
d = [f for f in os.listdir('/dev/shm') if f.startswith('xenia_memory_')]
|
|
return '/dev/shm/' + d[0] if d else None
|
|
|
|
def scan(path, cap=(1 << 62)):
|
|
"""Walk EVERY allocated extent with SEEK_DATA. A 32 MB cap is page-cache cheap
|
|
(0.0 s measured), so the cap is off: the expensive thing the old probes did was
|
|
the FULL-region search, not a fixed-size read."""
|
|
got = 0
|
|
with open(path, 'rb', buffering=0) as f:
|
|
end = os.fstat(f.fileno()).st_size
|
|
off = 0
|
|
while off < end and got < cap:
|
|
try:
|
|
off = os.lseek(f.fileno(), off, os.SEEK_DATA)
|
|
except OSError:
|
|
break
|
|
n = min(1 << 20, cap - got)
|
|
b = f.read(n)
|
|
if not b:
|
|
break
|
|
got += len(b); off += len(b)
|
|
return got
|
|
|
|
def cpu_scan(path):
|
|
"""The expensive thing: touch every word in Python, as the witness search did."""
|
|
import struct
|
|
words = 0
|
|
with open(path, 'rb', buffering=0) as f:
|
|
end = os.fstat(f.fileno()).st_size
|
|
off = 0
|
|
while off < end:
|
|
try:
|
|
off = os.lseek(f.fileno(), off, os.SEEK_DATA)
|
|
except OSError:
|
|
break
|
|
b = f.read(1 << 20)
|
|
if not b:
|
|
break
|
|
n = len(b) // 4
|
|
for v in struct.unpack('>%dI' % n, b[:n * 4]):
|
|
if 0 < v < 1000:
|
|
words += 1
|
|
off += len(b)
|
|
return words
|
|
|
|
secs = float(sys.argv[1]) if len(sys.argv) > 1 else 600
|
|
period = float(sys.argv[2]) if len(sys.argv) > 2 else 20
|
|
mode = sys.argv[3] if len(sys.argv) > 3 else 'read'
|
|
p = shm()
|
|
if not p:
|
|
print('no guest memory'); sys.exit(1)
|
|
print('heavy reads on %s every %gs for %gs' % (p, period, secs), flush=True)
|
|
t0 = time.time(); n = 0
|
|
while time.time() - t0 < secs:
|
|
a = time.time(); n += 1
|
|
if mode == 'cpu':
|
|
got = cpu_scan(p)
|
|
print(' cpu-scan %d: %d hits in %.1fs' % (n, got, time.time() - a), flush=True)
|
|
else:
|
|
got = scan(p)
|
|
print(' scan %d: %.1f MB in %.1fs' % (n, got / 1048576, time.time() - a), flush=True)
|
|
time.sleep(period)
|