diff options
Diffstat (limited to 'src/eval_tune/match_play.py')
| -rwxr-xr-x | src/eval_tune/match_play.py | 90 |
1 files changed, 82 insertions, 8 deletions
diff --git a/src/eval_tune/match_play.py b/src/eval_tune/match_play.py index 9591330..b26244a 100755 --- a/src/eval_tune/match_play.py +++ b/src/eval_tune/match_play.py @@ -41,8 +41,10 @@ import argparse import hashlib import io import math +import os import random import re +import select import sys import time from concurrent.futures import ThreadPoolExecutor, wait, FIRST_COMPLETED @@ -67,7 +69,64 @@ _SEARCHED_RE = re.compile( _DEPTH_RE = re.compile(r"^tellothers d(\d+),") _FIRST_MOVE_BETA_RE = re.compile( r"^First move beta cutoff rate was\s+([\d.]+) percent\.") -_STATS_TRAILING_LINES = 20 # bound on how far past "move" to keep reading +# Reading PostMoveSearchReport's trailing block used to stop either at a +# bounded line count or at gamelist.c's "_white(move N)_"/"_black(move N)_" +# prompt -- both unreliable: the block's line count depends on whether the +# binary was built with PERF_COUNTERS (root.c gates "First move beta +# cutoff rate" and several other lines behind #ifdef PERF_COUNTERS, so a +# binary built without it -- true of ../typhoon in this tree, unlike +# head_reference -- prints a shorter block), and the prompt line is +# suppressed entirely once Engine.__init__ (tune_eval_dna.py) sends +# "xboard" at startup, which sets g_Options.fRunningUnderXboard and makes +# MakeStatusLine() skip printing it (gamelist.c: "if +# (!g_Options.fRunningUnderXboard)"). Either mismatch left readline() +# blocking forever waiting for a line that would never come -- every +# worker deadlocked silently after its first move (0% CPU, no further +# games), which looked like "no matches happening" from outside. +# +# A "ping <id>"-after-"go" xboard synchronization idiom was tried next and +# also failed: command.c's PingCommand gets serviced by an input path that +# runs concurrently with an in-progress search (confirmed live -- "pong 0" +# came back *before* the "move" line), so it's decoupled from output +# ordering and cannot mark end-of-report either. +# +# Fixed for real with an unconditional marker Trace()'d by +# PostMoveSearchReport itself (root.c) as the last thing it ever prints, +# regardless of build flags -- see "ReportEnd" there. But a pre-existing +# binary (e.g. head_reference/typhoon, deliberately left untouched as a +# pinned historical baseline -- see CLAUDE.md's head_reference protocol) +# predates this marker and will never print it, so ReportEnd alone would +# just trade one build-flag-shaped hang for a binary-vintage-shaped one. +# Belt-and-suspenders fix: _read_stats_line below uses select() to give up +# waiting after a short idle period with no new output, treating a quiet +# pipe as "report's done" regardless of whether any specific terminal line +# ever arrives. Costs up to that idle timeout once per move for a binary +# that never emits ReportEnd; costs nothing for one that does, since the +# marker line short-circuits the loop the moment it's read. +_REPORT_END_RE = re.compile(r"^ReportEnd$") +_STATS_TRAILING_LINES = 60 # hard cap on lines, belt to the idle-timeout suspenders +_STATS_IDLE_TIMEOUT_SEC = 0.5 + + +def _readline_or_none(stream, timeout): + """readline() with a timeout: None means the pipe went quiet for + `timeout` seconds with nothing to read (not EOF -- EOF is still a + normal, immediately-returned '' from readline() once select() reports + the fd readable).""" + ready, _, _ = select.select([stream], [], [], timeout) + if not ready: + return None + return stream.readline() + +# MATCH_DEBUG=1 traces every command sent and every line read per side, so a +# hang can be pinned to the exact readline() call blocking rather than just +# "process went idle" from the outside (ps shows CPU frozen but not why). +_DEBUG = os.environ.get("MATCH_DEBUG") == "1" + + +def _dbg(tag, msg): + if _DEBUG: + print(f"[{tag}] {msg}", file=sys.stderr, flush=True) def sample_openings(pgn_path, n, min_ply=8, max_ply=20, seed=0, @@ -181,16 +240,20 @@ def play_one_game(white_engine_path, black_engine_path, scratch_dir, fen, "set ThinkOnOpponentsTime false", "set ResignThreshold -1000", tc_cmd): + _dbg("W", f"send: {command}") we._send(command) + _dbg("B", f"send: {command}") be._send(command) board = chess.Board(fen) - for _ in range(max_plies): + for ply_idx in range(max_plies): if board.is_game_over(claim_draw=True): break white_to_move = board.turn == chess.WHITE mover = we if white_to_move else be + tag = "W" if white_to_move else "B" mover_stats = white_stats if white_to_move else black_stats + _dbg(tag, f"ply {ply_idx}: send force/setboard/go") mover._send("force") mover._send(f"setboard {board.fen()}") mover._send("go") @@ -198,7 +261,9 @@ def play_one_game(white_engine_path, black_engine_path, scratch_dir, fen, for _ in range(400): line = mover.stdout.readline() if not line: + _dbg(tag, "EOF while scanning for move line") break + _dbg(tag, f"read(move-scan): {line!r}") if line.startswith("tellics resign"): # Engine resigned instead of moving -- root.c prints # this and returns without ever printing "move ...", @@ -219,9 +284,18 @@ def play_one_game(white_engine_path, black_engine_path, scratch_dir, fen, # lines to pick it up before moving on to the next ply. ply_nodes = ply_time = ply_depth = ply_fmb = None for _ in range(_STATS_TRAILING_LINES): - line = mover.stdout.readline() + line = _readline_or_none(mover.stdout, _STATS_IDLE_TIMEOUT_SEC) + if line is None: + _dbg(tag, "idle timeout reading stats block -- " + "assuming report done (no ReportEnd marker, " + "e.g. an older binary like head_reference)") + break if not line: + _dbg(tag, "EOF while reading stats block") break + _dbg(tag, f"read(stats): {line!r}") + if _REPORT_END_RE.match(line): + break # PostMoveSearchReport's own end-of-report marker sm = _SEARCHED_RE.match(line) if sm: ply_time = float(sm.group(1)) @@ -234,7 +308,7 @@ def play_one_game(white_engine_path, black_engine_path, scratch_dir, fen, fm = _FIRST_MOVE_BETA_RE.match(line) if fm: ply_fmb = float(fm.group(1)) - break # last line of the block we care about + continue if ply_nodes is not None and ply_time is not None: mover_stats.add_ply(ply_nodes, ply_time, ply_depth) if ply_fmb is not None: @@ -373,10 +447,10 @@ def sprt_bar(llr, la, lb, width=9): the rounded llr position.""" frac = 0.5 if lb == la else (llr - la) / (lb - la) frac = min(max(frac, 0.0), 1.0) - slot = round(frac * (2 * width)) + slot = round(frac * (2 * width + 3)) bar = "|" + "-" * width + "|" + "-" * width + "|" idx = slot + 1 - return bar[:idx] + "V" + bar[idx:] + return bar[:idx - 1] + "V" + bar[idx:] class Sprt: @@ -621,8 +695,8 @@ def main(): f"H0={sprt.la:+.2f}" f"{sprt_bar(sprt.llr(), sprt.la, sprt.lb)}" f"H1={sprt.lb:+.2f}") - print(f" {done} games: -{losses} ={draws} +{wins} " - f"({avg_game_sec:.1f}s avg, eta={eta_sec/60:.0f}min, " + print(f"{done} games: -{losses} ={draws} +{wins} " + f"({avg_game_sec:.1f}s avg, eta={eta_sec/3600:.0f}hrs, " f"score={score:.3f}){sprt_note}", file=sys.stderr) |