#!/usr/bin/env bash # Audit IdleSpectator Watching / DROP / BAD / STATE from Player.log. # # Usage: # ./scripts/soak-audit-player-log.sh # last 120s wall wait, then audit new bytes # ./scripts/soak-audit-player-log.sh 60 # wait 60s then audit # ./scripts/soak-audit-player-log.sh --since-bytes N # audit from byte offset (no wait) # ./scripts/soak-audit-player-log.sh --since-bytes N 60 # wait 60s, then audit from N # ./scripts/soak-audit-player-log.sh --no-wait # audit empty window from current EOF # # Env: # PLAYER_LOG - override Player.log path set -euo pipefail LOG="${PLAYER_LOG:-$HOME/.config/unity3d/mkarpenko/WorldBox/Player.log}" SECONDS_WAIT=0 SINCE_BYTES="" while [[ $# -gt 0 ]]; do case "$1" in --since-bytes) SINCE_BYTES="${2:-}" shift 2 ;; --no-wait) SECONDS_WAIT=0 shift ;; -h|--help) sed -n '2,12p' "$0" exit 0 ;; *) if [[ "$1" =~ ^[0-9]+$ ]]; then SECONDS_WAIT="$1" else echo "Unknown arg: $1" >&2 exit 2 fi shift ;; esac done if [[ ! -f "$LOG" ]]; then echo "Player.log not found: $LOG" >&2 exit 1 fi MARKED_FROM_EOF=0 if [[ -z "$SINCE_BYTES" ]]; then SINCE_BYTES=$(wc -c < "$LOG" | tr -d ' ') MARKED_FROM_EOF=1 fi if [[ "$SECONDS_WAIT" -gt 0 ]]; then echo "Marked offset $SINCE_BYTES; waiting ${SECONDS_WAIT}s (leave Idle Spectator running) ..." sleep "$SECONDS_WAIT" elif [[ "$MARKED_FROM_EOF" -eq 1 ]]; then echo "No wait and no --since-bytes: auditing from current EOF (empty window)." echo "Tip: ./scripts/soak-audit-player-log.sh 60" fi python3 - "$LOG" "$SINCE_BYTES" <<'PY' import re, sys from collections import Counter from pathlib import Path log_path = Path(sys.argv[1]) armed = int(sys.argv[2]) raw = log_path.read_bytes()[armed:].decode("utf-8", errors="replace") lines = raw.splitlines() def harness_noise(ln: str) -> bool: if "[HARNESS]" not in ln and "[ASSERT]" not in ln: return False return "action=" in ln or "batch done" in ln or "inbox reset" in ln watching = [] pairs = [] drops = [] bads = [] scenes = [] states = [] hitch_details = [] hitch_summaries = [] first_active_line = -1 last = None for line_index, ln in enumerate(lines): if harness_noise(ln): continue if "IdleSpectator" not in ln: continue if "Watching:" in ln: tip = ln.split("Watching:", 1)[1].strip() tip = re.sub(r"^\[\d+\]\s*", "", tip) watching.append(tip) last = {"tip": tip, "unit": None, "caption": None} pairs.append(last) elif "[CAPTION]" in ln and last is not None: last["caption"] = ln.split("[CAPTION]", 1)[1].strip() elif "[DROP]" in ln: drops.append(ln.split("[DROP]", 1)[1].strip()) elif "[BAD]" in ln: bads.append(ln.split("[BAD]", 1)[1].strip()) elif "Scene end" in ln: scenes.append(ln.split("Scene end", 1)[1].strip()) elif "[STATE]" in ln: states.append(ln) if first_active_line < 0 and re.search(r"idle=True", ln): first_active_line = line_index if last is not None and last.get("unit") is None and "unit=" in ln: last["unit"] = ln.split("unit=", 1)[1].strip() elif "[HITCH] spike" in ln: hitch_details.append(ln) elif "[HITCH] summary" in ln: hitch_summaries.append(ln) drop_kinds = Counter() for d in drops: drop_kinds[d.split(":", 1)[0].strip()] += 1 focus_true = focus_false = 0 idle_true = idle_false = 0 for s in states: m = re.search(r"focus=(True|False)", s) if not m: continue if m.group(1) == "False": focus_false += 1 else: focus_true += 1 idle = re.search(r"idle=(True|False)", s) if idle: if idle.group(1) == "True": idle_true += 1 else: idle_false += 1 def bucket(t: str) -> str: tl = t.lower() # Combat scale first (before generic fight / vs). if tl.startswith("duel") or " duel " in f" {tl} " or tl.startswith("duel -"): return "combat_duel" if any(tl.startswith(p) for p in ("skirmish", "battle", "mass")) or " mass -" in f" {tl} ": return "combat_multi" if any(x in tl for x in ("fighting", "in a fight", " vs ")) and "war -" not in tl and "plot -" not in tl: return "combat_other" if "decides to start a new civilization" in tl or "decides to found" in tl: return "decision_genesis_intent" if any(x in tl for x in ("new city", "new kingdom", "founds a", "founded")): return "meta_genesis" if any(x in tl for x in ("war -", "kingdom", "rebellion")): return "politics" if any(x in tl for x in ("love", "smitten", "child", "parenthood", "mourns", "lover")): return "relationship" if any(x in tl for x in ("curs", "possess", "dream", "nightmare", "enchant", "stun")): return "status" if "new species" in tl or "appear" in tl or "hatch" in tl: return "discovery" if "plot" in tl or "decides to" in tl: return "plot_or_decision" if "fall" in tl and any(x in tl for x in ("tree", "plant", "bush", "flower", "maple")): return "object_fall" return "other" buckets = Counter(bucket(t) for t in watching) bucket_sequence = [bucket(t) for t in watching] scene_reasons = Counter() for s in scenes: m = re.match(r"\(([^)]+)\)", s) if m: scene_reasons[m.group(1)] += 1 identity = sum(1 for d in drops if "identity_filter" in d) unpresentable = sum(1 for d in drops if "unpresentable" in d) placeholder = sum(1 for t in watching if "something interesting" in t.lower()) veg = [t for t in watching if bucket(t) == "object_fall"] no_focus_bads = sum(1 for b in bads if "no focus" in b.lower()) mismatches = [] sleep_lag = [] for p in pairs: tip = p["tip"] unit = (p.get("unit") or "").strip() cap = p.get("caption") or "" if "fighting" in tip.lower() and "Sleeping" in cap: sleep_lag.append((tip, cap)) if not tip or not unit: continue if "fighting" not in tip.lower() and "fight of" not in tip.lower(): continue subj = tip.split(" is ", 1)[0].split(" ยท ", 1)[0].strip() u0 = unit.split()[0] if u0 and u0.lower() not in subj.lower(): mismatches.append((tip, unit, cap[:72])) print(f"Player.log soak audit") print(f" log={log_path}") print(f" since_bytes={armed} chunk_lines={len(lines)}") print() print(f"Watching cuts: {len(watching)}") print(f"Focus BADs: {no_focus_bads} (all BADs={len(bads)})") print(f"focus True/False: {focus_true}/{focus_false}") print(f"idle True/False: {idle_true}/{idle_false}") if first_active_line >= 0: print(f"first active state: line {first_active_line + 1}/{len(lines)}") print(f"identity_filter: {identity}") print(f"unpresentable: {unpresentable}") print(f"placeholder tips: {placeholder}") print(f"object falls: {len(veg)}") print(f"fight tip/focus mismatches: {len(mismatches)}") print(f"fighting+Sleeping lag: {len(sleep_lag)}") active_hitches = [h for h in hitch_details if "idle=on" in h] def metric_max(rows, name): values = [] pattern = re.compile(rf"\b{re.escape(name)}=([0-9.]+)ms") for row in rows: match = pattern.search(row) if match: values.append(float(match.group(1))) return max(values, default=0.0) summary_spikes = 0 summary_max_dt = 0.0 summary_max_dir = 0.0 summary_max_disc = 0.0 summary_max_cap = 0.0 for row in hitch_summaries: if "idle=on" not in row: continue spike = re.search(r"\bspikes=(\d+)", row) dt = re.search(r"\bmaxDt=([0-9.]+)ms", row) direct = re.search(r"\bmaxDir=([0-9.]+)ms", row) discovery = re.search(r"\bmaxDisc=([0-9.]+)ms", row) caption = re.search(r"\bmaxCap=([0-9.]+)ms", row) if spike: summary_spikes += int(spike.group(1)) if dt: summary_max_dt = max(summary_max_dt, float(dt.group(1))) if direct: summary_max_dir = max(summary_max_dir, float(direct.group(1))) if discovery: summary_max_disc = max(summary_max_disc, float(discovery.group(1))) if caption: summary_max_cap = max(summary_max_cap, float(caption.group(1))) print( "Hitches active: " f"detail={len(active_hitches)} summary_spikes={summary_spikes} " f"maxDt={max(summary_max_dt, metric_max(active_hitches, 'dt')):.1f}ms " f"dir={max(summary_max_dir, metric_max(active_hitches, 'dir')):.1f}ms " f"disc={max(summary_max_disc, metric_max(active_hitches, 'disc')):.1f}ms " f"cap={max(summary_max_cap, metric_max(active_hitches, 'cap')):.1f}ms " f"scan={metric_max(active_hitches, 'scanMs'):.1f}ms " f"soft={metric_max(active_hitches, 'softMs'):.1f}ms " f"scheduler={metric_max(active_hitches, 'schedulerMs'):.1f}ms" ) print() if buckets: print("Buckets:") for k, v in buckets.most_common(): print(f" {k:16} {v}") print() if drop_kinds: print("Drop kinds:") for k, v in drop_kinds.most_common(12): print(f" {k:24} {v}") print() if scene_reasons: print("Scene ends:") for k, v in scene_reasons.most_common(): print(f" {k:16} {v}") print() if watching: print("Tips:") for t in watching: print(f" - {t}") print() if mismatches: print("Fight tip/focus mismatches:") for tip, unit, cap in mismatches: print(f" tip={tip!r} focus={unit!r} caption={cap!r}") print() if sleep_lag: print("Fight tip + Sleeping caption:") for tip, cap in sleep_lag: print(f" tip={tip!r} caption={cap!r}") print() genesis_intent = buckets.get("decision_genesis_intent", 0) duel_n = buckets.get("combat_duel", 0) multi_n = buckets.get("combat_multi", 0) combat_total = duel_n + multi_n + buckets.get("combat_other", 0) combat_share = combat_total / len(watching) if watching else 0.0 max_combat_run = 0 combat_run = 0 for kind in bucket_sequence: if kind.startswith("combat_"): combat_run += 1 max_combat_run = max(max_combat_run, combat_run) else: combat_run = 0 relationship_n = buckets.get("relationship", 0) unique_tips = len(set(watching)) print( f"Variety: duel={duel_n} multi={multi_n} combat_total={combat_total} " f"combat_share={combat_share:.1%} max_combat_run={max_combat_run} " f"relationship={relationship_n} unique_tips={unique_tips}/{len(watching)} " f"genesis_intent={genesis_intent}" ) if genesis_intent: print(" NOTE: decision_genesis_intent tips should be 0 after 0.28.28 (meta outcomes only).") if combat_total >= 4 and multi_n == 0 and duel_n >= 3: print(" NOTE: combat tips are Duel-heavy; multi scrap may be scarce in this world.") if first_active_line >= 0 and len(lines) > 0 and first_active_line > len(lines) * 0.25: print(" NOTE: Idle Spectator activated late; most of this audit window is not a directed soak.") if len(watching) >= 20 and combat_share > 0.35: print(" NOTE: combat exceeds the story-first release target of 35%.") if max_combat_run > 3: print(" NOTE: more than three consecutive combat cuts; inspect critical bypasses and episode boundaries.") print() editorial_pacing_ok = len(watching) < 20 or combat_share <= 0.35 sample_valid = bool(watching) and idle_true > 0 and first_active_line >= 0 ok = ( sample_valid and no_focus_bads == 0 and focus_false == 0 and idle_false == 0 and identity == 0 and placeholder == 0 and len(veg) == 0 and len(mismatches) == 0 and len(sleep_lag) == 0 and genesis_intent == 0 and editorial_pacing_ok ) if not sample_valid: print(" NOTE: no valid active spectator sample was captured.") print("VERDICT:", "PASS" if ok else "REVIEW") sys.exit(0 if ok else 1) PY