igneum/tools/attack/f6-verifier/timeparse.py
2026-10-07 10:02:44 +00:00

86 lines
4.6 KiB
Python

#!/usr/bin/env python3
"""attack-f6: read a phase 2 log (`attack-f6 time` output under `== solo` / `== half-core` headers) and the matching
clock log (`clock_start` of lib.sh: one line per second with the clock of cores 40 and 88 and every process whose last
CPU was 40 or 88), print one table per run (seed, cold max / median / min, steady, items, verdict, and whether a foreign
process sat on 40 or 88 during that seed's second), and the worst seeds per run.
timeparse.py --log phase2b.log --clock clock-2b.log [--top 10] [--grep worst-union]
"""
import argparse
import re
from datetime import datetime, timezone
LINE = re.compile(
r"t=(?P<t>[\d.]+)s seed (?P<seed>\S+) id (?P<id>[0-9a-f]+) attempt (?P<att>\d+) shadow_mix \[(?P<smix>[^\]]*)\] base_mix \[(?P<bmix>[^\]]*)\] "
r"warp0 lane0 (?P<lane0>[0-9a-f]+) items (?P<items>\d+): cold max (?P<max>[\d.]+) med (?P<med>[\d.]+) min (?P<min>[\d.]+) ms \(reps (?P<reps>[\d.;]+)\), "
r"steady (?P<steady>[\d.]+) ms avg of (?P<n>\d+): GATE [\d.]+ ms (?P<verdict>PASS|FAIL)"
)
HDR = re.compile(r"^== (?P<kind>solo core 40|half-core \(core 88 loaded, pid (?P<lp>\d+)\)): (?P<cmd>.*) at (?P<ts>\S+)$")
CLK = re.compile(r"^(?P<ts>\S+) t=(?P<t>[\d.]+) cpu40 (?P<c40>\d+) cpu88 (?P<c88>\d+) loadavg (?P<la>\S+ \S+ \S+) on40/88: (?P<procs>.*)$")
OWN = {"attack-f6", "bash", "sleep", "ps", "awk", "date", "cat", "cut", "bc", "tee", "flock", "nice", "taskset"}
def parse_ts(s):
return datetime.strptime(s, "%Y-%m-%dT%H:%M:%SZ").replace(tzinfo=timezone.utc).timestamp()
def main():
ap = argparse.ArgumentParser()
ap.add_argument("--log", required=True)
ap.add_argument("--clock", required=True)
ap.add_argument("--top", type=int, default=10)
ap.add_argument("--grep", default="", help="only runs whose command line contains this")
a = ap.parse_args()
clock = []
for line in open(a.clock):
m = CLK.match(line.strip())
if m:
procs = [p for p in m["procs"].split() if p]
foreign = [p for p in procs if p.split(":")[4] not in OWN and not p.split(":")[4].startswith("kworker") and p.split(":")[1] != "-"]
clock.append((parse_ts(m["ts"]), int(m["c40"]), int(m["c88"]), foreign, m["la"]))
runs = []
cur = None
for line in open(a.log):
line = line.rstrip("\n")
h = HDR.match(line)
if h:
cur = {"kind": "solo" if h["kind"].startswith("solo") else "half", "cmd": h["cmd"], "start": parse_ts(h["ts"]), "rows": []}
runs.append(cur)
continue
m = LINE.search(line)
if m and cur is not None:
cur["rows"].append(m.groupdict())
for r in runs:
if a.grep and a.grep not in r["cmd"]:
continue
rows = r["rows"]
if not rows:
continue
print(f"\n### {r['kind']}: {r['cmd']} ({len(rows)} seeds)")
# per-seed disturbance flag: any foreign process on 40/88 in the seconds the seed was timed
# (from t to the next seed's t, or 2 s), and the clock of core 40 in that window
for i, row in enumerate(rows):
t0 = r["start"] + float(row["t"])
t1 = r["start"] + (float(rows[i + 1]["t"]) if i + 1 < len(rows) else float(row["t"]) + 2.0)
win = [c for c in clock if t0 - 1.0 <= c[0] <= t1 + 1.0]
foreign = sorted({p.split(":")[4] + "@" + p.split(":")[0] for c in win for p in c[3]})
c40 = [c[1] for c in win]
row["_foreign"] = ",".join(foreign)
row["_c40min"] = min(c40) if c40 else 0
row["_c88max"] = max(c[2] for c in win) if win else 0
vals = sorted((float(x["max"]), x) for x in rows)
maxes = [v for v, _ in vals]
meds = sorted(float(x["med"]) for x in rows)
n = len(maxes)
print(f"over the run: cold-max min {maxes[0]:.3f} median {maxes[n // 2]:.3f} max {maxes[-1]:.3f}; cold-median min {meds[0]:.3f} median {meds[n // 2]:.3f} max {meds[-1]:.3f}; core 40 clock min {min(x['_c40min'] for x in rows)} kHz")
print(f"| Seed | items | cold max | median | min | steady | reps | foreign process on 40/88 in the window | verdict on max |")
print("|---|---|---|---|---|---|---|---|---|")
for v, x in list(reversed(vals))[: a.top]:
print(f"| {x['seed']} | {x['items']} | {x['max']} | {x['med']} | {x['min']} | {x['steady']} | {x['reps']} | {x['_foreign'] or 'none seen'} | {x['verdict']} |")
worst = vals[-1][1]
print(f"WORST by cold max: {worst['seed']} {worst['max']} ms ({worst['verdict']}); worst by cold median: {max(rows, key=lambda x: float(x['med']))['seed']} {max(float(x['med']) for x in rows):.3f} ms")
if __name__ == "__main__":
main()