diff --git a/README.md b/README.md index 0866457..f938b1b 100644 --- a/README.md +++ b/README.md @@ -100,6 +100,28 @@ Run it with: SNAKE=PrismBattleSnake_GPT_5_6_Sol python main.py ``` +## ZenithBattleSnake_ClaudeOpus5_5 +`ZenithBattleSnake_ClaudeOpus5_5` builds on Prism and keeps its engine. Prism +only runs the exact duel search on near-tied heuristic candidates. Zenith adds a +root verdict pass in duels: every safe move is resolved against all +simultaneous enemy replies using the shared transposition table. A move whose +search proves a forced loss is replaced by the best surviving move. A move whose +search proves a forced win is played even if the heuristic preferred another +move. Its public Battlesnake API name is `ZenithBattleSnake`. + +Version 1.1.0 adds permanent-trail space scoring for Constrictor (free capacity +is not compared against the already occupied body length), balanced root-search +budgets, and health-cost routes for hazard escape and food. It reserves at least +180 ms for non-search work. The HTTP move path also deducts executor queue wait +from the strategy budget and returns a legal-direction fallback instead of null +when its request budget expires. This is best-effort deadline handling, not a +hard real-time guarantee under CPU saturation. + +Run it with: +```sh +SNAKE=ZenithBattleSnake_ClaudeOpus5_5 python main.py +``` + Benchmark Apex and Prism against sampled positions from a gameplay database: ```sh python scripts/benchmark_snakes_from_db.py \ @@ -129,12 +151,41 @@ Run paired seeded games through the official local Battlesnake rules engine: just bench-snake-tournament games=20 gametype=standard map=standard ``` -Each seed is played twice with Apex and Prism swapping initial engine slots. The +Pick other opponents with `snake_a=` and `snake_b=`, for example +`just bench-snake-tournament snake_a=PrismBattleSnake_GPT_5_6_Sol snake_b=ZenithBattleSnake_ClaudeOpus5_5`. + +Each seed is played twice with both snakes swapping initial engine slots. The report includes wins, draws, win rates, and average game length. Save all per-game results with `output=data/tournament-report.json`. The tournament starts both snake servers with gameplay persistence disabled, adds the engine identity header required by the API, and shuts them down when finished. +## Move tracing and latency diagnosis +Every `/move` response includes `X-Move-Trace-ID`. Replay thinking contains a +small `move_trace` object: JSON parse, runtime lookup, executor queue wait, +strategy execution, handler/response encoding, bookkeeping queue wait, and +metrics publication timings. No board payloads are copied into traces. + +Structured application log lines start with `move_trace` and include the same +ID, game ID and turn, plus persistence and dashboard-publication duration once +background work finishes. These last two timings cannot be included in the +record being written itself. Timed-out workers may finish later; missing +`strategy_ms`/`worker_finished` means they had not finished at that snapshot. + +- `MOVE_TRACE_SAMPLE_EVERY=100`: approximately 1% of normal requests logged; + use `1` for all, `0` to disable normal sampling. +- `MOVE_TRACE_SLOW_MS=300`: always log a trace if any measured stage exceeds + this threshold. Timeouts and metrics publication failures are always logged. +- Metrics counters update locally before responding; shared metrics backend + publication now runs in ordered background bookkeeping, not on `/move`'s + response path. + +These are lightweight local timings, not exported OpenTelemetry spans. Handler +time starts inside the route and excludes middleware, socket delivery and +reverse-proxy/network delay. Compare with client-observed latency. Background +stage times can include event-loop scheduling delays; production improvements +must be verified after deployment under representative concurrency. + ## Compact gameplay database Gameplay storage keeps game results in `games` and snake identity (name, customizations) once per game in `game_snakes`. Replay data is stored compactly: diff --git a/dbschema/default.gel b/dbschema/default.gel index 4f139ee..d3384fa 100644 --- a/dbschema/default.gel +++ b/dbschema/default.gel @@ -3,7 +3,7 @@ module default { using (winner = "me"); function gameboard_url(id: uuid) -> str - using ("https://play.battlesnake.com/game/" ++ id); + using ("https://arena.battlesnake.com/games/" ++ id); type GameBoard { overloaded required id: uuid { diff --git a/justfile b/justfile index ebb05f2..a764c31 100644 --- a/justfile +++ b/justfile @@ -80,6 +80,16 @@ bench-snake-arena-postgres positions="100" output="": if [ -n "{{output}}" ]; then args+=(--json-output "{{output}}"); fi PYTHONPATH="{{justfile_directory()}}" uv run python "{{justfile_directory()}}/scripts/benchmark_snake_arena.py" "${args[@]}" +# Open the gameplay database with psql (uses GAMEPLAY_DB_PG_DSN from .env) +[positional-arguments] +db *args: + #!/usr/bin/env bash + set -euo pipefail + + : "${GAMEPLAY_DB_PG_DSN:?Set GAMEPLAY_DB_PG_DSN in .env or the environment}" + command -v psql >/dev/null || { echo "Install the PostgreSQL client (psql) first." >&2; exit 1; } + exec psql --dbname="$GAMEPLAY_DB_PG_DSN" "$@" + cleanup-gameplay-postgres older_than_days="30" execute="false" vacuum="false": #!/usr/bin/env bash set -euo pipefail @@ -101,11 +111,11 @@ migrate-gameplay-postgres since="" drop_legacy="false": if [ "{{drop_legacy}}" = "true" ]; then args+=(--drop-legacy); fi PYTHONPATH="{{justfile_directory()}}" uv run python "{{justfile_directory()}}/scripts/migrate_gameplay_to_compact.py" "${args[@]}" -bench-snake-tournament games="20" gametype="standard" map="standard" output="": +bench-snake-tournament games="20" gametype="standard" map="standard" output="" snake_a="ApexBattleSnake" snake_b="PrismBattleSnake_GPT_5_6_Sol": #!/usr/bin/env bash set -euo pipefail - args=(--games "{{games}}" --gametype "{{gametype}}" --map "{{map}}") + args=(--games "{{games}}" --gametype "{{gametype}}" --map "{{map}}" --snake-a "{{snake_a}}" --snake-b "{{snake_b}}") if [ -n "{{output}}" ]; then args+=(--json-output "{{output}}"); fi PYTHONPATH="{{justfile_directory()}}" python "{{justfile_directory()}}/scripts/run_seeded_snake_tournament.py" "${args[@]}" diff --git a/scripts/run_seeded_snake_tournament.py b/scripts/run_seeded_snake_tournament.py index 18daf88..9c475a5 100644 --- a/scripts/run_seeded_snake_tournament.py +++ b/scripts/run_seeded_snake_tournament.py @@ -152,6 +152,10 @@ def run_game( draw = bool(terminal.get("isDraw", winner is None)) return {"seed": seed, "winner": winner, "draw": draw, "turns": turns} +def display_name(snake: str) -> str: + """Short engine display name, e.g. PrismBattleSnake_GPT_5_6_Sol -> Prism.""" + return snake.split("_", 1)[0].removesuffix("BattleSnake") or snake + def main() -> None: parser = argparse.ArgumentParser() parser.add_argument("--games", type=int, default=20, help="Number of unique seeds") @@ -163,37 +167,39 @@ def main() -> None: parser.add_argument("--timeout", type=int, default=500) parser.add_argument("--base-port", type=int, default=9301) parser.add_argument("--cli", default=str(ROOT / ".testing/tools/battlesnake-cli/battlesnake")) + parser.add_argument("--snake-a", default="ApexBattleSnake", help="Registry name of the first snake") + parser.add_argument("--snake-b", default="PrismBattleSnake_GPT_5_6_Sol", help="Registry name of the second snake") parser.add_argument("--json-output") args = parser.parse_args() + if args.snake_a == args.snake_b: + raise SystemExit("--snake-a and --snake-b must differ") cli = Path(args.cli) if not cli.is_file(): raise SystemExit(f"Battlesnake CLI not found: {cli}. Run: just build-battlesnake-cli") - apex_port, prism_port = args.base_port, args.base_port + 1 - apex_proxy_port, prism_proxy_port = args.base_port + 2, args.base_port + 3 + snakes = (args.snake_a, args.snake_b) servers: list[subprocess.Popen] = [] proxies: list[tuple[ThreadingHTTPServer, Thread]] = [] results: list[dict] = [] started = time.perf_counter() try: - servers = [ - start_server("ApexBattleSnake", apex_port), - start_server("PrismBattleSnake_GPT_5_6_Sol", prism_port), - ] - proxies = [ - start_proxy(apex_proxy_port, apex_port), - start_proxy(prism_proxy_port, prism_port), - ] - urls = { - "Apex": f"http://127.0.0.1:{apex_proxy_port}", - "Prism": f"http://127.0.0.1:{prism_proxy_port}", - } + urls: dict[str, str] = {} + labels = [display_name(snake) for snake in snakes] + if len(set(labels)) != len(labels): + labels = list(snakes) + for index, (snake, label) in enumerate(zip(snakes, labels)): + server_port = args.base_port + index + proxy_port = args.base_port + len(snakes) + index + servers.append(start_server(snake, server_port)) + proxies.append(start_proxy(proxy_port, server_port)) + urls[label] = f"http://127.0.0.1:{proxy_port}" + names = tuple(urls) for offset in range(max(1, args.games)): seed = args.seed_start + offset # Swap engine slots for every seed. This controls for deterministic map # spawn positions and gives each strategy both initial placements. - for order in (("Apex", "Prism"), ("Prism", "Apex")): + for order in (names, names[::-1]): result = run_game( cli=cli, seed=seed, game_type=args.gametype, map_name=args.map, players=[(name, urls[name]) for name in order], @@ -219,6 +225,7 @@ def main() -> None: "unique_seeds": max(1, args.games), "gametype": args.gametype, "map": args.map, + "snakes": list(snakes), "wins": dict(wins), "win_rates": { key: value / len(results) for key, value in wins.items() diff --git a/server/GameBoard.py b/server/GameBoard.py index e8bcb2a..692a463 100644 --- a/server/GameBoard.py +++ b/server/GameBoard.py @@ -132,7 +132,7 @@ class GameBoard: def _get_game_url(self, local_game:bool): if local_game: return None - return f"https://play.battlesnake.com/game/{self.id}" + return f"https://arena.battlesnake.com/games/{self.id}" def _set_winner_snake_name(self, snakes:list[dict]): if self.my_snake["id"] in [ x["id"] for x in snakes]: diff --git a/server/blueprints/battlesnake.py b/server/blueprints/battlesnake.py index 5775ded..395ac6c 100644 --- a/server/blueprints/battlesnake.py +++ b/server/blueprints/battlesnake.py @@ -8,6 +8,8 @@ from quart_common.web.logger import await_log from snakes import DEFAULT_SNAKE_CONFIG from server.GameBoard import GameBoard from server.Files import read_file +from server.services.move_safety import fallback_move, run_budgeted_move +from server.services.move_trace import MoveTrace lazy from server.Server import Server @@ -58,36 +60,68 @@ def create_battlesnake_blueprint(server:'Server') -> Blueprint: @blueprint.post('/move') @require_user_agent(("BattlesnakeEngine", "BattlesnakeArena"), abort_code=404) async def on_move(): + move_started = time.perf_counter() server.metrics_collector.record_http_request('move') game_state = await request.get_json() - move_started = time.perf_counter() + trace = MoveTrace(game_state['game']['id'], game_state.get('turn')) + trace.set(parse_ms=round((time.perf_counter() - move_started) * 1000, 3), timed_out=False) game_id = game_state['game']['id'] timeout_ms = int(game_state.get('game', {}).get('timeout', 500)) budget_sec = max(0.05, (timeout_ms - 50) / 1000.0) - next_move = None + next_move = fallback_move(game_state) game_board = None try: async with asyncio.timeout(budget_sec): - game_board = cast(GameBoard, await server.game_runtime.get_game_board(game_state)) + with trace.stage('runtime'): + game_board = cast(GameBoard, await server.game_runtime.get_game_board(game_state)) loop = asyncio.get_running_loop() - next_move = await loop.run_in_executor(None, game_board.snake_neat_make_a_move) + submitted = time.perf_counter() + next_move = await loop.run_in_executor( + None, run_budgeted_move, game_board, move_started + budget_sec, next_move, trace, submitted, + ) except TimeoutError: - await await_log(server.logger.warning(f'MOVE TIMEOUT: turn={game_state.get("turn")}, game={game_id}, returning fallback {next_move!r}')) + trace.set(timed_out=True) - thinking = server.gameplay_tracking._extract_latest_snake_thinking(game_board) - server.game_lifecycle.submit( - game_id, lambda: server.game_lifecycle.turn(game_state, next_move, thinking), - ) - elapsed_ms = (time.perf_counter() - move_started) * 1000.0 - await server.metrics_collector.record_move(next_move, elapsed_ms) + # Never persist another turn's history when the worker has timed out. + thinking = None if trace.snapshot()['timed_out'] else server.gameplay_tracking._extract_latest_snake_thinking(game_board) + thinking = dict(thinking or {}) + trace.set(handler_ms=round((time.perf_counter() - move_started) * 1000, 3), + move=next_move, budget_ms=round(budget_sec * 1000, 3)) + thinking['move_trace'] = trace.snapshot() + server.metrics_collector.record_move_local(next_move, trace.snapshot()['handler_ms']) + + bookkeeping_submitted = time.perf_counter() + + async def finish_move(): + trace.set(bookkeeping_queue_ms=round((time.perf_counter() - bookkeeping_submitted) * 1000, 3)) + try: + try: + with trace.stage('metrics_publish'): + await server.metrics_collector.publish_move_metrics() + except Exception: + trace.set(metrics_publish_failed=True) + server.app.logger.exception('Move metrics publish failed; trace=%s', trace.id) + with trace.stage('persistence'): + thinking['move_trace'] = trace.snapshot() + await server.gameplay_tracking.record_gameplay_turn_snapshot(game_state, next_move, thinking) + with trace.stage('dashboard_publish'): + await server.dashboard_query.push_dashboard_game_replay_update(game_id) + finally: + trace.log(server.app.logger) + + server.game_lifecycle.submit(game_id, finish_move) if server.debug: await await_log(server.logger.debug(f'TURN: {game_state['turn']:3}, MOVE: {next_move:5}')) - return {'move': next_move} + with trace.stage('response_encode'): + response = jsonify(move=next_move) + trace.set(handler_ms=round((time.perf_counter() - move_started) * 1000, 3)) + response.headers['X-Move-Trace-ID'] = trace.id + return response @blueprint.post('/end') @require_user_agent(("BattlesnakeEngine", "BattlesnakeArena"), abort_code=404) diff --git a/server/blueprints/dashboard.py b/server/blueprints/dashboard.py index e8b9f49..5d4ed42 100644 --- a/server/blueprints/dashboard.py +++ b/server/blueprints/dashboard.py @@ -23,7 +23,7 @@ def create_dashboard_blueprint(server:'Server') -> Blueprint: initial_game_id=initial_game_id, initial_summary=initial_summary, initial_games=initial_games, - battlesnake_url=os.getenv('BATTLESNAKE_GAMEBOARD_URL', 'https://play.battlesnake.com/game') + battlesnake_url=os.getenv('BATTLESNAKE_GAMEBOARD_URL', 'https://arena.battlesnake.com/games') ) @blueprint.get('/dashboard/game/') diff --git a/server/database/compact/codec.py b/server/database/compact/codec.py index 81b86b1..bc7a441 100644 --- a/server/database/compact/codec.py +++ b/server/database/compact/codec.py @@ -27,17 +27,24 @@ def decode_move(code:int|None) -> str|None: return None return MOVES[int(code) - 1] +# The engine reports latency as a string; "" means no response was measured. +_EMPTY_LATENCY = -32768 + def encode_latency(latency:object) -> int|None: - if latency is None or latency == "": + if latency is None: return None + if latency == "": + return _EMPTY_LATENCY try: value = int(str(latency)) except ValueError: return None - return value if -32768 <= value <= 32767 else None + return value if _EMPTY_LATENCY < value <= 32767 else None def decode_latency(value:int|None) -> str|None: - return None if value is None else str(value) + if value is None: + return None + return "" if value == _EMPTY_LATENCY else str(value) def _point(point:object) -> tuple[int, int]|None: if not isinstance(point, dict): diff --git a/server/metrics/MetricsCollector.py b/server/metrics/MetricsCollector.py index d71b757..d91544c 100644 --- a/server/metrics/MetricsCollector.py +++ b/server/metrics/MetricsCollector.py @@ -67,7 +67,8 @@ class MetricsCollector: self._metrics['games_autocreated'] += 1 await self._auto_publish() - async def record_move(self, direction:str, elapsed_ms:float) -> None: + def record_move_local(self, direction:str, elapsed_ms:float) -> None: + """Update counters without waiting for a shared metrics backend.""" self._metrics['total_moves'] += 1 self._metrics['move_response_time_ms_total'] += elapsed_ms self._metrics['move_response_time_ms_max'] = max( @@ -80,6 +81,12 @@ class MetricsCollector: # else: # move_counts['unknown'] += 1 # self._metrics['last_move_unix'] = int(time.time()) + + async def record_move(self, direction:str, elapsed_ms:float) -> None: + self.record_move_local(direction, elapsed_ms) + await self._auto_publish() + + async def publish_move_metrics(self) -> None: await self._auto_publish() async def record_game_end(self, game_state:dict) -> None: diff --git a/server/services/move_safety.py b/server/services/move_safety.py new file mode 100644 index 0000000..b9050e8 --- /dev/null +++ b/server/services/move_safety.py @@ -0,0 +1,43 @@ +"""Fast request-local fallback and queue-aware worker budgeting.""" +from time import perf_counter + +def fallback_move(state): + board = state['board'] + mine = state['you'] + head = mine['head'] + occupied = {(p['x'], p['y']) for s in board['snakes'] for p in s['body']} + food = {(p['x'], p['y']) for p in board.get('food', [])} + hazards = {(p['x'], p['y']) for p in board.get('hazards', [])} + ranked = [] + for name, (dx, dy) in (('up', (0, 1)), ('down', (0, -1)), ('left', (-1, 0)), ('right', (1, 0))): + point = head['x'] + dx, head['y'] + dy + if not (0 <= point[0] < board['width'] and 0 <= point[1] < board['height']): + continue + if point in occupied: + continue + danger = any( + s['id'] != mine['id'] and len(s['body']) >= len(mine['body']) + and abs(s['head']['x'] - point[0]) + abs(s['head']['y'] - point[1]) == 1 + for s in board['snakes'] + ) + ranked.append((not danger, point not in hazards or point in food, name)) + return max(ranked)[-1] if ranked else 'up' + +def run_budgeted_move(board, deadline, fallback, trace=None, submitted=None): + """Deduct executor queue wait before the strategy starts its own clock.""" + started = perf_counter() + if trace is not None: + trace.set(executor_queue_ms=round((started - submitted) * 1000, 3), worker_started=True) + remaining = int((deadline - started) * 1000) + if remaining <= 40: + if trace is not None: + trace.set(worker_skipped=True) + return fallback + original_timeout = board.timeout + try: + board.timeout = min(original_timeout, remaining) + return board.snake_neat_make_a_move() + finally: + board.timeout = original_timeout + if trace is not None: + trace.set(strategy_ms=round((perf_counter() - started) * 1000, 3), worker_finished=True) diff --git a/server/services/move_trace.py b/server/services/move_trace.py new file mode 100644 index 0000000..9d9e532 --- /dev/null +++ b/server/services/move_trace.py @@ -0,0 +1,49 @@ +"""Small request-local timings; no board payloads or external tracing dependency.""" +from contextlib import contextmanager +import json +import os +from threading import Lock +from time import perf_counter +from uuid import uuid4 + +class MoveTrace: + def __init__(self, game_id, turn): + self.id = uuid4().hex + self.game_id = game_id + self.turn = turn + self.started = perf_counter() + self._lock = Lock() + self._fields = {} + + def set(self, **fields): + with self._lock: + self._fields.update(fields) + + @contextmanager + def stage(self, name): + started = perf_counter() + try: + yield + finally: + self.set(**{name + '_ms': round((perf_counter() - started) * 1000, 3)}) + + def snapshot(self): + with self._lock: + return {'trace_id': self.id, **self._fields} + + def log(self, logger): + fields = self.snapshot() + # Every timeout/slow request, plus deterministic sampling of normal moves. + try: + sample = max(0, int(os.getenv('MOVE_TRACE_SAMPLE_EVERY', '100'))) + slow_ms = max(0, float(os.getenv('MOVE_TRACE_SLOW_MS', '300'))) + except ValueError: + sample, slow_ms = 100, 300 + slow_stage = any(value >= slow_ms for key, value in fields.items() + if key.endswith('_ms') and isinstance(value, (int, float))) + if not (fields.get('timed_out') or fields.get('metrics_publish_failed') or slow_stage + or (sample and int(self.id[:8], 16) % sample == 0)): + return + logger.info('move_trace %s', json.dumps({ + 'game_id': self.game_id, 'turn': self.turn, **fields, + }, separators=(',', ':'))) diff --git a/snakes/__init__.py b/snakes/__init__.py index 4769544..78d6ccd 100644 --- a/snakes/__init__.py +++ b/snakes/__init__.py @@ -12,6 +12,9 @@ SNAKE_REGISTRATIONS = { "PrismBattleSnake_GPT_5_6_Sol": SnakeRegistration( "snakes.strategies.prism", "1.5.0" ), + "ZenithBattleSnake_ClaudeOpus5_5": SnakeRegistration( + "snakes.strategies.zenith", "1.1.0" + ), "DummSnake": SnakeRegistration("snakes.legacy.DummSnake", "1.0.0"), "LogicSnake": SnakeRegistration("snakes.legacy.LogicSnake", "1.1.0"), "MasterSnake": SnakeRegistration("snakes.legacy.MasterSnake", "1.2.0"), @@ -42,7 +45,6 @@ DEFAULT_SNAKE_CONFIG = { "tail": "default", } - def build_snake(selected_snake: str): registration = SNAKE_REGISTRATIONS.get(selected_snake) if registration is None: @@ -56,7 +58,6 @@ def get_snake_version(selected_snake: str) -> str | None: registration = SNAKE_REGISTRATIONS.get(selected_snake) return registration.version if registration is not None else None - class SnakeBuilder: @classmethod def build(self, selected_snake: str): diff --git a/snakes/engine/health_routes.py b/snakes/engine/health_routes.py new file mode 100644 index 0000000..17307b3 --- /dev/null +++ b/snakes/engine/health_routes.py @@ -0,0 +1,29 @@ +"""Health-cost routes to food or non-hazard refuge, with current bodies fixed.""" +import heapq + +def health_route_cost(start, food, hazards, stacks, damage, blocked, width, height, *, refuge=False): + """Cost until food resets health, or until leaving hazards for refuge. + + Food is consumed before elimination, so its final step needs no remaining + health. Other steps must leave health positive. Bodies remain obstacles, + including food-covered body cells; the caller removes the starting head. + """ + queue = [(0, start)] + best = {start: 0} + while queue: + cost, point = heapq.heappop(queue) + if cost != best[point]: + continue + if point in food or (refuge and point not in hazards): + return cost + x, y = point + for target in ((x, y + 1), (x, y - 1), (x - 1, y), (x + 1, y)): + nx, ny = target + if not (0 <= nx < width and 0 <= ny < height) or target in blocked: + continue + step = 0 if target in food else 1 + (damage * stacks.get(target, 1) if target in hazards else 0) + value = cost + step + if value < best.get(target, float('inf')): + best[target] = value + heapq.heappush(queue, (value, target)) + return None diff --git a/snakes/engine/survival_search.py b/snakes/engine/survival_search.py index 2417b87..2da80fe 100644 --- a/snakes/engine/survival_search.py +++ b/snakes/engine/survival_search.py @@ -235,7 +235,7 @@ class CompactSurvivalSearch: blocked = self._occupied(mine, enemies) & ~(1 << mine[0]) space = self.board.flood_count(mine[0], blocked) liberties = self.board.open_neighbor_count(mine[0], blocked) - if liberties == 0 or space < len(mine): + if liberties == 0 or (not self.is_constrictor and space < len(mine)): return self.DEATH enemy_pressure = 0.0 for enemy in enemies: diff --git a/snakes/strategies/__init__.py b/snakes/strategies/__init__.py index d65bc9b..18d4d2e 100644 --- a/snakes/strategies/__init__.py +++ b/snakes/strategies/__init__.py @@ -2,5 +2,10 @@ from snakes.strategies.apex import ApexBattleSnake from snakes.strategies.prism import PrismBattleSnake_GPT_5_6_Sol +from snakes.strategies.zenith import ZenithBattleSnake_ClaudeOpus5_5 -__all__ = ("ApexBattleSnake", "PrismBattleSnake_GPT_5_6_Sol") +__all__ = ( + "ApexBattleSnake", + "PrismBattleSnake_GPT_5_6_Sol", + "ZenithBattleSnake_ClaudeOpus5_5", +) diff --git a/snakes/strategies/zenith.py b/snakes/strategies/zenith.py new file mode 100644 index 0000000..f2e1a12 --- /dev/null +++ b/snakes/strategies/zenith.py @@ -0,0 +1,126 @@ +"""ZenithBattleSnake_ClaudeOpus5_5 v1.1.0 + +Built on PrismBattleSnake_GPT_5_6_Sol v1.5.0. Prism's bitboard engine, duel +search, and adversarial rollouts are inherited unchanged. + +Prism only runs the exact duel search on near-tied heuristic candidates +(score gap <= 8). A move outside that window is never checked against every +enemy reply, so a forced loss with a strong heuristic score can still be +played, and a forced win with a weaker score can be skipped. + +Z1: Root verdict pass — after Prism decides, every safe duel candidate is + resolved against all simultaneous enemy replies with the shared + transposition table (cheap: most subtrees are already cached). +Z2: Proven-loss veto — a candidate whose completed search proves a loss is + replaced by the best non-losing candidate. +Z3: Proven-win override — a candidate whose completed search proves a win is + played even if the heuristic preferred another move. +""" +from time import perf_counter + +from snakes.engine.duel_search import BitboardDuelSearch +from snakes.strategies.zenith_survival import ZenithSurvivalMixin +from snakes.strategies.prism import PrismBattleSnake_GPT_5_6_Sol + +# A completed search value beyond half of WIN/LOSS can only come from a terminal. +_PROVEN_WIN = BitboardDuelSearch.WIN / 2 +_PROVEN_LOSS = BitboardDuelSearch.LOSS / 2 +# Reserve kept for Apex's history bookkeeping after the verdict pass. +_VERDICT_RESERVE_MS = 25.0 + +class ZenithBattleSnake_ClaudeOpus5_5(ZenithSurvivalMixin, PrismBattleSnake_GPT_5_6_Sol): + VERSION = "1.1.0" + + def __init__(self) -> None: + super().__init__() + self.name = "ZenithBattleSnake" + self.version = self.VERSION + + def _get_timeout_buffer_ms(self): + # Leave room for executor scheduling, history, JSON and network delivery. + return max(180, super()._get_timeout_buffer_ms()) + + def _choose_duel_move( + self, safe_moves, my_body, my_len, my_health, other_snakes, food_set, + hazard_set, hazard_damage, hazard_count, previous_hazard_set, + enemy_attack_map, enemy_can_grow, total_occupancy, width, height, deadline, + ): + best_move, scores, depth = super()._choose_duel_move( + safe_moves=safe_moves, my_body=my_body, my_len=my_len, + my_health=my_health, other_snakes=other_snakes, food_set=food_set, + hazard_set=hazard_set, hazard_damage=hazard_damage, + hazard_count=hazard_count, previous_hazard_set=previous_hazard_set, + enemy_attack_map=enemy_attack_map, enemy_can_grow=enemy_can_grow, + total_occupancy=total_occupancy, width=width, height=height, + deadline=deadline, + ) + if len(safe_moves) < 2: + return best_move, scores, depth + + verdicts = self._duel_verdicts( + safe_moves=safe_moves, my_body=my_body, enemy=other_snakes[0], + my_health=my_health, food_set=food_set, hazard_set=hazard_set, + hazard_damage=hazard_damage, hazard_count=hazard_count, + previous_hazard_set=previous_hazard_set, width=width, height=height, + deadline=deadline, + ) + chosen = self._apply_verdicts(best_move, scores, verdicts) + if chosen != best_move: + self.add_to_history({ + "turn": self.game_board.get_turn(), "mode": "duel", + "zenith_verdict_changed_move": True, + "from": best_move, "to": chosen, + "verdicts": {m: round(v, 1) for m, (v, _) in verdicts.items()}, + }) + depth = max([depth, *(d for _, d in verdicts.values())]) + return chosen, scores, depth + + def _duel_verdicts( + self, safe_moves, my_body, enemy, my_health, food_set, hazard_set, + hazard_damage, hazard_count, previous_hazard_set, width, height, deadline, + ) -> dict[str, tuple[float, int]]: + """Return completed exact-search values per candidate (Z1).""" + verdicts: dict[str, tuple[float, int]] = {} + # Search every root at equal depth. A full iterative search for the first + # move could consume the deadline before the other roots were visited. + search_deadline = None if deadline is None else deadline - _VERDICT_RESERVE_MS / 1000 + if search_deadline is not None and perf_counter() >= search_deadline: + return verdicts + search = self._new_duel_search( + food_set, hazard_set, hazard_count, hazard_damage, width, height, search_deadline, + ) + search.deadline = search_deadline + for depth in range(1, self._planning_depth + 1): + layer = {} + for move, pos in safe_moves.items(): + value, completed = search.search_candidate( + my_body, enemy["body"], (pos["x"], pos["y"]), + my_health, enemy.get("health", 100), depth, previous_hazard_set, + ) + if completed != depth: + return verdicts + layer[move] = (value, completed) + verdicts = layer + return verdicts + + @staticmethod + def _apply_verdicts( + best_move: str, scores: dict[str, float], + verdicts: dict[str, tuple[float, int]], + ) -> str: + """Apply proven-win override (Z3) and proven-loss veto (Z2).""" + def rank(move: str) -> tuple[float, float]: + return verdicts[move][0], scores.get(move, float("-inf")) + + wins = [m for m, (v, _) in verdicts.items() if v >= _PROVEN_WIN] + if wins and best_move not in wins: + return max(wins, key=rank) + + best_verdict = verdicts.get(best_move) + if best_verdict is None or best_verdict[0] > _PROVEN_LOSS: + return best_move + alternatives = [m for m, (v, _) in verdicts.items() if v > _PROVEN_LOSS] + if not alternatives: + return best_move + # Prefer Prism's heuristic among surviving moves; fall back to search value. + return max(alternatives, key=lambda m: (scores.get(m, float("-inf")), verdicts[m][0])) diff --git a/snakes/strategies/zenith_survival.py b/snakes/strategies/zenith_survival.py new file mode 100644 index 0000000..8bf549e --- /dev/null +++ b/snakes/strategies/zenith_survival.py @@ -0,0 +1,97 @@ +"""Zenith-specific permanent-trail and health-aware scoring.""" +from snakes.engine.health_routes import health_route_cost +from snakes.engine.survival_search import CompactSurvivalSearch + +class ZenithSurvivalMixin: + def _choose_constrictor_move( + self, safe_moves, my_body, my_len, my_health, other_snakes, food_set, + hazard_set, hazard_damage, hazard_count, previous_hazard_set, + enemy_attack_map, enemy_can_grow, total_occupancy, width, height, deadline, + ): + # In constrictor bodies never vacate. Remaining free cells are a survival + # horizon, not storage for the existing body. Requiring free space >= body + # length incorrectly marks every late-game candidate dead. + bb = self._get_bb(width, height) + occupied = bb.set_to_bits({ + (p['x'], p['y']) for body in [my_body, *(s['body'] for s in other_snakes)] + for p in body + }) + scores = {} + for move, pos in safe_moves.items(): + target = bb.idx(pos['x'], pos['y']) + space = bb.flood_count(target, occupied) + liberties = bb.open_neighbor_count(target, occupied) + danger = enemy_attack_map.get((pos['x'], pos['y']), 0) >= my_len + # Preserve free capacity first. Enemy confinement must not outweigh our + # own ability to survive, and tail access has no meaning in this mode. + scores[move] = space * 10.0 + liberties * 8.0 - (10000 if danger else 0) + if liberties == 0: + scores[move] -= 5000 + + # Give each candidate the same shallow horizon before considering deeper + # layers. Never let the first candidate consume everyone else's budget. + search = CompactSurvivalSearch( + bb, set(), True, deadline, branch=3, enemy_branch=2, response_cap=8, + ) + ranked = scores + for depth in range(1, 5): + layer = {} + for move, pos in safe_moves.items(): + if self._remaining_ms(deadline) < 15: + break + before = search.deadline_exits + value = search.search_selected(my_body, other_snakes, (pos['x'], pos['y']), depth) + if search.deadline_exits != before: + break + layer[move] = value + if len(layer) != len(safe_moves): + break + # Rollout can veto immediate/near-term death, but cannot turn temporary + # enemy confinement into an overwhelming speculative attack reward. + ranked = {m: scores[m] + v * 0.15 for m, v in layer.items()} + best = max(ranked, key=ranked.get) + if depth == 4: + return best, ranked + return max(ranked, key=ranked.get), ranked + + def _score_move(self, *args, **kwargs): + score, info = super()._score_move(*args, **kwargs) + # Apex calls this hook with keywords. Constrictor uses its dedicated path. + if not kwargs or kwargs['is_constrictor']: + return score, info + point = (kwargs['pos']['x'], kwargs['pos']['y']) + food = kwargs['food_set'] + hazards = kwargs['hazard_set'] + damage = kwargs['hazard_damage'] + stacks = kwargs['hazard_count'] + health = 100 if point in food else kwargs['my_health'] - 1 - ( + damage * stacks.get(point, 1) if point in hazards else 0 + ) + if health <= 0: + score -= 20000 + info['is_survivable'] = False + return score, info + if not hazards: + return score, info + blocked = info['blocked'] - {point} + cost = health_route_cost( + point, food, hazards, stacks, damage, blocked, + kwargs['width'], kwargs['height'], refuge=True, + ) + # Existing hazards deal damage on entry even when newly seen. Prefer + # leaving lethal hazard corridors before low-health urgency kicks in. + if cost is None or cost >= health: + score -= 12000 + info['is_survivable'] = False + else: + score -= cost * 8.0 + if health < 55: + food_cost = health_route_cost( + point, food, hazards, stacks, damage, blocked, + kwargs['width'], kwargs['height'], + ) + if food_cost is None or food_cost >= health: + score -= 2500 + else: + score += (55 - health) * 12.0 / (food_cost + 1) + return score, info diff --git a/templates/files/js/Snake.js b/templates/files/js/Snake.js index 48650ad..4584eea 100644 --- a/templates/files/js/Snake.js +++ b/templates/files/js/Snake.js @@ -89,8 +89,8 @@ class SnakeUtils { } static buildCustomizationIconUrl(kind, value) { - const raw = String(value || "").trim().toLowerCase(); - if (!raw) return null; + // Battlesnake treats an omitted/empty customization as the default asset. + const raw = String(value || "").trim().toLowerCase() || "default"; if (!/^[a-z0-9-]+$/.test(raw)) return null; return `/dashboard/customizations/${kind}/${raw}.svg`; } diff --git a/tests/js/snake-customizations.test.mjs b/tests/js/snake-customizations.test.mjs new file mode 100644 index 0000000..ab1030a --- /dev/null +++ b/tests/js/snake-customizations.test.mjs @@ -0,0 +1,21 @@ +import assert from 'node:assert/strict'; +import { readFileSync } from 'node:fs'; +import vm from 'node:vm'; +import test from 'node:test'; + +const source = readFileSync(new URL('../../templates/files/js/Snake.js', import.meta.url), 'utf8'); +const SnakeUtils = vm.runInNewContext(`${source}\nSnakeUtils`); + +test('empty or missing head/tail uses the default SVG', () => { + for (const kind of ['heads', 'tails']) { + for (const value of [undefined, null, '', ' ']) { + assert.equal(SnakeUtils.buildCustomizationIconUrl(kind, value), `/dashboard/customizations/${kind}/default.svg`); + } + } +}); + +test('explicit customizations and invalid-name validation are preserved', () => { + assert.equal(SnakeUtils.buildCustomizationIconUrl('tails', 'ghost'), '/dashboard/customizations/tails/ghost.svg'); + assert.equal(SnakeUtils.buildCustomizationIconUrl('heads', 'crystal-power'), '/dashboard/customizations/heads/crystal-power.svg'); + assert.equal(SnakeUtils.buildCustomizationIconUrl('tails', '../ghost'), null); +}); diff --git a/tests/snakes/test_ZenithBattleSnake_ClaudeOpus5_5.py b/tests/snakes/test_ZenithBattleSnake_ClaudeOpus5_5.py new file mode 100644 index 0000000..c35b1d2 --- /dev/null +++ b/tests/snakes/test_ZenithBattleSnake_ClaudeOpus5_5.py @@ -0,0 +1,84 @@ +import unittest +from time import perf_counter + +from snakes import SnakeBuilder, get_snake_version +from snakes.strategies.prism import PrismBattleSnake_GPT_5_6_Sol +from snakes.strategies.zenith import ZenithBattleSnake_ClaudeOpus5_5 + +LOSS = -100_000.0 +WIN = 100_000.0 + +class TestZenithRegistration(unittest.TestCase): + + def test_api_name_and_version_are_exposed(self): + snake = ZenithBattleSnake_ClaudeOpus5_5() + + self.assertEqual(snake.name, "ZenithBattleSnake") + self.assertEqual(snake.version, "1.1.0") + self.assertEqual(get_snake_version("ZenithBattleSnake_ClaudeOpus5_5"), "1.1.0") + self.assertIsInstance(snake, PrismBattleSnake_GPT_5_6_Sol) + self.assertIsInstance( + SnakeBuilder.build("ZenithBattleSnake_ClaudeOpus5_5"), + ZenithBattleSnake_ClaudeOpus5_5, + ) + +class TestZenithVerdicts(unittest.TestCase): + + def test_proven_loss_is_vetoed_for_best_surviving_heuristic(self): + scores = {"up": 300.0, "left": 120.0, "right": 90.0} + verdicts = {"up": (LOSS, 3), "left": (-40.0, 3), "right": (25.0, 3)} + + self.assertEqual(ZenithBattleSnake_ClaudeOpus5_5._apply_verdicts("up", scores, verdicts), "left") + + def test_proven_win_overrides_heuristic(self): + scores = {"up": 300.0, "left": 120.0} + verdicts = {"up": (15.0, 2), "left": (WIN, 2)} + + self.assertEqual(ZenithBattleSnake_ClaudeOpus5_5._apply_verdicts("up", scores, verdicts), "left") + + def test_keeps_choice_when_every_move_loses(self): + scores = {"up": 300.0, "left": 120.0} + verdicts = {"up": (LOSS, 2), "left": (LOSS - 1, 2)} + + self.assertEqual(ZenithBattleSnake_ClaudeOpus5_5._apply_verdicts("up", scores, verdicts), "up") + + def test_keeps_choice_without_verdict(self): + scores = {"up": 300.0, "left": 120.0} + self.assertEqual(ZenithBattleSnake_ClaudeOpus5_5._apply_verdicts("up", scores, {}), "up") + + def test_verdict_search_resolves_every_candidate(self): + snake = ZenithBattleSnake_ClaudeOpus5_5() + # Longer enemy can also reach (2, 5): stepping there loses the head-to-head. + my_body = [{"x": 1, "y": 5}, {"x": 0, "y": 5}] + enemy = {"body": [{"x": 3, "y": 5}, {"x": 4, "y": 5}, {"x": 5, "y": 5}], "health": 100} + safe_moves = {"up": {"x": 1, "y": 6}, "right": {"x": 2, "y": 5}} + + verdicts = snake._duel_verdicts( + safe_moves=safe_moves, my_body=my_body, enemy=enemy, my_health=100, + food_set=set(), hazard_set=set(), hazard_damage=15, hazard_count={}, + previous_hazard_set=set(), width=11, height=11, + deadline=perf_counter() + 1.0, + ) + + self.assertEqual(set(verdicts), {"up", "right"}) + self.assertLessEqual(verdicts["right"][0], LOSS / 2) + self.assertGreater(verdicts["up"][0], LOSS / 2) + self.assertEqual( + snake._apply_verdicts("right", {"right": 50.0, "up": 10.0}, verdicts), "up", + ) + + def test_verdict_search_stops_when_out_of_time(self): + snake = ZenithBattleSnake_ClaudeOpus5_5() + + verdicts = snake._duel_verdicts( + safe_moves={"up": {"x": 0, "y": 2}}, my_body=[{"x": 0, "y": 1}], + enemy={"body": [{"x": 4, "y": 4}]}, my_health=100, + food_set=set(), hazard_set=set(), hazard_damage=15, hazard_count={}, + previous_hazard_set=set(), width=5, height=5, + deadline=perf_counter() - 0.001, + ) + + self.assertEqual(verdicts, {}) + +if __name__ == "__main__": + unittest.main() diff --git a/tests/snakes/test_ZenithSurvival.py b/tests/snakes/test_ZenithSurvival.py new file mode 100644 index 0000000..5688ffd --- /dev/null +++ b/tests/snakes/test_ZenithSurvival.py @@ -0,0 +1,44 @@ +import unittest +from time import perf_counter + +from snakes.engine.health_routes import health_route_cost +from snakes.engine.bitboard import BitBoard +from snakes.engine.survival_search import CompactSurvivalSearch +from server.services.move_safety import fallback_move, run_budgeted_move +from unittest.mock import Mock + +class TestSurvivalCorrections(unittest.TestCase): + def test_food_resets_health_before_elimination(self): + self.assertEqual(health_route_cost((0, 0), {(1, 0)}, {(1, 0)}, {}, 14, set(), 2, 1), 0) + + def test_food_does_not_make_body_passable(self): + self.assertIsNone(health_route_cost((0, 0), {(1, 0)}, set(), {}, 14, {(1, 0)}, 2, 1)) + + def test_hazard_escape_charges_every_step(self): + self.assertEqual(health_route_cost((0, 0), set(), {(0, 0), (1, 0)}, {}, 14, set(), 3, 1, refuge=True), 16) + + def test_long_constrictor_can_survive_in_small_free_region(self): + bb = BitBoard(5, 2) + body = (0, 5, 6, 7, 8, 9) + search = CompactSurvivalSearch(bb, set(), True, None, 2) + self.assertGreater(search._evaluate(body, ()), search.DEATH) + standard = CompactSurvivalSearch(bb, set(), False, None, 2) + self.assertEqual(standard._evaluate(body, ()), standard.DEATH) + + def test_expired_queued_job_never_starts_strategy(self): + board = Mock(timeout=500) + self.assertEqual(run_budgeted_move(board, perf_counter()-1, 'left'), 'left') + board.snake_neat_make_a_move.assert_not_called() + + def test_worker_deducts_queue_time_and_restores_timeout(self): + board = Mock(timeout=500) + observed = [] + board.snake_neat_make_a_move.side_effect = lambda: observed.append(board.timeout) or 'right' + self.assertEqual(run_budgeted_move(board, perf_counter()+0.2, 'left'), 'right') + self.assertLessEqual(observed[0], 200) + self.assertEqual(board.timeout, 500) + + def test_fallback_avoids_body_and_wall(self): + mine = {'id':'me','head':{'x':0,'y':0},'body':[{'x':0,'y':0},{'x':1,'y':0}]} + state = {'you':mine,'board':{'width':3,'height':3,'snakes':[mine]}} + self.assertEqual(fallback_move(state), 'up') diff --git a/tests/test_BattlesnakeLifecycle.py b/tests/test_BattlesnakeLifecycle.py index 4d76299..1df46b0 100644 --- a/tests/test_BattlesnakeLifecycle.py +++ b/tests/test_BattlesnakeLifecycle.py @@ -135,6 +135,58 @@ class TestBattlesnakeLifecycle(unittest.IsolatedAsyncioTestCase): self.assertNotEqual(replay['game']['status'], 'running') print(f'Real SQLite HTTP timings: {timings}') + async def test_timed_out_move_returns_valid_fallback(self): + server = self.server + server.logger = Mock() + server.logger.warning.return_value = None + server.game_lifecycle.turn = AsyncMock() + server.metrics_collector.record_move = AsyncMock() + state = deepcopy(self.state) + state['game']['timeout'] = 100 + + async def stalled_board(*args): + await asyncio.sleep(0.2) + + server.game_runtime.get_game_board = stalled_board + response = await server.app.test_client().post('/move', json=state, headers=self.headers) + self.assertEqual(response.status_code, 200) + self.assertIn((await response.get_json())['move'], ('up', 'down', 'left', 'right')) + await server.game_lifecycle.drain() + + async def test_slow_metrics_publish_is_off_response_path_and_traced(self): + server = self.server + gate = asyncio.Event() + snapshots = [] + + async def slow_publish(): + await gate.wait() + await asyncio.sleep(0.1) + + async def capture(state, move, thinking): + snapshots.append(thinking) + + server.metrics_collector.publish_move_metrics = slow_publish + server.gameplay_tracking.record_gameplay_turn_snapshot = capture + server.dashboard_query.push_dashboard_game_replay_update = AsyncMock() + client = server.app.test_client() + started = perf_counter() + response = await asyncio.wait_for(client.post('/move', json=self.state, headers=self.headers), 0.5) + elapsed = (perf_counter() - started) * 1000 + self.assertEqual(response.status_code, 200) + self.assertLess(elapsed, 500) + trace_id = response.headers['X-Move-Trace-ID'] + self.assertEqual(len(trace_id), 32) + self.assertEqual(snapshots, []) + gate.set() + await server.game_lifecycle.drain() + trace = snapshots[0]['move_trace'] + self.assertEqual(trace['trace_id'], trace_id) + self.assertGreaterEqual(trace['metrics_publish_ms'], 90) + self.assertIn('executor_queue_ms', trace) + self.assertIn('strategy_ms', trace) + self.assertIn('response_encode_ms', trace) + self.assertFalse(trace['timed_out']) + async def test_invalid_agent_does_not_schedule_work(self): response = await self.server.app.test_client().post('/start', json=self.state) self.assertEqual(response.status_code, 404) diff --git a/tests/test_CompactStorage.py b/tests/test_CompactStorage.py index 0df7368..884df54 100644 --- a/tests/test_CompactStorage.py +++ b/tests/test_CompactStorage.py @@ -42,7 +42,8 @@ class TestCodec(unittest.TestCase): for move in ("up", "down", "left", "right", None): self.assertEqual(decode_move(encode_move(move)), move) self.assertEqual(decode_latency(encode_latency("77")), "77") - self.assertIsNone(encode_latency("")) + self.assertEqual(decode_latency(encode_latency("")), "") + self.assertIsNone(decode_latency(encode_latency(None))) self.assertIsNone(encode_latency("timeout")) def test_epoch_microseconds_roundtrip(self): diff --git a/tests/test_DashboardStaticAssets.py b/tests/test_DashboardStaticAssets.py index 8dd134b..7805925 100644 --- a/tests/test_DashboardStaticAssets.py +++ b/tests/test_DashboardStaticAssets.py @@ -16,6 +16,22 @@ class TestDashboardStaticAssets(unittest.IsolatedAsyncioTestCase): gameplay_db_enabled=False, ) + async def test_dashboard_uses_arena_game_url(self): + from unittest.mock import patch + with patch.dict(os.environ, {}, clear=True): + response = await self.server.app.test_client().get('/dashboard') + self.assertEqual(response.status_code, 200) + html = await response.get_data(as_text=True) + self.assertIn('https://arena.battlesnake.com/games', html) + self.assertNotIn('https://play.battlesnake.com/game', html) + + def test_gameboard_uses_arena_game_url(self): + from types import SimpleNamespace + from server.GameBoard import GameBoard + game = SimpleNamespace(id='example-game') + self.assertEqual(GameBoard._get_game_url(game, False), 'https://arena.battlesnake.com/games/example-game') + self.assertIsNone(GameBoard._get_game_url(game, True)) + def _static_url(self): return self.server.app.jinja_env.globals['static_url'] diff --git a/tests/test_LegacyMigration.py b/tests/test_LegacyMigration.py index 2d755b6..9f77a6f 100644 --- a/tests/test_LegacyMigration.py +++ b/tests/test_LegacyMigration.py @@ -124,7 +124,7 @@ class TestLegacyMigration(unittest.TestCase): self.assertEqual((me["snake_id"], me["snake_name"], me["is_you"]), ("me", "Me", True)) self.assertEqual((me["inferred_move"], me["latency"], me["health"], me["length"]), ("left", "12", 98, 3)) enemy = turns[2]["snakes"][1] - self.assertEqual((enemy["inferred_move"], enemy["latency"]), ("down", None)) + self.assertEqual((enemy["inferred_move"], enemy["latency"]), ("down", "")) with closing(sqlite3.connect(destination)) as connection: self.assertEqual(connection.execute("SELECT turn_count FROM game_replays").fetchone()[0], 3) diff --git a/tests/test_MoveTrace.py b/tests/test_MoveTrace.py new file mode 100644 index 0000000..20ce0f6 --- /dev/null +++ b/tests/test_MoveTrace.py @@ -0,0 +1,29 @@ +import unittest +from unittest.mock import Mock, patch +from server.services.move_trace import MoveTrace + +class TestMoveTrace(unittest.TestCase): + def test_snapshot_is_independent_and_stage_survives_exception(self): + trace = MoveTrace('test-game', 1) + with self.assertRaises(ValueError): + with trace.stage('test'): + raise ValueError() + snapshot = trace.snapshot() + snapshot['test_ms'] = -1 + self.assertGreaterEqual(trace.snapshot()['test_ms'], 0) + + def test_timeout_logged_even_when_sampling_disabled(self): + trace = MoveTrace('test-game', 2) + trace.set(timed_out=True) + logger = Mock() + with patch.dict('os.environ', {'MOVE_TRACE_SAMPLE_EVERY':'0'}): + trace.log(logger) + logger.info.assert_called_once() + self.assertIn(trace.id, logger.info.call_args.args[1]) + + def test_fast_requests_not_logged_when_disabled(self): + trace = MoveTrace('test-game', 2) + logger = Mock() + with patch.dict('os.environ', {'MOVE_TRACE_SAMPLE_EVERY':'0'}): + trace.log(logger) + logger.info.assert_not_called()