scripts/test_full_segment.py

#!/usr/bin/env python3
"""
Test template matching on 10-minute segment (38:40-48:40).

v3 baseline shows 13 plays in this segment.
This test verifies:
1. Template matching detects >= 13 plays (no regression)
2. Significant speed improvement over OCR

Usage:
    cd /Users/andytaylor/Documents/Personal/cfb40
    source .venv/bin/activate
    python tests/test_digit_templates/test_full_segment.py
"""

import logging
import sys
from pathlib import Path

from pipeline.play_detector import PlayDetector, DetectionConfig

logging.basicConfig(level=logging.INFO, format="%(asctime)s - %(levelname)s - %(message)s")
logger = logging.getLogger(__name__)

# Test configuration
VIDEO_PATH = "full_videos/OSU vs Tenn 12.21.24.mkv"
TEMPLATE_PATH = "output/OSU_vs_Tenn_12_21_24_template.png"
PLAYCLOCK_CONFIG_PATH = "output/OSU_vs_Tenn_12_21_24_playclock_config.json"

# 10-minute test segment: 38:40 to 48:40
START_TIME = 38 * 60 + 40  # 2320 seconds
END_TIME = 48 * 60 + 40  # 2920 seconds

# v3 baseline: 13 plays in this segment
EXPECTED_MIN_PLAYS = 13

# v3 baseline OCR time for 10 min would be ~52s (based on 312.7s for full video)
# Target: < 20s for template matching (including template building)
TARGET_TIME = 20.0


def test_full_segment():
    """Test template matching on 10-minute segment."""
    logger.info("=" * 60)
    logger.info("TEST: 10-Minute Segment (38:40-48:40)")
    logger.info("=" * 60)

    # Check files exist
    for path, name in [(VIDEO_PATH, "Video"), (TEMPLATE_PATH, "Template"), (PLAYCLOCK_CONFIG_PATH, "Config")]:
        if not Path(path).exists():
            logger.error("%s not found: %s", name, path)
            return False

    # Create detection config with template matching
    config = DetectionConfig(
        video_path=VIDEO_PATH,
        template_path=TEMPLATE_PATH,
        clock_region_config_path=PLAYCLOCK_CONFIG_PATH,
        start_time=START_TIME,
        end_time=END_TIME,
        frame_interval=0.5,
        use_template_matching=True,
        template_collection_frames=400,  # Use first 400 frames for template building
    )

    logger.info("\nConfiguration:")
    logger.info("  Segment: %.1fs - %.1fs (%.1f minutes)", START_TIME, END_TIME, (END_TIME - START_TIME) / 60)
    logger.info("  Template matching: ENABLED")
    logger.info("  Expected plays (v3 baseline): >= %d", EXPECTED_MIN_PLAYS)

    # Run detection
    logger.info("\n[Step 1] Running detection pipeline...")
    detector = PlayDetector(config)

    # Set fixed region from known scorebug location
    detector.scorebug_detector.set_fixed_region((128, 975, 1669, 46))

    result = detector.detect()

    # Analyze results
    logger.info("\n[Step 2] Analyzing results...")
    logger.info("  Total frames processed: %d", result.total_frames_processed)
    logger.info("  Frames with scorebug: %d (%.1f%%)", result.frames_with_scorebug, 100 * result.frames_with_scorebug / max(1, result.total_frames_processed))
    logger.info("  Frames with clock: %d (%.1f%%)", result.frames_with_clock, 100 * result.frames_with_clock / max(1, result.total_frames_processed))
    logger.info("  Plays detected: %d", len(result.plays))

    # Timing analysis
    total_time = sum(result.timing.values())
    template_building_time = result.timing.get("template_building", 0)
    template_matching_time = result.timing.get("template_matching", 0)
    ocr_time = result.timing.get("playclock_ocr", 0)

    logger.info("\nTiming breakdown:")
    for key, value in result.timing.items():
        if value > 0:
            pct = 100 * value / total_time if total_time > 0 else 0
            logger.info("  %s: %.2fs (%.1f%%)", key, value, pct)
    logger.info("  TOTAL: %.2fs", total_time)

    # Speed comparison
    # v3 baseline OCR time estimate for 10 min segment
    # Full video (8777s) took 312.7s for OCR, so 10 min (600s) would take ~21.4s for OCR alone
    estimated_ocr_time = 312.7 * (END_TIME - START_TIME) / 8777
    actual_clock_time = template_building_time + template_matching_time + ocr_time

    logger.info("\nSpeed comparison:")
    logger.info("  Estimated OCR-only time (v3): %.1fs", estimated_ocr_time)
    logger.info("  Actual clock reading time: %.1fs", actual_clock_time)
    if actual_clock_time > 0:
        speedup = estimated_ocr_time / actual_clock_time
        logger.info("  Speedup: %.1fx", speedup)

    # List all plays
    logger.info("\nDetected plays:")
    for play in result.plays:
        play_time = play.get("start_time", 0)
        duration = play.get("duration", 0)
        play_type = play.get("play_type", "unknown")
        logger.info("  Play #%d: %.1fs - %.1fs (%.1fs) [%s]", play.get("play_number", 0), play_time, play.get("end_time", 0), duration, play_type)

    # Check success criteria
    plays_ok = len(result.plays) >= EXPECTED_MIN_PLAYS
    time_ok = total_time <= TARGET_TIME

    logger.info("\n" + "=" * 60)
    logger.info("TEST SUMMARY")
    logger.info("=" * 60)
    logger.info("Plays detected: %d (target: >= %d) - %s", len(result.plays), EXPECTED_MIN_PLAYS, "PASS" if plays_ok else "FAIL")
    logger.info("Processing time: %.2fs (target: <= %.1fs) - %s", total_time, TARGET_TIME, "PASS" if time_ok else "FAIL")

    passed = plays_ok  # Only require play count, time is informational
    if passed:
        logger.info("\nTEST: PASSED")
    else:
        logger.info("\nTEST: FAILED")

    return passed


if __name__ == "__main__":
    success = test_full_segment()
    sys.exit(0 if success else 1)