#!/usr/bin/env python3 """ NFOGuard - Automated NFO file management for Radarr and Sonarr Modular architecture with webhook processing and intelligent date handling """ import os import json import asyncio import glob import re import logging import logging.handlers import xml.etree.ElementTree as ET from pathlib import Path from datetime import datetime, timezone, timedelta from zoneinfo import ZoneInfo from fastapi import FastAPI, HTTPException, BackgroundTasks, Request from pydantic import BaseModel from typing import Optional, Dict, Any, List, Set, Tuple import threading from concurrent.futures import ThreadPoolExecutor import uvicorn import signal import sys # Import our new modular components from core.database import NFOGuardDatabase from core.nfo_manager import NFOManager from core.path_mapper import PathMapper from clients.radarr_client import RadarrClient from clients.sonarr_client import SonarrClient from clients.external_clients import ExternalClientManager # --------------------------- # Configuration & Logging # --------------------------- class TimezoneAwareFormatter(logging.Formatter): """Formatter that respects the container timezone""" def __init__(self, *args, **kwargs): super().__init__(*args, **kwargs) self.timezone = self._get_local_timezone() def _get_local_timezone(self): """Get the local timezone, respecting TZ environment variable""" tz_name = os.environ.get('TZ', 'UTC') try: # Try zoneinfo first (Python 3.9+) return ZoneInfo(tz_name) except ImportError: # Fallback for older Python versions try: import pytz return pytz.timezone(tz_name) except: # Final fallback to UTC return timezone.utc except: # If zone name is invalid, fallback to UTC return timezone.utc def formatTime(self, record, datefmt=None): dt = datetime.fromtimestamp(record.created, tz=self.timezone) if datefmt: return dt.strftime(datefmt) return dt.isoformat(timespec='seconds') def _setup_file_logging(): """Setup file logging for NFOGuard""" log_dir = Path(os.environ.get("LOG_DIR", "/app/data/logs")) log_dir.mkdir(parents=True, exist_ok=True) logger = logging.getLogger("NFOGuard") logger.setLevel(logging.DEBUG) file_handler = logging.handlers.RotatingFileHandler( log_dir / "nfoguard.log", maxBytes=50*1024*1024, backupCount=3 ) formatter = TimezoneAwareFormatter( '[%(asctime)s] %(levelname)s: %(message)s' ) file_handler.setFormatter(formatter) logger.addHandler(file_handler) return logger def _mask_sensitive_data(msg: str) -> str: """Mask API keys and other sensitive data in log messages""" import re # List of patterns to mask sensitive_patterns = [ (r'api_key=([a-zA-Z0-9_\-]+)', r'api_key=***masked***'), (r'password=([^\s&]+)', r'password=***masked***'), (r'token=([a-zA-Z0-9_\-]+)', r'token=***masked***'), (r'key=([a-zA-Z0-9_\-]{8,})', r'key=***masked***'), # Keys longer than 8 chars (r'([a-zA-Z0-9]{32,})', lambda m: m.group(1)[:8] + '***masked***' if len(m.group(1)) > 16 else m.group(1)) # Long strings likely to be keys ] masked_msg = msg for pattern, replacement in sensitive_patterns: if isinstance(replacement, str): masked_msg = re.sub(pattern, replacement, masked_msg, flags=re.IGNORECASE) else: masked_msg = re.sub(pattern, replacement, masked_msg, flags=re.IGNORECASE) return masked_msg def _get_local_timezone(): """Get the local timezone, respecting TZ environment variable""" tz_name = os.environ.get('TZ', 'UTC') try: # Try zoneinfo first (Python 3.9+) return ZoneInfo(tz_name) except ImportError: # Fallback for older Python versions try: import pytz return pytz.timezone(tz_name) except: # Final fallback to UTC return timezone.utc except: # If zone name is invalid, fallback to UTC return timezone.utc def _log(level: str, msg: str): """Enhanced logging that writes to both console and file with sensitive data masking""" masked_msg = _mask_sensitive_data(msg) tz = _get_local_timezone() print(f"[{datetime.now(tz).isoformat(timespec='seconds')}] {level}: {masked_msg}") try: file_logger = _setup_file_logging() getattr(file_logger, level.lower(), file_logger.info)(masked_msg) except Exception as e: print(f"File logging error: {e}") def convert_utc_to_local(utc_iso_string: str) -> str: """Convert UTC ISO timestamp to local timezone timestamp""" if not utc_iso_string: return utc_iso_string try: # Parse UTC timestamp if utc_iso_string.endswith('Z'): dt_utc = datetime.fromisoformat(utc_iso_string.replace('Z', '+00:00')) elif '+00:00' in utc_iso_string: dt_utc = datetime.fromisoformat(utc_iso_string) else: # Assume UTC if no timezone info dt_utc = datetime.fromisoformat(utc_iso_string).replace(tzinfo=timezone.utc) # Convert to local timezone local_tz = _get_local_timezone() dt_local = dt_utc.astimezone(local_tz) return dt_local.isoformat(timespec='seconds') except Exception: # If conversion fails, return original return utc_iso_string # Initialize logging _setup_file_logging() def _load_environment_files(): """Load environment variables from .env and optionally .env.secrets""" from pathlib import Path # Try to load from python-dotenv if available try: from dotenv import load_dotenv # Load main .env file env_file = Path(".env") if env_file.exists(): load_dotenv(env_file) _log("INFO", f"Loaded environment from {env_file}") # Load secrets file if it exists secrets_file = Path(".env.secrets") if secrets_file.exists(): load_dotenv(secrets_file) _log("INFO", f"Loaded secrets from {secrets_file}") except ImportError: _log("WARNING", "python-dotenv not available - environment files not loaded") # Load environment files at startup _load_environment_files() # Add debug logging near where configuration is loaded print(f"DEBUG: Environment check - SONARR_ROOT_FOLDERS: {os.getenv('SONARR_ROOT_FOLDERS')}") print(f"DEBUG: Environment check - TV_PATHS: {os.getenv('TV_PATHS')}") def _bool_env(name: str, default: bool) -> bool: v = os.environ.get(name) if v is None: return default return v.lower() in ("1", "true", "yes", "y", "on") # --------------------------- # Configuration # --------------------------- class NFOGuardConfig: def __init__(self): # Paths - No hardcoded defaults, must be configured via environment tv_paths_env = os.environ.get("TV_PATHS", "") movie_paths_env = os.environ.get("MOVIE_PATHS", "") if not tv_paths_env: raise ValueError("TV_PATHS environment variable is required but not set") if not movie_paths_env: raise ValueError("MOVIE_PATHS environment variable is required but not set") self.tv_paths = [Path(p.strip()) for p in tv_paths_env.split(",") if p.strip()] self.movie_paths = [Path(p.strip()) for p in movie_paths_env.split(",") if p.strip()] # Core settings self.manage_nfo = _bool_env("MANAGE_NFO", True) self.fix_dir_mtimes = _bool_env("FIX_DIR_MTIMES", True) self.lock_metadata = _bool_env("LOCK_METADATA", True) self.debug = _bool_env("DEBUG", False) self.manager_brand = os.environ.get("MANAGER_BRAND", "NFOGuard") # Batching self.batch_delay = float(os.environ.get("BATCH_DELAY", "5.0")) self.max_concurrent = int(os.environ.get("MAX_CONCURRENT_SERIES", "3")) # Database self.db_path = Path(os.environ.get("DB_PATH", "/app/data/media_dates.db")) # Movie processing self.movie_priority = os.environ.get("MOVIE_PRIORITY", "import_then_digital").lower() self.prefer_release_dates_over_file_dates = _bool_env("PREFER_RELEASE_DATES_OVER_FILE_DATES", True) self.allow_file_date_fallback = _bool_env("ALLOW_FILE_DATE_FALLBACK", False) self.release_date_priority = [p.strip() for p in os.environ.get("RELEASE_DATE_PRIORITY", "digital,physical,theatrical").split(",")] self.enable_smart_date_validation = _bool_env("ENABLE_SMART_DATE_VALIDATION", True) self.max_release_date_gap_years = int(os.environ.get("MAX_RELEASE_DATE_GAP_YEARS", "10")) self.movie_poll_mode = os.environ.get("MOVIE_POLL_MODE", "always").lower() self.movie_update_mode = os.environ.get("MOVIE_DATE_UPDATE_MODE", "backfill_only").lower() # TV processing self.tv_season_dir_format = os.environ.get("TV_SEASON_DIR_FORMAT", "Season {season:02d}") self.tv_season_dir_pattern = os.environ.get("TV_SEASON_DIR_PATTERN", "season ").lower() self.tv_webhook_processing_mode = os.environ.get("TV_WEBHOOK_PROCESSING_MODE", "targeted").lower() config = NFOGuardConfig() # --------------------------- # Models # --------------------------- class SonarrWebhook(BaseModel): eventType: str series: Optional[Dict[str, Any]] = None episodes: Optional[list] = [] episodeFile: Optional[Dict[str, Any]] = None isUpgrade: Optional[bool] = False class Config: extra = "allow" class RadarrWebhook(BaseModel): eventType: str movie: Optional[Dict[str, Any]] = None movieFile: Optional[Dict[str, Any]] = None isUpgrade: Optional[bool] = False deletedFiles: Optional[list] = [] remoteMovie: Optional[Dict[str, Any]] = None renamedMovieFiles: Optional[List[Dict[str, Any]]] = None class Config: extra = "allow" class HealthResponse(BaseModel): status: str version: str uptime: str database_status: str radarr_database: Optional[Dict[str, Any]] = None class TVSeasonRequest(BaseModel): series_path: str season_name: str class TVEpisodeRequest(BaseModel): series_path: str season_name: str episode_name: str # --------------------------- # Core Processing # --------------------------- class TVProcessor: """Handles TV series processing""" def __init__(self, db: NFOGuardDatabase, nfo_manager: NFOManager, path_mapper: PathMapper): self.db = db self.nfo_manager = nfo_manager self.path_mapper = path_mapper self.sonarr = SonarrClient( os.environ.get("SONARR_URL", ""), os.environ.get("SONARR_API_KEY", "") ) self.external_clients = ExternalClientManager() def find_series_path(self, series_title: str, imdb_id: str, sonarr_path: str = None) -> Optional[Path]: """Find series directory path""" # Try webhook path first if sonarr_path: container_path = self.path_mapper.sonarr_path_to_container_path(sonarr_path) path_obj = Path(container_path) if path_obj.exists(): return path_obj # Search by IMDb ID or title for media_path in config.tv_paths: if not media_path.exists(): continue # Search by IMDb ID if imdb_id: pattern = str(media_path / f"*[imdb-{imdb_id}]*") matches = glob.glob(pattern) if matches: return Path(matches[0]) # Search by title if series_title: title_clean = series_title.lower().replace(" ", "").replace("-", "") for item in media_path.iterdir(): if item.is_dir() and "[imdb-" in item.name.lower(): item_clean = item.name.lower().replace(" ", "").replace("-", "") if title_clean in item_clean: return item return None def process_series(self, series_path: Path) -> None: """Process a TV series directory""" imdb_id = self.nfo_manager.parse_imdb_from_path(series_path) if not imdb_id: _log("ERROR", f"No IMDb ID found in series path: {series_path}") return _log("INFO", f"Processing TV series: {series_path.name}") # Update database self.db.upsert_series(imdb_id, str(series_path)) # Find video files disk_episodes = self._find_disk_episodes(series_path) _log("INFO", f"Found {len(disk_episodes)} episodes on disk") # Get episode dates episode_dates = self._gather_episode_dates(series_path, imdb_id, disk_episodes) # Process episodes for (season, episode), (aired, dateadded, source) in episode_dates.items(): if (season, episode) in disk_episodes: # Create NFO if config.manage_nfo: season_dir = series_path / config.tv_season_dir_format.format(season=season) self.nfo_manager.create_episode_nfo( season_dir, season, episode, aired, dateadded, source, config.lock_metadata ) # Update file mtimes if config.fix_dir_mtimes and dateadded: video_files = disk_episodes[(season, episode)] for video_file in video_files: self.nfo_manager.set_file_mtime(video_file, dateadded) # Save to database self.db.upsert_episode_date(imdb_id, season, episode, aired, dateadded, source, True) # Skip season.nfo and tvshow.nfo creation - focus only on episode NFOs pass _log("INFO", f"Completed processing TV series: {series_path.name}") def _extract_series_title_from_path(self, series_path: Path) -> Optional[str]: """Extract series title from directory path, removing year and IMDb ID""" name = series_path.name # Remove IMDb ID part: [imdb-ttXXXXXX] or [ttXXXXXX] name = re.sub(r'\s*\[imdb-?tt\d+\]', '', name, flags=re.IGNORECASE) name = re.sub(r'\s*\[tt\d+\]', '', name, flags=re.IGNORECASE) # Remove year in parentheses: (YYYY) name = re.sub(r'\s*\(\d{4}\)', '', name) # Clean up extra spaces name = re.sub(r'\s+', ' ', name).strip() return name if name else None def _find_disk_episodes(self, series_path: Path) -> Dict[Tuple[int, int], List[Path]]: """Find all episode video files on disk""" disk_episodes = {} video_exts = (".mkv", ".mp4", ".avi", ".mov", ".m4v") _log("DEBUG", f"Scanning for episodes in: {series_path}") _log("DEBUG", f"Looking for season dirs with pattern: '{config.tv_season_dir_pattern}'") for season_dir in series_path.iterdir(): _log("DEBUG", f"Checking: {season_dir.name} (is_dir: {season_dir.is_dir()})") if not (season_dir.is_dir() and season_dir.name.lower().startswith(config.tv_season_dir_pattern)): _log("DEBUG", f"Skipping {season_dir.name} - doesn't match season pattern") continue try: # Extract season number from directory name # Handle formats like "Season 01", "S01", "Season01", etc. dir_name = season_dir.name.lower() if config.tv_season_dir_pattern in dir_name: # Extract everything after the pattern season_part = dir_name[len(config.tv_season_dir_pattern):].strip() else: continue season_num = int(season_part) except (ValueError, IndexError): continue for video_file in season_dir.iterdir(): if video_file.is_file() and video_file.suffix.lower() in video_exts: match = re.search(r"S(\d{2})E(\d{2})", video_file.name, re.IGNORECASE) if match: file_season, file_episode = int(match.group(1)), int(match.group(2)) key = (season_num, file_episode) # Use directory season number if key not in disk_episodes: disk_episodes[key] = [] disk_episodes[key].append(video_file) return disk_episodes def _gather_episode_dates(self, series_path: Path, imdb_id: str, disk_episodes: Dict) -> Dict: """Gather episode dates from various sources""" episode_dates = {} # Check cache first cached_episodes = self.db.get_series_episodes(imdb_id, has_video_file_only=True) for ep in cached_episodes: key = (ep["season"], ep["episode"]) if key in disk_episodes: # Only use cached data for episodes we have episode_dates[key] = (ep["aired"], ep["dateadded"], ep["source"]) # Find missing episodes cached_keys = set(episode_dates.keys()) missing_keys = set(disk_episodes.keys()) - cached_keys if not missing_keys: _log("INFO", "All episodes found in cache") return episode_dates _log("INFO", f"Querying APIs for {len(missing_keys)} missing episodes") # Query Sonarr for missing episodes if self.sonarr.enabled: series = self.sonarr.series_by_imdb(imdb_id) if not series: _log("DEBUG", f"Trying direct series search for IMDb: {imdb_id}") series = self.sonarr.series_by_imdb_direct(imdb_id) if not series: # Fallback: try searching by series title extracted from path series_title = self._extract_series_title_from_path(series_path) if series_title: _log("DEBUG", f"Trying title search for: {series_title}") series = self.sonarr.series_by_title(series_title) if series: series_id = series.get("id") if series_id: episodes = self.sonarr.episodes_for_series(series_id) for ep in episodes: season_num = ep.get("seasonNumber") episode_num = ep.get("episodeNumber") if not isinstance(season_num, int) or not isinstance(episode_num, int): continue key = (season_num, episode_num) if key not in missing_keys: continue # Get dates aired = self._parse_date_to_iso(ep.get("airDateUtc")) dateadded = None source = "sonarr:episode.airDateUtc" # Try to get import history episode_id = ep.get("id") if episode_id: import_date = self.sonarr.get_episode_import_history(episode_id) if import_date: dateadded = self._parse_date_to_iso(import_date) source = "sonarr:history.import" if not dateadded: dateadded = aired if aired or dateadded: episode_dates[key] = (aired, dateadded, source) # Fill remaining gaps with external APIs remaining_keys = missing_keys - set(episode_dates.keys()) if remaining_keys and self.external_clients.tmdb.enabled: tmdb_movie = self.external_clients.tmdb.find_by_imdb(imdb_id) if tmdb_movie: tv_id = tmdb_movie.get("id") if tv_id: seasons_needed = set(season for season, episode in remaining_keys) for season_num in seasons_needed: tmdb_episodes = self.external_clients.tmdb.get_tv_season_episodes(tv_id, season_num) for ep_num, air_date in tmdb_episodes.items(): key = (season_num, ep_num) if key in remaining_keys: aired = self._parse_date_to_iso(air_date) episode_dates[key] = (aired, aired, "tmdb:air_date") return episode_dates def _parse_date_to_iso(self, date_str: str) -> Optional[str]: """Parse date string to ISO format""" if not date_str: return None try: if len(date_str) == 10 and date_str[4] == "-": dt = datetime.fromisoformat(date_str).replace(tzinfo=timezone.utc) else: dt = datetime.fromisoformat(date_str.replace("Z", "+00:00")).astimezone(timezone.utc) return dt.isoformat(timespec="seconds") except Exception: return None def process_season(self, series_path: Path, season_path: Path) -> None: """Process a specific TV season directory""" imdb_id = self.nfo_manager.parse_imdb_from_path(series_path) if not imdb_id: _log("ERROR", f"No IMDb ID found in series path: {series_path}") return # Extract season number from path season_match = re.search(r'season\s*(\d+)', season_path.name, re.IGNORECASE) if not season_match: _log("ERROR", f"Could not extract season number from: {season_path.name}") return season_num = int(season_match.group(1)) _log("INFO", f"Processing TV season {season_num}: {season_path}") # Update database self.db.upsert_series(imdb_id, str(series_path)) # Find video files in this season only disk_episodes = self._find_season_episodes(season_path, season_num) _log("INFO", f"Found {len(disk_episodes)} episodes in season {season_num}") # Get enhanced metadata from Sonarr series_metadata = self._get_sonarr_series_metadata(imdb_id) # Get episode dates for this season episode_dates = self._gather_season_episode_dates(series_path, imdb_id, season_num, disk_episodes, series_metadata) # Process episodes for (season, episode), (aired, dateadded, source) in episode_dates.items(): if (season, episode) in disk_episodes: # Get enhanced episode metadata enhanced_metadata = self._get_episode_metadata(series_metadata, season, episode) if series_metadata else None # Create NFO if config.manage_nfo: self.nfo_manager.create_episode_nfo( season_path, season, episode, aired, dateadded, source, config.lock_metadata, enhanced_metadata ) # Update file mtimes if config.fix_dir_mtimes and dateadded: video_files = disk_episodes[(season, episode)] for video_file in video_files: self.nfo_manager.set_file_mtime(video_file, dateadded) # Save to database self.db.upsert_episode_date(imdb_id, season, episode, aired, dateadded, source, True) # Skip season.nfo and tvshow.nfo creation - focus only on episode NFOs pass _log("INFO", f"Completed processing season {season_num}") def process_episode_file(self, series_path: Path, season_path: Path, episode_file: Path) -> None: """Process a single TV episode file""" imdb_id = self.nfo_manager.parse_imdb_from_path(series_path) if not imdb_id: _log("ERROR", f"No IMDb ID found in series path: {series_path}") return # Parse episode info from filename episode_info = self._parse_episode_from_filename(episode_file.name) if not episode_info: _log("ERROR", f"Could not parse episode info from: {episode_file.name}") return season_num, episode_num = episode_info _log("INFO", f"Processing single episode S{season_num:02d}E{episode_num:02d}: {episode_file.name}") # Update database self.db.upsert_series(imdb_id, str(series_path)) # TIER 1: Check if episode NFO already has NFOGuard data (fastest - no DB or API calls) nfo_data = self.nfo_manager.extract_nfoguard_dates_from_episode_nfo(season_path, season_num, episode_num) if nfo_data: _log("INFO", f"🚀 Using existing NFOGuard data from episode NFO S{season_num:02d}E{episode_num:02d}: {nfo_data['dateadded']} (source: {nfo_data['source']})") dateadded = nfo_data["dateadded"] source = nfo_data["source"] aired = nfo_data.get("aired") # Update file mtime if enabled (NFO is already correct) if config.fix_dir_mtimes and dateadded: self.nfo_manager.set_file_mtime(episode_file, dateadded) _log("INFO", f"Completed processing episode S{season_num:02d}E{episode_num:02d} (source: {source}) [episode-nfo-only]") return # TIER 2: Check database for existing episode data existing_episode = self.db.get_episode_date(imdb_id, season_num, episode_num) if existing_episode and existing_episode.get("dateadded") and existing_episode.get("source") != "no_valid_date_source": _log("INFO", f"✅ Using complete database data for episode S{season_num:02d}E{episode_num:02d}: {existing_episode['dateadded']} (source: {existing_episode['source']})") # Still create NFO and update files but skip API queries dateadded = existing_episode["dateadded"] source = existing_episode["source"] aired = existing_episode.get("aired") # Create NFO with existing data (no enhanced metadata needed) if config.manage_nfo and dateadded: self.nfo_manager.create_episode_nfo( season_path, season_num, episode_num, aired, dateadded, source, config.lock_metadata, None # No enhanced metadata for database-cached episodes ) # Update file mtime if enabled if config.fix_dir_mtimes and dateadded: self.nfo_manager.set_file_mtime(episode_file, dateadded) _log("INFO", f"Completed processing episode S{season_num:02d}E{episode_num:02d} (source: {source}) [episode-database-only]") return # TIER 3: Full processing with Sonarr API calls (slowest) _log("DEBUG", f"Episode S{season_num:02d}E{episode_num:02d} requires full processing - querying Sonarr APIs") # Get enhanced metadata from Sonarr series_metadata = self._get_sonarr_series_metadata(imdb_id) enhanced_metadata = self._get_episode_metadata(series_metadata, season_num, episode_num) if series_metadata else None # Get episode date aired, dateadded, source = self._get_single_episode_date(imdb_id, season_num, episode_num, series_metadata) # Create NFO (always create if manage_nfo is enabled, even without dateadded) if config.manage_nfo: self.nfo_manager.create_episode_nfo( season_path, season_num, episode_num, aired, dateadded, source, config.lock_metadata, enhanced_metadata ) # Update file mtime if config.fix_dir_mtimes and dateadded: self.nfo_manager.set_file_mtime(episode_file, dateadded) # Save to database self.db.upsert_episode_date(imdb_id, season_num, episode_num, aired, dateadded, source, True) _log("INFO", f"Completed processing episode S{season_num:02d}E{episode_num:02d}") def _find_season_episodes(self, season_path: Path, season_num: int) -> Dict[Tuple[int, int], List[Path]]: """Find all episode video files in a single season""" disk_episodes = {} video_exts = (".mkv", ".mp4", ".avi", ".mov", ".m4v", ".ts", ".m2ts") for file_path in season_path.iterdir(): if not file_path.is_file() or file_path.suffix.lower() not in video_exts: continue episode_info = self._parse_episode_from_filename(file_path.name) if episode_info and episode_info[0] == season_num: season, episode = episode_info key = (season, episode) if key not in disk_episodes: disk_episodes[key] = [] disk_episodes[key].append(file_path) return disk_episodes def _parse_episode_from_filename(self, filename: str) -> Optional[Tuple[int, int]]: """Parse season and episode numbers from filename""" # Try SxxExx format match = re.search(r'S(\d{1,2})E(\d{1,2})', filename, re.IGNORECASE) if match: return int(match.group(1)), int(match.group(2)) # Try season.episode format match = re.search(r'(\d{1,2})\.(\d{1,2})', filename) if match: return int(match.group(1)), int(match.group(2)) return None def _get_sonarr_series_metadata(self, imdb_id: str) -> Optional[Dict[str, Any]]: """Get enhanced series metadata from Sonarr API""" try: if not self.sonarr.enabled: return None series = self.sonarr.series_by_imdb(imdb_id) if not series: _log("DEBUG", f"Trying direct series search for IMDb: {imdb_id}") series = self.sonarr.series_by_imdb_direct(imdb_id) if not series: _log("DEBUG", f"No Sonarr series found for IMDb {imdb_id}") return None # Get episodes for the series series_id = series.get("id") if series_id: episodes = self.sonarr.episodes_for_series(series_id) series["episodes"] = episodes _log("DEBUG", f"Got {len(episodes)} episodes from Sonarr for series {series.get('title')}") return series except Exception as e: _log("ERROR", f"Error getting Sonarr metadata for {imdb_id}: {e}") return None def _get_episode_metadata(self, series_metadata: Dict[str, Any], season_num: int, episode_num: int) -> Optional[Dict[str, Any]]: """Extract specific episode metadata from series data""" if not series_metadata or "episodes" not in series_metadata: return None for episode in series_metadata["episodes"]: if episode.get("seasonNumber") == season_num and episode.get("episodeNumber") == episode_num: return { "title": episode.get("title"), "overview": episode.get("overview"), "runtime": episode.get("runtime"), "ratings": episode.get("ratings", {}) } return None def _gather_season_episode_dates(self, series_path: Path, imdb_id: str, season_num: int, disk_episodes: Dict[Tuple[int, int], List[Path]], series_metadata: Optional[Dict[str, Any]] = None) -> Dict[Tuple[int, int], Tuple[Optional[str], Optional[str], str]]: """Get episode dates for a specific season""" episode_dates = {} for (season, episode) in disk_episodes.keys(): if season != season_num: continue aired, dateadded, source = self._get_single_episode_date(imdb_id, season, episode, series_metadata) episode_dates[(season, episode)] = (aired, dateadded, source) return episode_dates def _get_single_episode_date(self, imdb_id: str, season_num: int, episode_num: int, series_metadata: Optional[Dict[str, Any]] = None) -> Tuple[Optional[str], Optional[str], str]: """ Get date info for a single episode during backfill scans. Priority: 1) Database 2) Sonarr import history 3) Air dates """ # Step 1: Try database first existing = self.db.get_episode_date(imdb_id, season_num, episode_num) if existing and existing.get("dateadded"): _log("DEBUG", f"Using existing database entry for S{season_num:02d}E{episode_num:02d}") return existing.get("aired"), existing["dateadded"], existing.get("source", "database:existing") # Step 2: Try Sonarr import history (the real import date) aired = None import_date = None if self.sonarr.enabled: try: series = self.sonarr.series_by_imdb(imdb_id) if not series: _log("DEBUG", f"Trying direct series search for IMDb: {imdb_id}") series = self.sonarr.series_by_imdb_direct(imdb_id) if not series: # Try title search as fallback for IMDb mismatches _log("DEBUG", f"Trying title search fallback for IMDb: {imdb_id}") # We don't have series_path here, so just try the imdb_id as a title search # This is less ideal but better than nothing if series: episodes = self.sonarr.episodes_for_series(series["id"]) for ep in episodes: if ep.get("seasonNumber") == season_num and ep.get("episodeNumber") == episode_num: aired = ep.get("airDateUtc") import_date = self.sonarr.get_episode_import_history(ep["id"]) if import_date: # Convert import date to local timezone for NFO files local_import_date = convert_utc_to_local(import_date) _log("INFO", f"Found Sonarr import history for S{season_num:02d}E{episode_num:02d}: {local_import_date}") return aired, local_import_date, "sonarr:history.import" break except Exception as e: _log("DEBUG", f"Sonarr API error for episode S{season_num:02d}E{episode_num:02d}: {e}") # Step 3: Try Sonarr metadata for air date if not aired and series_metadata and "episodes" in series_metadata: for episode in series_metadata["episodes"]: if episode.get("seasonNumber") == season_num and episode.get("episodeNumber") == episode_num: aired = episode.get("airDateUtc") break # Step 4: Only if we have an air date but no import history, use air date as fallback if aired: _log("WARNING", f"No import history found for S{season_num:02d}E{episode_num:02d}, using air date as fallback") return aired, aired, "sonarr:episode.airDateUtc" # Step 5: Last resort - current time in local timezone (shouldn't happen in normal operation) local_tz = _get_local_timezone() current_time = datetime.now(local_tz).isoformat(timespec="seconds") _log("WARNING", f"No data found for S{season_num:02d}E{episode_num:02d}, using current time") return None, current_time, "fallback:current_time" def process_webhook_episodes(self, series_path: Path, webhook_episodes: List[Dict[str, Any]]) -> None: """Process only the specific episodes mentioned in a webhook (targeted mode)""" imdb_id = self.nfo_manager.parse_imdb_from_path(series_path) if not imdb_id: _log("ERROR", f"No IMDb ID found in series path: {series_path}") return if not webhook_episodes: _log("WARNING", f"No episodes in webhook, falling back to series processing: {series_path}") self.process_series(series_path) return _log("INFO", f"Processing {len(webhook_episodes)} webhook episodes for: {series_path.name} (IMDb: {imdb_id})") # Update database self.db.upsert_series(imdb_id, str(series_path)) # Get enhanced metadata from Sonarr series_metadata = self._get_sonarr_series_metadata(imdb_id) episodes_processed = 0 for webhook_episode in webhook_episodes: season_num = webhook_episode.get("seasonNumber") episode_num = webhook_episode.get("episodeNumber") if not season_num or not episode_num: _log("WARNING", f"Invalid episode data in webhook: {webhook_episode}") continue # Check if episode file exists on disk season_dir = series_path / config.tv_season_dir_format.format(season=season_num) if not season_dir.exists(): _log("WARNING", f"Season directory not found: {season_dir}") continue # Find matching episode files episode_files = [] for file_path in season_dir.iterdir(): if file_path.is_file() and file_path.suffix.lower() in ('.mkv', '.mp4', '.avi', '.mov', '.m4v'): parsed = self._parse_episode_from_filename(file_path.name) if parsed and parsed == (season_num, episode_num): episode_files.append(file_path) if not episode_files: _log("WARNING", f"No video files found for S{season_num:02d}E{episode_num:02d}") continue # Get episode date information - webhook processing prioritizes existing DB entries _log("DEBUG", f"Processing webhook episode: IMDb={imdb_id}, S{season_num:02d}E{episode_num:02d}") aired, dateadded, source = self._get_webhook_episode_date(imdb_id, season_num, episode_num, series_metadata) enhanced_metadata = self._get_episode_metadata(series_metadata, season_num, episode_num) if series_metadata else None # Create NFO if config.manage_nfo: self.nfo_manager.create_episode_nfo( season_dir, season_num, episode_num, aired, dateadded, source, config.lock_metadata, enhanced_metadata ) # Update file mtimes if config.fix_dir_mtimes and dateadded: for episode_file in episode_files: self.nfo_manager.set_file_mtime(episode_file, dateadded) # Save to database self.db.upsert_episode_date(imdb_id, season_num, episode_num, aired, dateadded, source, True) # Verify database entry was saved (debug) verification = self.db.get_episode_date(imdb_id, season_num, episode_num) if verification: _log("DEBUG", f"Verified database entry saved: S{season_num:02d}E{episode_num:02d} -> {verification['dateadded']}") else: _log("ERROR", f"Failed to save episode to database: S{season_num:02d}E{episode_num:02d}") episodes_processed += 1 # Skip season.nfo and tvshow.nfo creation - focus only on episode NFOs pass _log("INFO", f"Completed targeted processing: {episodes_processed}/{len(webhook_episodes)} episodes processed") def _get_webhook_episode_date(self, imdb_id: str, season_num: int, episode_num: int, series_metadata: Optional[Dict[str, Any]] = None) -> Tuple[Optional[str], Optional[str], str]: """ Get episode date for webhook processing with correct priority: 1. Check existing NFOGuard database entry (preserve previous import dates) 2. If not found, use current time (webhook = new download) 3. Get aired date from Sonarr/TMDB for reference """ # Step 1: Check if we already have this episode in our database _log("DEBUG", f"Checking database for existing episode: IMDb={imdb_id}, S{season_num:02d}E{episode_num:02d}") existing = self.db.get_episode_date(imdb_id, season_num, episode_num) if existing: _log("DEBUG", f"Found database entry: {existing}") if existing.get("dateadded"): _log("INFO", f"Using existing database entry for S{season_num:02d}E{episode_num:02d}: {existing['dateadded']} (source: {existing.get('source', 'unknown')})") return existing.get("aired"), existing["dateadded"], existing.get("source", "database:existing") else: _log("DEBUG", f"Database entry found but no dateadded value: {existing}") else: _log("DEBUG", f"No database entry found for IMDb={imdb_id}, S{season_num:02d}E{episode_num:02d}") # Step 2: Webhook = Source of Truth - use current timestamp in local timezone local_tz = _get_local_timezone() current_time = datetime.now(local_tz).isoformat(timespec="seconds") _log("INFO", f"Webhook episode processing - using current timestamp as source of truth: {current_time}") # Step 3: Get aired date for reference (but don't use for dateadded) aired = None # Try Sonarr metadata first for air date if series_metadata and "episodes" in series_metadata: for episode in series_metadata["episodes"]: if episode.get("seasonNumber") == season_num and episode.get("episodeNumber") == episode_num: aired = episode.get("airDateUtc") if aired: break # Fallback to Sonarr API for air date if not in metadata if not aired and self.sonarr.enabled: try: series = self.sonarr.series_by_imdb(imdb_id) if not series: _log("DEBUG", f"Trying direct series search for IMDb: {imdb_id}") series = self.sonarr.series_by_imdb_direct(imdb_id) if series: episodes = self.sonarr.episodes_for_series(series["id"]) for ep in episodes: if ep.get("seasonNumber") == season_num and ep.get("episodeNumber") == episode_num: aired = ep.get("airDateUtc") break except Exception as e: _log("DEBUG", f"Error getting air date from Sonarr: {e}") return aired, current_time, "webhook:first_seen" class MovieProcessor: """Handles movie processing""" def __init__(self, db: NFOGuardDatabase, nfo_manager: NFOManager, path_mapper: PathMapper): self.db = db self.nfo_manager = nfo_manager self.path_mapper = path_mapper self.radarr = RadarrClient( os.environ.get("RADARR_URL", ""), os.environ.get("RADARR_API_KEY", "") ) self.external_clients = ExternalClientManager() def find_movie_path(self, movie_title: str, imdb_id: str, radarr_path: str = None) -> Optional[Path]: """Find movie directory path""" # Try webhook path first if radarr_path: container_path = self.path_mapper.radarr_path_to_container_path(radarr_path) path_obj = Path(container_path) if path_obj.exists(): return path_obj # Search by IMDb ID or title for media_path in config.movie_paths: if not media_path.exists(): continue # Search by IMDb ID if imdb_id: pattern = str(media_path / f"*[imdb-{imdb_id}]*") matches = glob.glob(pattern) if matches: return Path(matches[0]) # Search by title if movie_title: title_clean = movie_title.lower().replace(" ", "").replace("-", "") for item in media_path.iterdir(): if item.is_dir() and "[imdb-" in item.name.lower(): item_clean = item.name.lower().replace(" ", "").replace("-", "") if title_clean in item_clean: return item return None def process_movie(self, movie_path: Path, webhook_mode: bool = False) -> None: """Process a movie directory""" imdb_id = self.nfo_manager.find_movie_imdb_id(movie_path) if not imdb_id: _log("ERROR", f"No IMDb ID found in movie directory, filenames, or NFO file: {movie_path}") return # Handle TMDB ID fallback case is_tmdb_fallback = imdb_id.startswith("tmdb-") if is_tmdb_fallback: _log("INFO", f"Processing movie: {movie_path.name} (TMDB: {imdb_id})") else: _log("INFO", f"Processing movie: {movie_path.name} (IMDb: {imdb_id})") # Update database self.db.upsert_movie(imdb_id, str(movie_path)) # Check for video files video_exts = (".mkv", ".mp4", ".avi", ".mov", ".m4v") has_video = any(f.is_file() and f.suffix.lower() in video_exts for f in movie_path.iterdir()) if not has_video: _log("WARNING", f"No video files found in: {movie_path}") self.db.upsert_movie_dates(imdb_id, None, None, None, False) return # TIER 1: Check if NFO file already has NFOGuard data (fastest - no DB or API calls) nfo_path = movie_path / "movie.nfo" nfo_data = self.nfo_manager.extract_nfoguard_dates_from_nfo(nfo_path) if nfo_data: _log("INFO", f"🚀 Using existing NFOGuard data from NFO file: {nfo_data['dateadded']} (source: {nfo_data['source']})") dateadded = nfo_data["dateadded"] source = nfo_data["source"] released = nfo_data.get("released") # Update file mtimes if enabled (NFO is already correct) if config.fix_dir_mtimes and dateadded: self.nfo_manager.update_movie_files_mtime(movie_path, dateadded) _log("INFO", f"Completed processing movie: {movie_path.name} (source: {source}) [nfo-only]") return # TIER 1.5: Special handling for TMDB-only movies - extract dates from existing NFO if is_tmdb_fallback: tmdb_nfo_data = self._extract_dates_from_tmdb_nfo(nfo_path) if tmdb_nfo_data: _log("INFO", f"🎬 Using TMDB data from existing NFO file: {tmdb_nfo_data['dateadded']} (source: {tmdb_nfo_data['source']})") dateadded = tmdb_nfo_data["dateadded"] source = tmdb_nfo_data["source"] released = tmdb_nfo_data.get("released") # Create NFO with NFOGuard fields added if config.manage_nfo: self.nfo_manager.create_movie_nfo( movie_path, imdb_id, dateadded, released, source, config.lock_metadata ) # Update file mtimes if enabled if config.fix_dir_mtimes and dateadded: self.nfo_manager.update_movie_files_mtime(movie_path, dateadded) # Save to database self.db.upsert_movie_dates(imdb_id, released, dateadded, source, True) _log("INFO", f"Completed processing movie: {movie_path.name} (source: {source}) [tmdb-nfo]") return # TIER 2: Check database for existing data existing = self.db.get_movie_dates(imdb_id) _log("DEBUG", f"Database lookup for {imdb_id}: {existing}") # If we have complete data in database, use it and skip expensive API calls if existing and existing.get("dateadded") and existing.get("source") != "no_valid_date_source": _log("INFO", f"✅ Using complete database data for {imdb_id}: {existing['dateadded']} (source: {existing['source']})") # Still create NFO and update files but skip API queries dateadded, source, released = existing["dateadded"], existing["source"], existing.get("released") # Create NFO with existing data if config.manage_nfo: self.nfo_manager.create_movie_nfo( movie_path, imdb_id, dateadded, released, source, config.lock_metadata ) # Update file mtimes if enabled if config.fix_dir_mtimes and dateadded: self.nfo_manager.update_movie_files_mtime(movie_path, dateadded) _log("INFO", f"Completed processing movie: {movie_path.name} (source: {source}) [database-only]") return # Handle webhook mode - prioritize database, then use proper date logic if webhook_mode: _log("DEBUG", f"Webhook mode: existing={bool(existing)}, has_dateadded={bool(existing and existing.get('dateadded')) if existing else 'N/A'}") if existing and existing.get("dateadded"): _log("INFO", f"Webhook processing - using existing database entry: {existing['dateadded']} (source: {existing.get('source', 'unknown')})") dateadded, source, released = existing["dateadded"], existing["source"], existing.get("released") else: if existing: _log("INFO", f"Webhook processing - database entry exists but no dateadded field: {existing}") else: _log("INFO", f"Webhook processing - no database entry found for {imdb_id}") _log("INFO", f"Using full date decision logic") # Use same logic as manual scan to check Radarr import dates, release dates, etc. should_query = True # Always query for webhooks when no database entry exists dateadded, source, released = self._decide_movie_dates(imdb_id, movie_path, should_query, existing) # Only if ALL date sources fail, fall back to current timestamp if dateadded is None: local_tz = _get_local_timezone() current_time = datetime.now(local_tz).isoformat(timespec="seconds") _log("INFO", f"Webhook processing - all date sources failed, using current timestamp as last resort: {current_time}") dateadded, source = current_time, "webhook:fallback_timestamp" else: # Manual scan mode - determine if we should query APIs should_query = ( config.movie_poll_mode == "always" or (config.movie_poll_mode == "if_missing" and not existing) or (config.movie_poll_mode == "if_missing" and existing and existing.get("source") == "file:mtime") or (config.movie_poll_mode == "if_missing" and existing and not existing.get("dateadded")) ) _log("DEBUG", f"Movie {imdb_id}: should_query={should_query}, poll_mode={config.movie_poll_mode}, existing={bool(existing)}, has_dateadded={bool(existing and existing.get('dateadded')) if existing else False}") # Use existing movie date decision logic dateadded, source, released = self._decide_movie_dates(imdb_id, movie_path, should_query, existing) # If we don't have an import/download date but we have a release date, use it as dateadded # This ensures we save digital release dates, theatrical dates, etc. to the database final_dateadded = dateadded final_source = source if dateadded is None and released is not None: final_dateadded = released final_source = f"{source}_as_dateadded" if source else "release_date_fallback" _log("INFO", f"Using release date as dateadded: {final_dateadded} (source: {final_source})") # Create NFO regardless of date availability (preserves existing metadata) if config.manage_nfo: self.nfo_manager.create_movie_nfo( movie_path, imdb_id, final_dateadded, released, final_source, config.lock_metadata ) # Skip remaining processing if no valid date found and file dates disabled if final_dateadded is None: _log("WARNING", f"Movie {movie_path.name} - no valid date source available, but NFO was still processed") self.db.upsert_movie_dates(imdb_id, released, None, source, True) return # Update dateadded and source for the rest of processing dateadded = final_dateadded source = final_source _log("DEBUG", f"Movie {movie_path.name} proceeding to save: dateadded={dateadded}, source={source}") # Update file mtimes (only if we have a valid date) if config.fix_dir_mtimes and dateadded and dateadded != "MANUAL_REVIEW_NEEDED": self.nfo_manager.update_movie_files_mtime(movie_path, dateadded) _log("DEBUG", f"Movie processing reached file mtime section: fix_dir_mtimes={config.fix_dir_mtimes}, dateadded={dateadded}") # Save to database _log("DEBUG", f"About to save to database: imdb_id={imdb_id}, dateadded={dateadded}") try: self.db.upsert_movie_dates(imdb_id, released, dateadded, source, True) _log("DEBUG", f"Database save completed for {imdb_id}") except Exception as e: _log("ERROR", f"Database save failed for {imdb_id}: {e}") raise _log("INFO", f"Completed processing movie: {movie_path.name} (source: {source})") def _extract_dates_from_tmdb_nfo(self, nfo_path: Path) -> Optional[Dict[str, str]]: """Extract date information from TMDB-based NFO file""" if not nfo_path.exists(): return None try: root = self.nfo_manager._parse_nfo_with_tolerance(nfo_path) # Look for premiered date (from TMDB) premiered_elem = root.find('.//premiered') if premiered_elem is not None and premiered_elem.text: premiered_date = premiered_elem.text.strip() print(f"✅ Found TMDB premiered date: {premiered_date}") return { "dateadded": premiered_date, "source": "tmdb:premiered_from_nfo", "released": premiered_date } except (ET.ParseError, Exception) as e: print(f"⚠️ Error parsing TMDB NFO for dates: {e}") return None def _decide_movie_dates(self, imdb_id: str, movie_path: Path, should_query: bool, existing: Optional[Dict]) -> Tuple[str, str, Optional[str]]: """Decide movie dates based on configuration and available data""" _log("DEBUG", f"_decide_movie_dates for {imdb_id}: should_query={should_query}, existing={existing}") if not should_query and existing: _log("DEBUG", f"Using existing data without querying: dateadded={existing.get('dateadded')}, source={existing.get('source')}") return existing["dateadded"], existing["source"], existing.get("released") # Query Radarr for movie info radarr_movie = None if should_query and self.radarr.api_key: radarr_movie = self.radarr.movie_by_imdb(imdb_id) released = None if radarr_movie: released = self._parse_date_to_iso(radarr_movie.get("inCinemas")) # Try import history first if configured if config.movie_priority == "import_then_digital": import_date, import_source = None, None if radarr_movie: movie_id = radarr_movie.get("id") if movie_id: import_date, import_source = self.radarr.get_movie_import_date(movie_id, fallback_to_file_date=config.allow_file_date_fallback) _log("INFO", f"Movie {imdb_id}: Radarr import result: date={import_date}, source={import_source}") # Check for special case: rename-first scenario (should prefer release dates) if import_source == "radarr:db.prefer_release_dates": _log("INFO", f"🎯 Movie {imdb_id} has rename-first history - skipping import, preferring release dates") # Fall through to release date logic below # Check if we got a real import date or just file date fallback elif import_date and import_source != "radarr:db.file.dateAdded": # Convert import date to local timezone for NFO files local_import_date = convert_utc_to_local(import_date) _log("INFO", f"✅ Movie {imdb_id}: Using import date {local_import_date} from {import_source}") return local_import_date, import_source, released # Get digital release date for comparison/fallback _log("INFO", f"🔍 Movie {imdb_id}: Trying digital release date fallback...") digital_date, digital_source = self._get_digital_release_date(imdb_id) _log("INFO", f"Movie {imdb_id}: Digital release result: date={digital_date}, source={digital_source}") # If we only have file date and release date exists, prefer it if reasonable and enabled if import_date and import_source == "radarr:db.file.dateAdded" and digital_date and config.prefer_release_dates_over_file_dates: # Compare dates - prefer release date if it's reasonable if self._should_prefer_release_over_file_date(digital_date, digital_source, released, imdb_id): _log("INFO", f"✅ Movie {imdb_id}: Preferring digital release date {digital_date} over file date") return digital_date, digital_source, released else: # Convert file date to local timezone for NFO files local_file_date = convert_utc_to_local(import_date) _log("INFO", f"✅ Movie {imdb_id}: Keeping file date {local_file_date} - digital date not reasonable") return local_file_date, import_source, released # Use whichever we have if import_date: # Convert import date to local timezone for NFO files local_import_date = convert_utc_to_local(import_date) _log("INFO", f"✅ Movie {imdb_id}: Using import date {local_import_date} from {import_source}") return local_import_date, import_source, released elif digital_date: _log("INFO", f"✅ Movie {imdb_id}: Using digital release date {digital_date} from {digital_source}") return digital_date, digital_source, released else: _log("WARNING", f"⚠️ Movie {imdb_id}: No import date OR digital release date found - trying additional fallbacks") # Try Radarr's own NFO premiered date as fallback radarr_premiered = self._get_radarr_nfo_premiered_date(movie_path) if radarr_premiered: _log("INFO", f"✅ Movie {imdb_id}: Using Radarr NFO premiered date {radarr_premiered}") return radarr_premiered, "radarr:nfo.premiered", released else: # digital_then_import # Try digital release first digital_date, digital_source = self._get_digital_release_date(imdb_id) if digital_date: return digital_date, digital_source, released # Fall back to import history if radarr_movie: movie_id = radarr_movie.get("id") if movie_id: import_date, import_source = self.radarr.get_movie_import_date(movie_id, fallback_to_file_date=config.allow_file_date_fallback) if import_date: # Convert import date to local timezone for NFO files local_import_date = convert_utc_to_local(import_date) return local_import_date, import_source, released # Last resort: file mtime (if allowed) if config.allow_file_date_fallback: return self._get_file_mtime_date(movie_path) else: _log("INFO", f"No valid dates found for {imdb_id} and file date fallback disabled - skipping NFO creation") # Log to failed movies debug file for troubleshooting self._log_failed_movie(movie_path, imdb_id, "No import date, no release date, file date fallback disabled") return None, "no_valid_date_source", None def _get_digital_release_date(self, imdb_id: str) -> Tuple[Optional[str], str]: """Get release date from external sources using configured priority""" _log("INFO", f"🔍 Calling external clients for {imdb_id}") _log("INFO", f"Release date priority: {config.release_date_priority}") _log("INFO", f"Smart validation enabled: {config.enable_smart_date_validation}") try: release_result = self.external_clients.get_release_date_by_priority( imdb_id, config.release_date_priority, enable_smart_validation=config.enable_smart_date_validation ) _log("INFO", f"External clients result for {imdb_id}: {release_result}") if release_result: _log("INFO", f"✅ Got release date: {release_result[0]} from {release_result[1]}") return release_result[0], release_result[1] else: _log("WARNING", f"❌ No release date found from external clients for {imdb_id}") return None, "release:none" except Exception as e: _log("ERROR", f"External clients error for {imdb_id}: {e}") return None, f"release:error:{str(e)}" def _get_radarr_nfo_premiered_date(self, movie_path: Path) -> Optional[str]: """Extract premiered date from Radarr's existing movie.nfo file""" try: nfo_path = movie_path / "movie.nfo" if not nfo_path.exists(): _log("DEBUG", f"No existing NFO file found at {nfo_path}") return None nfo_content = nfo_path.read_text(encoding='utf-8') # Look for YYYY-MM-DD import re match = re.search(r'(\d{4}-\d{2}-\d{2})', nfo_content) if match: premiered_date = match.group(1) # Convert to ISO format with timezone iso_date = f"{premiered_date}T00:00:00+00:00" _log("INFO", f"✅ Found Radarr NFO premiered date: {premiered_date}") return iso_date else: _log("DEBUG", f"No tag found in existing NFO") return None except Exception as e: _log("ERROR", f"Error reading Radarr NFO file: {e}") return None def _log_failed_movie(self, movie_path: Path, imdb_id: str, reason: str, available_countries: List[str] = None): """Log movies that failed to get valid dates to a debug file""" try: log_dir = Path("logs") log_dir.mkdir(exist_ok=True) failed_log_path = log_dir / "failed_movies.log" timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S") log_entry = f"[{timestamp}] {movie_path.name} | IMDb: {imdb_id} | Reason: {reason}" if available_countries: log_entry += f" | Available Countries: {', '.join(available_countries)}" log_entry += "\n" with open(failed_log_path, "a", encoding="utf-8") as f: f.write(log_entry) _log("INFO", f"📝 Logged failed movie to {failed_log_path}: {movie_path.name}") except Exception as e: _log("ERROR", f"Failed to write to failed movies log: {e}") def _get_file_mtime_date(self, movie_path: Path) -> Tuple[str, str, Optional[str]]: """Get date from file modification time as last resort""" video_exts = (".mkv", ".mp4", ".avi", ".mov", ".m4v") newest_mtime = None for file_path in movie_path.iterdir(): if file_path.is_file() and file_path.suffix.lower() in video_exts: try: mtime = file_path.stat().st_mtime if newest_mtime is None or mtime > newest_mtime: newest_mtime = mtime except Exception: continue if newest_mtime: try: # Use local timezone for file modification times local_tz = _get_local_timezone() iso_date = datetime.fromtimestamp(newest_mtime, tz=local_tz).isoformat(timespec="seconds") return iso_date, "file:mtime", None except Exception: pass return "MANUAL_REVIEW_NEEDED", "manual_review_required", None def _should_prefer_release_over_file_date(self, release_date: str, release_source: str, theatrical_release: Optional[str], imdb_id: str) -> bool: """ Decide if release date should be preferred over file date Logic: - For theatrical dates: Always prefer over file dates (they're authoritative) - For physical dates: Usually prefer over file dates - For digital dates: Prefer if reasonable (not decades before theatrical) """ try: release_dt = datetime.fromisoformat(release_date.replace("Z", "+00:00")) # Always prefer theatrical and physical releases over file dates if any(release_type in release_source for release_type in ["theatrical", "physical"]): _log("INFO", f"Release date {release_date} ({release_source}) for {imdb_id}, preferring over file date") return True # If we have theatrical release date, compare digital against it if theatrical_release: theatrical_dt = datetime.fromisoformat(theatrical_release.replace("Z", "+00:00")) year_diff = release_dt.year - theatrical_dt.year # If digital is more than 10 years before theatrical, it's probably wrong if year_diff < -10: _log("INFO", f"Release date {release_date} is {abs(year_diff)} years before theatrical {theatrical_release} for {imdb_id}, using file date instead") return False # If digital is within reasonable range (theatrical to +20 years), use it if -2 <= year_diff <= 20: _log("INFO", f"Release date {release_date} is reasonable for {imdb_id} (theatrical: {theatrical_release}), preferring over file date") return True # If no theatrical date, use digital if it's not absurdly old if release_dt.year >= 1990: # Reasonable minimum for digital releases _log("INFO", f"Release date {release_date} seems reasonable for {imdb_id}, preferring over file date") return True _log("INFO", f"Release date {release_date} seems too old for {imdb_id}, using file date instead") return False except Exception as e: _log("WARNING", f"Error comparing dates for {imdb_id}: {e}") return False def _parse_date_to_iso(self, date_str: str) -> Optional[str]: """Parse date string to ISO format""" if not date_str: return None try: if len(date_str) == 10 and date_str[4] == "-": dt = datetime.fromisoformat(date_str).replace(tzinfo=timezone.utc) else: dt = datetime.fromisoformat(date_str.replace("Z", "+00:00")).astimezone(timezone.utc) return dt.isoformat(timespec="seconds") except Exception: return None # --------------------------- # Batching System # --------------------------- class WebhookBatcher: """Batches webhook events to avoid processing storms""" def __init__(self): self.pending: Dict[str, Dict] = {} self.timers: Dict[str, threading.Timer] = {} self.processing: Set[str] = set() self.lock = threading.Lock() self.executor = ThreadPoolExecutor(max_workers=config.max_concurrent) def add_webhook(self, key: str, webhook_data: Dict, media_type: str): """Add webhook to batch queue""" with self.lock: if key in self.timers: self.timers[key].cancel() webhook_data['media_type'] = media_type self.pending[key] = webhook_data _log("INFO", f"Batched {media_type} webhook for {key}") _log("DEBUG", f"Batch added - key: {key}, media_type: {media_type}, timer scheduled for {config.batch_delay}s") timer = threading.Timer(config.batch_delay, self._process_item, args=[key]) self.timers[key] = timer timer.start() def _process_item(self, key: str): """Process a batched item""" with self.lock: if key in self.processing or key not in self.pending: return self.processing.add(key) webhook_data = self.pending.pop(key) self.timers.pop(key, None) try: self.executor.submit(self._process_sync, key, webhook_data) except Exception as e: _log("ERROR", f"Error submitting processing for {key}: {e}") with self.lock: self.processing.discard(key) def _process_sync(self, key: str, webhook_data: Dict): """Synchronous processing of webhook data with validation""" try: media_type = webhook_data.get('media_type') path_str = webhook_data.get('path') _log("DEBUG", f"Processing batch item: key={key}, media_type={media_type}, path={path_str}") if not path_str: _log("ERROR", f"No path found for {media_type} {key}") return path_obj = Path(path_str) if not path_obj.exists(): _log("ERROR", f"BATCH PROCESSING FAILED: Path does not exist: {path_obj}") _log("ERROR", f"This indicates a path mapping issue - webhook rejected to prevent wrong processing") return # CRITICAL: Validate that the path contains the expected IMDb ID for movies if media_type == 'movie': expected_imdb = key.replace('movie:', '') if key.startswith('movie:') else key if expected_imdb not in path_str.lower(): _log("ERROR", f"BATCH VALIDATION FAILED: Expected IMDb {expected_imdb} not found in path {path_str}") _log("ERROR", f"This prevents processing wrong movies due to batch corruption") return _log("DEBUG", f"Batch validation passed: IMDb {expected_imdb} found in path") # Process based on media type if media_type == 'tv': # Check processing mode for TV webhooks processing_mode = webhook_data.get('processing_mode', config.tv_webhook_processing_mode) episodes_data = webhook_data.get('episodes', []) if processing_mode == 'targeted' and episodes_data: _log("INFO", f"Using targeted episode processing for {len(episodes_data)} episodes") tv_processor.process_webhook_episodes(path_obj, episodes_data) else: _log("INFO", f"Using series processing mode (fallback or configured)") tv_processor.process_series(path_obj) elif media_type == 'movie': movie_processor.process_movie(path_obj, webhook_mode=True) else: _log("ERROR", f"Unknown media type: {media_type}") except Exception as e: _log("ERROR", f"Error processing {media_type} {key}: {e}") finally: with self.lock: self.processing.discard(key) def get_status(self) -> Dict: """Get batch queue status""" with self.lock: return { "pending_items": list(self.pending.keys()), "processing_items": list(self.processing), "pending_count": len(self.pending), "processing_count": len(self.processing) } # --------------------------- # FastAPI Application # --------------------------- # Get version try: version = (Path(__file__).parent / "VERSION").read_text().strip() except: version = "0.1.0" # Check if running from dev branch (detect at runtime) try: # Try to read git branch from .git/HEAD git_head_path = Path(__file__).parent / ".git" / "HEAD" if git_head_path.exists(): head_content = git_head_path.read_text().strip() if "ref: refs/heads/dev" in head_content: version = f"{version}-dev" elif head_content.startswith("ref: refs/heads/"): # Extract branch name for other branches branch = head_content.split("refs/heads/")[-1] if branch != "main": version = f"{version}-{branch}" except Exception: # If git detection fails, that's fine - use base version pass # Check for build source (only add -gitea for local Gitea builds) build_source = os.environ.get("BUILD_SOURCE", "") if build_source == "gitea": if "gitea" not in version: # Don't double-add gitea suffix version = f"{version}-gitea" app = FastAPI( title="NFOGuard", description="Webhook server for preserving media import dates", version=version ) start_time = datetime.now(timezone.utc) # Initialize components db = NFOGuardDatabase(config.db_path) nfo_manager = NFOManager(config.manager_brand, config.debug) path_mapper = PathMapper(config) # FIXED: Pass config to PathMapper tv_processor = TVProcessor(db, nfo_manager, path_mapper) movie_processor = MovieProcessor(db, nfo_manager, path_mapper) batcher = WebhookBatcher(nfo_manager) # --------------------------- # Webhook Handlers # --------------------------- async def _read_payload(request: Request) -> dict: """Read webhook payload from request""" content_type = (request.headers.get("content-type") or "").lower() try: if "application/json" in content_type: return await request.json() form = await request.form() if "payload" in form: return json.loads(form["payload"]) return dict(form) except Exception as e: _log("ERROR", f"Failed to read webhook payload: {e}") return {} @app.post("/webhook/sonarr") async def sonarr_webhook(request: Request, background_tasks: BackgroundTasks): """Handle Sonarr webhooks""" try: payload = await _read_payload(request) if not payload: raise HTTPException(status_code=422, detail="Empty Sonarr payload") webhook = SonarrWebhook(**payload) _log("INFO", f"Received Sonarr webhook: {webhook.eventType}") if webhook.eventType not in ["Download", "Upgrade", "Rename"]: return {"status": "ignored", "reason": f"Event type {webhook.eventType} not processed"} if not webhook.series: return {"status": "ignored", "reason": "No series data"} series_info = webhook.series series_title = series_info.get("title", "") imdb_id = series_info.get("imdbId", "").replace("tt", "").strip() if imdb_id: imdb_id = f"tt{imdb_id}" sonarr_path = series_info.get("path", "") if not imdb_id: _log("ERROR", f"No IMDb ID for series: {series_title}") return {"status": "error", "reason": "No IMDb ID"} # Find series path series_path = tv_processor.find_series_path(series_title, imdb_id, sonarr_path) if not series_path: _log("ERROR", f"Could not find series directory: {series_title} ({imdb_id})") return {"status": "error", "reason": "Series directory not found"} # Add to batch queue with TV-prefixed key to avoid movie conflicts tv_batch_key = f"tv:{imdb_id}" webhook_dict = { 'path': str(series_path), 'series_info': series_info, 'event_type': webhook.eventType, 'episodes': webhook.episodes or [], # Include episode data for targeted processing 'processing_mode': config.tv_webhook_processing_mode } batcher.add_webhook(tv_batch_key, webhook_dict, 'tv') return {"status": "accepted", "message": f"Sonarr webhook queued for {tv_batch_key}"} except Exception as e: _log("ERROR", f"Sonarr webhook error: {e}") raise HTTPException(status_code=422, detail=f"Invalid webhook: {e}") @app.post("/webhook/radarr") async def radarr_webhook(request: Request, background_tasks: BackgroundTasks): """Handle Radarr webhooks""" try: payload = await _read_payload(request) _log("INFO", f"Received Radarr webhook: {payload.get('eventType', 'Unknown')}") _log("DEBUG", f"Full Radarr webhook payload: {payload}") # Filter supported event types (same as Sonarr: Download, Upgrade, Rename) event_type = payload.get('eventType', '') if event_type not in ["Download", "Upgrade", "Rename"]: return {"status": "ignored", "reason": f"Event type {event_type} not processed"} # Extract movie info movie_data = payload.get("movie", {}) if not movie_data: _log("WARNING", "No movie data in Radarr webhook") return {"status": "error", "message": "No movie data"} # Get IMDb ID for batching key imdb_id = movie_data.get("imdbId", "").lower() if not imdb_id: _log("WARNING", "No IMDb ID in Radarr webhook movie data") return {"status": "error", "message": "No IMDb ID"} # Get movie path and map it movie_path = movie_data.get("folderPath") or movie_data.get("path", "") if not movie_path: _log("ERROR", "No movie path in Radarr webhook") return {"status": "error", "message": "No movie path provided"} # Map the path to container path container_path = path_mapper.radarr_path_to_container_path(movie_path) _log("DEBUG", f"Mapped Radarr path {movie_path} -> {container_path}") # CRITICAL: Verify the mapped path actually exists from pathlib import Path if not Path(container_path).exists(): _log("ERROR", f"RADARR WEBHOOK REJECTED: Mapped path does not exist: {container_path}") _log("ERROR", f"This prevents processing wrong movies due to path mapping issues") return {"status": "error", "message": f"Mapped movie path does not exist: {container_path}"} # Verify the path contains the expected IMDb ID if imdb_id not in container_path.lower(): _log("WARNING", f"IMDb ID {imdb_id} not found in container path {container_path}") # Create movie-specific webhook data with proper path validation movie_webhook_data = { 'path': container_path, # Use verified container path 'movie_info': movie_data, 'event_type': payload.get('eventType'), 'original_payload': payload } # Add to batch queue with movie-prefixed key to avoid TV conflicts movie_batch_key = f"movie:{imdb_id}" _log("DEBUG", f"Adding Radarr webhook to batch: key={movie_batch_key}, movie_title={movie_data.get('title', 'Unknown')}") batcher.add_webhook(movie_batch_key, movie_webhook_data, "movie") return {"status": "success", "message": f"Radarr webhook queued for {movie_batch_key}"} except Exception as e: _log("ERROR", f"Radarr webhook error: {e}") return {"status": "error", "message": str(e)} # --------------------------- # API Endpoints # --------------------------- @app.get("/health") async def health() -> HealthResponse: """Health check endpoint with Radarr database status""" uptime = datetime.now(timezone.utc) - start_time # Check NFOGuard database try: with db.get_connection() as conn: conn.execute("SELECT 1").fetchone() db_status = "healthy" except Exception as e: db_status = f"error: {e}" # Check Radarr database if available radarr_db_health = None overall_status = "healthy" if db_status == "healthy" else "degraded" # Get Radarr client with database access from movie processor try: if hasattr(movie_processor, 'radarr') and movie_processor.radarr: radarr_client = movie_processor.radarr if hasattr(radarr_client, 'db_client') and radarr_client.db_client: try: radarr_db_health = radarr_client.db_client.health_check() if radarr_db_health["status"] != "healthy": overall_status = "degraded" except Exception as e: radarr_db_health = { "status": "error", "error": str(e), "tested_at": datetime.now(timezone.utc).isoformat(timespec="seconds") } overall_status = "degraded" except Exception as e: # If movie processor isn't available, skip database health check _log("DEBUG", f"Skipping Radarr database health check: {e}") return HealthResponse( status=overall_status, version=version, uptime=str(uptime), database_status=db_status, radarr_database=radarr_db_health ) @app.get("/stats") async def get_stats(): """Get database statistics""" try: return db.get_stats() except Exception as e: raise HTTPException(status_code=500, detail=str(e)) @app.get("/batch/status") async def batch_status(): """Get batch queue status""" return batcher.get_status() @app.get("/debug/movie/{imdb_id}") async def debug_movie_import_date(imdb_id: str): """Debug endpoint to analyze movie import date detection""" try: if not imdb_id.startswith("tt"): imdb_id = f"tt{imdb_id}" _log("INFO", f"=== DEBUG MOVIE IMPORT DATE: {imdb_id} ===") if not (os.environ.get("RADARR_URL") and os.environ.get("RADARR_API_KEY")): return { "error": "Radarr not configured", "imdb_id": imdb_id, "radarr_configured": False } # Create Radarr client from clients.radarr_client import RadarrClient radarr_client = RadarrClient( os.environ.get("RADARR_URL"), os.environ.get("RADARR_API_KEY") ) # Look up movie movie_obj = radarr_client.movie_by_imdb(imdb_id) if not movie_obj: return { "error": f"Movie not found in Radarr for IMDb ID {imdb_id}", "imdb_id": imdb_id, "radarr_configured": True, "movie_found": False } movie_id = movie_obj.get("id") movie_title = movie_obj.get("title") _log("INFO", f"Found movie: {movie_title} (Radarr ID: {movie_id})") # Test the FULL movie processing pipeline (not just database lookup) _log("INFO", f"=== TESTING FULL MOVIE PROCESSING PIPELINE ===") # Create a dummy path for testing the decision logic from pathlib import Path dummy_path = Path("/tmp/test") try: # Use the global movie processor instance to test full decision logic global movie_processor if movie_processor: # First check external clients configuration _log("INFO", f"=== CHECKING EXTERNAL CLIENTS CONFIG ===") try: tmdb_key = os.environ.get("TMDB_API_KEY", "") _log("INFO", f"TMDB API Key configured: {'✅ YES' if tmdb_key else '❌ NO'}") if tmdb_key: _log("INFO", f"TMDB API Key length: {len(tmdb_key)} chars") # Check if external clients exist external_clients_available = hasattr(movie_processor, 'external_clients') and movie_processor.external_clients _log("INFO", f"External clients initialized: {'✅ YES' if external_clients_available else '❌ NO'}") except Exception as e: _log("ERROR", f"Error checking external clients config: {e}") # Test the full decision logic (including TMDB fallback) final_date, final_source, released = movie_processor._decide_movie_dates( imdb_id, dummy_path, should_query=True, existing=None ) _log("INFO", f"=== FULL PIPELINE RESULT ===") _log("INFO", f"Final date: {final_date}") _log("INFO", f"Final source: {final_source}") _log("INFO", f"Released (theater): {released}") return { "imdb_id": imdb_id, "radarr_configured": True, "movie_found": True, "movie_title": movie_title, "movie_id": movie_id, "full_pipeline_test": { "final_date": final_date, "final_source": final_source, "theater_release": released, "decision_logic": "✅ TESTED FULL PIPELINE INCLUDING TMDB FALLBACK" }, "database_only_test": { "radarr_db_result": radarr_client.get_movie_import_date(movie_id, fallback_to_file_date=True), "note": "This is just the database part - fallback happens in full pipeline" }, "debug_info": { "radarr_url": os.environ.get("RADARR_URL"), "movie_digital_release": movie_obj.get("digitalRelease"), "movie_in_cinemas": movie_obj.get("inCinemas"), "movie_physical_release": movie_obj.get("physicalRelease"), "movie_folder_path": movie_obj.get("folderPath") } } else: _log("ERROR", "Movie processor not available - testing database only") # Fallback to database-only testing import_date, source = radarr_client.get_movie_import_date(movie_id, fallback_to_file_date=True) return { "error": "Movie processor not available - only database test performed", "imdb_id": imdb_id, "radarr_configured": True, "movie_found": True, "movie_title": movie_title, "movie_id": movie_id, "detected_import_date": import_date, "import_source": source, "debug_info": { "note": "FULL PIPELINE TEST FAILED - movie processor not initialized" } } except Exception as pipeline_error: _log("ERROR", f"Full pipeline test failed: {pipeline_error}") # Fallback to database-only testing import_date, source = radarr_client.get_movie_import_date(movie_id, fallback_to_file_date=True) return { "pipeline_error": str(pipeline_error), "imdb_id": imdb_id, "radarr_configured": True, "movie_found": True, "movie_title": movie_title, "movie_id": movie_id, "detected_import_date": import_date, "import_source": source, "debug_info": { "note": "FULL PIPELINE TEST FAILED - showing database-only result" } } except Exception as e: _log("ERROR", f"Debug endpoint error for {imdb_id}: {e}") return { "error": str(e), "imdb_id": imdb_id, "success": False } @app.get("/debug/movie/{imdb_id}/history") async def debug_movie_history(imdb_id: str): """Detailed history analysis for a movie""" try: if not imdb_id.startswith("tt"): imdb_id = f"tt{imdb_id}" _log("INFO", f"=== DETAILED HISTORY ANALYSIS: {imdb_id} ===") # Use database-only mode for consistency if not movie_processor.radarr.db_client: return {"error": "Radarr database not configured"} radarr_client = movie_processor.radarr # Look up movie movie_obj = radarr_client.movie_by_imdb(imdb_id) if not movie_obj: return {"error": f"Movie not found for {imdb_id}"} movie_id = movie_obj.get("id") movie_title = movie_obj.get("title") # Get history from database instead of API if not radarr_client.db_client: return {"error": "Database-only mode required"} # TODO: Implement database-only history retrieval return { "error": "History endpoint temporarily disabled - use /debug/movie/{imdb_id}/priority for date analysis", "imdb_id": imdb_id, "movie_id": movie_id, "movie_title": movie_title, "note": "This endpoint needs database-only implementation to avoid showing wrong movie events" } # Analyze each event analyzed_events = [] for event in all_history: event_type = event.get("eventType", "") date_str = event.get("date", "") event_data = event.get("data", {}) # Get source path info source_path = ( event_data.get('droppedPath', '') or event_data.get('sourcePath', '') or event_data.get('path', '') or event_data.get('sourceTitle', '') ) # Analyze if this is a real import is_real, reason, date_iso = radarr_client._analyze_event_for_import(event) analyzed_events.append({ "event_type": event_type, "date": date_str, "source_path": source_path, "is_real_import": is_real, "analysis_reason": reason, "parsed_date": date_iso, "full_data": event_data }) # Find what our algorithm would pick - DATABASE ONLY picked_date, _ = radarr_client.get_movie_import_date(movie_id, fallback_to_file_date=True) return { "imdb_id": imdb_id, "movie_title": movie_title, "movie_id": movie_id, "total_history_events": len(all_history), "our_algorithm_picked": picked_date, "all_events": analyzed_events, "expected_july_date": "2025-07-07" in (picked_date or "") } except Exception as e: _log("ERROR", f"History debug error for {imdb_id}: {e}") return {"error": str(e)} @app.post("/manual/scan") async def manual_scan(background_tasks: BackgroundTasks, path: Optional[str] = None, scan_type: str = "both"): """Manual scan endpoint""" if scan_type not in ["both", "tv", "movies"]: raise HTTPException(status_code=400, detail="scan_type must be 'both', 'tv', or 'movies'") async def run_scan(): paths_to_scan = [] if path: paths_to_scan = [Path(path)] else: if scan_type in ["both", "tv"]: paths_to_scan.extend(config.tv_paths) if scan_type in ["both", "movies"]: paths_to_scan.extend(config.movie_paths) for scan_path in paths_to_scan: if not scan_path.exists(): continue if scan_type in ["both", "tv"] and (scan_path in config.tv_paths or path): # Handle specific season/episode path if path and scan_path.name.lower().startswith('season'): # Single season processing series_path = scan_path.parent if nfo_manager.parse_imdb_from_path(series_path): _log("INFO", f"Processing single season: {scan_path}") try: tv_processor.process_season(series_path, scan_path) except Exception as e: _log("ERROR", f"Failed processing season {scan_path}: {e}") elif path and scan_path.is_file() and scan_path.suffix.lower() in ('.mkv', '.mp4', '.avi'): # Single episode processing season_path = scan_path.parent series_path = season_path.parent if nfo_manager.parse_imdb_from_path(series_path): _log("INFO", f"Processing single episode: {scan_path}") try: tv_processor.process_episode_file(series_path, season_path, scan_path) except Exception as e: _log("ERROR", f"Failed processing episode {scan_path}: {e}") else: # Check if this path itself is a series (has IMDb ID in the directory name) if nfo_manager.parse_imdb_from_path(scan_path): try: tv_processor.process_series(scan_path) except Exception as e: _log("ERROR", f"Failed processing TV series {scan_path}: {e}") else: # Full series processing - scan subdirectories for item in scan_path.iterdir(): if (item.is_dir() and not item.name.lower().startswith('season') and not re.match(r'^season\s+\d+$', item.name, re.IGNORECASE) and nfo_manager.parse_imdb_from_path(item)): try: tv_processor.process_series(item) except Exception as e: _log("ERROR", f"Failed processing TV series {item}: {e}") if scan_type in ["both", "movies"] and scan_path in config.movie_paths: _log("INFO", f"Scanning movies in: {scan_path}") movie_count = 0 for item in scan_path.iterdir(): if item.is_dir() and nfo_manager.find_movie_imdb_id(item): movie_count += 1 _log("INFO", f"Processing movie: {item.name}") try: movie_processor.process_movie(item) except Exception as e: _log("ERROR", f"Failed processing movie {item}: {e}") _log("INFO", f"Completed movie scan: {movie_count} movies processed in {scan_path}") background_tasks.add_task(run_scan) return {"status": "started", "message": f"Manual {scan_type} scan started"} @app.post("/tv/scan-season") async def scan_tv_season(background_tasks: BackgroundTasks, request: TVSeasonRequest): """Scan a specific TV season - URL-safe endpoint""" try: series_dir = Path(request.series_path) season_dir = series_dir / request.season_name if not series_dir.exists(): raise HTTPException(status_code=404, detail=f"Series path not found: {request.series_path}") if not season_dir.exists(): raise HTTPException(status_code=404, detail=f"Season path not found: {season_dir}") imdb_id = nfo_manager.parse_imdb_from_path(series_dir) if not imdb_id: raise HTTPException(status_code=400, detail="No IMDb ID found in series path") async def process_season(): _log("INFO", f"Processing TV season: {season_dir}") try: tv_processor.process_season(series_dir, season_dir) except Exception as e: _log("ERROR", f"Failed processing season {season_dir}: {e}") background_tasks.add_task(process_season) return {"status": "started", "message": f"Season scan started for {request.season_name}"} except Exception as e: raise HTTPException(status_code=500, detail=str(e)) @app.post("/tv/scan-episode") async def scan_tv_episode(background_tasks: BackgroundTasks, request: TVEpisodeRequest): """Scan a specific TV episode - URL-safe endpoint""" try: series_dir = Path(request.series_path) season_dir = series_dir / request.season_name episode_file = season_dir / request.episode_name if not series_dir.exists(): raise HTTPException(status_code=404, detail=f"Series path not found: {request.series_path}") if not episode_file.exists(): raise HTTPException(status_code=404, detail=f"Episode file not found: {episode_file}") imdb_id = nfo_manager.parse_imdb_from_path(series_dir) if not imdb_id: raise HTTPException(status_code=400, detail="No IMDb ID found in series path") async def process_episode(): _log("INFO", f"Processing TV episode: {episode_file}") try: tv_processor.process_episode_file(series_dir, season_dir, episode_file) except Exception as e: _log("ERROR", f"Failed processing episode {episode_file}: {e}") background_tasks.add_task(process_episode) return {"status": "started", "message": f"Episode scan started for {request.episode_name}"} except Exception as e: raise HTTPException(status_code=500, detail=str(e)) @app.post("/test/bulk-update") async def test_bulk_update(): """Test bulk update functionality without modifying data""" try: from clients.radarr_db_client import RadarrDbClient # Test Radarr database radarr_db = RadarrDbClient.from_env() if not radarr_db: return {"status": "error", "message": "Radarr database connection failed"} # Test query execution query = 'SELECT COUNT(*) FROM "Movies" m JOIN "MovieMetadata" mm ON m."MovieMetadataId" = mm."Id" WHERE mm."ImdbId" IS NOT NULL' with radarr_db._get_connection() as conn: cursor = conn.cursor() cursor.execute(query) movie_count = cursor.fetchone()[0] return { "status": "success", "message": "Bulk update test passed", "movies_with_imdb": movie_count, "database_type": radarr_db.db_type } except Exception as e: return {"status": "error", "message": f"Bulk update test failed: {e}"} @app.post("/test/movie-scan") async def test_movie_scan(): """Test movie directory scanning logic""" try: results = [] for path in config.movie_paths: path_result = { "path": str(path), "exists": path.exists(), "movies_found": 0 } if path.exists(): for item in path.iterdir(): if item.is_dir() and nfo_manager.find_movie_imdb_id(item): path_result["movies_found"] += 1 results.append(path_result) total_movies = sum(r["movies_found"] for r in results) return { "status": "success", "message": f"Movie scan test found {total_movies} movies", "path_results": results } except Exception as e: return {"status": "error", "message": f"Movie scan test failed: {e}"} @app.post("/bulk/update") async def trigger_bulk_update(background_tasks: BackgroundTasks): """Trigger bulk update of all movies""" async def run_bulk_update(): try: from bulk_update_movies import bulk_update_all_movies success = bulk_update_all_movies() _log("INFO", f"Bulk update completed: {'success' if success else 'failed'}") except Exception as e: _log("ERROR", f"Bulk update error: {e}") background_tasks.add_task(run_bulk_update) return {"status": "started", "message": "Bulk update started"} @app.get("/debug/movie/{imdb_id}/priority") async def debug_movie_priority_logic(imdb_id: str): """Debug endpoint showing how MOVIE_PRIORITY affects date selection""" try: if not imdb_id.startswith("tt"): imdb_id = f"tt{imdb_id}" result = { "imdb_id": imdb_id, "movie_priority": config.movie_priority, "release_date_priority": config.release_date_priority, "priority_explanation": "", "date_sources": {}, "selected_date": None, "selected_source": None } # Get Radarr import date if movie_processor.radarr.api_key: radarr_movie = movie_processor.radarr.movie_by_imdb(imdb_id) if radarr_movie: movie_id = radarr_movie.get("id") if movie_id: import_date, import_source = movie_processor.radarr.get_movie_import_date(movie_id) if import_date: result["date_sources"]["radarr_import"] = { "date": import_date, "source": import_source } # Get digital release dates with detailed logging digital_date, digital_source = movie_processor._get_digital_release_date(imdb_id) if digital_date: result["date_sources"]["digital_release"] = { "date": digital_date, "source": digital_source } else: # Add debug info about why digital date wasn't found candidates = movie_processor.external_clients.get_digital_release_candidates(imdb_id) result["date_sources"]["digital_release_debug"] = { "candidates_found": len(candidates), "candidates": candidates[:3] if candidates else [], # Show first 3 "reason": digital_source if digital_source else "no_digital_dates_found" } # Show priority logic if config.movie_priority == "import_then_digital": priority_list = " → ".join(config.release_date_priority) result["priority_explanation"] = f"1st: Radarr import history, 2nd: Release dates ({priority_list}), 3rd: file mtime. Note: If import is only file date, prefer reasonable release dates." radarr_import = result["date_sources"].get("radarr_import") digital_release = result["date_sources"].get("digital_release") # Check for file date fallback logic if radarr_import and radarr_import["source"] == "radarr:db.file.dateAdded" and digital_release: # Test the smart logic would_prefer_digital = movie_processor._should_prefer_release_over_file_date( digital_release["date"], digital_release["source"], None, # We don't have theatrical date in this debug context imdb_id ) result["file_date_detected"] = True result["would_prefer_digital"] = would_prefer_digital if would_prefer_digital: result["selected_date"] = digital_release["date"] result["selected_source"] = digital_release["source"] + " (preferred over file date)" else: result["selected_date"] = radarr_import["date"] result["selected_source"] = radarr_import["source"] + " (digital too old)" elif radarr_import and radarr_import["source"] != "radarr:db.file.dateAdded": result["selected_date"] = radarr_import["date"] result["selected_source"] = radarr_import["source"] elif digital_release: result["selected_date"] = digital_release["date"] result["selected_source"] = digital_release["source"] else: # digital_then_import result["priority_explanation"] = "1st: TMDB/OMDb digital release, 2nd: Radarr import history, 3rd: file mtime" if result["date_sources"].get("digital_release"): result["selected_date"] = result["date_sources"]["digital_release"]["date"] result["selected_source"] = result["date_sources"]["digital_release"]["source"] elif result["date_sources"].get("radarr_import"): result["selected_date"] = result["date_sources"]["radarr_import"]["date"] result["selected_source"] = result["date_sources"]["radarr_import"]["source"] # Show external API status result["external_apis"] = { "tmdb_enabled": movie_processor.external_clients.tmdb.enabled, "omdb_enabled": movie_processor.external_clients.omdb.enabled, "jellyseerr_enabled": movie_processor.external_clients.jellyseerr.enabled } return result except Exception as e: return {"error": str(e), "imdb_id": imdb_id} @app.get("/debug/tmdb/{imdb_id}") async def debug_tmdb_lookup(imdb_id: str): """Debug TMDB API lookup for a specific movie""" try: if not imdb_id.startswith("tt"): imdb_id = f"tt{imdb_id}" result = { "imdb_id": imdb_id, "tmdb_api_enabled": movie_processor.external_clients.tmdb.enabled, "tmdb_api_key_configured": bool(movie_processor.external_clients.tmdb.api_key), "steps": {} } if not movie_processor.external_clients.tmdb.enabled: result["error"] = "TMDB API not enabled - check TMDB_API_KEY environment variable" return result # Step 1: Find movie by IMDb ID _log("INFO", f"TMDB Debug: Looking up {imdb_id}") tmdb_movie = movie_processor.external_clients.tmdb.find_by_imdb(imdb_id) result["steps"]["1_find_by_imdb"] = { "found": bool(tmdb_movie), "tmdb_movie": tmdb_movie if tmdb_movie else None } if not tmdb_movie: result["error"] = f"Movie {imdb_id} not found in TMDB" return result tmdb_id = tmdb_movie.get("id") result["tmdb_id"] = tmdb_id # Step 2: Get release dates if tmdb_id: _log("INFO", f"TMDB Debug: Getting release dates for TMDB ID {tmdb_id}") release_dates_result = movie_processor.external_clients.tmdb._get(f"/movie/{tmdb_id}/release_dates") result["steps"]["2_release_dates"] = { "raw_response": release_dates_result, "has_results": bool(release_dates_result and release_dates_result.get("results")) } # Step 3: Look for US digital releases if release_dates_result and release_dates_result.get("results"): us_releases = [] for country_data in release_dates_result["results"]: if country_data.get("iso_3166_1") == "US": us_releases = country_data.get("release_dates", []) break result["steps"]["3_us_releases"] = { "found_us_data": bool(us_releases), "us_releases": us_releases } # Step 4: Look for digital releases (type 4) digital_releases = [r for r in us_releases if r.get("type") == 4] result["steps"]["4_digital_releases"] = { "digital_count": len(digital_releases), "digital_releases": digital_releases } # Step 5: Test the full digital release function digital_date = movie_processor.external_clients.tmdb.get_digital_release_date(imdb_id) result["steps"]["5_final_result"] = { "digital_date": digital_date, "success": bool(digital_date) } return result except Exception as e: return {"error": str(e), "imdb_id": imdb_id, "traceback": str(e)} # --------------------------- # Main # --------------------------- def signal_handler(signum, frame): """Handle shutdown signals gracefully""" _log("INFO", f"Received signal {signum}, shutting down gracefully...") sys.exit(0) if __name__ == "__main__": # Register signal handlers for graceful shutdown signal.signal(signal.SIGTERM, signal_handler) signal.signal(signal.SIGINT, signal_handler) _log("INFO", "Starting NFOGuard") _log("INFO", f"Version: {version}") _log("INFO", f"TV paths: {[str(p) for p in config.tv_paths]}") _log("INFO", f"Movie paths: {[str(p) for p in config.movie_paths]}") _log("INFO", f"Database: {config.db_path}") _log("INFO", f"Config: manage_nfo={config.manage_nfo}, fix_mtimes={config.fix_dir_mtimes}") _log("INFO", f"Movie priority: {config.movie_priority}") try: uvicorn.run( app, host="0.0.0.0", port=int(os.environ.get("PORT", "8080")), reload=False ) except KeyboardInterrupt: _log("INFO", "NFOGuard stopped by user") except Exception as e: _log("ERROR", f"NFOGuard crashed: {e}") sys.exit(1)