diff --git a/harbor/cli.py b/harbor/cli.py index ace3961..fc74c06 100644 --- a/harbor/cli.py +++ b/harbor/cli.py @@ -263,12 +263,14 @@ def build_parser(): p.add_argument("--count", type=int, default=16) p.add_argument("--as", dest="as_type", default="hex", choices=["hex", "int32", "uint32", "float", "double", "string"]) p = sub.add_parser("logbook", help="the project Logbook: add a log entry, set statistics, the chart or a milestone") - p.add_argument("action", choices=["add", "stats", "map", "milestone", "show", "import", "refresh"]) + p.add_argument("action", choices=["add", "stats", "map", "milestone", "show", "import", "refresh", "results"]) p.add_argument("--title") p.add_argument("--kind", default="note") p.add_argument("--detail", help="the entry text (or --file)") p.add_argument("--file", help="a text file (add) or a JSON file (stats, map, milestone) or an export folder (import)") p.add_argument("--no-history", action="store_true", help="stats: do not add a trend point") + p.add_argument("--job", choices=["match", "behaviour"], + help="results: ask the server for this run (whole-program check or emulator) now") p = sub.add_parser("next-functions", help="functions in your bands to decompile next, easiest first") p.add_argument("-n", type=int, default=10) p = sub.add_parser("defer", help="set a function aside with a reason and evidence") @@ -757,6 +759,17 @@ def main(argv=None): from . import logbook_auto res = logbook_auto.refresh(project, force=True) out(res, json.dumps(res)) + elif args.action == "results": + from . import results_refresh + if args.job: + if who() not in harbor.coordinators: + raise HarborError("the Logbook is written by a coordinator") + res = results_refresh.request(project, args.job) + out(res, f"asked the Harbor server for a {args.job} run; it starts within two minutes " + "(after any run in progress)") + else: + res = results_refresh.status(project) + out(res, json.dumps(res, indent=1)) elif args.action == "import": res = logbook.import_export(project, args.file) out(res, json.dumps(res)) diff --git a/harbor/progress_map.py b/harbor/progress_map.py index e182415..87935cc 100644 --- a/harbor/progress_map.py +++ b/harbor/progress_map.py @@ -14,6 +14,7 @@ Definitions follow the Logbook exactly (open-seas tools/progress/progress.py, wh Decompiled functions are split further, best first: exact (byte match in the [reverse] match_results), verified (behaves the same in the emulator, diffrun_results, not 'weak'), readable. The rest: deferred (a live DEFERRED note), raw, and, not counted, unsorted, engine (Gamebryo, named only) and library (C runtime, D3DX9, platform wrappers). +"results" says which commit the exact and verified tiers are from (harbor.results_refresh keeps them current). Without a stats_repo the categories come from names.csv / facts and readable from the src headers (the queue's view). Units, first that applies: the source file from the Xbox build's assert sites ([reverse] source_files); the D3DX9 block @@ -97,7 +98,8 @@ class ProgressMap: rev, _ = self._config() decomp = self._decomp() head = _git(decomp, "rev-parse", "HEAD") if decomp and (decomp / ".git").exists() else "" - paths = [self._symbols_path(), self._logbook_dir() / "stats.json", self._logbook_dir() / "history.json"] + paths = [self._symbols_path(), self._logbook_dir() / "stats.json", self._logbook_dir() / "history.json", + self._logbook_dir() / "results.json"] paths += [rev.get(k) for k in ("facts", "match_results", "diffrun_results", "library_results", "library_ranges", "source_files")] if rev.get("annotations"): @@ -282,8 +284,10 @@ class ProgressMap: commit["at"] = _utc(_git(decomp, "log", "-1", "--format=%cI", commit["sha"])) or None main = {"sha": head[:7] if head else None, "at": _utc(_git(decomp, "log", "-1", "--format=%cI", head)) if head else None} + from . import results_refresh return { "project": self.project.title or self.project.name, + "results": results_refresh.freshness(self.project), "source": "logbook symbol table" if symbols else "src headers and names.csv", "commit": commit, "main": main, "updated_at": stats.get("updated_at"), "percent": percent, "logbook_percent": stats.get("game_bytes_decompiled_percent"), diff --git a/harbor/results_refresh.py b/harbor/results_refresh.py new file mode 100644 index 0000000..7c037dc --- /dev/null +++ b/harbor/results_refresh.py @@ -0,0 +1,379 @@ +"""Keeps the match and emulator results that the Logbook's exact and verified tiers come from current, so nobody has to +remember to rerun them: + + match the whole-program check of main ([reverse] ltcg: `ltcg.py check --build --decomp
--json`), + written to [reverse] match_results; when main's HEAD has moved, at most every match_every_minutes. + behaviour the emulator over every readable file ([reverse] diffrun_command: `diffrun.py --readable --jobs 4 + --json`), written to [reverse] diffrun_results, its printout to readable.txt beside it; when main's + HEAD has moved, at most every behaviour_every_hours and only inside behaviour_window (local hours). + +Configured per project in the [logbook] table (main is [logbook] decomp): + results_refresh = true off unless set + match_every_minutes = 60 + behaviour_every_hours = 12 + behaviour_window = "01-06" from 01:00 to 06:00 local time; "" for any hour + +One run at a time (the server runs one thread for every project), at the lowest process priority, into a .partial file +that replaces the results only once it is complete. The match run holds the same per-checkout lock as re_match_program, +so it waits its turn behind any other whole-program build of main. + +State (per job: the commit, start and finish of the last run, its counts and error; a run in progress) is kept in the +logbook folder as results.json, so a restarted server neither repeats a run nor starts a second one beside a run its +predecessor left going (that run's output is adopted when it finishes). `harbor logbook results --job match|behaviour` +asks the server for a run now, whatever the schedule; it is a file, refresh-.request, in the same folder.""" +import datetime +import json +import os +import subprocess +import sys +import tempfile +import time +import traceback +from pathlib import Path + +from . import logbook + +JOBS = ("match", "behaviour") +RESULTS_KEY = {"match": "match_results", "behaviour": "diffrun_results"} +DEFAULTS = {"results_refresh": False, "match_every_minutes": 60, "behaviour_every_hours": 12, + "behaviour_window": "01-06"} +TIMEOUT = {"match": 2 * 3600, "behaviour": 8 * 3600} # generous: the runs are at idle priority on a busy machine +TICK = 120 # seconds between looks +START_DELAY = 60 # let a restarted server settle first +STATE = "results.json" + + +# ---------------------------------------------------------------------------------------------- configuration +def settings(project): + lb = getattr(project, "logbook", None) or {} + return {k: lb.get(k, v) for k, v in DEFAULTS.items()} + + +def window(text): + """"01-06" -> (1, 6): from 01:00 up to 06:00. "22-04" wraps past midnight. ""/None -> None (any hour).""" + text = str(text or "").strip() + if not text or text.lower() in ("any", "always"): + return None + start, end = (int(part) for part in text.split("-", 1)) + if not (0 <= start <= 24 and 0 <= end <= 24): + raise ValueError(f"behaviour_window hours must be 0-24: {text!r}") + return start, end + + +def in_window(span, hour): + if span is None: + return True + start, end = span + if start == end: + return True + return start <= hour < end if start < end else hour >= start or hour < end + + +def configured(project, job): + """What a job needs from the project, or None when it cannot run here.""" + rev = project.reverse or {} + lb = getattr(project, "logbook", None) or {} + if not lb.get("decomp") or not rev.get(RESULTS_KEY[job]): + return None + if job == "match" and rev.get("ltcg"): + return {"script": rev["ltcg"], "results": rev["match_results"]} + if job == "behaviour" and rev.get("diffrun_command"): + command = rev["diffrun_command"] + return {"command": command if isinstance(command, list) else [command], "results": rev["diffrun_results"]} + return None + + +# ---------------------------------------------------------------------------------------------- state +def _folder(project): + return logbook.folder(project) + + +def load_state(project): + path = _folder(project) / STATE + try: + state = json.loads(path.read_text(encoding="utf-8")) if path.exists() else {} + except (OSError, ValueError): + state = {} + state.setdefault("jobs", {}) + return state + + +def save_state(project, state): + path = _folder(project) / STATE + partial = path.with_name(path.name + ".partial") + partial.write_text(json.dumps(state, indent=1), encoding="utf-8") + os.replace(partial, path) + + +def request(project, job): + """Ask the server's refresher for a run of `job` at its next look, whatever the schedule.""" + if job not in JOBS: + raise ValueError(f"job is one of {', '.join(JOBS)}") + path = _folder(project) / f"refresh-{job}.request" + path.write_text(_iso(time.time()), encoding="utf-8") + return {"requested": job, "file": str(path)} + + +def _requested(project): + return {job for job in JOBS if (_folder(project) / f"refresh-{job}.request").exists()} + + +def _clear_request(project, job): + try: + (_folder(project) / f"refresh-{job}.request").unlink() + except FileNotFoundError: + pass + + +def _iso(ts): + return datetime.datetime.fromtimestamp(ts, datetime.timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ") + + +# ---------------------------------------------------------------------------------------------- the decision +def due(cfg, state, job, head, now, hour, requested=()): + """(True, why) when `job` should run now; (False, why not) otherwise. Pure: the tests drive it directly.""" + if job in requested: + return True, "requested" + if not cfg.get("results_refresh"): + return False, "results_refresh is off" + last = state.get("jobs", {}).get(job, {}) + if last.get("head") == head: + return False, "already at main's HEAD" + if job == "match": + every = float(cfg.get("match_every_minutes", 60)) * 60 + else: + every = float(cfg.get("behaviour_every_hours", 12)) * 3600 + if last.get("started_ts") and now - last["started_ts"] < every: + return False, f"last run started {int((now - last['started_ts']) / 60)} min ago" + if job == "behaviour" and not in_window(window(cfg.get("behaviour_window")), hour): + return False, f"outside behaviour_window {cfg.get('behaviour_window')}" + return True, "main moved" + + +def choose(cfg, state, head, now, hour, requested=(), available=JOBS): + """The one job to run now (the match first: it is quicker and more often due), or (None, reasons).""" + reasons = {} + for job in JOBS: + if job not in available: + reasons[job] = "not configured" + continue + ok, why = due(cfg, state, job, head, now, hour, requested) + if ok: + return job, why + reasons[job] = why + return None, reasons + + +# ---------------------------------------------------------------------------------------------- running +def _head(project): + from .logbook_auto import _git + return _git(project.logbook["decomp"], "rev-parse", "HEAD").strip() + + +def _spawn(argv, cwd, stdout, stderr): + flags = 0 + if os.name == "nt": + flags = subprocess.IDLE_PRIORITY_CLASS | subprocess.CREATE_NO_WINDOW # children (cl.exe) inherit idle + env = dict(os.environ, PYTHONIOENCODING="utf-8") + return subprocess.Popen(argv, cwd=str(cwd), stdin=subprocess.DEVNULL, stdout=stdout, stderr=stderr, env=env, + creationflags=flags) + + +def _kill_tree(pid): + if os.name == "nt": + subprocess.run(["taskkill", "/PID", str(pid), "/T", "/F"], capture_output=True, + creationflags=getattr(subprocess, "CREATE_NO_WINDOW", 0)) + else: + try: + os.kill(pid, 9) + except OSError: + pass + + +def _alive(pid): + from .reverse import pid_alive + return bool(pid) and pid_alive(pid) + + +def _paths(project, job): + target = Path(configured(project, job)["results"]) + paths = {"target": target, "partial": target.with_name(target.name + ".partial"), + "log": _folder(project) / f"{job}.log"} + if job == "behaviour": + paths["text"] = target.with_suffix(".txt") + paths["text_partial"] = target.with_suffix(".txt.partial") + return paths + + +def _argv(project, job, out): + need = configured(project, job) + if job == "match": + script = Path(need["script"]) + return [sys.executable, "-B", str(script), "check", "--build", "--decomp", + str(Path(project.logbook["decomp"])), "--json", str(out)], script.parent + command = [str(c) for c in need["command"]] + return command + ["--readable", "--jobs", "4", "--json", str(out)], Path(command[-1]).parent + + +def _match_lock(project): + """The lock re_match_program holds around a whole-program build of main (harbor.reverse.match_program).""" + from .reverse import _exclusive + rev = project.reverse or {} + return _exclusive(Path(rev.get("debugger_temp") or tempfile.gettempdir()) / "ltcg-main.lock", wait_seconds=0) + + +def _counts(rows, field): + counts = {} + for r in rows: + counts[str(r.get(field))] = counts.get(str(r.get(field)), 0) + 1 + return counts + + +def _complete(project, state, run, now, returncode=None): + """Move a finished run's output into place, or record why it failed. Clears state['running'].""" + job, paths = run["job"], _paths(project, run["job"]) + last = dict(state["jobs"].get(job, {})) + last.update(started_ts=run["started_ts"], started=_iso(run["started_ts"]), finished=_iso(now)) + try: + partial = paths["partial"] + text = partial.read_text(encoding="utf-8") if partial.exists() else "" + if not text.strip(): + ended = "the run was interrupted" if returncode is None else \ + returncode if isinstance(returncode, str) else f"exit code {returncode}" + raise RuntimeError(f"no results were written ({ended}); see {paths['log']}") + rows = json.loads(text) + if not isinstance(rows, list) or not rows: + raise RuntimeError("the results file is empty") + os.replace(partial, paths["target"]) + if job == "behaviour" and paths["text_partial"].exists(): + os.replace(paths["text_partial"], paths["text"]) + last.update(head=run["head"], ok=True, error=None, functions=len(rows), + counts=_counts(rows, "status" if job == "match" else "verdict"), + results_mtime_ns=paths["target"].stat().st_mtime_ns) + except (OSError, ValueError, RuntimeError) as error: + last.update(ok=False, error=str(error)[:500]) + state["jobs"][job] = last + state.pop("running", None) + save_state(project, state) + return {"job": job, "ok": last["ok"], "head": run["head"][:8], **({"error": last["error"]} if not last["ok"] else {})} + + +def run_job(project, state, job, head, now, reason=""): + paths = _paths(project, job) + argv, cwd = _argv(project, job, paths["partial"]) + for stale in [paths["partial"]] + ([paths["text_partial"]] if job == "behaviour" else []): + if stale.exists(): + stale.write_bytes(b"") # a leftover of an interrupted run is never taken for this one + run = {"job": job, "pid": None, "head": head, "started_ts": now, "reason": reason} + clock = time.monotonic() + returncode = None + with open(paths["log"], "wb") as log: + stdout = open(paths["text_partial"], "wb") if job == "behaviour" else log + try: + log.write(f"{_iso(now)} {job} at {head[:8]} ({reason}): {' '.join(argv)}\n".encode("utf-8")) + log.flush() + proc = _spawn(argv, cwd, stdout, log if job == "behaviour" else subprocess.STDOUT) + run["pid"] = proc.pid + state["running"] = {**run, "started": _iso(now)} + save_state(project, state) + try: + returncode = proc.wait(timeout=TIMEOUT[job]) + except subprocess.TimeoutExpired: + _kill_tree(proc.pid) + proc.wait() + returncode = f"timed out after {TIMEOUT[job] // 60} min" + except OSError as error: + returncode = f"could not start: {error}" + finally: + if stdout is not log: + stdout.close() + return _complete(project, state, run, now + (time.monotonic() - clock), returncode) + + +def tick(project, now=None, hour=None): + """One look: finish off a run an earlier server left, then start the job that is due (and wait for it).""" + now = time.time() if now is None else now + hour = datetime.datetime.now().hour if hour is None else hour + available = [job for job in JOBS if configured(project, job)] + if not available: + return {"idle": "not configured"} + state = load_state(project) + running = state.get("running") + if running: + if _alive(running.get("pid")) and now - running.get("started_ts", 0) < TIMEOUT.get(running.get("job"), 0): + return {"busy": running["job"], "pid": running["pid"]} + return {"adopted": _complete(project, state, running, now)} + requested = _requested(project) + if not requested and not settings(project).get("results_refresh"): + return {"idle": "results_refresh is off"} + head = _head(project) + job, why = choose(settings(project), state, head, now, hour, requested, available) + if not job: + return {"idle": why, "head": head[:8]} + if job == "match": + from .util import HarborError + try: + with _match_lock(project): + _clear_request(project, job) + return run_job(project, state, job, head, now, why) + except HarborError: + return {"waiting": "another whole-program build of main holds the lock"} + _clear_request(project, job) + return run_job(project, state, job, head, now, why) + + +# ---------------------------------------------------------------------------------------------- reading +def freshness(project): + """For the progress view: which commit the exact and verified tiers are from, and how old they are.""" + state = load_state(project) + out = {} + for job in JOBS: + need = configured(project, job) + target = Path(need["results"]) if need else Path((project.reverse or {}).get(RESULTS_KEY[job]) or "") + last = state["jobs"].get(job, {}) + try: + mtime_ns = target.stat().st_mtime_ns if str(target) not in ("", ".") else None + except OSError: + mtime_ns = None + if mtime_ns is None: + out[job] = None + continue + ours = last.get("ok") and last.get("results_mtime_ns") == mtime_ns + out[job] = {"sha": last["head"][:7] if ours else None, + "at": last.get("finished") if ours else _iso(mtime_ns / 1e9), + "error": last.get("error") if last.get("ok") is False else None} + running = state.get("running") + out["running"] = {"job": running["job"], "started": running.get("started")} if running else None + out["enabled"] = bool(settings(project).get("results_refresh")) + return out + + +def status(project, now=None, hour=None): + """For `harbor logbook results`: the state plus what the next look would do.""" + now = time.time() if now is None else now + hour = datetime.datetime.now().hour if hour is None else hour + state = load_state(project) + available = [job for job in JOBS if configured(project, job)] + try: + head = _head(project) if available else "" + except RuntimeError: + head = "" + nxt = {job: due(settings(project), state, job, head, now, hour, _requested(project)) + for job in available} + return {"settings": settings(project), "head": head[:8], "jobs": state["jobs"], "running": state.get("running"), + "requested": sorted(_requested(project)), + "next": {job: {"due": ok, "why": why} for job, (ok, why) in nxt.items()}, + "state_file": str(_folder(project) / STATE)} + + +def loop(registry): + """Server thread: one look every two minutes at every project (results_refresh on, or a run requested).""" + time.sleep(START_DELAY) + while True: + for name in registry.names(): + try: + h, _ = registry.get(name) + tick(h.project) + except Exception: + traceback.print_exc() + time.sleep(TICK) diff --git a/harbor/server.py b/harbor/server.py index 2586e31..bc04cf0 100644 --- a/harbor/server.py +++ b/harbor/server.py @@ -558,6 +558,8 @@ def main(argv=None): threading.Thread(target=toast_loop, daemon=True).start() from . import logbook_auto threading.Thread(target=logbook_auto.loop, args=(REGISTRY,), daemon=True).start() + from . import results_refresh + threading.Thread(target=results_refresh.loop, args=(REGISTRY,), daemon=True).start() print(f"Harbor on http://127.0.0.1:{PORT} - projects: {', '.join(REGISTRY.names())}", flush=True) server.serve_forever() diff --git a/harbor/web/app.html b/harbor/web/app.html index 66f8271..e7ecb1a 100644 --- a/harbor/web/app.html +++ b/harbor/web/app.html @@ -68,6 +68,7 @@ body { overflow: hidden; } .pm-seg.pm-exact { background: var(--pm-exact); } .pm-seg.pm-verified { background: var(--pm-verified); } .pm-seg.pm-readable { background: repeating-linear-gradient(135deg, var(--pm-readable) 0 4px, color-mix(in srgb, var(--pm-readable) 45%, var(--surface-3)) 4px 8px); } .pm-seg.pm-named { background: var(--blue); } +.pm-fresh { margin-top: 6px; } .pm-fresh:empty { display: none; } .pm-fresh .mono { font-family: var(--mono); } .pm-commit { display: flex; flex-wrap: wrap; align-items: center; gap: 8px 10px; margin-top: 12px; font-size: 13px; color: var(--muted); } .pm-commit b { color: var(--text); font-weight: 600; } .pm-commit .grow { flex: 1; } .pm-tools { display: flex; flex-wrap: wrap; gap: 8px 10px; align-items: center; margin-top: 16px; } .pm-tools select { max-width: min(100%, 340px); } .pm-tools input { flex: 1 1 220px; min-width: 0; } .pm-crumb { display: flex; flex-wrap: wrap; gap: 6px 10px; align-items: center; margin-top: 12px; font-size: 13px; } .pm-crumb:empty { display: none; } .pm-crumb .pm-bar-row { flex: 1 1 100%; } @@ -700,6 +701,7 @@ button.chip:hover { color: var(--accent-ink); background: var(--accent-soft); }

The project is – decompiled

+
@@ -1239,8 +1241,17 @@ function pmBar(label,size,segs,total,extra){const sum=segs.reduce((a,s)=>a+s[1], function pmCodeSegs(x,total){return [['pm-exact',x.exact,pc(x.exact,total)+'% perfect match ('+kB(x.exact)+')'], ['pm-verified',x.verified,pc(x.verified,total)+'% decompiled, verified in the emulator, not exact ('+kB(x.verified)+')'], ['pm-readable',x.readable,pc(x.readable,total)+'% decompiled, readable only ('+kB(x.readable)+')']]} +function pmFresh(r){if(!r||(!r.match&&!r.behaviour&&!r.running))return ''; + const when=x=>(x.sha?'commit '+esc(x.sha)+', ':'')+''+esc(rel(x.at))+'', + m=r.match,b=r.behaviour,parts=[]; + if(m&&b&&m.sha&&m.sha===b.sha)parts.push('Exact and verified as of '+when(Date.parse(m.at)the last '+name[k]+' failed'); + return parts.join(' · ')} function pmHeader(){const d=PM.doc;if(!d)return;const h=d.history,pt=PM.hist!=null?h[PM.hist]:null,c=d.code; - el('pmProject').textContent=d.project; + el('pmProject').textContent=d.project;put('pmFresh',pt?'':pmFresh(d.results)); if(!pt){el('pmPct').textContent=d.percent.toFixed(2)+'%'; put('pmBars',pmBar('Code',kB(c.bytes),pmCodeSegs(c,c.bytes),c.bytes,'game code · '+fmt(c.decompiled_functions)+' of '+fmt(c.functions)+' functions') +(d.data?pmBar('Data',fmt(d.data.addresses)+' addresses',[['pm-named',d.data.named,pc(d.data.named,d.data.addresses)+'% of the data addresses the code touches have a name in globals.csv ('+fmt(d.data.named)+' of '+fmt(d.data.addresses)+')']],d.data.addresses,'globals named'):'')); diff --git a/tests/test_results_refresh.py b/tests/test_results_refresh.py new file mode 100644 index 0000000..20e6070 --- /dev/null +++ b/tests/test_results_refresh.py @@ -0,0 +1,228 @@ +"""harbor.results_refresh: when the whole-program check and the emulator run are rerun, and how their results land. +The subprocess is replaced by a fake that writes what the real tools would.""" +import json +import os +import subprocess +import sys +import unittest +from unittest import mock + +from helpers import HarborCase +from harbor import results_refresh as rr + +HOUR = 3600 +T0 = 1_790_000_000.0 + + +class Decisions(unittest.TestCase): + """due() and choose() are pure: the schedule without any files or processes.""" + cfg = {"results_refresh": True, "match_every_minutes": 60, "behaviour_every_hours": 12, "behaviour_window": "01-06"} + + def state(self, **jobs): + return {"jobs": jobs} + + def test_window(self): + self.assertEqual(rr.window("01-06"), (1, 6)) + self.assertIsNone(rr.window("")) + self.assertEqual([h for h in range(24) if rr.in_window((1, 6), h)], [1, 2, 3, 4, 5]) + self.assertEqual([h for h in range(24) if rr.in_window((22, 2), h)], [0, 1, 22, 23]) + self.assertTrue(all(rr.in_window(None, h) for h in range(24))) + with self.assertRaises(ValueError): + rr.window("1-30") + + def test_off_unless_enabled_but_a_request_always_runs(self): + off = dict(self.cfg, results_refresh=False) + self.assertEqual(rr.due(off, self.state(), "match", "abc", T0, 3), (False, "results_refresh is off")) + self.assertEqual(rr.due(off, self.state(match={"head": "abc", "started_ts": T0}), "match", "abc", T0, 12, + requested={"match"}), (True, "requested")) + + def test_match_when_head_moved_at_most_hourly(self): + s = self.state(match={"head": "old", "started_ts": T0}) + self.assertFalse(rr.due(self.cfg, self.state(match={"head": "abc", "started_ts": T0 - 9 * HOUR}), + "match", "abc", T0, 12)[0]) # nothing new on main + self.assertFalse(rr.due(self.cfg, s, "match", "new", T0 + 59 * 60, 12)[0]) # too soon + self.assertEqual(rr.due(self.cfg, s, "match", "new", T0 + 60 * 60, 12), (True, "main moved")) + self.assertTrue(rr.due(self.cfg, self.state(), "match", "new", T0, 12)[0]) # never ran: due at once + self.assertTrue(rr.due(dict(self.cfg, match_every_minutes=10), s, "match", "new", T0 + 600, 12)[0]) + + def test_behaviour_twelve_hourly_inside_its_window(self): + s = self.state(behaviour={"head": "old", "started_ts": T0}) + self.assertFalse(rr.due(self.cfg, s, "behaviour", "new", T0 + 11 * HOUR, 3)[0]) + self.assertFalse(rr.due(self.cfg, s, "behaviour", "new", T0 + 13 * HOUR, 12)[0]) # outside 01-06 + self.assertTrue(rr.due(self.cfg, s, "behaviour", "new", T0 + 13 * HOUR, 1)[0]) + self.assertFalse(rr.due(self.cfg, s, "behaviour", "new", T0 + 13 * HOUR, 6)[0]) # the window ends at 06:00 + self.assertTrue(rr.due(dict(self.cfg, behaviour_window=""), s, "behaviour", "new", T0 + 13 * HOUR, 15)[0]) + self.assertFalse(rr.due(self.cfg, self.state(behaviour={"head": "new", "started_ts": T0 - 99 * HOUR}), + "behaviour", "new", T0, 3)[0]) + + def test_choose_one_job_match_first(self): + self.assertEqual(rr.choose(self.cfg, self.state(), "new", T0, 3)[0], "match") + s = self.state(match={"head": "new", "started_ts": T0}) + self.assertEqual(rr.choose(self.cfg, s, "new", T0 + 60, 3)[0], "behaviour") + job, why = rr.choose(self.cfg, s, "new", T0 + 60, 12) + self.assertIsNone(job) + self.assertEqual(set(why), {"match", "behaviour"}) + self.assertEqual(rr.choose(self.cfg, self.state(), "new", T0, 3, available=["behaviour"])[0], "behaviour") + + +class FakeProc: + """Stands in for subprocess.Popen: writes the --json file (and a printout) the way ltcg.py / diffrun.py do.""" + def __init__(self, argv, cwd, stdout, stderr, rows=None, pid=None): + self.argv, self.cwd, self.pid = argv, cwd, pid or os.getpid() + out = argv[argv.index("--json") + 1] + if rows is not None: + with open(out, "w", encoding="utf-8") as f: + json.dump(rows, f) + stdout.write(b"0x401000 ResetPlayer: same\n1 functions: 1 same in 1s\n") + + def wait(self, timeout=None): + return 0 + + +class Refresher(HarborCase): + def setUp(self): + super().setUp() + d = self.dir + (d / "ltcg").mkdir() + (d / "ltcg" / "ltcg.py").write_text("", encoding="utf-8") + (d / "diffrun").mkdir() + (d / "temp").mkdir() + self.match_out, self.behaviour_out = d / "check.json", d / "diffrun" / "readable.json" + self.h.project.reverse = {"ltcg": str(d / "ltcg" / "ltcg.py"), "match_results": str(self.match_out), + "diffrun_command": ["python.exe", "-B", str(d / "diffrun" / "diffrun.py")], + "diffrun_results": str(self.behaviour_out), "debugger_temp": str(d / "temp")} + self.h.project.logbook = {"dir": str(d / "logbook"), "decomp": str(d / "decomp"), "results_refresh": True} + self.head = "a" * 40 + self.calls = [] + self.real_spawn = rr._spawn + self.rows = {"match": [{"address": "0x401000", "status": "match"}, {"address": "0x401100", "status": "differs"}], + "behaviour": [{"address": "0x401000", "verdict": "same"}]} + patches = [mock.patch.object(rr, "_head", lambda project: self.head), + mock.patch.object(rr, "_spawn", self.spawn)] + for p in patches: + p.start() + self.addCleanup(p.stop) + + def spawn(self, argv, cwd, stdout, stderr): + job = "match" if "check" in argv else "behaviour" + self.calls.append((job, argv, cwd)) + return FakeProc(argv, cwd, stdout, stderr, rows=self.rows.get(job)) + + def state(self): + return rr.load_state(self.h.project) + + def test_match_runs_when_main_moves_and_lands_atomically(self): + out = rr.tick(self.h.project, now=T0, hour=12) + self.assertTrue(out["ok"], out) + job, argv, cwd = self.calls[0] + self.assertEqual(job, "match") + self.assertEqual(argv[1:5], ["-B", str(self.dir / "ltcg" / "ltcg.py"), "check", "--build"]) + self.assertEqual(argv[argv.index("--decomp") + 1], str(self.dir / "decomp")) + self.assertEqual(argv[argv.index("--json") + 1], str(self.match_out) + ".partial") + self.assertEqual(cwd, self.dir / "ltcg") + self.assertEqual(json.loads(self.match_out.read_text(encoding="utf-8")), self.rows["match"]) + self.assertFalse((self.dir / "check.json.partial").exists()) + st = self.state() + self.assertEqual((st["jobs"]["match"]["head"], st["jobs"]["match"]["counts"]), + (self.head, {"match": 1, "differs": 1})) + self.assertNotIn("running", st) + self.assertIn("idle", rr.tick(self.h.project, now=T0 + 10, hour=12)) # nothing new on main + self.head = "b" * 40 + self.assertIn("idle", rr.tick(self.h.project, now=T0 + 30 * 60, hour=12)) # within the hour + self.assertTrue(rr.tick(self.h.project, now=T0 + 61 * 60, hour=12)["ok"]) + self.assertEqual(len(self.calls), 2) + + def test_behaviour_at_night_with_its_printout(self): + rr.tick(self.h.project, now=T0, hour=12) # the match first + self.assertIn("idle", rr.tick(self.h.project, now=T0 + 600, hour=12)) # emulator waits for its window + out = rr.tick(self.h.project, now=T0 + 600, hour=2) + self.assertEqual((out["job"], out["ok"]), ("behaviour", True)) + job, argv, cwd = self.calls[-1] + self.assertEqual(argv[:3], self.h.project.reverse["diffrun_command"]) + self.assertEqual(argv[3:7], ["--readable", "--jobs", "4", "--json"]) + self.assertEqual(cwd, self.dir / "diffrun") + self.assertEqual(json.loads(self.behaviour_out.read_text(encoding="utf-8")), self.rows["behaviour"]) + self.assertIn("1 functions: 1 same", (self.dir / "diffrun" / "readable.txt").read_text(encoding="utf-8")) + self.assertEqual(self.state()["jobs"]["behaviour"]["counts"], {"same": 1}) + + def test_a_failed_run_keeps_the_old_results_and_retries_after_the_interval(self): + self.match_out.write_text('[{"old": 1}]', encoding="utf-8") + self.rows["match"] = None # the tool wrote nothing + out = rr.tick(self.h.project, now=T0, hour=12) + self.assertFalse(out["ok"]) + self.assertIn("no results were written", out["error"]) + self.assertEqual(self.match_out.read_text(encoding="utf-8"), '[{"old": 1}]') + st = self.state()["jobs"]["match"] + self.assertIsNone(st.get("head")) + self.assertIn("idle", rr.tick(self.h.project, now=T0 + 600, hour=12)) # not hammered + self.rows["match"] = [{"address": "0x401000", "status": "match"}] + self.assertTrue(rr.tick(self.h.project, now=T0 + HOUR, hour=12)["ok"]) + + def test_a_run_left_by_an_earlier_server_is_waited_for_then_adopted(self): + state = {"jobs": {}, "running": {"job": "match", "pid": os.getpid(), "head": self.head, + "started_ts": T0, "started": rr._iso(T0)}} + rr.save_state(self.h.project, state) + self.assertEqual(rr.tick(self.h.project, now=T0 + 60, hour=12)["busy"], "match") # still going: no second run + self.assertEqual(self.calls, []) + done = subprocess.Popen([sys.executable, "-c", "pass"]) + done.wait() + state["running"]["pid"] = done.pid # it has finished since + rr.save_state(self.h.project, state) + (self.dir / "check.json.partial").write_text(json.dumps(self.rows["match"]), encoding="utf-8") + out = rr.tick(self.h.project, now=T0 + 600, hour=12) + self.assertTrue(out["adopted"]["ok"], out) + self.assertEqual(self.calls, []) + self.assertEqual(json.loads(self.match_out.read_text(encoding="utf-8")), self.rows["match"]) + self.assertEqual(self.state()["jobs"]["match"]["head"], self.head) + self.assertNotIn("running", self.state()) + + def test_waits_while_another_whole_program_build_of_main_holds_the_lock(self): + lock = self.dir / "temp" / "ltcg-main.lock" + lock.write_text(str(os.getpid()), encoding="utf-8") + rr.request(self.h.project, "match") + self.assertIn("waiting", rr.tick(self.h.project, now=T0, hour=12)) + self.assertEqual(self.calls, []) + self.assertEqual(rr._requested(self.h.project), {"match"}) # kept for the next look + lock.write_text("", encoding="utf-8") + os.utime(lock, (T0 - 60, T0 - 60)) # an empty, old lock is stale + self.assertTrue(rr.tick(self.h.project, now=T0 + 120, hour=12)["ok"]) + self.assertFalse(lock.exists()) # released after the run + + def test_a_request_runs_whatever_the_schedule(self): + self.h.project.logbook["results_refresh"] = False + self.assertEqual(rr.tick(self.h.project, now=T0, hour=12), {"idle": "results_refresh is off"}) + rr.request(self.h.project, "behaviour") + out = rr.tick(self.h.project, now=T0, hour=12) + self.assertEqual((out["job"], out["ok"]), ("behaviour", True)) + self.assertEqual(rr._requested(self.h.project), set()) + self.assertEqual(rr.tick(self.h.project, now=T0 + 5, hour=12), {"idle": "results_refresh is off"}) + + def test_freshness_names_the_commit_until_someone_else_rewrites_the_file(self): + rr.tick(self.h.project, now=T0, hour=12) + fresh = rr.freshness(self.h.project) + self.assertEqual((fresh["match"]["sha"], fresh["match"]["error"]), (self.head[:7], None)) + self.assertIsNone(fresh["behaviour"]) + self.assertTrue(fresh["enabled"]) + st = rr.load_state(self.h.project) + st["jobs"]["match"]["results_mtime_ns"] -= 1 # a different write than ours + rr.save_state(self.h.project, st) + self.assertIsNone(rr.freshness(self.h.project)["match"]["sha"]) + + def test_runs_at_idle_priority(self): + seen = {} + + class P: + pid = 1 + + def __init__(self, argv, **kw): + seen.update(kw) + + with mock.patch.object(rr.subprocess, "Popen", P): + self.real_spawn(["x"], self.dir, subprocess.DEVNULL, subprocess.DEVNULL) + if os.name == "nt": + self.assertTrue(seen["creationflags"] & subprocess.IDLE_PRIORITY_CLASS) + self.assertEqual(seen["stdin"], subprocess.DEVNULL) + + +if __name__ == "__main__": + unittest.main()