Sylpheed/tools/re-capture/wave6_probe.py

#!/usr/bin/env python3
"""Per-record arrival/loss watch against the verified 116/300 baseline.

Supersedes wave5_probe.py, which reported 42 records in a run nobody could
reproduce. Changes:
  * refuses to interpret a run whose roster count is not the reproduced
    baseline (mission-per-record-strength.md: discard, do not interpret);
  * keys records by file offset rather than by primary VA;
  * samples faster and for longer, since losses appear at ~1 per 10 s and no
    arrival has been seen in five runs.

An arrival is a record going 0 -> n; a loss is n -> n-1.
"""
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)
# A guest that has stalled produces flat samples that read exactly like a quiet
# mission -- that happened at t~255 in the keep-out run and was only caught by
# eyeballing the pilot log afterwards. timer_probe found counters advancing at
# frame rate; sampling one of them makes every run self-validating.
TICK_LO, TICK_HI = 0xBC000000, 0xBE000000
DELTA, WIN, LINK = 0x130, 0x400, 0x08
BASELINE = 116

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 find_tick(fd, dt=3.0):
    """One word that advances steadily: the guest-is-running witness."""
    lo, hi = gmem.va_to_off(TICK_LO), gmem.va_to_off(TICK_LO + 0x400000)
    a = os.pread(fd, hi - lo, lo)
    time.sleep(dt)
    b = os.pread(fd, hi - lo, lo)
    best = None
    for k in range(0, min(len(a), len(b)) - 3, 4):
        va = struct.unpack_from('>I', a, k)[0]
        vb = struct.unpack_from('>I', b, k)[0]
        if va < vb and (vb - va) / dt > 5 and (vb - va) < 1 << 20:
            best = (lo + k, (vb - va) / dt); break
    return best

def sample(fd, defs, want):
    lo, hi = gmem.va_to_off(entities2.ENT_VA_LO), gmem.va_to_off(entities2.ENT_VA_HI)
    per = collections.Counter(); tot = 0; pos = lo
    while pos < hi:
        m = min(1 << 24, hi - pos)
        blob = os.pread(fd, m, pos)
        for k in range(0, len(blob) - 3, 4):
            if blob[k:k+4] not in defs: continue
            tot += 1
            head = os.pread(fd, WIN, pos + k - DELTA)
            for j in range(0, len(head) - 3, 4):
                (p,) = struct.unpack_from('>I', head, j)
                if p in want:
                    per[want[p]] += 1; break
        pos += m
    return per, tot

def main():
    secs  = int(sys.argv[1]) if len(sys.argv) > 1 else 240
    every = int(sys.argv[2]) if len(sys.argv) > 2 else 10
    w = gworld.World(); fd = w.fd
    defs = entities2.definitions(w)
    if not defs: print('NOT IN A MISSION'); return 2
    roster = scan_vt(fd, w.size, ROSTER_VT)
    print('roster records: %d (baseline %d)' % (len(roster), BASELINE))
    if len(roster) != BASELINE:
        print('DISCARD: roster count is not the reproduced baseline. '
              'Per mission-per-record-strength.md this run is not interpreted.')
        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
    tick = find_tick(fd)
    if tick: print('tick witness at %#x, ~%.1f/s' % (tick[0], tick[1]))
    else: print('WARNING: no advancing counter found; stalls cannot be detected')
    last_tick = struct.unpack('>I', os.pread(fd, 4, tick[0]))[0] if tick else 0
    log = open('/tmp/wave6.tsv', 'w'); log.write('t\tkind\toff\tunit\tfrom\tto\n')
    prev = None; t0 = time.time(); arr_n = loss_n = 0
    while time.time() - t0 < secs:
        per, tot = sample(fd, defs, want)
        el = round(time.time() - t0)
        if prev is None:
            print('t=%4ds craft=%d deployed=%d/%d strengths %s'
                  % (el, tot, len(per), len(roster),
                     sorted(collections.Counter(per.values()).items())), flush=True)
        else:
            arr = [(o, per[o]) for o in per if prev.get(o, 0) == 0 < per[o]]
            los = [(o, prev[o], per.get(o, 0)) for o in prev if per.get(o, 0) < prev[o]]
            arr_n += len(arr); loss_n += len(los)
            stalled = ''
            if tick:
                now = struct.unpack('>I', os.pread(fd, 4, tick[0]))[0]
                if now <= last_tick: stalled = '  *** GUEST STALLED ***'
                last_tick = now
            print('t=%4ds craft=%d deployed=%d  ARRIVALS=%d losses=%d  (cum %d/%d)%s'
                  % (el, tot, len(per), len(arr), len(los), arr_n, loss_n, stalled),
                  flush=True)
            for o, c in arr:
                print('   ARRIVAL %-30s 0 -> %d' % (label.get(o, '?'), c), flush=True)
                log.write('%d\tarrival\t%#x\t%s\t0\t%d\n' % (el, o, label.get(o, '?'), c))
            for o, a, b in los:
                print('   loss    %-30s %d -> %d' % (label.get(o, '?'), a, b), flush=True)
                log.write('%d\tloss\t%#x\t%s\t%d\t%d\n' % (el, o, label.get(o, '?'), a, b))
            log.flush()
        prev = per
        time.sleep(max(0, every - (time.time() - t0 - el)))
    log.close()
    print('\nTOTAL arrivals=%d losses=%d over %ds' % (arr_n, loss_n, secs))
    return 0

if __name__ == '__main__':
    sys.exit(main())