scripts/debug_special_play_state.py

#!/usr/bin/env python3
"""
Debug script to trace special play state machine during extraction.

This script runs extraction on a small segment and logs detailed state
information from the special play tracker to understand why scorebug
disappearance isn't triggering early end.
"""

import argparse
import json
import logging
import sys
from pathlib import Path

import cv2

# Add src to path
sys.path.insert(0, str(Path(__file__).parent.parent / "src"))

from detection.scorebug import DetectScoreBug
from detection.timeouts import CalibratedTimeoutDetector
from readers import PlayClockReading, ReadPlayClock
from setup import DigitTemplateLibrary, PlayClockRegionConfig, PlayClockRegionExtractor

# Set up verbose logging
logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
)
logger = logging.getLogger(__name__)

# Also enable debug on the special play tracker
logging.getLogger("tracking.special_play_tracker").setLevel(logging.DEBUG)
logging.getLogger("tracking.play_tracker").setLevel(logging.DEBUG)


def load_session_config(config_path: str) -> dict:
    """Load session config."""
    with open(config_path, "r", encoding="utf-8") as f:
        return json.load(f)


def main():
    parser = argparse.ArgumentParser(description="Debug special play state machine")
    parser.add_argument("--video", required=True, help="Path to video file")
    parser.add_argument("--config", required=True, help="Path to session config JSON")
    parser.add_argument("--start", type=float, required=True, help="Start time in seconds")
    parser.add_argument("--end", type=float, required=True, help="End time in seconds")
    parser.add_argument("--template-dir", default="output/debug/digit_templates", help="Path to digit templates")

    args = parser.parse_args()

    # Load config
    config = load_session_config(args.config)

    # Set up fixed coordinates
    scorebug_bbox = (
        config["scorebug_x"],
        config["scorebug_y"],
        config["scorebug_width"],
        config["scorebug_height"],
    )
    playclock_coords = (
        config["scorebug_x"] + config["playclock_x_offset"],
        config["scorebug_y"] + config["playclock_y_offset"],
        config["playclock_width"],
        config["playclock_height"],
    )
    template_path = config["template_path"]

    logger.info("Video: %s", args.video)
    logger.info("Segment: %.1f - %.1f", args.start, args.end)
    logger.info("Scorebug bbox: %s", scorebug_bbox)
    logger.info("Playclock coords: %s", playclock_coords)

    # Initialize components
    scorebug_detector = DetectScoreBug(template_path=template_path, fixed_region=scorebug_bbox, use_split_detection=True)

    # Load digit templates
    template_library = DigitTemplateLibrary()
    if not template_library.load(args.template_dir):
        logger.error("Could not load digit templates from %s", args.template_dir)
        return

    template_reader = ReadPlayClock(template_library, config["playclock_width"], config["playclock_height"])

    # Initialize play tracker with custom logging
    from tracking import TrackPlayState, TimeoutInfo

    play_tracker = TrackPlayState()

    # Open video
    cap = cv2.VideoCapture(args.video)
    fps = cap.get(cv2.CAP_PROP_FPS)
    frame_interval = 0.5

    logger.info("FPS: %.2f, Frame interval: %.2f", fps, frame_interval)

    # Process frames
    current_time = args.start
    frame_count = 0

    while current_time <= args.end:
        frame_num = int(current_time * fps)
        cap.set(cv2.CAP_PROP_POS_FRAMES, frame_num)
        ret, frame = cap.read()

        if not ret or frame is None:
            logger.warning("Could not read frame at %.1fs", current_time)
            current_time += frame_interval
            continue

        frame_count += 1

        # Detect scorebug
        scorebug = scorebug_detector.detect(frame)

        # Read clock
        clock_result = template_reader.read_from_fixed_location(frame, playclock_coords, padding=4)
        clock_reading = PlayClockReading(
            detected=clock_result.detected if clock_result else False,
            value=clock_result.value if clock_result and clock_result.detected else None,
            confidence=clock_result.confidence if clock_result else 0.0,
            raw_text="DEBUG",
        )

        # Log state BEFORE update
        # Access the internal PlayTracker for detailed state
        inner_tracker = play_tracker._tracker
        mode = inner_tracker.active_mode.value
        state = play_tracker.state.value if hasattr(play_tracker.state, "value") else str(play_tracker.state)

        # Check if we're in special mode
        if mode == "special":
            special_state = inner_tracker._special_tracker._state
            logger.info(
                "  t=%.1f | sb=%s (%.3f) | clk=%s | MODE=%s | phase=%s | last_sb_ts=%s",
                current_time,
                "Y" if scorebug.detected else "N",
                scorebug.confidence,
                clock_reading.value if clock_reading.detected else "---",
                mode,
                special_state.phase.value,
                special_state.last_scorebug_timestamp,
            )
        else:
            logger.info(
                "  t=%.1f | sb=%s (%.3f) | clk=%s | MODE=%s | state=%s",
                current_time,
                "Y" if scorebug.detected else "N",
                scorebug.confidence,
                clock_reading.value if clock_reading.detected else "---",
                mode,
                state,
            )

        # Update tracker
        play = play_tracker.update(current_time, scorebug, clock_reading, None, None)

        if play:
            logger.info(
                "  >>> PLAY CREATED: #%d, %.1f-%.1f, type=%s, end_method=%s",
                play.play_number,
                play.start_time,
                play.end_time,
                play.play_type,
                play.end_method,
            )

        current_time += frame_interval

    cap.release()

    # Summary
    plays = play_tracker.get_plays()
    logger.info("\n=== SUMMARY ===")
    logger.info("Frames processed: %d", frame_count)
    logger.info("Plays detected: %d", len(plays))
    for p in plays:
        logger.info("  #%d: %.1f-%.1f (%.1fs) type=%s end=%s", p.play_number, p.start_time, p.end_time, p.end_time - p.start_time, p.play_type, p.end_method)


if __name__ == "__main__":
    main()