From 92bd55ada19441bd5eddaa1f62a62d648e101b5e Mon Sep 17 00:00:00 2001 From: Lukas Date: Tue, 17 Mar 2026 11:39:27 +0100 Subject: [PATCH] chore: apply pending code updates --- Docker/test_vpn.py | 34 +- docs/instructions.md | 32 +- src/cli/nfo_cli.py | 275 +-- src/core/entities/SerieList.py | 24 +- src/core/entities/series.py | 10 + src/core/error_handler.py | 21 +- src/core/interfaces/callbacks.py | 8 +- src/core/providers/aniworld_provider.py | 1386 ++++++------ src/core/providers/config_manager.py | 12 +- src/core/providers/enhanced_provider.py | 1979 +++++++++-------- src/core/providers/failover.py | 2 +- src/core/providers/health_monitor.py | 6 +- src/core/services/nfo_service.py | 30 +- src/core/services/series_manager_service.py | 8 +- src/core/services/tmdb_client.py | 20 +- src/core/utils/image_downloader.py | 33 +- src/core/utils/nfo_generator.py | 2 +- .../security/config_encryption.py | 22 +- .../security/database_integrity.py | 4 +- src/infrastructure/security/file_integrity.py | 27 +- src/server/api/anime.py | 4 +- src/server/api/health.py | 8 +- src/server/api/nfo.py | 8 +- src/server/config/logging_config.py | 8 +- src/server/database/connection.py | 8 +- src/server/database/init.py | 26 +- src/server/database/service.py | 22 +- src/server/fastapi_app.py | 4 +- src/server/middleware/error_handler.py | 29 +- src/server/middleware/security.py | 12 +- src/server/services/anime_service.py | 8 +- .../services/background_loader_service.py | 58 +- src/server/services/cache_service.py | 26 +- src/server/services/config_service.py | 5 +- src/server/services/initialization_service.py | 2 +- src/server/services/notification_service.py | 16 +- src/server/utils/log_manager.py | 34 +- src/server/utils/logging.py | 4 +- src/server/utils/metrics.py | 2 +- src/server/utils/system.py | 34 +- tests/api/test_concurrent_anime_add.py | 7 +- .../performance/test_nfo_batch_performance.py | 10 +- tests/performance/test_websocket_load.py | 59 +- tests/unit/test_nfo_update_parsing.py | 28 +- tests/unit/test_parallel_anime_add.py | 9 +- 45 files changed, 2236 insertions(+), 2130 deletions(-) diff --git a/Docker/test_vpn.py b/Docker/test_vpn.py index 4e07d80..91e4511 100644 --- a/Docker/test_vpn.py +++ b/Docker/test_vpn.py @@ -18,11 +18,14 @@ Usage: sudo python3 test_vpn.py """ +import logging import subprocess import time import unittest import os +logger = logging.getLogger(__name__) + IMAGE_NAME = "vpn-wireguard-test" CONTAINER_NAME = "vpn-test-container" CONFIG_FILE = os.path.join(os.path.dirname(os.path.abspath(__file__)), "wg0.conf") @@ -63,23 +66,26 @@ class TestVPNImage(unittest.TestCase): ) # ── 1. Get host public IP before VPN ── - print("\n[setup] Fetching host public IP...") + logger.info("Fetching host public IP...") cls.host_ip = get_host_ip() - print(f"[setup] Host public IP: {cls.host_ip}") + logger.info("Host public IP: %s", cls.host_ip) assert cls.host_ip, "Could not determine host public IP" # ── 2. Build the image ── - print(f"[setup] Building image '{IMAGE_NAME}'...") + logger.info("Building image '%s'...", IMAGE_NAME) result = run( ["podman", "build", "-t", IMAGE_NAME, BUILD_DIR], timeout=180, ) - print(result.stdout[-500:] if len(result.stdout) > 500 else result.stdout) + logger.debug( + "Build output: %s", + result.stdout[-500:] if len(result.stdout) > 500 else result.stdout, + ) assert result.returncode == 0, f"Build failed:\n{result.stderr}" - print("[setup] Image built successfully.") + logger.info("Image built successfully.") # ── 3. Start the container ── - print(f"[setup] Starting container '{CONTAINER_NAME}'...") + logger.info("Starting container '%s'...", CONTAINER_NAME) result = run( [ "podman", "run", "-d", @@ -96,7 +102,7 @@ class TestVPNImage(unittest.TestCase): ) assert result.returncode == 0, f"Container failed to start:\n{result.stderr}" cls.container_id = result.stdout.strip() - print(f"[setup] Container started: {cls.container_id[:12]}") + logger.info("Container started: %s", cls.container_id[:12]) # Verify it's running inspect = run( @@ -106,17 +112,17 @@ class TestVPNImage(unittest.TestCase): assert inspect.stdout.strip() == "true", "Container is not running" # ── 4. Wait for VPN to come up ── - print(f"[setup] Waiting up to {STARTUP_TIMEOUT}s for VPN tunnel...") + logger.info("Waiting up to %d seconds for VPN tunnel...", STARTUP_TIMEOUT) vpn_up = cls._wait_for_vpn_cls(STARTUP_TIMEOUT) assert vpn_up, f"VPN did not come up within {STARTUP_TIMEOUT}s" - print("[setup] VPN tunnel is up. Running tests.\n") + logger.info("VPN tunnel is up. Running tests.") @classmethod def tearDownClass(cls): """Stop and remove the container.""" - print("\n[teardown] Cleaning up...") + logger.info("Cleaning up test container...") subprocess.run(["podman", "rm", "-f", CONTAINER_NAME], capture_output=True, check=False) - print("[teardown] Done.") + logger.info("Cleanup complete.") @classmethod def _wait_for_vpn_cls(cls, timeout: int = STARTUP_TIMEOUT) -> bool: @@ -143,8 +149,8 @@ class TestVPNImage(unittest.TestCase): def test_01_ip_differs_from_host(self): """Public IP inside VPN is different from host IP.""" vpn_ip = self._get_vpn_ip() - print(f"\n[test] VPN public IP: {vpn_ip}") - print(f"[test] Host public IP: {self.host_ip}") + logger.info("VPN public IP: %s", vpn_ip) + logger.info("Host public IP: %s", self.host_ip) self.assertTrue(vpn_ip, "Could not fetch IP from inside the container") self.assertNotEqual( @@ -178,7 +184,7 @@ class TestVPNImage(unittest.TestCase): result.returncode, 0, "Traffic went through even with WireGuard down — kill switch is NOT working!", ) - print("\n[test] Kill switch confirmed: traffic blocked with VPN down") + logger.info("Kill switch confirmed: traffic blocked with VPN down") if __name__ == "__main__": diff --git a/docs/instructions.md b/docs/instructions.md index 80ddc74..3de7c14 100644 --- a/docs/instructions.md +++ b/docs/instructions.md @@ -101,26 +101,20 @@ conda run -n AniWorld python -m uvicorn src.server.fastapi_app:app --host 127.0. For each task completed: -- [x] Implementation follows coding standards -- [x] Unit tests written and passing -- [x] Integration tests passing -- [x] Documentation updated -- [x] Error handling implemented -- [x] Logging added -- [x] Security considerations addressed -- [x] Performance validated -- [x] Code reviewed -- [x] Task marked as complete in instructions.md -- [x] Infrastructure.md updated and other docs -- [x] Changes committed to git; keep your messages in git short and clear -- [x] Take the next task +- [ ] Implementation follows coding standards +- [ ] Unit tests written and passing +- [ ] Integration tests passing +- [ ] Documentation updated +- [ ] Error handling implemented +- [ ] Logging added +- [ ] Security considerations addressed +- [ ] Performance validated +- [ ] Code reviewed +- [ ] Task marked as complete in instructions.md +- [ ] Infrastructure.md updated and other docs +- [ ] Changes committed to git; keep your messages in git short and clear +- [ ] Take the next task --- ## TODO List: - -- [x] Add a UI option to show series that have **no episodes downloaded** (i.e., series present in the library but with zero episodes). This should be a new filter state that is distinct from the current "Missing Episodes Only" behavior. -- [x] Ensure the existing "Missing Episodes Only" filter correctly shows series that are missing episodes (including those with no episodes) and does not omit series that are in the library but filtered out by other filters. -- [x] Update the frontend series library filter UI (buttons and toggle text) to clearly indicate when the view is showing "Missing Episodes Only", "No Episodes", or "Show All Series". -- [x] Update `docs/features.md` to document the new filter behavior and any new UI options. -- [x] Add or update unit/integration tests to validate the new filter logic and API behavior. diff --git a/src/cli/nfo_cli.py b/src/cli/nfo_cli.py index 308eefc..a16b736 100644 --- a/src/cli/nfo_cli.py +++ b/src/cli/nfo_cli.py @@ -5,6 +5,7 @@ and checking NFO metadata files. """ import asyncio +import logging import sys from pathlib import Path @@ -14,48 +15,50 @@ sys.path.insert(0, str(Path(__file__).parent.parent.parent)) from src.config.settings import settings from src.core.services.series_manager_service import SeriesManagerService +logger = logging.getLogger(__name__) + async def scan_and_create_nfo(): """Scan all series and create missing NFO files.""" - print("=" * 70) - print("NFO Auto-Creation Tool") - print("=" * 70) - + logger.info("%s", "=" * 70) + logger.info("NFO Auto-Creation Tool") + logger.info("%s", "=" * 70) + if not settings.tmdb_api_key: - print("\n❌ Error: TMDB_API_KEY not configured") - print(" Set TMDB_API_KEY in .env file or environment") - print(" Get API key from: https://www.themoviedb.org/settings/api") + logger.error("TMDB_API_KEY not configured") + logger.error("Set TMDB_API_KEY in .env file or environment") + logger.error("Get API key from: https://www.themoviedb.org/settings/api") return 1 if not settings.anime_directory: - print("\n❌ Error: ANIME_DIRECTORY not configured") + logger.error("ANIME_DIRECTORY not configured") return 1 - - print(f"\nAnime Directory: {settings.anime_directory}") - print(f"Auto-create NFO: {settings.nfo_auto_create}") - print(f"Update on scan: {settings.nfo_update_on_scan}") - print(f"Download poster: {settings.nfo_download_poster}") - print(f"Download logo: {settings.nfo_download_logo}") - print(f"Download fanart: {settings.nfo_download_fanart}") - + + logger.info("Anime Directory: %s", settings.anime_directory) + logger.info("Auto-create NFO: %s", settings.nfo_auto_create) + logger.info("Update on scan: %s", settings.nfo_update_on_scan) + logger.info("Download poster: %s", settings.nfo_download_poster) + logger.info("Download logo: %s", settings.nfo_download_logo) + logger.info("Download fanart: %s", settings.nfo_download_fanart) + if not settings.nfo_auto_create: - print("\n⚠️ Warning: NFO_AUTO_CREATE is set to False") - print(" Enable it in .env to auto-create NFO files") - print("\n Continuing anyway to demonstrate functionality...") + logger.warning("NFO_AUTO_CREATE is set to False") + logger.warning("Enable it in .env to auto-create NFO files") + logger.info("Continuing anyway to demonstrate functionality...") # Override for demonstration settings.nfo_auto_create = True - print("\nInitializing series manager...") + logger.info("Initializing series manager...") manager = SeriesManagerService.from_settings() - + # Get series list first serie_list = manager.get_serie_list() all_series = serie_list.get_all() - - print(f"Found {len(all_series)} series in directory") - + + logger.info("Found %d series in directory", len(all_series)) + if not all_series: - print("\n⚠️ No series found. Add some anime series first.") + logger.warning("No series found. Add some anime series first.") return 0 # Show series without NFO @@ -65,25 +68,25 @@ async def scan_and_create_nfo(): series_without_nfo.append(serie) if series_without_nfo: - print(f"\nSeries without NFO: {len(series_without_nfo)}") + logger.info("Series without NFO: %d", len(series_without_nfo)) for serie in series_without_nfo[:5]: # Show first 5 - print(f" - {serie.name} ({serie.folder})") + logger.debug("Missing NFO: %s (%s)", serie.name, serie.folder) if len(series_without_nfo) > 5: - print(f" ... and {len(series_without_nfo) - 5} more") + logger.info("... and %d more", len(series_without_nfo) - 5) else: - print("\n✅ All series already have NFO files!") - + logger.info("All series already have NFO files") + if not settings.nfo_update_on_scan: - print("\nNothing to do. Enable NFO_UPDATE_ON_SCAN to update existing NFOs.") + logger.info("Nothing to do. Enable NFO_UPDATE_ON_SCAN to update existing NFOs.") return 0 - print("\nProcessing NFO files...") - print("(This may take a while depending on the number of series)") - + logger.info("Processing NFO files...") + logger.info("This may take a while depending on the number of series") + try: await manager.scan_and_process_nfo() - print("\n✅ NFO processing complete!") - + logger.info("NFO processing complete") + # Show updated stats serie_list.load_series() # Reload to get updated stats all_series = serie_list.get_all() @@ -91,17 +94,17 @@ async def scan_and_create_nfo(): series_with_poster = [s for s in all_series if s.has_poster()] series_with_logo = [s for s in all_series if s.has_logo()] series_with_fanart = [s for s in all_series if s.has_fanart()] - - print("\nFinal Statistics:") - print(f" Series with NFO: {len(series_with_nfo)}/{len(all_series)}") - print(f" Series with poster: {len(series_with_poster)}/{len(all_series)}") - print(f" Series with logo: {len(series_with_logo)}/{len(all_series)}") - print(f" Series with fanart: {len(series_with_fanart)}/{len(all_series)}") - - except Exception as e: - print(f"\n❌ Error: {e}") - import traceback - traceback.print_exc() + + logger.info("Final statistics", extra={ + "total_series": len(all_series), + "with_nfo": len(series_with_nfo), + "with_poster": len(series_with_poster), + "with_logo": len(series_with_logo), + "with_fanart": len(series_with_fanart), + }) + + except Exception: + logger.exception("Failed to process NFO files") return 1 finally: await manager.close() @@ -111,78 +114,92 @@ async def scan_and_create_nfo(): async def check_nfo_status(): """Check NFO status for all series.""" - print("=" * 70) - print("NFO Status Check") - print("=" * 70) - + logger.info("%s", "=" * 70) + logger.info("NFO Status Check") + logger.info("%s", "=" * 70) + if not settings.anime_directory: - print("\n❌ Error: ANIME_DIRECTORY not configured") + logger.error("ANIME_DIRECTORY not configured") return 1 - - print(f"\nAnime Directory: {settings.anime_directory}") - + + logger.info("Anime Directory: %s", settings.anime_directory) + # Create series list (no NFO service needed for status check) from src.core.entities.SerieList import SerieList serie_list = SerieList(settings.anime_directory) all_series = serie_list.get_all() - + if not all_series: - print("\n⚠️ No series found") + logger.warning("No series found") return 0 - - print(f"\nTotal series: {len(all_series)}") - + + logger.info("Total series: %d", len(all_series)) + # Categorize series with_nfo = [] without_nfo = [] - + for serie in all_series: if serie.has_nfo(): with_nfo.append(serie) else: without_nfo.append(serie) - - print(f"\nWith NFO: {len(with_nfo)} ({len(with_nfo) * 100 // len(all_series)}%)") - print(f"Without NFO: {len(without_nfo)} ({len(without_nfo) * 100 // len(all_series)}%)") - + + logger.info( + "Series NFO coverage", + extra={ + "with_nfo": len(with_nfo), + "without_nfo": len(without_nfo), + "total": len(all_series), + }, + ) + if without_nfo: - print("\nSeries missing NFO:") + logger.info("Series missing NFO: %d", len(without_nfo)) for serie in without_nfo[:10]: - print(f" ❌ {serie.name} ({serie.folder})") + logger.debug("Missing NFO: %s (%s)", serie.name, serie.folder) if len(without_nfo) > 10: - print(f" ... and {len(without_nfo) - 10} more") - + logger.info("... and %d more", len(without_nfo) - 10) + # Media file statistics with_poster = sum(1 for s in all_series if s.has_poster()) with_logo = sum(1 for s in all_series if s.has_logo()) with_fanart = sum(1 for s in all_series if s.has_fanart()) - - print("\nMedia Files:") - print(f" Posters: {with_poster}/{len(all_series)} ({with_poster * 100 // len(all_series)}%)") - print(f" Logos: {with_logo}/{len(all_series)} ({with_logo * 100 // len(all_series)}%)") - print(f" Fanart: {with_fanart}/{len(all_series)} ({with_fanart * 100 // len(all_series)}%)") - + + logger.info( + "Media file coverage", + extra={ + "posters": with_poster, + "logos": with_logo, + "fanart": with_fanart, + "total": len(all_series), + }, + ) + return 0 async def update_nfo_files(): """Update existing NFO files with fresh data from TMDB.""" - print("=" * 70) - print("NFO Update Tool") - print("=" * 70) - + logger.info("%s", "=" * 70) + logger.info("NFO Update Tool") + logger.info("%s", "=" * 70) + if not settings.tmdb_api_key: - print("\n❌ Error: TMDB_API_KEY not configured") - print(" Set TMDB_API_KEY in .env file or environment") - print(" Get API key from: https://www.themoviedb.org/settings/api") + logger.error("TMDB_API_KEY not configured") + logger.error("Set TMDB_API_KEY in .env file or environment") + logger.error("Get API key from: https://www.themoviedb.org/settings/api") return 1 - + if not settings.anime_directory: - print("\n❌ Error: ANIME_DIRECTORY not configured") + logger.error("ANIME_DIRECTORY not configured") return 1 - - print(f"\nAnime Directory: {settings.anime_directory}") - print(f"Download media: {settings.nfo_download_poster or settings.nfo_download_logo or settings.nfo_download_fanart}") + + logger.info("Anime Directory: %s", settings.anime_directory) + logger.info( + "Download media: %s", + settings.nfo_download_poster or settings.nfo_download_logo or settings.nfo_download_fanart, + ) # Get series with NFO from src.core.entities.SerieList import SerieList @@ -191,57 +208,55 @@ async def update_nfo_files(): series_with_nfo = [s for s in all_series if s.has_nfo()] if not series_with_nfo: - print("\n⚠️ No series with NFO files found") - print(" Run 'scan' command first to create NFO files") + logger.warning("No series with NFO files found") + logger.info("Run 'scan' command first to create NFO files") return 0 - - print(f"\nFound {len(series_with_nfo)} series with NFO files") - print("Updating NFO files with fresh data from TMDB...") - print("(This may take a while)") - + + logger.info("Found %d series with NFO files", len(series_with_nfo)) + logger.info("Updating NFO files with fresh data from TMDB...") + logger.info("This may take a while") + # Initialize NFO service using factory from src.core.services.nfo_factory import create_nfo_service try: nfo_service = create_nfo_service() except ValueError as e: - print(f"\nError: {e}") + logger.error("Error creating NFO service: %s", e) return 1 - + success_count = 0 error_count = 0 - + try: for i, serie in enumerate(series_with_nfo, 1): - print(f"\n[{i}/{len(series_with_nfo)}] Updating: {serie.name}") - + logger.info("[%d/%d] Updating: %s", i, len(series_with_nfo), serie.name) + try: await nfo_service.update_tvshow_nfo( serie_folder=serie.folder, download_media=( - settings.nfo_download_poster or - settings.nfo_download_logo or + settings.nfo_download_poster or + settings.nfo_download_logo or settings.nfo_download_fanart - ) + ), ) - print(f" ✅ Updated successfully") + logger.info("Updated successfully: %s", serie.name) success_count += 1 - + # Small delay to respect API rate limits await asyncio.sleep(0.5) - + except Exception as e: - print(f" ❌ Error: {e}") + logger.exception("Failed to update NFO for %s", serie.name) error_count += 1 - - print("\n" + "=" * 70) - print(f"✅ Update complete!") - print(f" Success: {success_count}") - print(f" Errors: {error_count}") - - except Exception as e: - print(f"\n❌ Fatal error: {e}") - import traceback - traceback.print_exc() + + logger.info("%s", "=" * 70) + logger.info("Update complete") + logger.info("Success: %d", success_count) + logger.info("Errors: %d", error_count) + + except Exception: + logger.exception("Fatal error during NFO update") return 1 finally: await nfo_service.close() @@ -251,20 +266,22 @@ async def update_nfo_files(): def main(): """Main CLI entry point.""" + logging.basicConfig(level=logging.INFO, format="%(message)s") + if len(sys.argv) < 2: - print("NFO Management Tool") - print("\nUsage:") - print(" python -m src.cli.nfo_cli scan # Scan and create missing NFO files") - print(" python -m src.cli.nfo_cli status # Check NFO status for all series") - print(" python -m src.cli.nfo_cli update # Update existing NFO files with fresh data") - print("\nConfiguration:") - print(" Set TMDB_API_KEY in .env file") - print(" Set NFO_AUTO_CREATE=true to enable auto-creation") - print(" Set NFO_UPDATE_ON_SCAN=true to update existing NFOs during scan") + logger.info("NFO Management Tool") + logger.info("\nUsage:") + logger.info(" python -m src.cli.nfo_cli scan # Scan and create missing NFO files") + logger.info(" python -m src.cli.nfo_cli status # Check NFO status for all series") + logger.info(" python -m src.cli.nfo_cli update # Update existing NFO files with fresh data") + logger.info("\nConfiguration:") + logger.info(" Set TMDB_API_KEY in .env file") + logger.info(" Set NFO_AUTO_CREATE=true to enable auto-creation") + logger.info(" Set NFO_UPDATE_ON_SCAN=true to update existing NFOs during scan") return 1 - + command = sys.argv[1].lower() - + if command == "scan": return asyncio.run(scan_and_create_nfo()) elif command == "status": @@ -272,8 +289,8 @@ def main(): elif command == "update": return asyncio.run(update_nfo_files()) else: - print(f"Unknown command: {command}") - print("Use 'scan', 'status', or 'update'") + logger.error("Unknown command: %s", command) + logger.info("Use 'scan', 'status', or 'update'") return 1 diff --git a/src/core/entities/SerieList.py b/src/core/entities/SerieList.py index d995716..f6da8af 100644 --- a/src/core/entities/SerieList.py +++ b/src/core/entities/SerieList.py @@ -121,11 +121,11 @@ class SerieList: def load_series(self) -> None: """Populate the in-memory map with metadata discovered on disk.""" - logging.info("Scanning anime folders in %s", self.directory) + logger.info("Scanning anime folders in %s", self.directory) try: entries: Iterable[str] = os.listdir(self.directory) except OSError as error: - logging.error( + logger.error( "Unable to scan directory %s: %s", self.directory, error, @@ -145,7 +145,7 @@ class SerieList: for anime_folder in entries: anime_path = os.path.join(self.directory, anime_folder, "data") if os.path.isfile(anime_path): - logging.debug("Found data file for folder %s", anime_folder) + logger.debug("Found data file for folder %s", anime_folder) serie = self._load_data(anime_folder, anime_path) if serie: @@ -159,7 +159,7 @@ class SerieList: nfo_stats["with_nfo"] += 1 else: nfo_stats["without_nfo"] += 1 - logging.debug( + logger.debug( "Series '%s' (key: %s) is missing tvshow.nfo", serie.name, serie.key @@ -173,7 +173,7 @@ class SerieList: media_stats["with_poster"] += 1 else: media_stats["without_poster"] += 1 - logging.debug( + logger.debug( "Series '%s' (key: %s) is missing poster.jpg", serie.name, serie.key @@ -184,7 +184,7 @@ class SerieList: media_stats["with_logo"] += 1 else: media_stats["without_logo"] += 1 - logging.debug( + logger.debug( "Series '%s' (key: %s) is missing logo.png", serie.name, serie.key @@ -195,7 +195,7 @@ class SerieList: media_stats["with_fanart"] += 1 else: media_stats["without_fanart"] += 1 - logging.debug( + logger.debug( "Series '%s' (key: %s) is missing fanart.jpg", serie.name, serie.key @@ -203,20 +203,20 @@ class SerieList: continue - logging.warning( + logger.warning( "Skipping folder %s because no metadata file was found", anime_folder, ) # Log summary statistics if nfo_stats["total"] > 0: - logging.info( + logger.info( "NFO scan complete: %d series total, %d with NFO, %d without NFO", nfo_stats["total"], nfo_stats["with_nfo"], nfo_stats["without_nfo"] ) - logging.info( + logger.info( "Media scan complete: Poster (%d/%d), Logo (%d/%d), Fanart (%d/%d)", media_stats["with_poster"], nfo_stats["total"], @@ -241,14 +241,14 @@ class SerieList: serie = Serie.load_from_file(data_path) # Store by key, not folder self.keyDict[serie.key] = serie - logging.debug( + logger.debug( "Successfully loaded metadata for %s (key: %s)", anime_folder, serie.key ) return serie except (OSError, JSONDecodeError, KeyError, ValueError) as error: - logging.error( + logger.error( "Failed to load metadata for folder %s from %s: %s", anime_folder, data_path, diff --git a/src/core/entities/series.py b/src/core/entities/series.py index 7d18c8b..61ede25 100644 --- a/src/core/entities/series.py +++ b/src/core/entities/series.py @@ -64,6 +64,16 @@ class Serie: f"episodeDict={self.episodeDict}{year_str})" ) + def __repr__(self): + """Concise developer representation of Serie object.""" + season_count = len(self.episodeDict) + episode_count = sum(len(eps) for eps in self.episodeDict.values()) + year_str = f", year={self.year}" if self.year else "" + return ( + f"Serie(key={self.key!r}, name={self.name!r}" + f"{year_str}, seasons={season_count}, episodes={episode_count})" + ) + @property def key(self) -> str: """ diff --git a/src/core/error_handler.py b/src/core/error_handler.py index f1ee232..2eb66c0 100644 --- a/src/core/error_handler.py +++ b/src/core/error_handler.py @@ -55,7 +55,8 @@ class RecoveryStrategies: if attempt == max_retries - 1: raise logger.warning( - f"Network error on attempt {attempt + 1}, retrying..." + "Network error on attempt %d, retrying...", + attempt + 1, ) continue @@ -72,7 +73,8 @@ class RecoveryStrategies: if attempt == max_retries - 1: raise logger.warning( - f"Download error on attempt {attempt + 1}, retrying..." + "Download error on attempt %d, retrying...", + attempt + 1, ) continue @@ -92,7 +94,7 @@ class FileCorruptionDetector: # Video files should be at least 1MB return file_size > 1024 * 1024 except Exception as e: - logger.error(f"Error checking file validity: {e}") + logger.error("Error checking file validity: %s", e) return False @@ -123,13 +125,18 @@ def with_error_recovery( last_error = e if attempt < max_retries - 1: logger.warning( - f"Error in {context} (attempt {attempt + 1}/" - f"{max_retries}): {e}, retrying..." + "Error in %s (attempt %d/%d): %s, retrying...", + context, + attempt + 1, + max_retries, + e, ) else: logger.error( - f"Error in {context} failed after {max_retries} " - f"attempts: {e}" + "Error in %s failed after %d attempts: %s", + context, + max_retries, + e, ) if last_error: diff --git a/src/core/interfaces/callbacks.py b/src/core/interfaces/callbacks.py index 3a7837c..b16a495 100644 --- a/src/core/interfaces/callbacks.py +++ b/src/core/interfaces/callbacks.py @@ -12,6 +12,8 @@ from dataclasses import dataclass, field from enum import Enum from typing import Any, Dict, Optional +logger = logging.getLogger(__name__) + class OperationType(str, Enum): """Types of operations that can report progress.""" @@ -313,7 +315,7 @@ class CallbackManager: callback.on_progress(context) except Exception as e: # Log but don't let callback errors break the operation - logging.error( + logger.error( "Error in progress callback %s: %s", callback, e, @@ -332,7 +334,7 @@ class CallbackManager: callback.on_error(context) except Exception as e: # Log but don't let callback errors break the operation - logging.error( + logger.error( "Error in error callback %s: %s", callback, e, @@ -351,7 +353,7 @@ class CallbackManager: callback.on_completion(context) except Exception as e: # Log but don't let callback errors break the operation - logging.error( + logger.error( "Error in completion callback %s: %s", callback, e, diff --git a/src/core/providers/aniworld_provider.py b/src/core/providers/aniworld_provider.py index bfac3b3..6538f04 100644 --- a/src/core/providers/aniworld_provider.py +++ b/src/core/providers/aniworld_provider.py @@ -1,694 +1,692 @@ - -import html -import json -import logging -import os -import re -import shutil -import threading -from pathlib import Path -from urllib.parse import quote - -import requests -from bs4 import BeautifulSoup -from events import Events -from fake_useragent import UserAgent -from requests.adapters import HTTPAdapter -from urllib3.util.retry import Retry -from yt_dlp import YoutubeDL -from yt_dlp.utils import DownloadCancelled - -from ..interfaces.providers import Providers -from .base_provider import Loader - - -def _cleanup_temp_file(temp_path: str) -> None: - """Clean up a temp file and any associated partial download files. - - Removes the temp file itself and any yt-dlp partial files - (e.g. ``.part``) that may have been left behind. - - Args: - temp_path: Absolute or relative path to the temp file. - """ - paths_to_remove = [temp_path] - # yt-dlp writes partial fragments to .part - paths_to_remove.extend( - str(p) for p in Path(temp_path).parent.glob( - Path(temp_path).name + ".*" - ) - ) - for path in paths_to_remove: - if os.path.exists(path): - try: - os.remove(path) - logging.debug(f"Removed temp file: {path}") - except OSError as exc: - logging.warning(f"Failed to remove temp file {path}: {exc}") - -# Imported shared provider configuration -from .provider_config import ( - ANIWORLD_HEADERS, - DEFAULT_DOWNLOAD_TIMEOUT, - DEFAULT_PROVIDERS, - INVALID_PATH_CHARS, - LULUVDO_USER_AGENT, - ProviderType, -) - -# Configure persistent loggers but don't add duplicate handlers when module -# is imported multiple times (common in test environments). -# Use absolute paths for log files to prevent security issues - -# Determine project root (assuming this file is in src/core/providers/) -_module_dir = Path(__file__).parent -_project_root = _module_dir.parent.parent.parent -_logs_dir = _project_root / "logs" - -# Ensure logs directory exists -_logs_dir.mkdir(parents=True, exist_ok=True) - -download_error_logger = logging.getLogger("DownloadErrors") -if not download_error_logger.handlers: - log_path = _logs_dir / "download_errors.log" - download_error_handler = logging.FileHandler(str(log_path)) - download_error_handler.setLevel(logging.ERROR) - download_error_logger.addHandler(download_error_handler) - -noKeyFound_logger = logging.getLogger() - - -class AniworldLoader(Loader): - def __init__(self) -> None: - self.SUPPORTED_PROVIDERS = DEFAULT_PROVIDERS - # Copy default AniWorld headers so modifications remain local - self.AniworldHeaders = dict(ANIWORLD_HEADERS) - self.INVALID_PATH_CHARS = INVALID_PATH_CHARS - self.RANDOM_USER_AGENT = UserAgent().random - self.LULUVDO_USER_AGENT = LULUVDO_USER_AGENT - self.PROVIDER_HEADERS = { - ProviderType.VIDMOLY.value: ['Referer: "https://vidmoly.to"'], - ProviderType.DOODSTREAM.value: ['Referer: "https://dood.li/"'], - ProviderType.VOE.value: [f"User-Agent: {self.RANDOM_USER_AGENT}"], - ProviderType.LULUVDO.value: [ - f"User-Agent: {self.LULUVDO_USER_AGENT}", - "Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7", - 'Origin: "https://luluvdo.com"', - 'Referer: "https://luluvdo.com/"', - ], - } - self.ANIWORLD_TO = "https://aniworld.to" - self.session = requests.Session() - - # Cancellation flag for graceful shutdown - self._cancel_flag = threading.Event() - - # Configure retries with backoff - retries = Retry( - total=5, # Number of retries - backoff_factor=1, # Delay multiplier (1s, 2s, 4s, ...) - status_forcelist=[500, 502, 503, 504], - allowed_methods=["GET"] - ) - - adapter = HTTPAdapter(max_retries=retries) - self.session.mount("https://", adapter) - # Default HTTP request timeout used for requests.Session calls. - # Allows overriding via DOWNLOAD_TIMEOUT env var at runtime. - self.DEFAULT_REQUEST_TIMEOUT = int( - os.getenv("DOWNLOAD_TIMEOUT") or DEFAULT_DOWNLOAD_TIMEOUT - ) - - self._KeyHTMLDict = {} - self._EpisodeHTMLDict = {} - self.Providers = Providers() - - # Events: download_progress is triggered with progress dict - self.events = Events() - - def subscribe_download_progress(self, handler): - """Subscribe a handler to the download_progress event. - Args: - handler: Callable to be called with progress dict. - """ - self.events.download_progress += handler - - def unsubscribe_download_progress(self, handler): - """Unsubscribe a handler from the download_progress event. - Args: - handler: Callable previously subscribed. - """ - self.events.download_progress -= handler - - def clear_cache(self): - """Clear the cached HTML data.""" - logging.debug("Clearing HTML cache") - self._KeyHTMLDict = {} - self._EpisodeHTMLDict = {} - logging.debug("HTML cache cleared successfully") - - def remove_from_cache(self): - """Remove episode HTML from cache.""" - logging.debug("Removing episode HTML from cache") - self._EpisodeHTMLDict = {} - logging.debug("Episode HTML cache cleared") - - def search(self, word: str) -> list: - """Search for anime series. - - Args: - word: Search term - - Returns: - List of found series - """ - logging.info(f"Searching for anime with keyword: '{word}'") - search_url = ( - f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}" - ) - logging.debug(f"Search URL: {search_url}") - anime_list = self.fetch_anime_list(search_url) - logging.info(f"Found {len(anime_list)} anime series for keyword '{word}'") - - return anime_list - - def fetch_anime_list(self, url: str) -> list: - logging.debug(f"Fetching anime list from URL: {url}") - response = self.session.get(url, timeout=self.DEFAULT_REQUEST_TIMEOUT) - response.raise_for_status() - logging.debug(f"Response status code: {response.status_code}") - - clean_text = response.text.strip() - - try: - decoded_data = json.loads(html.unescape(clean_text)) - logging.debug(f"Successfully decoded JSON data on first attempt") - return decoded_data if isinstance(decoded_data, list) else [] - except json.JSONDecodeError: - logging.warning("Initial JSON decode failed, attempting cleanup") - try: - # Remove BOM and problematic characters - clean_text = clean_text.encode('utf-8').decode('utf-8-sig') - # Remove problematic characters - clean_text = re.sub(r'[\x00-\x1F\x7F-\x9F]', '', clean_text) - # Parse the new text - decoded_data = json.loads(clean_text) - logging.debug("Successfully decoded JSON after cleanup") - return decoded_data if isinstance(decoded_data, list) else [] - except (requests.RequestException, json.JSONDecodeError) as exc: - logging.error(f"Failed to decode anime list from {url}: {exc}") - raise ValueError("Could not get valid anime: ") from exc - - def _get_language_key(self, language: str) -> int: - """Convert language name to language code. - - Language Codes: - 1: German Dub - 2: English Sub - 3: German Sub - """ - language_code = 0 - if language == "German Dub": - language_code = 1 - if language == "English Sub": - language_code = 2 - if language == "German Sub": - language_code = 3 - logging.debug(f"Converted language '{language}' to code {language_code}") - return language_code - - def is_language( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub" - ) -> bool: - """Check if episode is available in specified language.""" - logging.debug(f"Checking if S{season:02}E{episode:03} ({key}) is available in {language}") - language_code = self._get_language_key(language) - - episode_soup = BeautifulSoup( - self._get_episode_html(season, episode, key).content, - 'html.parser' - ) - change_language_box_div = episode_soup.find( - 'div', class_='changeLanguageBox') - languages = [] - - if change_language_box_div: - img_tags = change_language_box_div.find_all('img') - for img in img_tags: - lang_key = img.get('data-lang-key') - if lang_key and lang_key.isdigit(): - languages.append(int(lang_key)) - - is_available = language_code in languages - logging.debug(f"Available languages for S{season:02}E{episode:03}: {languages}, requested: {language_code}, available: {is_available}") - return is_available - - def download( - self, - base_directory: str, - serie_folder: str, - season: int, - episode: int, - key: str, - language: str = "German Dub" - ) -> bool: - """Download episode to specified directory. - - Args: - base_directory: Base download directory path - serie_folder: Filesystem folder name (metadata only, used for - file path construction) - season: Season number - episode: Episode number - key: Series unique identifier from provider (used for - identification and API calls) - language: Audio language preference (default: German Dub) - Returns: - bool: True if download succeeded, False otherwise - """ - logging.info( - f"Starting download for S{season:02}E{episode:03} " - f"({key}) in {language}" - ) - sanitized_anime_title = ''.join( - char for char in self.get_title(key) - if char not in self.INVALID_PATH_CHARS - ) - logging.debug(f"Sanitized anime title: {sanitized_anime_title}") - - if season == 0: - output_file = ( - f"{sanitized_anime_title} - " - f"Movie {episode:02} - " - f"({language}).mp4" - ) - else: - output_file = ( - f"{sanitized_anime_title} - " - f"S{season:02}E{episode:03} - " - f"({language}).mp4" - ) - - folder_path = os.path.join( - os.path.join(base_directory, serie_folder), - f"Season {season}" - ) - output_path = os.path.join(folder_path, output_file) - logging.debug(f"Output path: {output_path}") - os.makedirs(os.path.dirname(output_path), exist_ok=True) - - temp_dir = "./Temp/" - os.makedirs(os.path.dirname(temp_dir), exist_ok=True) - temp_path = os.path.join(temp_dir, output_file) - logging.debug(f"Temporary path: {temp_path}") - - for provider in self.SUPPORTED_PROVIDERS: - logging.debug(f"Attempting download with provider: {provider}") - link, header = self._get_direct_link_from_provider( - season, episode, key, language - ) - logging.debug("Direct link obtained from provider") - - cancel_flag = self._cancel_flag - - def events_progress_hook(d): - if cancel_flag.is_set(): - logging.info("Cancellation detected in progress hook") - raise DownloadCancelled("Download cancelled by user") - # Fire the event for progress - self.events.download_progress(d) - - ydl_opts = { - 'fragment_retries': float('inf'), - 'outtmpl': temp_path, - 'quiet': True, - 'no_warnings': True, - 'progress_with_newline': False, - 'nocheckcertificate': True, - 'progress_hooks': [events_progress_hook], - } - - if header: - ydl_opts['http_headers'] = header - logging.debug("Using custom headers for download") - - try: - logging.debug("Starting YoutubeDL download") - logging.debug(f"Download link: {link[:100]}...") - logging.debug(f"YDL options: {ydl_opts}") - - with YoutubeDL(ydl_opts) as ydl: - info = ydl.extract_info(link, download=True) - logging.debug( - f"Download info: " - f"title={info.get('title')}, " - f"filesize={info.get('filesize')}" - ) - - if os.path.exists(temp_path): - logging.debug("Moving file from temp to final destination") - # Use copyfile instead of copy to avoid metadata permission issues - shutil.copyfile(temp_path, output_path) - os.remove(temp_path) - logging.info( - f"Download completed successfully: {output_file}" - ) - self.clear_cache() - return True - else: - logging.error( - f"Download failed: temp file not found at {temp_path}" - ) - self.clear_cache() - return False - except BrokenPipeError as e: - logging.error( - f"Broken pipe error with provider {provider}: {e}. " - f"This usually means the stream connection was closed." - ) - _cleanup_temp_file(temp_path) - continue - except Exception as e: - logging.error( - f"YoutubeDL download failed with provider {provider}: " - f"{type(e).__name__}: {e}" - ) - _cleanup_temp_file(temp_path) - continue - break - - # If we get here, all providers failed - logging.error("All download providers failed") - _cleanup_temp_file(temp_path) - self.clear_cache() - return False - - def get_site_key(self) -> str: - """Get the site key for this provider.""" - return "aniworld.to" - - def get_title(self, key: str) -> str: - """Get anime title from series key.""" - logging.debug(f"Getting title for key: {key}") - soup = BeautifulSoup( - self._get_key_html(key).content, - 'html.parser' - ) - title_div = soup.find('div', class_='series-title') - - if title_div: - h1_tag = title_div.find('h1') - span_tag = h1_tag.find('span') if h1_tag else None - if span_tag: - title = span_tag.text - logging.debug(f"Found title: {title}") - return title - - logging.warning(f"No title found for key: {key}") - return "" - - def get_year(self, key: str) -> int | None: - """Get anime release year from series key. - - Attempts to extract the year from the series page metadata. - Returns None if year cannot be determined. - - Args: - key: Series identifier - - Returns: - int or None: Release year if found, None otherwise - """ - logging.debug(f"Getting year for key: {key}") - try: - soup = BeautifulSoup( - self._get_key_html(key).content, - 'html.parser' - ) - - # Try to find year in metadata - # Check for "Jahr:" or similar metadata fields - for p_tag in soup.find_all('p'): - text = p_tag.get_text() - if 'Jahr:' in text or 'Year:' in text: - # Extract year from text like "Jahr: 2025" - match = re.search(r'(\d{4})', text) - if match: - year = int(match.group(1)) - logging.debug(f"Found year in metadata: {year}") - return year - - # Try alternative: look for year in genre/info section - info_div = soup.find('div', class_='series-info') - if info_div: - text = info_div.get_text() - match = re.search(r'\b(19\d{2}|20\d{2})\b', text) - if match: - year = int(match.group(1)) - logging.debug(f"Found year in info section: {year}") - return year - - logging.debug(f"No year found for key: {key}") - return None - - except Exception as e: - logging.warning(f"Error extracting year for key {key}: {e}") - return None - - def _get_key_html(self, key: str): - """Get cached HTML for series key. - - Args: - key: Series identifier (will be URL-encoded for safety) - - Returns: - Cached or fetched HTML response - """ - if key in self._KeyHTMLDict: - logging.debug(f"Using cached HTML for key: {key}") - return self._KeyHTMLDict[key] - - # Sanitize key parameter for URL - safe_key = quote(key, safe='') - url = f"{self.ANIWORLD_TO}/anime/stream/{safe_key}" - logging.debug(f"Fetching HTML for key: {key} from {url}") - self._KeyHTMLDict[key] = self.session.get( - url, - timeout=self.DEFAULT_REQUEST_TIMEOUT - ) - logging.debug(f"Cached HTML for key: {key}") - return self._KeyHTMLDict[key] - - def _get_episode_html(self, season: int, episode: int, key: str): - """Get cached HTML for episode. - - Args: - season: Season number (validated to be positive) - episode: Episode number (validated to be positive) - key: Series identifier (will be URL-encoded for safety) - - Returns: - Cached or fetched HTML response - - Raises: - ValueError: If season or episode are invalid - """ - # Validate season and episode numbers - if season < 1 or season > 999: - logging.error(f"Invalid season number: {season}") - raise ValueError(f"Invalid season number: {season}") - if episode < 1 or episode > 9999: - logging.error(f"Invalid episode number: {episode}") - raise ValueError(f"Invalid episode number: {episode}") - - if key in self._EpisodeHTMLDict: - logging.debug(f"Using cached HTML for S{season:02}E{episode:03} ({key})") - return self._EpisodeHTMLDict[(key, season, episode)] - - # Sanitize key parameter for URL - safe_key = quote(key, safe='') - link = ( - f"{self.ANIWORLD_TO}/anime/stream/{safe_key}/" - f"staffel-{season}/episode-{episode}" - ) - logging.debug(f"Fetching episode HTML from: {link}") - html = self.session.get(link, timeout=self.DEFAULT_REQUEST_TIMEOUT) - self._EpisodeHTMLDict[(key, season, episode)] = html - logging.debug(f"Cached episode HTML for S{season:02}E{episode:03} ({key})") - return self._EpisodeHTMLDict[(key, season, episode)] - - def _get_provider_from_html( - self, - season: int, - episode: int, - key: str - ) -> dict: - """Parse HTML content to extract streaming providers. - - Returns a dictionary with provider names as keys - and language key-to-redirect URL mappings as values. - - Example: - { - 'VOE': {1: 'https://aniworld.to/redirect/1766412', - 2: 'https://aniworld.to/redirect/1766405'}, - } - """ - logging.debug(f"Extracting providers from HTML for S{season:02}E{episode:03} ({key})") - soup = BeautifulSoup( - self._get_episode_html(season, episode, key).content, - 'html.parser' - ) - providers: dict[str, dict[int, str]] = {} - - episode_links = soup.find_all( - 'li', class_=lambda x: x and x.startswith('episodeLink') - ) - - if not episode_links: - logging.warning(f"No episode links found for S{season:02}E{episode:03} ({key})") - return providers - - for link in episode_links: - provider_name_tag = link.find('h4') - provider_name = ( - provider_name_tag.text.strip() - if provider_name_tag else None - ) - - redirect_link_tag = link.find('a', class_='watchEpisode') - redirect_link = ( - redirect_link_tag.get('href') - if redirect_link_tag else None - ) - - lang_key = link.get('data-lang-key') - lang_key = ( - int(lang_key) - if lang_key and lang_key.isdigit() else None - ) - - if provider_name and redirect_link and lang_key: - if provider_name not in providers: - providers[provider_name] = {} - providers[provider_name][lang_key] = ( - f"{self.ANIWORLD_TO}{redirect_link}" - ) - logging.debug(f"Found provider: {provider_name}, lang_key: {lang_key}") - - logging.debug(f"Total providers found: {len(providers)}") - return providers - - def _get_redirect_link( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub" - ): - """Get redirect link for episode in specified language.""" - logging.debug(f"Getting redirect link for S{season:02}E{episode:03} ({key}) in {language}") - language_code = self._get_language_key(language) - if self.is_language(season, episode, key, language): - for (provider_name, lang_dict) in ( - self._get_provider_from_html( - season, episode, key - ).items() - ): - if language_code in lang_dict: - logging.debug(f"Found redirect link with provider: {provider_name}") - return (lang_dict[language_code], provider_name) - logging.warning(f"No redirect link found for S{season:02}E{episode:03} ({key}) in {language}") - return None - - def _get_embeded_link( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub" - ): - """Get embedded link from redirect link.""" - logging.debug(f"Getting embedded link for S{season:02}E{episode:03} ({key}) in {language}") - redirect_link, provider_name = ( - self._get_redirect_link(season, episode, key, language) - ) - logging.debug(f"Redirect link: {redirect_link}, provider: {provider_name}") - - embeded_link = self.session.get( - redirect_link, - timeout=self.DEFAULT_REQUEST_TIMEOUT, - headers={'User-Agent': self.RANDOM_USER_AGENT} - ).url - logging.debug(f"Embedded link: {embeded_link}") - return embeded_link - - def _get_direct_link_from_provider( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub" - ): - """Get direct download link from streaming provider.""" - logging.debug(f"Getting direct link from provider for S{season:02}E{episode:03} ({key}) in {language}") - embeded_link = self._get_embeded_link( - season, episode, key, language - ) - if embeded_link is None: - logging.error(f"No embedded link found for S{season:02}E{episode:03} ({key})") - return None - - logging.debug(f"Using VOE provider to extract direct link") - return self.Providers.GetProvider( - "VOE" - ).get_link(embeded_link, self.DEFAULT_REQUEST_TIMEOUT) - - def get_season_episode_count(self, slug: str) -> dict: - """Get episode count for each season. - - Args: - slug: Series identifier (will be URL-encoded for safety) - - Returns: - Dictionary mapping season numbers to episode counts - """ - logging.info(f"Getting season and episode count for slug: {slug}") - # Sanitize slug parameter for URL - safe_slug = quote(slug, safe='') - base_url = f"{self.ANIWORLD_TO}/anime/stream/{safe_slug}/" - logging.debug(f"Base URL: {base_url}") - response = requests.get(base_url, timeout=self.DEFAULT_REQUEST_TIMEOUT) - soup = BeautifulSoup(response.content, 'html.parser') - - season_meta = soup.find('meta', itemprop='numberOfSeasons') - number_of_seasons = int(season_meta['content']) if season_meta else 0 - logging.info(f"Found {number_of_seasons} seasons for '{slug}'") - - episode_counts = {} - - for season in range(1, number_of_seasons + 1): - season_url = f"{base_url}staffel-{season}" - logging.debug(f"Fetching episodes for season {season} from: {season_url}") - response = requests.get( - season_url, - timeout=self.DEFAULT_REQUEST_TIMEOUT, - ) - soup = BeautifulSoup(response.content, 'html.parser') - - episode_links = soup.find_all('a', href=True) - unique_links = set( - link['href'] - for link in episode_links - if f"staffel-{season}/episode-" in link['href'] - ) - - episode_counts[season] = len(unique_links) - logging.debug(f"Season {season} has {episode_counts[season]} episodes") - - logging.info(f"Episode count retrieval complete for '{slug}': {episode_counts}") - return episode_counts + +import html +import json +import logging +import os +import re +import shutil +import threading +from pathlib import Path +from urllib.parse import quote + +import requests +from bs4 import BeautifulSoup +from events import Events +from fake_useragent import UserAgent +from requests.adapters import HTTPAdapter +from urllib3.util.retry import Retry +from yt_dlp import YoutubeDL +from yt_dlp.utils import DownloadCancelled + +from ..interfaces.providers import Providers +from .base_provider import Loader + + +def _cleanup_temp_file(temp_path: str) -> None: + """Clean up a temp file and any associated partial download files. + + Removes the temp file itself and any yt-dlp partial files + (e.g. ``.part``) that may have been left behind. + + Args: + temp_path: Absolute or relative path to the temp file. + """ + paths_to_remove = [temp_path] + # yt-dlp writes partial fragments to .part + paths_to_remove.extend( + str(p) for p in Path(temp_path).parent.glob( + Path(temp_path).name + ".*" + ) + ) + for path in paths_to_remove: + if os.path.exists(path): + try: + os.remove(path) + logger.debug("Removed temp file: %s", path) + except OSError as exc: + logger.warning("Failed to remove temp file %s: %s", path, exc) + +# Imported shared provider configuration +from .provider_config import ( + ANIWORLD_HEADERS, + DEFAULT_DOWNLOAD_TIMEOUT, + DEFAULT_PROVIDERS, + INVALID_PATH_CHARS, + LULUVDO_USER_AGENT, + ProviderType, +) + +logger = logging.getLogger(__name__) + +# Configure persistent loggers but don't add duplicate handlers when module +# is imported multiple times (common in test environments). +# Use absolute paths for log files to prevent security issues + +# Determine project root (assuming this file is in src/core/providers/) +_module_dir = Path(__file__).parent +_project_root = _module_dir.parent.parent.parent +_logs_dir = _project_root / "logs" + +# Ensure logs directory exists +_logs_dir.mkdir(parents=True, exist_ok=True) + +download_error_logger = logging.getLogger("DownloadErrors") +if not download_error_logger.handlers: + log_path = _logs_dir / "download_errors.log" + download_error_handler = logging.FileHandler(str(log_path)) + download_error_handler.setLevel(logging.ERROR) + download_error_logger.addHandler(download_error_handler) + +noKeyFound_logger = logging.getLogger() + + +class AniworldLoader(Loader): + def __init__(self) -> None: + self.SUPPORTED_PROVIDERS = DEFAULT_PROVIDERS + # Copy default AniWorld headers so modifications remain local + self.AniworldHeaders = dict(ANIWORLD_HEADERS) + self.INVALID_PATH_CHARS = INVALID_PATH_CHARS + self.RANDOM_USER_AGENT = UserAgent().random + self.LULUVDO_USER_AGENT = LULUVDO_USER_AGENT + self.PROVIDER_HEADERS = { + ProviderType.VIDMOLY.value: ['Referer: "https://vidmoly.to"'], + ProviderType.DOODSTREAM.value: ['Referer: "https://dood.li/"'], + ProviderType.VOE.value: [f"User-Agent: {self.RANDOM_USER_AGENT}"], + ProviderType.LULUVDO.value: [ + f"User-Agent: {self.LULUVDO_USER_AGENT}", + "Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7", + 'Origin: "https://luluvdo.com"', + 'Referer: "https://luluvdo.com/"', + ], + } + self.ANIWORLD_TO = "https://aniworld.to" + self.session = requests.Session() + + # Cancellation flag for graceful shutdown + self._cancel_flag = threading.Event() + + # Configure retries with backoff + retries = Retry( + total=5, # Number of retries + backoff_factor=1, # Delay multiplier (1s, 2s, 4s, ...) + status_forcelist=[500, 502, 503, 504], + allowed_methods=["GET"] + ) + + adapter = HTTPAdapter(max_retries=retries) + self.session.mount("https://", adapter) + # Default HTTP request timeout used for requests.Session calls. + # Allows overriding via DOWNLOAD_TIMEOUT env var at runtime. + self.DEFAULT_REQUEST_TIMEOUT = int( + os.getenv("DOWNLOAD_TIMEOUT") or DEFAULT_DOWNLOAD_TIMEOUT + ) + + self._KeyHTMLDict = {} + self._EpisodeHTMLDict = {} + self.Providers = Providers() + + # Events: download_progress is triggered with progress dict + self.events = Events() + + def subscribe_download_progress(self, handler): + """Subscribe a handler to the download_progress event. + Args: + handler: Callable to be called with progress dict. + """ + self.events.download_progress += handler + + def unsubscribe_download_progress(self, handler): + """Unsubscribe a handler from the download_progress event. + Args: + handler: Callable previously subscribed. + """ + self.events.download_progress -= handler + + def clear_cache(self): + """Clear the cached HTML data.""" + logger.debug("Clearing HTML cache") + self._KeyHTMLDict = {} + self._EpisodeHTMLDict = {} + logger.debug("HTML cache cleared successfully") + + def remove_from_cache(self): + """Remove episode HTML from cache.""" + logger.debug("Removing episode HTML from cache") + self._EpisodeHTMLDict = {} + logger.debug("Episode HTML cache cleared") + + def search(self, word: str) -> list: + """Search for anime series. + + Args: + word: Search term + + Returns: + List of found series + """ + logger.info("Searching for anime with keyword: '%s'", word) + search_url = ( + f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}" + ) + logger.debug("Search URL: %s", search_url) + anime_list = self.fetch_anime_list(search_url) + logger.info("Found %s anime series for keyword '%s'", len(anime_list), word) + + return anime_list + + def fetch_anime_list(self, url: str) -> list: + logger.debug("Fetching anime list from URL: %s", url) + response = self.session.get(url, timeout=self.DEFAULT_REQUEST_TIMEOUT) + response.raise_for_status() + logger.debug("Response status code: %s", response.status_code) + + clean_text = response.text.strip() + + try: + decoded_data = json.loads(html.unescape(clean_text)) + logger.debug("Successfully decoded JSON data on first attempt") + return decoded_data if isinstance(decoded_data, list) else [] + except json.JSONDecodeError: + logger.warning("Initial JSON decode failed, attempting cleanup") + try: + # Remove BOM and problematic characters + clean_text = clean_text.encode('utf-8').decode('utf-8-sig') + # Remove problematic characters + clean_text = re.sub(r'[\x00-\x1F\x7F-\x9F]', '', clean_text) + # Parse the new text + decoded_data = json.loads(clean_text) + logger.debug("Successfully decoded JSON after cleanup") + return decoded_data if isinstance(decoded_data, list) else [] + except (requests.RequestException, json.JSONDecodeError) as exc: + logger.error("Failed to decode anime list from %s: %s", url, exc) + raise ValueError("Could not get valid anime: ") from exc + + def _get_language_key(self, language: str) -> int: + """Convert language name to language code. + + Language Codes: + 1: German Dub + 2: English Sub + 3: German Sub + """ + language_code = 0 + if language == "German Dub": + language_code = 1 + if language == "English Sub": + language_code = 2 + if language == "German Sub": + language_code = 3 + logger.debug("Converted language '%s' to code %s", language, language_code) + return language_code + + def is_language( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub" + ) -> bool: + """Check if episode is available in specified language.""" + logger.debug("Checking if S%02dE%03d (%s) is available in %s", season, episode, key, language) + language_code = self._get_language_key(language) + + episode_soup = BeautifulSoup( + self._get_episode_html(season, episode, key).content, + 'html.parser' + ) + change_language_box_div = episode_soup.find( + 'div', class_='changeLanguageBox') + languages = [] + + if change_language_box_div: + img_tags = change_language_box_div.find_all('img') + for img in img_tags: + lang_key = img.get('data-lang-key') + if lang_key and lang_key.isdigit(): + languages.append(int(lang_key)) + + is_available = language_code in languages + logger.debug("Available languages for S%02dE%03d: %s, requested: %s, available: %s", season, episode, languages, language_code, is_available) + return is_available + + def download( + self, + base_directory: str, + serie_folder: str, + season: int, + episode: int, + key: str, + language: str = "German Dub" + ) -> bool: + """Download episode to specified directory. + + Args: + base_directory: Base download directory path + serie_folder: Filesystem folder name (metadata only, used for + file path construction) + season: Season number + episode: Episode number + key: Series unique identifier from provider (used for + identification and API calls) + language: Audio language preference (default: German Dub) + Returns: + bool: True if download succeeded, False otherwise + """ + logger.info( + "Starting download for S%02dE%03d (%s) in %s", + season, episode, key, language + ) + sanitized_anime_title = ''.join( + char for char in self.get_title(key) + if char not in self.INVALID_PATH_CHARS + ) + logger.debug("Sanitized anime title: %s", sanitized_anime_title) + + if season == 0: + output_file = ( + f"{sanitized_anime_title} - " + f"Movie {episode:02} - " + f"({language}).mp4" + ) + else: + output_file = ( + f"{sanitized_anime_title} - " + f"S{season:02}E{episode:03} - " + f"({language}).mp4" + ) + + folder_path = os.path.join( + os.path.join(base_directory, serie_folder), + f"Season {season}" + ) + output_path = os.path.join(folder_path, output_file) + logger.debug("Output path: %s", output_path) + os.makedirs(os.path.dirname(output_path), exist_ok=True) + + temp_dir = "./Temp/" + os.makedirs(os.path.dirname(temp_dir), exist_ok=True) + temp_path = os.path.join(temp_dir, output_file) + logger.debug("Temporary path: %s", temp_path) + + for provider in self.SUPPORTED_PROVIDERS: + logger.debug("Attempting download with provider: %s", provider) + link, header = self._get_direct_link_from_provider( + season, episode, key, language + ) + logger.debug("Direct link obtained from provider") + + cancel_flag = self._cancel_flag + + def events_progress_hook(d): + if cancel_flag.is_set(): + logger.info("Cancellation detected in progress hook") + raise DownloadCancelled("Download cancelled by user") + # Fire the event for progress + self.events.download_progress(d) + + ydl_opts = { + 'fragment_retries': float('inf'), + 'outtmpl': temp_path, + 'quiet': True, + 'no_warnings': True, + 'progress_with_newline': False, + 'nocheckcertificate': True, + 'progress_hooks': [events_progress_hook], + } + + if header: + ydl_opts['http_headers'] = header + logger.debug("Using custom headers for download") + + try: + logger.debug("Starting YoutubeDL download") + logger.debug("Download link: %s...", link[:100]) + logger.debug("YDL options: %s", ydl_opts) + + with YoutubeDL(ydl_opts) as ydl: + info = ydl.extract_info(link, download=True) + logger.debug( + "Download info: title=%s, filesize=%s", + info.get('title'), info.get('filesize') + ) + + if os.path.exists(temp_path): + logger.debug("Moving file from temp to final destination") + # Use copyfile instead of copy to avoid metadata permission issues + shutil.copyfile(temp_path, output_path) + os.remove(temp_path) + logger.info("Download completed successfully: %s", output_file) + self.clear_cache() + return True + else: + logger.error("Download failed: temp file not found at %s", temp_path) + self.clear_cache() + return False + except BrokenPipeError as e: + logger.error( + "Broken pipe error with provider %s: %s. " + "This usually means the stream connection was closed.", + provider, e + ) + _cleanup_temp_file(temp_path) + continue + except Exception as e: + logger.error( + "YoutubeDL download failed with provider %s: %s: %s", + provider, type(e).__name__, e + ) + _cleanup_temp_file(temp_path) + continue + break + + # If we get here, all providers failed + logger.error("All download providers failed") + _cleanup_temp_file(temp_path) + self.clear_cache() + return False + + def get_site_key(self) -> str: + """Get the site key for this provider.""" + return "aniworld.to" + + def get_title(self, key: str) -> str: + """Get anime title from series key.""" + logger.debug("Getting title for key: %s", key) + soup = BeautifulSoup( + self._get_key_html(key).content, + 'html.parser' + ) + title_div = soup.find('div', class_='series-title') + + if title_div: + h1_tag = title_div.find('h1') + span_tag = h1_tag.find('span') if h1_tag else None + if span_tag: + title = span_tag.text + logger.debug("Found title: %s", title) + return title + + logger.warning("No title found for key: %s", key) + return "" + + def get_year(self, key: str) -> int | None: + """Get anime release year from series key. + + Attempts to extract the year from the series page metadata. + Returns None if year cannot be determined. + + Args: + key: Series identifier + + Returns: + int or None: Release year if found, None otherwise + """ + logger.debug("Getting year for key: %s", key) + try: + soup = BeautifulSoup( + self._get_key_html(key).content, + 'html.parser' + ) + + # Try to find year in metadata + # Check for "Jahr:" or similar metadata fields + for p_tag in soup.find_all('p'): + text = p_tag.get_text() + if 'Jahr:' in text or 'Year:' in text: + # Extract year from text like "Jahr: 2025" + match = re.search(r'(\d{4})', text) + if match: + year = int(match.group(1)) + logger.debug("Found year in metadata: %s", year) + return year + + # Try alternative: look for year in genre/info section + info_div = soup.find('div', class_='series-info') + if info_div: + text = info_div.get_text() + match = re.search(r'\b(19\d{2}|20\d{2})\b', text) + if match: + year = int(match.group(1)) + logger.debug("Found year in info section: %s", year) + return year + + logger.debug("No year found for key: %s", key) + return None + + except Exception as e: + logger.warning("Error extracting year for key %s: %s", key, e) + return None + + def _get_key_html(self, key: str): + """Get cached HTML for series key. + + Args: + key: Series identifier (will be URL-encoded for safety) + + Returns: + Cached or fetched HTML response + """ + if key in self._KeyHTMLDict: + logger.debug("Using cached HTML for key: %s", key) + return self._KeyHTMLDict[key] + + # Sanitize key parameter for URL + safe_key = quote(key, safe='') + url = f"{self.ANIWORLD_TO}/anime/stream/{safe_key}" + logger.debug("Fetching HTML for key: %s from %s", key, url) + self._KeyHTMLDict[key] = self.session.get( + url, + timeout=self.DEFAULT_REQUEST_TIMEOUT + ) + logger.debug("Cached HTML for key: %s", key) + return self._KeyHTMLDict[key] + + def _get_episode_html(self, season: int, episode: int, key: str): + """Get cached HTML for episode. + + Args: + season: Season number (validated to be positive) + episode: Episode number (validated to be positive) + key: Series identifier (will be URL-encoded for safety) + + Returns: + Cached or fetched HTML response + + Raises: + ValueError: If season or episode are invalid + """ + # Validate season and episode numbers + if season < 1 or season > 999: + logger.error("Invalid season number: %s", season) + raise ValueError(f"Invalid season number: {season}") + if episode < 1 or episode > 9999: + logger.error("Invalid episode number: %s", episode) + raise ValueError(f"Invalid episode number: {episode}") + + if key in self._EpisodeHTMLDict: + logger.debug("Using cached HTML for S%02dE%03d (%s)", season, episode, key) + return self._EpisodeHTMLDict[(key, season, episode)] + + # Sanitize key parameter for URL + safe_key = quote(key, safe='') + link = ( + f"{self.ANIWORLD_TO}/anime/stream/{safe_key}/" + f"staffel-{season}/episode-{episode}" + ) + logger.debug("Fetching episode HTML from: %s", link) + html = self.session.get(link, timeout=self.DEFAULT_REQUEST_TIMEOUT) + self._EpisodeHTMLDict[(key, season, episode)] = html + logger.debug("Cached episode HTML for S%02dE%03d (%s)", season, episode, key) + return self._EpisodeHTMLDict[(key, season, episode)] + + def _get_provider_from_html( + self, + season: int, + episode: int, + key: str + ) -> dict: + """Parse HTML content to extract streaming providers. + + Returns a dictionary with provider names as keys + and language key-to-redirect URL mappings as values. + + Example: + { + 'VOE': {1: 'https://aniworld.to/redirect/1766412', + 2: 'https://aniworld.to/redirect/1766405'}, + } + """ + logger.debug("Extracting providers from HTML for S%02dE%03d (%s)", season, episode, key) + soup = BeautifulSoup( + self._get_episode_html(season, episode, key).content, + 'html.parser' + ) + providers: dict[str, dict[int, str]] = {} + + episode_links = soup.find_all( + 'li', class_=lambda x: x and x.startswith('episodeLink') + ) + + if not episode_links: + logger.warning("No episode links found for S%02dE%03d (%s)", season, episode, key) + return providers + + for link in episode_links: + provider_name_tag = link.find('h4') + provider_name = ( + provider_name_tag.text.strip() + if provider_name_tag else None + ) + + redirect_link_tag = link.find('a', class_='watchEpisode') + redirect_link = ( + redirect_link_tag.get('href') + if redirect_link_tag else None + ) + + lang_key = link.get('data-lang-key') + lang_key = ( + int(lang_key) + if lang_key and lang_key.isdigit() else None + ) + + if provider_name and redirect_link and lang_key: + if provider_name not in providers: + providers[provider_name] = {} + providers[provider_name][lang_key] = ( + f"{self.ANIWORLD_TO}{redirect_link}" + ) + logger.debug("Found provider: %s, lang_key: %s", provider_name, lang_key) + + logger.debug("Total providers found: %s", len(providers)) + return providers + + def _get_redirect_link( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub" + ): + """Get redirect link for episode in specified language.""" + logger.debug("Getting redirect link for S%02dE%03d (%s) in %s", season, episode, key, language) + language_code = self._get_language_key(language) + if self.is_language(season, episode, key, language): + for (provider_name, lang_dict) in ( + self._get_provider_from_html( + season, episode, key + ).items() + ): + if language_code in lang_dict: + logger.debug("Found redirect link with provider: %s", provider_name) + return (lang_dict[language_code], provider_name) + logger.warning("No redirect link found for S%02dE%03d (%s) in %s", season, episode, key, language) + return None + + def _get_embeded_link( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub" + ): + """Get embedded link from redirect link.""" + logger.debug("Getting embedded link for S%02dE%03d (%s) in %s", season, episode, key, language) + redirect_link, provider_name = ( + self._get_redirect_link(season, episode, key, language) + ) + logger.debug("Redirect link: %s, provider: %s", redirect_link, provider_name) + + embeded_link = self.session.get( + redirect_link, + timeout=self.DEFAULT_REQUEST_TIMEOUT, + headers={'User-Agent': self.RANDOM_USER_AGENT} + ).url + logger.debug("Embedded link: %s", embeded_link) + return embeded_link + + def _get_direct_link_from_provider( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub" + ): + """Get direct download link from streaming provider.""" + logger.debug("Getting direct link from provider for S%02dE%03d (%s) in %s", season, episode, key, language) + embeded_link = self._get_embeded_link( + season, episode, key, language + ) + if embeded_link is None: + logger.error("No embedded link found for S%02dE%03d (%s)", season, episode, key) + return None + + logger.debug("Using VOE provider to extract direct link") + return self.Providers.GetProvider( + "VOE" + ).get_link(embeded_link, self.DEFAULT_REQUEST_TIMEOUT) + + def get_season_episode_count(self, slug: str) -> dict: + """Get episode count for each season. + + Args: + slug: Series identifier (will be URL-encoded for safety) + + Returns: + Dictionary mapping season numbers to episode counts + """ + logger.info("Getting season and episode count for slug: %s", slug) + # Sanitize slug parameter for URL + safe_slug = quote(slug, safe='') + base_url = f"{self.ANIWORLD_TO}/anime/stream/{safe_slug}/" + logger.debug("Base URL: %s", base_url) + response = requests.get(base_url, timeout=self.DEFAULT_REQUEST_TIMEOUT) + soup = BeautifulSoup(response.content, 'html.parser') + + season_meta = soup.find('meta', itemprop='numberOfSeasons') + number_of_seasons = int(season_meta['content']) if season_meta else 0 + logger.info("Found %s seasons for '%s'", number_of_seasons, slug) + + episode_counts = {} + + for season in range(1, number_of_seasons + 1): + season_url = f"{base_url}staffel-{season}" + logger.debug("Fetching episodes for season %s from: %s", season, season_url) + response = requests.get( + season_url, + timeout=self.DEFAULT_REQUEST_TIMEOUT, + ) + soup = BeautifulSoup(response.content, 'html.parser') + + episode_links = soup.find_all('a', href=True) + unique_links = set( + link['href'] + for link in episode_links + if f"staffel-{season}/episode-" in link['href'] + ) + + episode_counts[season] = len(unique_links) + logger.debug("Season %s has %s episodes", season, episode_counts[season]) + + logger.info("Episode count retrieval complete for '%s': %s", slug, episode_counts) + return episode_counts diff --git a/src/core/providers/config_manager.py b/src/core/providers/config_manager.py index 1d5fafb..06b65d5 100644 --- a/src/core/providers/config_manager.py +++ b/src/core/providers/config_manager.py @@ -87,7 +87,7 @@ class ProviderConfigManager: settings: Provider settings to apply. """ self._provider_settings[provider_name] = settings - logger.info(f"Updated settings for provider: {provider_name}") + logger.info("Updated settings for provider: %s", provider_name) def update_provider_settings( self, provider_name: str, **kwargs @@ -106,7 +106,7 @@ class ProviderConfigManager: self._provider_settings[provider_name] = ProviderSettings( name=provider_name, **kwargs ) - logger.info(f"Created new settings for provider: {provider_name}") # noqa: E501 + logger.info("Created new settings for provider: %s", provider_name) # noqa: E501 return True settings = self._provider_settings[provider_name] @@ -152,7 +152,7 @@ class ProviderConfigManager: """ if provider_name in self._provider_settings: self._provider_settings[provider_name].enabled = True - logger.info(f"Enabled provider: {provider_name}") + logger.info("Enabled provider: %s", provider_name) return True return False @@ -167,7 +167,7 @@ class ProviderConfigManager: """ if provider_name in self._provider_settings: self._provider_settings[provider_name].enabled = False - logger.info(f"Disabled provider: {provider_name}") + logger.info("Disabled provider: %s", provider_name) return True return False @@ -224,7 +224,7 @@ class ProviderConfigManager: value: Setting value. """ self._global_settings[key] = value - logger.info(f"Updated global setting {key}: {value}") + logger.info("Updated global setting %s: %s", key, value) def get_all_global_settings(self) -> Dict[str, Any]: """Get all global settings. @@ -307,7 +307,7 @@ class ProviderConfigManager: with open(config_path, "w", encoding="utf-8") as f: json.dump(data, f, indent=2) - logger.info(f"Saved configuration to {config_path}") + logger.info("Saved configuration to %s", config_path) return True except Exception as e: diff --git a/src/core/providers/enhanced_provider.py b/src/core/providers/enhanced_provider.py index 34ad3d7..8679691 100644 --- a/src/core/providers/enhanced_provider.py +++ b/src/core/providers/enhanced_provider.py @@ -1,988 +1,991 @@ -""" -Enhanced AniWorld Loader with Error Handling and Recovery - -This module extends the original AniWorldLoader with comprehensive -error handling, retry mechanisms, and recovery strategies. -""" - -import html -import json -import logging -import os -import re -import shutil -from pathlib import Path -from typing import Any, Callable, Dict, Optional -from urllib.parse import quote - -import requests -from bs4 import BeautifulSoup -from fake_useragent import UserAgent -from requests.adapters import HTTPAdapter -from urllib3.util.retry import Retry -from yt_dlp import YoutubeDL - -from ...infrastructure.security.file_integrity import get_integrity_manager -from ..error_handler import ( - DownloadError, - NetworkError, - NonRetryableError, - RetryableError, - file_corruption_detector, - recovery_strategies, - with_error_recovery, -) -from ..interfaces.providers import Providers -from .base_provider import Loader -from .provider_config import ( - ANIWORLD_HEADERS, - DEFAULT_PROVIDERS, - INVALID_PATH_CHARS, - LULUVDO_USER_AGENT, - ProviderType, -) - - -def _cleanup_temp_file( - temp_path: str, - logger: Optional[logging.Logger] = None, -) -> None: - """Remove a temp file and any associated yt-dlp partial files. - - Args: - temp_path: Path to the primary temp file. - logger: Optional logger for diagnostic messages. - """ - _log = logger or logging.getLogger(__name__) - candidates = [temp_path] - # yt-dlp creates fragment files like .part - candidates.extend( - str(p) for p in Path(temp_path).parent.glob( - Path(temp_path).name + ".*" - ) - ) - for path in candidates: - if os.path.exists(path): - try: - os.remove(path) - _log.debug(f"Removed temp file: {path}") - except OSError as exc: - _log.warning(f"Failed to remove temp file {path}: {exc}") - - -class EnhancedAniWorldLoader(Loader): - """Aniworld provider with retry and recovery strategies. - - Also exposes metrics hooks for download statistics. - """ - - def __init__(self) -> None: - super().__init__() - self.logger = logging.getLogger(__name__) - self.SUPPORTED_PROVIDERS = DEFAULT_PROVIDERS - # local copy so modifications don't mutate shared constant - self.AniworldHeaders = dict(ANIWORLD_HEADERS) - self.INVALID_PATH_CHARS = INVALID_PATH_CHARS - self.RANDOM_USER_AGENT = UserAgent().random - self.LULUVDO_USER_AGENT = LULUVDO_USER_AGENT - - self.PROVIDER_HEADERS = { - ProviderType.VIDMOLY.value: ['Referer: "https://vidmoly.to"'], - ProviderType.DOODSTREAM.value: ['Referer: "https://dood.li/"'], - ProviderType.VOE.value: [f'User-Agent: {self.RANDOM_USER_AGENT}'], - ProviderType.LULUVDO.value: [ - f'User-Agent: {self.LULUVDO_USER_AGENT}', - "Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7", - 'Origin: "https://luluvdo.com"', - 'Referer: "https://luluvdo.com/"', - ], - } - - self.ANIWORLD_TO = "https://aniworld.to" - self.DEFAULT_REQUEST_TIMEOUT = 30 - - # Initialize session with enhanced retry configuration - self.session = self._create_robust_session() - - # Cache dictionaries - self._KeyHTMLDict = {} - self._EpisodeHTMLDict = {} - - # Provider manager - self.Providers = Providers() - - # Download statistics - self.download_stats = { - 'total_downloads': 0, - 'successful_downloads': 0, - 'failed_downloads': 0, - 'retried_downloads': 0 - } - - # Read timeout from environment variable (string->int safely) - self.download_timeout = int(os.getenv("DOWNLOAD_TIMEOUT") or "600") - - # Setup logging - self._setup_logging() - - def _create_robust_session(self) -> requests.Session: - """Create a session with robust retry and error handling - configuration. - """ - session = requests.Session() - - # Configure retries so transient network problems are retried while we - # still fail fast on permanent errors. The status codes cover - # timeouts, rate limits, and the Cloudflare-origin 52x responses that - # AniWorld occasionally emits under load. - retries = Retry( - total=5, - backoff_factor=2, # More aggressive backoff - status_forcelist=[ - 408, - 429, - 500, - 502, - 503, - 504, - 520, - 521, - 522, - 523, - 524, - ], - allowed_methods=["GET", "POST", "HEAD"], - raise_on_status=False, # Handle status errors manually - ) - - adapter = HTTPAdapter( - max_retries=retries, - pool_connections=10, - pool_maxsize=20, - pool_block=True - ) - - session.mount("https://", adapter) - session.mount("http://", adapter) - - # Set default headers - session.headers.update(self.AniworldHeaders) - - return session - - def _setup_logging(self): - """Setup specialized logging for download errors and missing keys.""" - # Download error logger - self.download_error_logger = logging.getLogger("DownloadErrors") - download_error_handler = logging.FileHandler( - "../../download_errors.log" - ) - download_error_handler.setLevel(logging.ERROR) - download_error_formatter = logging.Formatter( - '%(asctime)s - %(name)s - %(levelname)s - %(message)s' - ) - download_error_handler.setFormatter(download_error_formatter) - - if not self.download_error_logger.handlers: - self.download_error_logger.addHandler(download_error_handler) - self.download_error_logger.setLevel(logging.ERROR) - - # No key found logger - self.nokey_logger = logging.getLogger("NoKeyFound") - nokey_handler = logging.FileHandler("../../NoKeyFound.log") - nokey_handler.setLevel(logging.ERROR) - nokey_handler.setFormatter(download_error_formatter) - - if not self.nokey_logger.handlers: - self.nokey_logger.addHandler(nokey_handler) - self.nokey_logger.setLevel(logging.ERROR) - - def ClearCache(self): - """Clear all cached data.""" - self._KeyHTMLDict.clear() - self._EpisodeHTMLDict.clear() - self.logger.debug("Cache cleared") - - def RemoveFromCache(self): - """Remove episode HTML cache.""" - self._EpisodeHTMLDict.clear() - self.logger.debug("Episode cache cleared") - - @with_error_recovery(max_retries=3, context="anime_search") - def Search(self, word: str) -> list: - """Search for anime with error handling.""" - if not word or not word.strip(): - raise ValueError("Search term cannot be empty") - - search_url = ( - f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}" - ) - - try: - return self._fetch_anime_list_with_recovery(search_url) - except Exception as e: - self.logger.error(f"Search failed for term '{word}': {e}") - raise RetryableError(f"Search failed: {e}") from e - - def _fetch_anime_list_with_recovery(self, url: str) -> list: - """Fetch anime list with comprehensive error handling.""" - try: - response = recovery_strategies.handle_network_failure( - self.session.get, - url, - timeout=self.DEFAULT_REQUEST_TIMEOUT - ) - - if not response.ok: - if response.status_code == 404: - raise NonRetryableError(f"URL not found: {url}") - elif response.status_code == 403: - raise NonRetryableError(f"Access forbidden: {url}") - elif response.status_code >= 500: - # Log suspicious server errors for monitoring - self.logger.warning( - f"Server error {response.status_code} from {url} " - f"- will retry" - ) - raise RetryableError(f"Server error {response.status_code}") - else: - raise RetryableError(f"HTTP error {response.status_code}") - - return self._parse_anime_response(response.text) - - except (requests.RequestException, ConnectionError) as e: - raise NetworkError(f"Network error during anime search: {e}") from e - - def _parse_anime_response(self, response_text: str) -> list: - """Parse anime search response with error handling.""" - if not response_text or not response_text.strip(): - raise ValueError("Empty response from server") - - clean_text = response_text.strip() - - # Quick fail for obviously non-JSON responses - if not (clean_text.startswith('[') or clean_text.startswith('{')): - # Check if it's HTML error page - if clean_text.lower().startswith(' int: - """Get numeric language code.""" - language_map = { - "German Dub": 1, - "English Sub": 2, - "German Sub": 3, - } - return language_map.get(language, 0) - - @with_error_recovery(max_retries=2, context="language_check") - def IsLanguage( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub", - ) -> bool: - """Check if episode is available in specified language.""" - try: - languageCode = self._GetLanguageKey(language) - if languageCode == 0: - raise ValueError(f"Unknown language: {language}") - - episode_response = self._GetEpisodeHTML(season, episode, key) - soup = BeautifulSoup(episode_response.content, "html.parser") - - lang_box = soup.find("div", class_="changeLanguageBox") - if not lang_box: - debug_msg = ( - f"No language box found for {key} S{season}E{episode}" - ) - self.logger.debug(debug_msg) - return False - - img_tags = lang_box.find_all("img") - available_languages = [] - - for img in img_tags: - lang_key = img.get("data-lang-key") - if lang_key and lang_key.isdigit(): - available_languages.append(int(lang_key)) - - is_available = languageCode in available_languages - debug_msg = ( - f"Language check for {key} S{season}E{episode}: " - f"Requested={languageCode}, " - f"Available={available_languages}, " - f"Result={is_available}" - ) - self.logger.debug(debug_msg) - - return is_available - - except Exception as e: - error_msg = ( - f"Language check failed for {key} S{season}E{episode}: {e}" - ) - self.logger.error(error_msg) - raise RetryableError(f"Language check failed: {e}") from e - - def Download( - self, - baseDirectory: str, - serieFolder: str, - season: int, - episode: int, - key: str, - language: str = "German Dub", - progress_callback: Optional[Callable] = None, - ) -> bool: - """Download episode with comprehensive error handling. - - Args: - baseDirectory: Base download directory path - serieFolder: Filesystem folder name (metadata only, used for - file path construction) - season: Season number (0 for movies) - episode: Episode number - key: Series unique identifier from provider (used for - identification and API calls) - language: Audio language preference (default: German Dub) - progress_callback: Optional callback for download progress - updates - - Returns: - bool: True if download succeeded, False otherwise - - Raises: - DownloadError: If download fails after all retry attempts - ValueError: If required parameters are missing or invalid - """ - self.download_stats["total_downloads"] += 1 - - try: - # Validate inputs - if not all([baseDirectory, serieFolder, key]): - raise ValueError("Missing required parameters for download") - - if season < 0 or episode < 0: - raise ValueError("Season and episode must be non-negative") - - # Prepare file paths - sanitized_anime_title = "".join( - char - for char in self.GetTitle(key) - if char not in self.INVALID_PATH_CHARS - ) - - if not sanitized_anime_title: - sanitized_anime_title = f"Unknown_{key}" - - # Generate output filename - if season == 0: - output_file = ( - f"{sanitized_anime_title} - Movie {episode:02} - " - f"({language}).mp4" - ) - else: - output_file = ( - f"{sanitized_anime_title} - S{season:02}E{episode:03} - " - f"({language}).mp4" - ) - - # Create directory structure - folder_path = os.path.join( - baseDirectory, serieFolder, f"Season {season}" - ) - output_path = os.path.join(folder_path, output_file) - - # Check if file already exists and is valid - if os.path.exists(output_path): - is_valid = file_corruption_detector.is_valid_video_file( - output_path - ) - - # Also verify checksum if available - integrity_mgr = get_integrity_manager() - checksum_valid = True - if integrity_mgr.has_checksum(Path(output_path)): - checksum_valid = integrity_mgr.verify_checksum( - Path(output_path) - ) - if not checksum_valid: - self.logger.warning( - f"Checksum verification failed for {output_file}" - ) - - if is_valid and checksum_valid: - msg = ( - f"File already exists and is valid: " - f"{output_file}" - ) - self.logger.info(msg) - self.download_stats["successful_downloads"] += 1 - return True - else: - warning_msg = ( - f"Existing file appears corrupted, removing: " - f"{output_path}" - ) - self.logger.warning(warning_msg) - try: - os.remove(output_path) - # Remove checksum entry - integrity_mgr.remove_checksum(Path(output_path)) - except OSError as e: - error_msg = f"Failed to remove corrupted file: {e}" - self.logger.error(error_msg) - - os.makedirs(folder_path, exist_ok=True) - - # Create temp directory - temp_dir = "./Temp/" - os.makedirs(temp_dir, exist_ok=True) - temp_path = os.path.join(temp_dir, output_file) - - # Attempt download with recovery strategies - success = self._download_with_recovery( - season, - episode, - key, - language, - temp_path, - output_path, - progress_callback, - ) - - if success: - self.download_stats["successful_downloads"] += 1 - success_msg = f"Successfully downloaded: {output_file}" - self.logger.info(success_msg) - else: - self.download_stats["failed_downloads"] += 1 - fail_msg = ( - f"Download failed for {key} S{season}E{episode} " - f"({language})" - ) - self.download_error_logger.error(fail_msg) - - return success - - except Exception as e: - self.download_stats["failed_downloads"] += 1 - err_msg = ( - f"Download error for {key} S{season}E{episode}: {e}" - ) - self.download_error_logger.error(err_msg, exc_info=True) - raise DownloadError(f"Download failed: {e}") from e - finally: - self.ClearCache() - - def _download_with_recovery( - self, - season: int, - episode: int, - key: str, - language: str, - temp_path: str, - output_path: str, - progress_callback: Optional[Callable], - ) -> bool: - """Attempt download with multiple providers and recovery.""" - - for provider_name in self.SUPPORTED_PROVIDERS: - try: - info_msg = ( - f"Attempting download with provider: {provider_name}" - ) - self.logger.info(info_msg) - - # Get download link and headers for provider - link, headers = recovery_strategies.handle_network_failure( - self._get_direct_link_from_provider, - season, - episode, - key, - language, - ) - - if not link: - warn_msg = ( - f"No download link found for provider: " - f"{provider_name}" - ) - self.logger.warning(warn_msg) - continue - - # Configure yt-dlp options - ydl_opts = { - "fragment_retries": float("inf"), - "outtmpl": temp_path, - "quiet": True, - "no_warnings": True, - "progress_with_newline": False, - "nocheckcertificate": True, - "socket_timeout": self.download_timeout, - "http_chunk_size": 1024 * 1024, # 1MB chunks - } - if headers: - ydl_opts['http_headers'] = headers - - if progress_callback: - ydl_opts['progress_hooks'] = [progress_callback] - - # Perform download with recovery - success = recovery_strategies.handle_download_failure( - self._perform_ytdl_download, - temp_path, - ydl_opts, - link - ) - - if success and os.path.exists(temp_path): - # Verify downloaded file - if file_corruption_detector.is_valid_video_file(temp_path): - # Move to final location - # Use copyfile instead of copy2 to avoid metadata permission issues - shutil.copyfile(temp_path, output_path) - - # Calculate and store checksum for integrity - integrity_mgr = get_integrity_manager() - try: - checksum = integrity_mgr.store_checksum( - Path(output_path) - ) - filename = Path(output_path).name - self.logger.info( - f"Stored checksum for {filename}: " - f"{checksum[:16]}..." - ) - except Exception as e: - self.logger.warning( - f"Failed to store checksum: {e}" - ) - - # Clean up temp file - try: - os.remove(temp_path) - except Exception as e: - warn_msg = f"Failed to remove temp file: {e}" - self.logger.warning(warn_msg) - - return True - else: - warn_msg = ( - f"Downloaded file failed validation: " - f"{temp_path}" - ) - self.logger.warning(warn_msg) - try: - os.remove(temp_path) - except OSError as e: - warn_msg = f"Failed to remove temp file: {e}" - self.logger.warning(warn_msg) - - except Exception as e: - self.logger.warning(f"Provider {provider_name} failed: {e}") - # Clean up any partial temp files left by this failed attempt - _cleanup_temp_file(temp_path, self.logger) - self.download_stats['retried_downloads'] += 1 - continue - - # All providers failed – make sure no temp remnants are left behind - _cleanup_temp_file(temp_path, self.logger) - return False - - def _perform_ytdl_download( - self, ydl_opts: Dict[str, Any], link: str - ) -> bool: - """Perform actual download using yt-dlp.""" - try: - with YoutubeDL(ydl_opts) as ydl: - ydl.download([link]) - return True - except Exception as e: - self.logger.error(f"yt-dlp download failed: {e}") - raise DownloadError(f"Download failed: {e}") from e - - @with_error_recovery(max_retries=2, context="get_title") - def GetTitle(self, key: str) -> str: - """Get anime title with error handling.""" - try: - soup = BeautifulSoup(self._GetKeyHTML(key).content, 'html.parser') - title_div = soup.find('div', class_='series-title') - - if title_div: - title_span = title_div.find('h1') - if title_span: - span = title_span.find('span') - if span: - return span.text.strip() - - self.logger.warning(f"Could not extract title for key: {key}") - return f"Unknown_Title_{key}" - - except Exception as e: - self.logger.error(f"Failed to get title for key {key}: {e}") - raise RetryableError(f"Title extraction failed: {e}") from e - - def GetSiteKey(self) -> str: - """Get site identifier.""" - return "aniworld.to" - - @with_error_recovery(max_retries=2, context="get_key_html") - def _GetKeyHTML(self, key: str): - """Get cached HTML for anime key.""" - if key in self._KeyHTMLDict: - return self._KeyHTMLDict[key] - - try: - url = f"{self.ANIWORLD_TO}/anime/stream/{key}" - response = recovery_strategies.handle_network_failure( - self.session.get, - url, - timeout=self.DEFAULT_REQUEST_TIMEOUT - ) - - if not response.ok: - if response.status_code == 404: - msg = f"Anime key not found: {key}" - self.nokey_logger.error(msg) - raise NonRetryableError(msg) - else: - err_msg = ( - f"HTTP error {response.status_code} for key {key}" - ) - raise RetryableError(err_msg) - - self._KeyHTMLDict[key] = response - return self._KeyHTMLDict[key] - - except Exception as e: - error_msg = f"Failed to get HTML for key {key}: {e}" - self.logger.error(error_msg) - raise - - @with_error_recovery(max_retries=2, context="get_episode_html") - def _GetEpisodeHTML(self, season: int, episode: int, key: str): - """Get cached HTML for specific episode. - - Args: - season: Season number (must be 1-999) - episode: Episode number (must be 1-9999) - key: Series identifier (should be non-empty) - - Returns: - Cached or fetched HTML response - - Raises: - ValueError: If parameters are invalid - NonRetryableError: If episode not found (404) - RetryableError: If HTTP error occurs - """ - # Validate parameters - if not key or not key.strip(): - raise ValueError("Series key cannot be empty") - if season < 1 or season > 999: - raise ValueError( - f"Invalid season number: {season} (must be 1-999)" - ) - if episode < 1 or episode > 9999: - raise ValueError( - f"Invalid episode number: {episode} (must be 1-9999)" - ) - - cache_key = (key, season, episode) - if cache_key in self._EpisodeHTMLDict: - return self._EpisodeHTMLDict[cache_key] - - try: - url = ( - f"{self.ANIWORLD_TO}/anime/stream/{key}/" - f"staffel-{season}/episode-{episode}" - ) - response = recovery_strategies.handle_network_failure( - self.session.get, url, timeout=self.DEFAULT_REQUEST_TIMEOUT - ) - - if not response.ok: - if response.status_code == 404: - err_msg = ( - f"Episode not found: {key} S{season}E{episode}" - ) - raise NonRetryableError(err_msg) - else: - err_msg = ( - f"HTTP error {response.status_code} for episode" - ) - raise RetryableError(err_msg) - - self._EpisodeHTMLDict[cache_key] = response - return self._EpisodeHTMLDict[cache_key] - - except Exception as e: - error_msg = ( - f"Failed to get episode HTML for {key} " - f"S{season}E{episode}: {e}" - ) - self.logger.error(error_msg) - raise - - def _get_provider_from_html( - self, season: int, episode: int, key: str - ) -> dict: - """Extract providers from HTML with error handling.""" - try: - episode_html = self._GetEpisodeHTML(season, episode, key) - soup = BeautifulSoup(episode_html.content, "html.parser") - providers: dict[str, dict] = {} - - episode_links = soup.find_all( - "li", class_=lambda x: x and x.startswith("episodeLink") - ) - - if not episode_links: - warn_msg = ( - f"No episode links found for {key} S{season}E{episode}" - ) - self.logger.warning(warn_msg) - return providers - - for link in episode_links: - provider_name_tag = link.find("h4") - provider_name = ( - provider_name_tag.text.strip() - if provider_name_tag - else None - ) - - redirect_link_tag = link.find("a", class_="watchEpisode") - redirect_link = ( - redirect_link_tag["href"] - if redirect_link_tag - else None - ) - - lang_key = link.get("data-lang-key") - lang_key = ( - int(lang_key) - if lang_key and lang_key.isdigit() - else None - ) - - if provider_name and redirect_link and lang_key: - if provider_name not in providers: - providers[provider_name] = {} - providers[provider_name][lang_key] = ( - f"{self.ANIWORLD_TO}{redirect_link}" - ) - - debug_msg = ( - f"Found {len(providers)} providers for " - f"{key} S{season}E{episode}" - ) - self.logger.debug(debug_msg) - return providers - - except Exception as e: - error_msg = f"Failed to parse providers from HTML: {e}" - self.logger.error(error_msg) - raise RetryableError(f"Provider parsing failed: {e}") from e - - def _get_redirect_link( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub", - ): - """Get redirect link for episode with error handling.""" - languageCode = self._GetLanguageKey(language) - - if not self.IsLanguage(season, episode, key, language): - err_msg = ( - f"Language {language} not available for " - f"{key} S{season}E{episode}" - ) - raise NonRetryableError(err_msg) - - providers = self._get_provider_from_html(season, episode, key) - - for provider_name, lang_dict in providers.items(): - if languageCode in lang_dict: - return lang_dict[languageCode], provider_name - - err_msg = ( - f"No provider found for {language} in " - f"{key} S{season}E{episode}" - ) - raise NonRetryableError(err_msg) - - def _get_embeded_link( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub", - ): - """Get embedded link with error handling.""" - try: - redirect_link, provider_name = self._get_redirect_link( - season, episode, key, language - ) - - response = recovery_strategies.handle_network_failure( - self.session.get, - redirect_link, - timeout=self.DEFAULT_REQUEST_TIMEOUT, - headers={"User-Agent": self.RANDOM_USER_AGENT}, - ) - - return response.url - - except Exception as e: - error_msg = f"Failed to get embedded link: {e}" - self.logger.error(error_msg) - raise - - def _get_direct_link_from_provider( - self, - season: int, - episode: int, - key: str, - language: str = "German Dub", - ): - """Get direct download link from provider.""" - try: - embedded_link = self._get_embeded_link( - season, episode, key, language - ) - if not embedded_link: - raise NonRetryableError("No embedded link found") - - # Use VOE provider as default (could be made configurable) - provider = self.Providers.GetProvider("VOE") - if not provider: - raise NonRetryableError("VOE provider not available") - - return provider.get_link( - embedded_link, self.DEFAULT_REQUEST_TIMEOUT - ) - - except Exception as e: - error_msg = f"Failed to get direct link from provider: {e}" - self.logger.error(error_msg) - raise - - @with_error_recovery(max_retries=2, context="get_season_episode_count") - def get_season_episode_count(self, slug: str) -> dict: - """Get episode count per season with error handling.""" - try: - base_url = f"{self.ANIWORLD_TO}/anime/stream/{slug}/" - response = recovery_strategies.handle_network_failure( - requests.get, - base_url, - timeout=self.DEFAULT_REQUEST_TIMEOUT, - ) - - soup = BeautifulSoup(response.content, "html.parser") - - season_meta = soup.find("meta", itemprop="numberOfSeasons") - number_of_seasons = ( - int(season_meta["content"]) if season_meta else 0 - ) - - episode_counts = {} - - for season in range(1, number_of_seasons + 1): - season_url = f"{base_url}staffel-{season}" - season_response = ( - recovery_strategies.handle_network_failure( - requests.get, - season_url, - timeout=self.DEFAULT_REQUEST_TIMEOUT, - ) - ) - - season_soup = BeautifulSoup( - season_response.content, "html.parser" - ) - - episode_links = season_soup.find_all("a", href=True) - unique_links = set( - link["href"] - for link in episode_links - if f"staffel-{season}/episode-" in link['href'] - ) - - episode_counts[season] = len(unique_links) - - return episode_counts - - except Exception as e: - self.logger.error(f"Failed to get episode counts for {slug}: {e}") - raise RetryableError(f"Episode count retrieval failed: {e}") from e - - def get_download_statistics(self) -> Dict[str, Any]: - """Get download statistics.""" - stats = self.download_stats.copy() - stats['success_rate'] = ( - (stats['successful_downloads'] / stats['total_downloads'] * 100) - if stats['total_downloads'] > 0 else 0 - ) - return stats - - def reset_statistics(self): - """Reset download statistics.""" - self.download_stats = { - 'total_downloads': 0, - 'successful_downloads': 0, - 'failed_downloads': 0, - 'retried_downloads': 0 - } - - -# For backward compatibility, create wrapper that uses enhanced loader -class AniworldLoader(EnhancedAniWorldLoader): - """Backward compatibility wrapper for the enhanced loader.""" - - pass +""" +Enhanced AniWorld Loader with Error Handling and Recovery + +This module extends the original AniWorldLoader with comprehensive +error handling, retry mechanisms, and recovery strategies. +""" + +import html +import json +import logging +import os +import re +import shutil +from pathlib import Path +from typing import Any, Callable, Dict, Optional +from urllib.parse import quote + +import requests +from bs4 import BeautifulSoup +from fake_useragent import UserAgent +from requests.adapters import HTTPAdapter +from urllib3.util.retry import Retry +from yt_dlp import YoutubeDL + +from ...infrastructure.security.file_integrity import get_integrity_manager +from ..error_handler import ( + DownloadError, + NetworkError, + NonRetryableError, + RetryableError, + file_corruption_detector, + recovery_strategies, + with_error_recovery, +) +from ..interfaces.providers import Providers +from .base_provider import Loader +from .provider_config import ( + ANIWORLD_HEADERS, + DEFAULT_PROVIDERS, + INVALID_PATH_CHARS, + LULUVDO_USER_AGENT, + ProviderType, +) + + +def _cleanup_temp_file( + temp_path: str, + logger: Optional[logging.Logger] = None, +) -> None: + """Remove a temp file and any associated yt-dlp partial files. + + Args: + temp_path: Path to the primary temp file. + logger: Optional logger for diagnostic messages. + """ + _log = logger or logging.getLogger(__name__) + candidates = [temp_path] + # yt-dlp creates fragment files like .part + candidates.extend( + str(p) for p in Path(temp_path).parent.glob( + Path(temp_path).name + ".*" + ) + ) + for path in candidates: + if os.path.exists(path): + try: + os.remove(path) + _log.debug(f"Removed temp file: {path}") + except OSError as exc: + _log.warning(f"Failed to remove temp file {path}: {exc}") + + +class EnhancedAniWorldLoader(Loader): + """Aniworld provider with retry and recovery strategies. + + Also exposes metrics hooks for download statistics. + """ + + def __init__(self) -> None: + super().__init__() + self.logger = logging.getLogger(__name__) + self.SUPPORTED_PROVIDERS = DEFAULT_PROVIDERS + # local copy so modifications don't mutate shared constant + self.AniworldHeaders = dict(ANIWORLD_HEADERS) + self.INVALID_PATH_CHARS = INVALID_PATH_CHARS + self.RANDOM_USER_AGENT = UserAgent().random + self.LULUVDO_USER_AGENT = LULUVDO_USER_AGENT + + self.PROVIDER_HEADERS = { + ProviderType.VIDMOLY.value: ['Referer: "https://vidmoly.to"'], + ProviderType.DOODSTREAM.value: ['Referer: "https://dood.li/"'], + ProviderType.VOE.value: [f'User-Agent: {self.RANDOM_USER_AGENT}'], + ProviderType.LULUVDO.value: [ + f'User-Agent: {self.LULUVDO_USER_AGENT}', + "Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7", + 'Origin: "https://luluvdo.com"', + 'Referer: "https://luluvdo.com/"', + ], + } + + self.ANIWORLD_TO = "https://aniworld.to" + self.DEFAULT_REQUEST_TIMEOUT = 30 + + # Initialize session with enhanced retry configuration + self.session = self._create_robust_session() + + # Cache dictionaries + self._KeyHTMLDict = {} + self._EpisodeHTMLDict = {} + + # Provider manager + self.Providers = Providers() + + # Download statistics + self.download_stats = { + 'total_downloads': 0, + 'successful_downloads': 0, + 'failed_downloads': 0, + 'retried_downloads': 0 + } + + # Read timeout from environment variable (string->int safely) + self.download_timeout = int(os.getenv("DOWNLOAD_TIMEOUT") or "600") + + # Setup logging + self._setup_logging() + + def _create_robust_session(self) -> requests.Session: + """Create a session with robust retry and error handling + configuration. + """ + session = requests.Session() + + # Configure retries so transient network problems are retried while we + # still fail fast on permanent errors. The status codes cover + # timeouts, rate limits, and the Cloudflare-origin 52x responses that + # AniWorld occasionally emits under load. + retries = Retry( + total=5, + backoff_factor=2, # More aggressive backoff + status_forcelist=[ + 408, + 429, + 500, + 502, + 503, + 504, + 520, + 521, + 522, + 523, + 524, + ], + allowed_methods=["GET", "POST", "HEAD"], + raise_on_status=False, # Handle status errors manually + ) + + adapter = HTTPAdapter( + max_retries=retries, + pool_connections=10, + pool_maxsize=20, + pool_block=True + ) + + session.mount("https://", adapter) + session.mount("http://", adapter) + + # Set default headers + session.headers.update(self.AniworldHeaders) + + return session + + def _setup_logging(self): + """Setup specialized logging for download errors and missing keys.""" + # Determine project root so log files land in a predictable location + # regardless of the working directory at runtime. + _project_root = Path(__file__).parent.parent.parent.parent + _logs_dir = _project_root / "logs" + _logs_dir.mkdir(parents=True, exist_ok=True) + + formatter = logging.Formatter( + '%(asctime)s - %(name)s - %(levelname)s - %(message)s' + ) + + # Download error logger — records every failed download attempt + self.download_error_logger = logging.getLogger("DownloadErrors") + if not self.download_error_logger.handlers: + handler = logging.FileHandler(str(_logs_dir / "download_errors.log")) + handler.setLevel(logging.ERROR) + handler.setFormatter(formatter) + self.download_error_logger.addHandler(handler) + self.download_error_logger.setLevel(logging.ERROR) + + # No-key logger — records episodes for which no stream key was found + self.nokey_logger = logging.getLogger("NoKeyFound") + if not self.nokey_logger.handlers: + handler = logging.FileHandler(str(_logs_dir / "no_key_found.log")) + handler.setLevel(logging.ERROR) + handler.setFormatter(formatter) + self.nokey_logger.addHandler(handler) + self.nokey_logger.setLevel(logging.ERROR) + + def ClearCache(self): + """Clear all cached data.""" + self._KeyHTMLDict.clear() + self._EpisodeHTMLDict.clear() + self.logger.debug("Cache cleared") + + def RemoveFromCache(self): + """Remove episode HTML cache.""" + self._EpisodeHTMLDict.clear() + self.logger.debug("Episode cache cleared") + + @with_error_recovery(max_retries=3, context="anime_search") + def Search(self, word: str) -> list: + """Search for anime with error handling.""" + if not word or not word.strip(): + raise ValueError("Search term cannot be empty") + + search_url = ( + f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}" + ) + + try: + return self._fetch_anime_list_with_recovery(search_url) + except Exception as e: + self.logger.error("Search failed for term '%s': %s", word, e) + raise RetryableError(f"Search failed: {e}") from e + + def _fetch_anime_list_with_recovery(self, url: str) -> list: + """Fetch anime list with comprehensive error handling.""" + try: + response = recovery_strategies.handle_network_failure( + self.session.get, + url, + timeout=self.DEFAULT_REQUEST_TIMEOUT + ) + + if not response.ok: + if response.status_code == 404: + raise NonRetryableError(f"URL not found: {url}") + elif response.status_code == 403: + raise NonRetryableError(f"Access forbidden: {url}") + elif response.status_code >= 500: + # Log suspicious server errors for monitoring + self.logger.warning( + f"Server error {response.status_code} from {url} " + f"- will retry" + ) + raise RetryableError(f"Server error {response.status_code}") + else: + raise RetryableError(f"HTTP error {response.status_code}") + + return self._parse_anime_response(response.text) + + except (requests.RequestException, ConnectionError) as e: + raise NetworkError(f"Network error during anime search: {e}") from e + + def _parse_anime_response(self, response_text: str) -> list: + """Parse anime search response with error handling.""" + if not response_text or not response_text.strip(): + raise ValueError("Empty response from server") + + clean_text = response_text.strip() + + # Quick fail for obviously non-JSON responses + if not (clean_text.startswith('[') or clean_text.startswith('{')): + # Check if it's HTML error page + if clean_text.lower().startswith(' int: + """Get numeric language code.""" + language_map = { + "German Dub": 1, + "English Sub": 2, + "German Sub": 3, + } + return language_map.get(language, 0) + + @with_error_recovery(max_retries=2, context="language_check") + def IsLanguage( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub", + ) -> bool: + """Check if episode is available in specified language.""" + try: + languageCode = self._GetLanguageKey(language) + if languageCode == 0: + raise ValueError(f"Unknown language: {language}") + + episode_response = self._GetEpisodeHTML(season, episode, key) + soup = BeautifulSoup(episode_response.content, "html.parser") + + lang_box = soup.find("div", class_="changeLanguageBox") + if not lang_box: + debug_msg = ( + f"No language box found for {key} S{season}E{episode}" + ) + self.logger.debug(debug_msg) + return False + + img_tags = lang_box.find_all("img") + available_languages = [] + + for img in img_tags: + lang_key = img.get("data-lang-key") + if lang_key and lang_key.isdigit(): + available_languages.append(int(lang_key)) + + is_available = languageCode in available_languages + debug_msg = ( + f"Language check for {key} S{season}E{episode}: " + f"Requested={languageCode}, " + f"Available={available_languages}, " + f"Result={is_available}" + ) + self.logger.debug(debug_msg) + + return is_available + + except Exception as e: + error_msg = ( + f"Language check failed for {key} S{season}E{episode}: {e}" + ) + self.logger.error(error_msg) + raise RetryableError(f"Language check failed: {e}") from e + + def Download( + self, + baseDirectory: str, + serieFolder: str, + season: int, + episode: int, + key: str, + language: str = "German Dub", + progress_callback: Optional[Callable] = None, + ) -> bool: + """Download episode with comprehensive error handling. + + Args: + baseDirectory: Base download directory path + serieFolder: Filesystem folder name (metadata only, used for + file path construction) + season: Season number (0 for movies) + episode: Episode number + key: Series unique identifier from provider (used for + identification and API calls) + language: Audio language preference (default: German Dub) + progress_callback: Optional callback for download progress + updates + + Returns: + bool: True if download succeeded, False otherwise + + Raises: + DownloadError: If download fails after all retry attempts + ValueError: If required parameters are missing or invalid + """ + self.download_stats["total_downloads"] += 1 + + try: + # Validate inputs + if not all([baseDirectory, serieFolder, key]): + raise ValueError("Missing required parameters for download") + + if season < 0 or episode < 0: + raise ValueError("Season and episode must be non-negative") + + # Prepare file paths + sanitized_anime_title = "".join( + char + for char in self.GetTitle(key) + if char not in self.INVALID_PATH_CHARS + ) + + if not sanitized_anime_title: + sanitized_anime_title = f"Unknown_{key}" + + # Generate output filename + if season == 0: + output_file = ( + f"{sanitized_anime_title} - Movie {episode:02} - " + f"({language}).mp4" + ) + else: + output_file = ( + f"{sanitized_anime_title} - S{season:02}E{episode:03} - " + f"({language}).mp4" + ) + + # Create directory structure + folder_path = os.path.join( + baseDirectory, serieFolder, f"Season {season}" + ) + output_path = os.path.join(folder_path, output_file) + + # Check if file already exists and is valid + if os.path.exists(output_path): + is_valid = file_corruption_detector.is_valid_video_file( + output_path + ) + + # Also verify checksum if available + integrity_mgr = get_integrity_manager() + checksum_valid = True + if integrity_mgr.has_checksum(Path(output_path)): + checksum_valid = integrity_mgr.verify_checksum( + Path(output_path) + ) + if not checksum_valid: + self.logger.warning( + f"Checksum verification failed for {output_file}" + ) + + if is_valid and checksum_valid: + msg = ( + f"File already exists and is valid: " + f"{output_file}" + ) + self.logger.info(msg) + self.download_stats["successful_downloads"] += 1 + return True + else: + warning_msg = ( + f"Existing file appears corrupted, removing: " + f"{output_path}" + ) + self.logger.warning(warning_msg) + try: + os.remove(output_path) + # Remove checksum entry + integrity_mgr.remove_checksum(Path(output_path)) + except OSError as e: + error_msg = f"Failed to remove corrupted file: {e}" + self.logger.error(error_msg) + + os.makedirs(folder_path, exist_ok=True) + + # Create temp directory + temp_dir = "./Temp/" + os.makedirs(temp_dir, exist_ok=True) + temp_path = os.path.join(temp_dir, output_file) + + # Attempt download with recovery strategies + success = self._download_with_recovery( + season, + episode, + key, + language, + temp_path, + output_path, + progress_callback, + ) + + if success: + self.download_stats["successful_downloads"] += 1 + success_msg = f"Successfully downloaded: {output_file}" + self.logger.info(success_msg) + else: + self.download_stats["failed_downloads"] += 1 + fail_msg = ( + f"Download failed for {key} S{season}E{episode} " + f"({language})" + ) + self.download_error_logger.error(fail_msg) + + return success + + except Exception as e: + self.download_stats["failed_downloads"] += 1 + err_msg = ( + f"Download error for {key} S{season}E{episode}: {e}" + ) + self.download_error_logger.error(err_msg, exc_info=True) + raise DownloadError(f"Download failed: {e}") from e + finally: + self.ClearCache() + + def _download_with_recovery( + self, + season: int, + episode: int, + key: str, + language: str, + temp_path: str, + output_path: str, + progress_callback: Optional[Callable], + ) -> bool: + """Attempt download with multiple providers and recovery.""" + + for provider_name in self.SUPPORTED_PROVIDERS: + try: + info_msg = ( + f"Attempting download with provider: {provider_name}" + ) + self.logger.info(info_msg) + + # Get download link and headers for provider + link, headers = recovery_strategies.handle_network_failure( + self._get_direct_link_from_provider, + season, + episode, + key, + language, + ) + + if not link: + warn_msg = ( + f"No download link found for provider: " + f"{provider_name}" + ) + self.logger.warning(warn_msg) + continue + + # Configure yt-dlp options + ydl_opts = { + "fragment_retries": float("inf"), + "outtmpl": temp_path, + "quiet": True, + "no_warnings": True, + "progress_with_newline": False, + "nocheckcertificate": True, + "socket_timeout": self.download_timeout, + "http_chunk_size": 1024 * 1024, # 1MB chunks + } + if headers: + ydl_opts['http_headers'] = headers + + if progress_callback: + ydl_opts['progress_hooks'] = [progress_callback] + + # Perform download with recovery + success = recovery_strategies.handle_download_failure( + self._perform_ytdl_download, + temp_path, + ydl_opts, + link + ) + + if success and os.path.exists(temp_path): + # Verify downloaded file + if file_corruption_detector.is_valid_video_file(temp_path): + # Move to final location + # Use copyfile instead of copy2 to avoid metadata permission issues + shutil.copyfile(temp_path, output_path) + + # Calculate and store checksum for integrity + integrity_mgr = get_integrity_manager() + try: + checksum = integrity_mgr.store_checksum( + Path(output_path) + ) + filename = Path(output_path).name + self.logger.info( + f"Stored checksum for {filename}: " + f"{checksum[:16]}..." + ) + except Exception as e: + self.logger.warning( + f"Failed to store checksum: {e}" + ) + + # Clean up temp file + try: + os.remove(temp_path) + except Exception as e: + warn_msg = f"Failed to remove temp file: {e}" + self.logger.warning(warn_msg) + + return True + else: + warn_msg = ( + f"Downloaded file failed validation: " + f"{temp_path}" + ) + self.logger.warning(warn_msg) + try: + os.remove(temp_path) + except OSError as e: + warn_msg = f"Failed to remove temp file: {e}" + self.logger.warning(warn_msg) + + except Exception as e: + self.logger.warning("Provider %s failed: %s", provider_name, e) + # Clean up any partial temp files left by this failed attempt + _cleanup_temp_file(temp_path, self.logger) + self.download_stats['retried_downloads'] += 1 + continue + + # All providers failed – make sure no temp remnants are left behind + _cleanup_temp_file(temp_path, self.logger) + return False + + def _perform_ytdl_download( + self, ydl_opts: Dict[str, Any], link: str + ) -> bool: + """Perform actual download using yt-dlp.""" + try: + with YoutubeDL(ydl_opts) as ydl: + ydl.download([link]) + return True + except Exception as e: + self.logger.error("yt-dlp download failed: %s", e) + raise DownloadError(f"Download failed: {e}") from e + + @with_error_recovery(max_retries=2, context="get_title") + def GetTitle(self, key: str) -> str: + """Get anime title with error handling.""" + try: + soup = BeautifulSoup(self._GetKeyHTML(key).content, 'html.parser') + title_div = soup.find('div', class_='series-title') + + if title_div: + title_span = title_div.find('h1') + if title_span: + span = title_span.find('span') + if span: + return span.text.strip() + + self.logger.warning("Could not extract title for key: %s", key) + return f"Unknown_Title_{key}" + + except Exception as e: + self.logger.error("Failed to get title for key %s: %s", key, e) + raise RetryableError(f"Title extraction failed: {e}") from e + + def GetSiteKey(self) -> str: + """Get site identifier.""" + return "aniworld.to" + + @with_error_recovery(max_retries=2, context="get_key_html") + def _GetKeyHTML(self, key: str): + """Get cached HTML for anime key.""" + if key in self._KeyHTMLDict: + return self._KeyHTMLDict[key] + + try: + url = f"{self.ANIWORLD_TO}/anime/stream/{key}" + response = recovery_strategies.handle_network_failure( + self.session.get, + url, + timeout=self.DEFAULT_REQUEST_TIMEOUT + ) + + if not response.ok: + if response.status_code == 404: + msg = f"Anime key not found: {key}" + self.nokey_logger.error(msg) + raise NonRetryableError(msg) + else: + err_msg = ( + f"HTTP error {response.status_code} for key {key}" + ) + raise RetryableError(err_msg) + + self._KeyHTMLDict[key] = response + return self._KeyHTMLDict[key] + + except Exception as e: + error_msg = f"Failed to get HTML for key {key}: {e}" + self.logger.error(error_msg) + raise + + @with_error_recovery(max_retries=2, context="get_episode_html") + def _GetEpisodeHTML(self, season: int, episode: int, key: str): + """Get cached HTML for specific episode. + + Args: + season: Season number (must be 1-999) + episode: Episode number (must be 1-9999) + key: Series identifier (should be non-empty) + + Returns: + Cached or fetched HTML response + + Raises: + ValueError: If parameters are invalid + NonRetryableError: If episode not found (404) + RetryableError: If HTTP error occurs + """ + # Validate parameters + if not key or not key.strip(): + raise ValueError("Series key cannot be empty") + if season < 1 or season > 999: + raise ValueError( + f"Invalid season number: {season} (must be 1-999)" + ) + if episode < 1 or episode > 9999: + raise ValueError( + f"Invalid episode number: {episode} (must be 1-9999)" + ) + + cache_key = (key, season, episode) + if cache_key in self._EpisodeHTMLDict: + return self._EpisodeHTMLDict[cache_key] + + try: + url = ( + f"{self.ANIWORLD_TO}/anime/stream/{key}/" + f"staffel-{season}/episode-{episode}" + ) + response = recovery_strategies.handle_network_failure( + self.session.get, url, timeout=self.DEFAULT_REQUEST_TIMEOUT + ) + + if not response.ok: + if response.status_code == 404: + err_msg = ( + f"Episode not found: {key} S{season}E{episode}" + ) + raise NonRetryableError(err_msg) + else: + err_msg = ( + f"HTTP error {response.status_code} for episode" + ) + raise RetryableError(err_msg) + + self._EpisodeHTMLDict[cache_key] = response + return self._EpisodeHTMLDict[cache_key] + + except Exception as e: + error_msg = ( + f"Failed to get episode HTML for {key} " + f"S{season}E{episode}: {e}" + ) + self.logger.error(error_msg) + raise + + def _get_provider_from_html( + self, season: int, episode: int, key: str + ) -> dict: + """Extract providers from HTML with error handling.""" + try: + episode_html = self._GetEpisodeHTML(season, episode, key) + soup = BeautifulSoup(episode_html.content, "html.parser") + providers: dict[str, dict] = {} + + episode_links = soup.find_all( + "li", class_=lambda x: x and x.startswith("episodeLink") + ) + + if not episode_links: + warn_msg = ( + f"No episode links found for {key} S{season}E{episode}" + ) + self.logger.warning(warn_msg) + return providers + + for link in episode_links: + provider_name_tag = link.find("h4") + provider_name = ( + provider_name_tag.text.strip() + if provider_name_tag + else None + ) + + redirect_link_tag = link.find("a", class_="watchEpisode") + redirect_link = ( + redirect_link_tag["href"] + if redirect_link_tag + else None + ) + + lang_key = link.get("data-lang-key") + lang_key = ( + int(lang_key) + if lang_key and lang_key.isdigit() + else None + ) + + if provider_name and redirect_link and lang_key: + if provider_name not in providers: + providers[provider_name] = {} + providers[provider_name][lang_key] = ( + f"{self.ANIWORLD_TO}{redirect_link}" + ) + + debug_msg = ( + f"Found {len(providers)} providers for " + f"{key} S{season}E{episode}" + ) + self.logger.debug(debug_msg) + return providers + + except Exception as e: + error_msg = f"Failed to parse providers from HTML: {e}" + self.logger.error(error_msg) + raise RetryableError(f"Provider parsing failed: {e}") from e + + def _get_redirect_link( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub", + ): + """Get redirect link for episode with error handling.""" + languageCode = self._GetLanguageKey(language) + + if not self.IsLanguage(season, episode, key, language): + err_msg = ( + f"Language {language} not available for " + f"{key} S{season}E{episode}" + ) + raise NonRetryableError(err_msg) + + providers = self._get_provider_from_html(season, episode, key) + + for provider_name, lang_dict in providers.items(): + if languageCode in lang_dict: + return lang_dict[languageCode], provider_name + + err_msg = ( + f"No provider found for {language} in " + f"{key} S{season}E{episode}" + ) + raise NonRetryableError(err_msg) + + def _get_embeded_link( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub", + ): + """Get embedded link with error handling.""" + try: + redirect_link, provider_name = self._get_redirect_link( + season, episode, key, language + ) + + response = recovery_strategies.handle_network_failure( + self.session.get, + redirect_link, + timeout=self.DEFAULT_REQUEST_TIMEOUT, + headers={"User-Agent": self.RANDOM_USER_AGENT}, + ) + + return response.url + + except Exception as e: + error_msg = f"Failed to get embedded link: {e}" + self.logger.error(error_msg) + raise + + def _get_direct_link_from_provider( + self, + season: int, + episode: int, + key: str, + language: str = "German Dub", + ): + """Get direct download link from provider.""" + try: + embedded_link = self._get_embeded_link( + season, episode, key, language + ) + if not embedded_link: + raise NonRetryableError("No embedded link found") + + # Use VOE provider as default (could be made configurable) + provider = self.Providers.GetProvider("VOE") + if not provider: + raise NonRetryableError("VOE provider not available") + + return provider.get_link( + embedded_link, self.DEFAULT_REQUEST_TIMEOUT + ) + + except Exception as e: + error_msg = f"Failed to get direct link from provider: {e}" + self.logger.error(error_msg) + raise + + @with_error_recovery(max_retries=2, context="get_season_episode_count") + def get_season_episode_count(self, slug: str) -> dict: + """Get episode count per season with error handling.""" + try: + base_url = f"{self.ANIWORLD_TO}/anime/stream/{slug}/" + response = recovery_strategies.handle_network_failure( + requests.get, + base_url, + timeout=self.DEFAULT_REQUEST_TIMEOUT, + ) + + soup = BeautifulSoup(response.content, "html.parser") + + season_meta = soup.find("meta", itemprop="numberOfSeasons") + number_of_seasons = ( + int(season_meta["content"]) if season_meta else 0 + ) + + episode_counts = {} + + for season in range(1, number_of_seasons + 1): + season_url = f"{base_url}staffel-{season}" + season_response = ( + recovery_strategies.handle_network_failure( + requests.get, + season_url, + timeout=self.DEFAULT_REQUEST_TIMEOUT, + ) + ) + + season_soup = BeautifulSoup( + season_response.content, "html.parser" + ) + + episode_links = season_soup.find_all("a", href=True) + unique_links = set( + link["href"] + for link in episode_links + if f"staffel-{season}/episode-" in link['href'] + ) + + episode_counts[season] = len(unique_links) + + return episode_counts + + except Exception as e: + self.logger.error("Failed to get episode counts for %s: %s", slug, e) + raise RetryableError(f"Episode count retrieval failed: {e}") from e + + def get_download_statistics(self) -> Dict[str, Any]: + """Get download statistics.""" + stats = self.download_stats.copy() + stats['success_rate'] = ( + (stats['successful_downloads'] / stats['total_downloads'] * 100) + if stats['total_downloads'] > 0 else 0 + ) + return stats + + def reset_statistics(self): + """Reset download statistics.""" + self.download_stats = { + 'total_downloads': 0, + 'successful_downloads': 0, + 'failed_downloads': 0, + 'retried_downloads': 0 + } + + +# For backward compatibility, create wrapper that uses enhanced loader +class AniworldLoader(EnhancedAniWorldLoader): + """Backward compatibility wrapper for the enhanced loader.""" + + pass diff --git a/src/core/providers/failover.py b/src/core/providers/failover.py index c039ce9..217fd94 100644 --- a/src/core/providers/failover.py +++ b/src/core/providers/failover.py @@ -207,7 +207,7 @@ class ProviderFailover: """ if provider_name not in self._providers: self._providers.append(provider_name) - logger.info(f"Added provider to failover chain: {provider_name}") + logger.info("Added provider to failover chain: %s", provider_name) def remove_provider(self, provider_name: str) -> bool: """Remove a provider from the failover chain. diff --git a/src/core/providers/health_monitor.py b/src/core/providers/health_monitor.py index 0f945eb..f6d0c39 100644 --- a/src/core/providers/health_monitor.py +++ b/src/core/providers/health_monitor.py @@ -151,7 +151,7 @@ class ProviderHealthMonitor: except asyncio.CancelledError: break except Exception as e: - logger.error(f"Error in health check loop: {e}", exc_info=True) + logger.exception("Error in health check loop: %s", e) await asyncio.sleep(self._health_check_interval) async def _perform_health_checks(self) -> None: @@ -314,7 +314,7 @@ class ProviderHealthMonitor: ) best_provider = available[0][0] - logger.debug(f"Best provider selected: {best_provider}") + logger.debug("Best provider selected: %s", best_provider) return best_provider def _get_recent_metrics( @@ -355,7 +355,7 @@ class ProviderHealthMonitor: provider_name=provider_name ) self._request_history[provider_name].clear() - logger.info(f"Reset metrics for provider: {provider_name}") + logger.info("Reset metrics for provider: %s", provider_name) return True def get_health_summary(self) -> Dict[str, Any]: diff --git a/src/core/services/nfo_service.py b/src/core/services/nfo_service.py index 67bb709..0431dc5 100644 --- a/src/core/services/nfo_service.py +++ b/src/core/services/nfo_service.py @@ -134,21 +134,21 @@ class NFOService: clean_name, extracted_year = self._extract_year_from_name(serie_name) if year is None and extracted_year is not None: year = extracted_year - logger.info(f"Extracted year {year} from series name") + logger.info("Extracted year %s from series name", year) # Use clean name for search search_name = clean_name - logger.info(f"Creating NFO for {search_name} (year: {year})") + logger.info("Creating NFO for %s (year: %s)", search_name, year) folder_path = self.anime_directory / serie_folder if not folder_path.exists(): - logger.info(f"Creating series folder: {folder_path}") + logger.info("Creating series folder: %s", folder_path) folder_path.mkdir(parents=True, exist_ok=True) async with self.tmdb_client: # Search for TV show with clean name (without year) - logger.debug(f"Searching TMDB for: {search_name}") + logger.debug("Searching TMDB for: %s", search_name) search_results = await self.tmdb_client.search_tv_show(search_name) if not search_results.get("results"): @@ -158,7 +158,7 @@ class NFOService: tv_show = self._find_best_match(search_results["results"], search_name, year) tv_id = tv_show["id"] - logger.info(f"Found match: {tv_show['name']} (ID: {tv_id})") + logger.info("Found match: %s (ID: %s)", tv_show['name'], tv_id) # Get detailed information with multi-language image support details = await self.tmdb_client.get_tv_show_details( @@ -190,7 +190,7 @@ class NFOService: # Save NFO file nfo_path = folder_path / "tvshow.nfo" nfo_path.write_text(nfo_xml, encoding="utf-8") - logger.info(f"Created NFO: {nfo_path}") + logger.info("Created NFO: %s", nfo_path) # Download media files await self._download_media_files( @@ -227,7 +227,7 @@ class NFOService: if not nfo_path.exists(): raise FileNotFoundError(f"NFO file not found: {nfo_path}") - logger.info(f"Updating NFO for {serie_folder}") + logger.info("Updating NFO for %s", serie_folder) # Parse existing NFO to extract TMDB ID try: @@ -253,7 +253,7 @@ class NFOService: f"Delete the NFO and create a new one instead." ) - logger.debug(f"Found TMDB ID: {tmdb_id}") + logger.debug("Found TMDB ID: %s", tmdb_id) except etree.XMLSyntaxError as e: raise TMDBAPIError(f"Invalid XML in NFO file: {e}") @@ -262,7 +262,7 @@ class NFOService: # Fetch fresh data from TMDB async with self.tmdb_client: - logger.debug(f"Fetching fresh data for TMDB ID: {tmdb_id}") + logger.debug("Fetching fresh data for TMDB ID: %s", tmdb_id) details = await self.tmdb_client.get_tv_show_details( tmdb_id, append_to_response="credits,external_ids,images" @@ -286,7 +286,7 @@ class NFOService: # Save updated NFO file nfo_path.write_text(nfo_xml, encoding="utf-8") - logger.info(f"Updated NFO: {nfo_path}") + logger.info("Updated NFO: %s", nfo_path) # Re-download media files if requested if download_media: @@ -318,7 +318,7 @@ class NFOService: result = {"tmdb_id": None, "tvdb_id": None} if not nfo_path.exists(): - logger.debug(f"NFO file not found: {nfo_path}") + logger.debug("NFO file not found: %s", nfo_path) return result try: @@ -375,9 +375,9 @@ class NFOService: ) except etree.XMLSyntaxError as e: - logger.error(f"Invalid XML in NFO file {nfo_path}: {e}") + logger.error("Invalid XML in NFO file %s: %s", nfo_path, e) except Exception as e: # pylint: disable=broad-except - logger.error(f"Error parsing NFO file {nfo_path}: {e}") + logger.error("Error parsing NFO file %s: %s", nfo_path, e) return result @@ -480,7 +480,7 @@ class NFOService: for result in results: first_air_date = result.get("first_air_date", "") if first_air_date.startswith(str(year)): - logger.debug(f"Found year match: {result['name']} ({first_air_date})") + logger.debug("Found year match: %s (%s)", result['name'], first_air_date) return result # Return first result (usually best match) @@ -545,7 +545,7 @@ class NFOService: skip_existing=True ) - logger.info(f"Media download results: {results}") + logger.info("Media download results: %s", results) return results diff --git a/src/core/services/series_manager_service.py b/src/core/services/series_manager_service.py index 4cb769b..fa35746 100644 --- a/src/core/services/series_manager_service.py +++ b/src/core/services/series_manager_service.py @@ -136,7 +136,7 @@ class SeriesManagerService: # If NFO exists, parse IDs and update database if nfo_exists: - logger.debug(f"Parsing IDs from existing NFO for '{serie_name}'") + logger.debug("Parsing IDs from existing NFO for '%s'", serie_name) ids = self.nfo_service.parse_nfo_ids(nfo_path) if ids["tmdb_id"] or ids["tvdb_id"]: @@ -203,14 +203,14 @@ class SeriesManagerService: download_logo=self.download_logo, download_fanart=self.download_fanart ) - logger.info(f"Successfully created NFO for '{serie_name}'") + logger.info("Successfully created NFO for '%s'", serie_name) elif nfo_exists: logger.debug( f"NFO exists for '{serie_name}', skipping download" ) except TMDBAPIError as e: - logger.error(f"TMDB API error processing '{serie_name}': {e}") + logger.error("TMDB API error processing '%s': %s", serie_name, e) except Exception as e: logger.error( f"Unexpected error processing NFO for '{serie_name}': {e}", @@ -246,7 +246,7 @@ class SeriesManagerService: logger.info("No series found in database to process") return - logger.info(f"Processing NFO for {len(anime_series_list)} series...") + logger.info("Processing NFO for %s series...", len(anime_series_list)) # Create tasks for concurrent processing # Each task creates its own database session diff --git a/src/core/services/tmdb_client.py b/src/core/services/tmdb_client.py index 05a642b..b5370f9 100644 --- a/src/core/services/tmdb_client.py +++ b/src/core/services/tmdb_client.py @@ -107,7 +107,7 @@ class TMDBClient: # Cache key for deduplication cache_key = f"{endpoint}:{str(sorted(params.items()))}" if cache_key in self._cache: - logger.debug(f"Cache hit for {endpoint}") + logger.debug("Cache hit for %s", endpoint) return self._cache[cache_key] delay = 1 @@ -121,7 +121,7 @@ class TMDBClient: if self.session is None: raise TMDBAPIError("Session is not available") - logger.debug(f"TMDB API request: {endpoint} (attempt {attempt + 1})") + logger.debug("TMDB API request: %s (attempt %s)", endpoint, attempt + 1) async with self.session.get(url, params=params, timeout=aiohttp.ClientTimeout(total=60)) as resp: if resp.status == 401: raise TMDBAPIError("Invalid TMDB API key") @@ -130,7 +130,7 @@ class TMDBClient: elif resp.status == 429: # Rate limit - wait longer retry_after = int(resp.headers.get('Retry-After', delay * 2)) - logger.warning(f"Rate limited, waiting {retry_after}s") + logger.warning("Rate limited, waiting %ss", retry_after) await asyncio.sleep(retry_after) continue @@ -142,26 +142,26 @@ class TMDBClient: except asyncio.TimeoutError as e: last_error = e if attempt < max_retries - 1: - logger.warning(f"Request timeout (attempt {attempt + 1}), retrying in {delay}s") + logger.warning("Request timeout (attempt %s), retrying in %ss", attempt + 1, delay) await asyncio.sleep(delay) delay *= 2 else: - logger.error(f"Request timed out after {max_retries} attempts") + logger.error("Request timed out after %s attempts", max_retries) except (aiohttp.ClientError, AttributeError) as e: last_error = e # If connector/session was closed, try to recreate it if "Connector is closed" in str(e) or isinstance(e, AttributeError): - logger.warning(f"Session issue detected, recreating session: {e}") + logger.warning("Session issue detected, recreating session: %s", e) self.session = None await self._ensure_session() if attempt < max_retries - 1: - logger.warning(f"Request failed (attempt {attempt + 1}): {e}, retrying in {delay}s") + logger.warning("Request failed (attempt %s): %s, retrying in %ss", attempt + 1, e, delay) await asyncio.sleep(delay) delay *= 2 else: - logger.error(f"Request failed after {max_retries} attempts: {e}") + logger.error("Request failed after %s attempts: %s", max_retries, e) raise TMDBAPIError(f"Request failed after {max_retries} attempts: {last_error}") @@ -275,7 +275,7 @@ class TMDBClient: url = f"{self.image_base_url}/{size}{image_path}" try: - logger.debug(f"Downloading image from {url}") + logger.debug("Downloading image from %s", url) async with self.session.get(url, timeout=aiohttp.ClientTimeout(total=60)) as resp: resp.raise_for_status() @@ -286,7 +286,7 @@ class TMDBClient: with open(local_path, "wb") as f: f.write(await resp.read()) - logger.info(f"Downloaded image to {local_path}") + logger.info("Downloaded image to %s", local_path) except aiohttp.ClientError as e: raise TMDBAPIError(f"Failed to download image: {e}") diff --git a/src/core/utils/image_downloader.py b/src/core/utils/image_downloader.py index 83cd6dc..8023e13 100644 --- a/src/core/utils/image_downloader.py +++ b/src/core/utils/image_downloader.py @@ -125,7 +125,7 @@ class ImageDownloader: # Check if file already exists if skip_existing and local_path.exists(): if local_path.stat().st_size >= self.min_file_size: - logger.debug(f"Image already exists: {local_path}") + logger.debug("Image already exists: %s", local_path) return True # Ensure parent directory exists @@ -137,15 +137,16 @@ class ImageDownloader: for attempt in range(self.max_retries): try: logger.debug( - f"Downloading image from {url} " - f"(attempt {attempt + 1})" + "Downloading image from %s (attempt %d)", + url, + attempt + 1, ) # Use persistent session session = self._get_session() async with session.get(url) as resp: if resp.status == 404: - logger.warning(f"Image not found: {url}") + logger.warning("Image not found: %s", url) return False resp.raise_for_status() @@ -168,21 +169,25 @@ class ImageDownloader: local_path.unlink(missing_ok=True) raise ImageDownloadError("Image validation failed") - logger.info(f"Downloaded image to {local_path}") + logger.info("Downloaded image to %s", local_path) return True except (aiohttp.ClientError, IOError, ImageDownloadError) as e: last_error = e if attempt < self.max_retries - 1: logger.warning( - f"Download failed (attempt {attempt + 1}): {e}, " - f"retrying in {delay}s" + "Download failed (attempt %d): %s, retrying in %s", + attempt + 1, + e, + delay, ) await asyncio.sleep(delay) delay *= 2 else: logger.error( - f"Download failed after {self.max_retries} attempts: {e}" + "Download failed after %d attempts: %s", + self.max_retries, + e, ) raise ImageDownloadError( @@ -211,7 +216,7 @@ class ImageDownloader: try: return await self.download_image(url, local_path, skip_existing) except ImageDownloadError as e: - logger.warning(f"Failed to download poster: {e}") + logger.warning("Failed to download poster: %s", e) return False async def download_logo( @@ -236,7 +241,7 @@ class ImageDownloader: try: return await self.download_image(url, local_path, skip_existing) except ImageDownloadError as e: - logger.warning(f"Failed to download logo: {e}") + logger.warning("Failed to download logo: %s", e) return False async def download_fanart( @@ -261,7 +266,7 @@ class ImageDownloader: try: return await self.download_image(url, local_path, skip_existing) except ImageDownloadError as e: - logger.warning(f"Failed to download fanart: {e}") + logger.warning("Failed to download fanart: %s", e) return False def validate_image(self, image_path: Path) -> bool: @@ -280,13 +285,13 @@ class ImageDownloader: # Check file size if image_path.stat().st_size < self.min_file_size: - logger.warning(f"Image file too small: {image_path}") + logger.warning("Image file too small: %s", image_path) return False return True except Exception as e: - logger.warning(f"Image validation failed for {image_path}: {e}") + logger.warning("Image validation failed for %s: %s", image_path, e) return False async def download_all_media( @@ -341,7 +346,7 @@ class ImageDownloader: for (media_type, _), result in zip(tasks, task_results): if isinstance(result, Exception): - logger.error(f"Error downloading {media_type}: {result}") + logger.error("Error downloading %s: %s", media_type, result) results[media_type] = False else: results[media_type] = result diff --git a/src/core/utils/nfo_generator.py b/src/core/utils/nfo_generator.py index f683d01..8968a9e 100644 --- a/src/core/utils/nfo_generator.py +++ b/src/core/utils/nfo_generator.py @@ -209,5 +209,5 @@ def validate_nfo_xml(xml_string: str) -> bool: etree.fromstring(xml_string.encode('utf-8')) return True except etree.XMLSyntaxError as e: - logger.error(f"Invalid NFO XML: {e}") + logger.error("Invalid NFO XML: %s", e) return False diff --git a/src/infrastructure/security/config_encryption.py b/src/infrastructure/security/config_encryption.py index 7e1c6b3..7590971 100644 --- a/src/infrastructure/security/config_encryption.py +++ b/src/infrastructure/security/config_encryption.py @@ -36,10 +36,10 @@ class ConfigEncryption: def _ensure_key_exists(self) -> None: """Ensure encryption key exists or create one.""" if not self.key_file.exists(): - logger.info(f"Creating new encryption key at {self.key_file}") + logger.info("Creating new encryption key at %s", self.key_file) self._generate_new_key() else: - logger.info(f"Using existing encryption key from {self.key_file}") + logger.info("Using existing encryption key from %s", self.key_file) def _generate_new_key(self) -> None: """Generate and store a new encryption key.""" @@ -56,7 +56,7 @@ class ConfigEncryption: logger.info("Generated new encryption key") except IOError as e: - logger.error(f"Failed to generate encryption key: {e}") + logger.error("Failed to generate encryption key: %s", e) raise def _load_key(self) -> bytes: @@ -77,7 +77,7 @@ class ConfigEncryption: key = self.key_file.read_bytes() return key except IOError as e: - logger.error(f"Failed to load encryption key: {e}") + logger.error("Failed to load encryption key: %s", e) raise def _get_cipher(self) -> Fernet: @@ -117,7 +117,7 @@ class ConfigEncryption: return encrypted_str except Exception as e: - logger.error(f"Failed to encrypt value: {e}") + logger.error("Failed to encrypt value: %s", e) raise def decrypt_value(self, encrypted_value: str) -> str: @@ -149,7 +149,7 @@ class ConfigEncryption: return decrypted_str except Exception as e: - logger.error(f"Failed to decrypt value: {e}") + logger.error("Failed to decrypt value: %s", e) raise def encrypt_config(self, config: Dict[str, Any]) -> Dict[str, Any]: @@ -191,9 +191,9 @@ class ConfigEncryption: 'encrypted': True, 'value': self.encrypt_value(value) } - logger.debug(f"Encrypted config field: {key}") + logger.debug("Encrypted config field: %s", key) except Exception as e: - logger.warning(f"Failed to encrypt {key}: {e}") + logger.warning("Failed to encrypt %s: %s", key, e) encrypted_config[key] = value else: encrypted_config[key] = value @@ -222,9 +222,9 @@ class ConfigEncryption: decrypted_config[key] = self.decrypt_value( value['value'] ) - logger.debug(f"Decrypted config field: {key}") + logger.debug("Decrypted config field: %s", key) except Exception as e: - logger.error(f"Failed to decrypt {key}: {e}") + logger.error("Failed to decrypt %s: %s", key, e) decrypted_config[key] = None else: decrypted_config[key] = value @@ -248,7 +248,7 @@ class ConfigEncryption: if self.key_file.exists(): backup_path = self.key_file.with_suffix('.key.bak') self.key_file.rename(backup_path) - logger.info(f"Backed up old key to {backup_path}") + logger.info("Backed up old key to %s", backup_path) # Generate new key if new_key_file: diff --git a/src/infrastructure/security/database_integrity.py b/src/infrastructure/security/database_integrity.py index 66dee66..1f75fae 100644 --- a/src/infrastructure/security/database_integrity.py +++ b/src/infrastructure/security/database_integrity.py @@ -276,13 +276,13 @@ class DatabaseIntegrityChecker: removed += 1 self.session.commit() - logger.info(f"Removed {removed} orphaned records") + logger.info("Removed %s orphaned records", removed) return removed except Exception as e: self.session.rollback() - logger.error(f"Error removing orphaned records: {e}") + logger.error("Error removing orphaned records: %s", e) raise diff --git a/src/infrastructure/security/file_integrity.py b/src/infrastructure/security/file_integrity.py index 2b24fb0..18c14cf 100644 --- a/src/infrastructure/security/file_integrity.py +++ b/src/infrastructure/security/file_integrity.py @@ -39,13 +39,15 @@ class FileIntegrityManager: self.checksums = json.load(f) count = len(self.checksums) logger.info( - f"Loaded {count} checksums from {self.checksum_file}" + "Loaded %d checksums from %s", + count, + self.checksum_file, ) except (json.JSONDecodeError, IOError) as e: - logger.error(f"Failed to load checksums: {e}") + logger.error("Failed to load checksums: %s", e) self.checksums = {} else: - logger.info(f"Checksum file does not exist: {self.checksum_file}") + logger.info("Checksum file does not exist: %s", self.checksum_file) self.checksums = {} def _save_checksums(self) -> None: @@ -56,10 +58,12 @@ class FileIntegrityManager: json.dump(self.checksums, f, indent=2) count = len(self.checksums) logger.debug( - f"Saved {count} checksums to {self.checksum_file}" + "Saved %d checksums to %s", + count, + self.checksum_file, ) except IOError as e: - logger.error(f"Failed to save checksums: {e}") + logger.error("Failed to save checksums: %s", e) def calculate_checksum( self, file_path: Path, algorithm: str = "sha256" @@ -94,12 +98,15 @@ class FileIntegrityManager: checksum = hash_obj.hexdigest() filename = file_path.name logger.debug( - f"Calculated {algorithm} checksum for {filename}: {checksum}" + "Calculated %s checksum for %s: %s", + algorithm, + filename, + checksum, ) return checksum except IOError as e: - logger.error(f"Failed to read file {file_path}: {e}") + logger.error("Failed to read file %s: %s", file_path, e) raise def store_checksum( @@ -126,7 +133,7 @@ class FileIntegrityManager: self.checksums[key] = checksum self._save_checksums() - logger.info(f"Stored checksum for {file_path.name}") + logger.info("Stored checksum for %s", file_path.name) return checksum def verify_checksum( @@ -197,10 +204,10 @@ class FileIntegrityManager: if key in self.checksums: del self.checksums[key] self._save_checksums() - logger.info(f"Removed checksum for {file_path.name}") + logger.info("Removed checksum for %s", file_path.name) return True else: - logger.debug(f"No checksum found to remove for {file_path.name}") + logger.debug("No checksum found to remove for %s", file_path.name) return False def has_checksum(self, file_path: Path) -> bool: diff --git a/src/server/api/anime.py b/src/server/api/anime.py index deae710..77e35f9 100644 --- a/src/server/api/anime.py +++ b/src/server/api/anime.py @@ -724,9 +724,9 @@ async def add_series( if series_app and hasattr(series_app, 'loader'): try: year = series_app.loader.get_year(key) - logger.info(f"Fetched year for {key}: {year}") + logger.info("Fetched year for %s: %s", key, year) except Exception as e: - logger.warning(f"Could not fetch year for {key}: {e}") + logger.warning("Could not fetch year for %s: %s", key, e) # Create folder name with year if available if year: diff --git a/src/server/api/health.py b/src/server/api/health.py index da01f0e..f50331a 100644 --- a/src/server/api/health.py +++ b/src/server/api/health.py @@ -91,7 +91,7 @@ async def check_database_health(db: AsyncSession) -> DatabaseHealth: message="Database connection successful", ) except Exception as e: - logger.error(f"Database health check failed: {e}") + logger.error("Database health check failed: %s", e) return DatabaseHealth( status="unhealthy", connection_time_ms=0, @@ -121,7 +121,7 @@ async def check_filesystem_health() -> Dict[str, Any]: "message": "Filesystem check completed", } except Exception as e: - logger.error(f"Filesystem health check failed: {e}") + logger.error("Filesystem health check failed: %s", e) return { "status": "unhealthy", "message": f"Filesystem check failed: {str(e)}", @@ -164,7 +164,7 @@ def get_system_metrics() -> SystemMetrics: uptime_seconds=uptime_seconds, ) except Exception as e: - logger.error(f"System metrics collection failed: {e}") + logger.error("System metrics collection failed: %s", e) raise HTTPException( status_code=500, detail=f"Failed to collect system metrics: {str(e)}" ) @@ -236,7 +236,7 @@ async def detailed_health_check( startup_time=startup_time, ) except Exception as e: - logger.error(f"Detailed health check failed: {e}") + logger.error("Detailed health check failed: %s", e) raise HTTPException(status_code=500, detail="Health check failed") diff --git a/src/server/api/nfo.py b/src/server/api/nfo.py index c3485ed..ab893b1 100644 --- a/src/server/api/nfo.py +++ b/src/server/api/nfo.py @@ -243,7 +243,7 @@ async def get_missing_nfo( ) except Exception as e: - logger.error(f"Error getting missing NFOs: {e}", exc_info=True) + logger.exception("Error getting missing NFOs: %s", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail=f"Failed to get missing NFOs: {str(e)}" @@ -334,7 +334,7 @@ async def check_nfo( except HTTPException: raise except Exception as e: - logger.error(f"Error checking NFO for {serie_id}: {e}", exc_info=True) + logger.exception("Error checking NFO for %s: %s", serie_id, e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail=f"Failed to check NFO: {str(e)}" @@ -429,7 +429,7 @@ async def create_nfo( except HTTPException: raise except TMDBAPIError as e: - logger.warning(f"TMDB API error creating NFO for {serie_id}: {e}") + logger.warning("TMDB API error creating NFO for %s: %s", serie_id, e) raise HTTPException( status_code=status.HTTP_503_SERVICE_UNAVAILABLE, detail=f"TMDB API error: {str(e)}" @@ -524,7 +524,7 @@ async def update_nfo( except HTTPException: raise except TMDBAPIError as e: - logger.warning(f"TMDB API error updating NFO for {serie_id}: {e}") + logger.warning("TMDB API error updating NFO for %s: %s", serie_id, e) raise HTTPException( status_code=status.HTTP_503_SERVICE_UNAVAILABLE, detail=f"TMDB API error: {str(e)}" diff --git a/src/server/config/logging_config.py b/src/server/config/logging_config.py index ff899eb..c783a5c 100644 --- a/src/server/config/logging_config.py +++ b/src/server/config/logging_config.py @@ -95,10 +95,10 @@ def setup_logging() -> Dict[str, logging.Logger]: # Log initial setup root_logger.info("=" * 80) root_logger.info("FastAPI Server Logging Initialized") - root_logger.info(f"Log Level: {settings.log_level.upper()}") - root_logger.info(f"Server Log: {server_log_file.absolute()}") - root_logger.info(f"Error Log: {error_log_file.absolute()}") - root_logger.info(f"Access Log: {access_log_file.absolute()}") + root_logger.info("Log Level: %s", settings.log_level.upper()) + root_logger.info("Server Log: %s", server_log_file.absolute()) + root_logger.info("Error Log: %s", error_log_file.absolute()) + root_logger.info("Access Log: %s", access_log_file.absolute()) root_logger.info("=" * 80) return { diff --git a/src/server/database/connection.py b/src/server/database/connection.py index 511b182..b1ed2a0 100644 --- a/src/server/database/connection.py +++ b/src/server/database/connection.py @@ -88,7 +88,7 @@ async def init_db() -> None: try: # Get database URL db_url = _get_database_url() - logger.info(f"Initializing database: {db_url}") + logger.info("Initializing database: %s", db_url) # Build engine kwargs based on database type is_sqlite = "sqlite" in db_url @@ -143,7 +143,7 @@ async def init_db() -> None: logger.info("Database initialization complete") except Exception as e: - logger.error(f"Failed to initialize database: {e}") + logger.error("Failed to initialize database: %s", e) raise @@ -171,7 +171,7 @@ async def close_db() -> None: conn.commit() logger.info("SQLite WAL checkpoint completed") except Exception as e: - logger.warning(f"WAL checkpoint failed (non-critical): {e}") + logger.warning("WAL checkpoint failed (non-critical): %s", e) if _engine: logger.info("Closing async database engine...") @@ -188,7 +188,7 @@ async def close_db() -> None: logger.info("Database connections closed") except Exception as e: - logger.error(f"Error closing database: {e}") + logger.error("Error closing database: %s", e) def get_engine() -> AsyncEngine: diff --git a/src/server/database/init.py b/src/server/database/init.py index 2c12738..63a372c 100644 --- a/src/server/database/init.py +++ b/src/server/database/init.py @@ -98,7 +98,7 @@ async def initialize_database( seed_data=True ) if result["success"]: - logger.info(f"Database initialized: {result['schema_version']}") + logger.info("Database initialized: %s", result['schema_version']) """ if engine is None: engine = get_engine() @@ -117,7 +117,7 @@ async def initialize_database( if create_schema: tables = await create_database_schema(engine) result["tables_created"] = tables - logger.info(f"Created {len(tables)} tables") + logger.info("Created %s tables", len(tables)) # Validate schema if requested if validate_schema: @@ -148,7 +148,7 @@ async def initialize_database( return result except Exception as e: - logger.error(f"Database initialization failed: {e}", exc_info=True) + logger.exception("Database initialization failed: %s", e) raise RuntimeError(f"Failed to initialize database: {e}") from e @@ -194,14 +194,14 @@ async def create_database_schema( created_tables = [t for t in new_tables if t not in existing_tables] if created_tables: - logger.info(f"Created tables: {', '.join(created_tables)}") + logger.info("Created tables: %s", ', '.join(created_tables)) else: logger.info("All tables already exist") return new_tables except Exception as e: - logger.error(f"Failed to create schema: {e}", exc_info=True) + logger.exception("Failed to create schema: %s", e) raise RuntimeError(f"Schema creation failed: {e}") from e @@ -295,7 +295,7 @@ async def validate_database_schema( return result except Exception as e: - logger.error(f"Schema validation failed: {e}", exc_info=True) + logger.exception("Schema validation failed: %s", e) return { "valid": False, "missing_tables": [], @@ -342,7 +342,7 @@ async def get_schema_version(engine: Optional[AsyncEngine] = None) -> str: return "unknown" except Exception as e: - logger.error(f"Failed to get schema version: {e}") + logger.error("Failed to get schema version: %s", e) return "error" @@ -409,7 +409,7 @@ async def seed_initial_data(engine: Optional[AsyncEngine] = None) -> None: logger.info("Data will be populated via normal application usage") except Exception as e: - logger.error(f"Failed to seed initial data: {e}", exc_info=True) + logger.exception("Failed to seed initial data: %s", e) raise @@ -484,12 +484,12 @@ async def check_database_health( f"(connectivity: {result['connectivity_ms']}ms)" ) else: - logger.warning(f"Database health issues: {result['issues']}") + logger.warning("Database health issues: %s", result['issues']) return result except Exception as e: - logger.error(f"Database health check failed: {e}") + logger.error("Database health check failed: %s", e) return { "healthy": False, "accessible": False, @@ -547,13 +547,13 @@ async def create_database_backup( backup_path = backup_dir / f"aniworld_{timestamp}.db" try: - logger.info(f"Creating database backup: {backup_path}") + logger.info("Creating database backup: %s", backup_path) shutil.copy2(db_path, backup_path) - logger.info(f"Backup created successfully: {backup_path}") + logger.info("Backup created successfully: %s", backup_path) return backup_path except Exception as e: - logger.error(f"Failed to create backup: {e}", exc_info=True) + logger.exception("Failed to create backup: %s", e) raise RuntimeError(f"Backup creation failed: {e}") from e diff --git a/src/server/database/service.py b/src/server/database/service.py index 2eb746d..872068f 100644 --- a/src/server/database/service.py +++ b/src/server/database/service.py @@ -107,7 +107,7 @@ class AnimeSeriesService: db.add(series) await db.flush() await db.refresh(series) - logger.info(f"Created anime series: {series.name} (key={series.key}, year={year})") + logger.info("Created anime series: %s (key=%s, year=%s)", series.name, series.key, year) return series @staticmethod @@ -205,7 +205,7 @@ class AnimeSeriesService: await db.flush() await db.refresh(series) - logger.info(f"Updated anime series: {series.name} (id={series_id})") + logger.info("Updated anime series: %s (id=%s)", series.name, series_id) return series @staticmethod @@ -226,7 +226,7 @@ class AnimeSeriesService: ) deleted = result.rowcount > 0 if deleted: - logger.info(f"Deleted anime series with id={series_id}") + logger.info("Deleted anime series with id=%s", series_id) return deleted @staticmethod @@ -701,7 +701,7 @@ class EpisodeService: updated_count += 1 await db.flush() - logger.info(f"Bulk marked {updated_count} episodes as downloaded") + logger.info("Bulk marked %s episodes as downloaded", updated_count) return updated_count @@ -850,7 +850,7 @@ class DownloadQueueService: await db.flush() await db.refresh(item) - logger.debug(f"Set error on download queue item {item_id}") + logger.debug("Set error on download queue item %s", item_id) return item @staticmethod @@ -869,7 +869,7 @@ class DownloadQueueService: ) deleted = result.rowcount > 0 if deleted: - logger.info(f"Deleted download queue item with id={item_id}") + logger.info("Deleted download queue item with id=%s", item_id) return deleted @staticmethod @@ -931,7 +931,7 @@ class DownloadQueueService: ) count = result.rowcount - logger.info(f"Bulk deleted {count} download queue items") + logger.info("Bulk deleted %s download queue items", count) return count @@ -952,7 +952,7 @@ class DownloadQueueService: """ result = await db.execute(delete(DownloadQueueItem)) count = result.rowcount - logger.info(f"Cleared all {count} download queue items") + logger.info("Cleared all %s download queue items", count) return count @@ -1006,7 +1006,7 @@ class UserSessionService: db.add(session) await db.flush() await db.refresh(session) - logger.info(f"Created user session: {session_id}") + logger.info("Created user session: %s", session_id) return session @staticmethod @@ -1093,7 +1093,7 @@ class UserSessionService: session.revoke() await db.flush() - logger.info(f"Revoked user session: {session_id}") + logger.info("Revoked user session: %s", session_id) return True @staticmethod @@ -1115,7 +1115,7 @@ class UserSessionService: ) ) count = result.rowcount - logger.info(f"Cleaned up {count} expired sessions") + logger.info("Cleaned up %s expired sessions", count) return count @staticmethod diff --git a/src/server/fastapi_app.py b/src/server/fastapi_app.py index b38ad2c..f519b27 100644 --- a/src/server/fastapi_app.py +++ b/src/server/fastapi_app.py @@ -97,10 +97,10 @@ async def _check_incomplete_series_on_startup(background_loader) -> None: logger.info("All series data is complete. No background loading needed.") except Exception as e: - logger.error(f"Error checking incomplete series: {e}", exc_info=True) + logger.exception("Error checking incomplete series: %s", e) except Exception as e: - logger.error(f"Failed to check incomplete series on startup: {e}", exc_info=True) + logger.exception("Failed to check incomplete series on startup: %s", e) @asynccontextmanager diff --git a/src/server/middleware/error_handler.py b/src/server/middleware/error_handler.py index dcda117..8b1bd77 100644 --- a/src/server/middleware/error_handler.py +++ b/src/server/middleware/error_handler.py @@ -74,7 +74,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle authentication errors (401).""" logger.warning( - f"Authentication error: {exc.message}", + "Authentication error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -94,7 +95,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle authorization errors (403).""" logger.warning( - f"Authorization error: {exc.message}", + "Authorization error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -114,7 +116,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle validation errors (422).""" logger.info( - f"Validation error: {exc.message}", + "Validation error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -134,7 +137,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle bad request errors (400).""" logger.info( - f"Bad request error: {exc.message}", + "Bad request error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -154,7 +158,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle not found errors (404).""" logger.info( - f"Not found error: {exc.message}", + "Not found error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -174,7 +179,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle conflict errors (409).""" logger.info( - f"Conflict error: {exc.message}", + "Conflict error: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -194,7 +200,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle rate limit errors (429).""" logger.warning( - f"Rate limit exceeded: {exc.message}", + "Rate limit exceeded: %s", + exc.message, extra={"details": exc.details, "path": str(request.url.path)}, ) return JSONResponse( @@ -214,7 +221,8 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle generic API exceptions.""" logger.error( - f"API error: {exc.message}", + "API error: %s", + exc.message, extra={ "error_code": exc.error_code, "details": exc.details, @@ -238,12 +246,13 @@ def register_exception_handlers(app: FastAPI) -> None: ) -> JSONResponse: """Handle unexpected exceptions.""" logger.exception( - f"Unexpected error: {str(exc)}", + "Unexpected error: %s", + str(exc), extra={"path": str(request.url.path)}, ) # Log full traceback for debugging - logger.debug(f"Traceback: {traceback.format_exc()}") + logger.debug("Traceback: %s", traceback.format_exc()) # Return generic error response for security return JSONResponse( diff --git a/src/server/middleware/security.py b/src/server/middleware/security.py index 96fcd08..af4f110 100644 --- a/src/server/middleware/security.py +++ b/src/server/middleware/security.py @@ -315,11 +315,11 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware): None if malicious content detected, sanitized value otherwise """ if self.check_sql_injection and self._check_sql_injection(value): - logger.warning(f"Potential SQL injection detected: {value[:100]}") + logger.warning("Potential SQL injection detected: %s", value[:100]) return None if self.check_xss and self._check_xss(value): - logger.warning(f"Potential XSS detected: {value[:100]}") + logger.warning("Potential XSS detected: %s", value[:100]) return None return value @@ -341,7 +341,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware): content_type and not any(ct in content_type for ct in self.allowed_content_types) ): - logger.warning(f"Unsupported content type: {content_type}") + logger.warning("Unsupported content type: %s", content_type) return JSONResponse( status_code=415, content={"detail": "Unsupported Media Type"}, @@ -350,7 +350,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware): # Check request size content_length = request.headers.get("content-length") if content_length and int(content_length) > self.max_request_size: - logger.warning(f"Request too large: {content_length} bytes") + logger.warning("Request too large: %s bytes", content_length) return JSONResponse( status_code=413, content={"detail": "Request Entity Too Large"}, @@ -361,7 +361,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware): if isinstance(value, str): sanitized = self._sanitize_value(value) if sanitized is None: - logger.warning(f"Malicious query parameter detected: {key}") + logger.warning("Malicious query parameter detected: %s", key) return JSONResponse( status_code=400, content={"detail": "Malicious request detected"}, @@ -372,7 +372,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware): if isinstance(value, str): sanitized = self._sanitize_value(value) if sanitized is None: - logger.warning(f"Malicious path parameter detected: {key}") + logger.warning("Malicious path parameter detected: %s", key) return JSONResponse( status_code=400, content={"detail": "Malicious request detected"}, diff --git a/src/server/services/anime_service.py b/src/server/services/anime_service.py index f623a08..581009d 100644 --- a/src/server/services/anime_service.py +++ b/src/server/services/anime_service.py @@ -945,12 +945,12 @@ class AnimeService: # Get the serie from in-memory cache if not hasattr(self._app, 'list') or not hasattr(self._app.list, 'keyDict'): - logger.warning(f"Series list not available for episode sync: {series_key}") + logger.warning("Series list not available for episode sync: %s", series_key) return 0 serie = self._app.list.keyDict.get(series_key) if not serie: - logger.warning(f"Series not found in memory for episode sync: {series_key}") + logger.warning("Series not found in memory for episode sync: %s", series_key) return 0 episodes_added = 0 @@ -959,7 +959,7 @@ class AnimeService: # Get series from database series_db = await AnimeSeriesService.get_by_key(db, series_key) if not series_db: - logger.warning(f"Series not found in database: {series_key}") + logger.warning("Series not found in database: %s", series_key) return 0 # Get existing episodes from database @@ -1000,7 +1000,7 @@ class AnimeService: try: await self._broadcast_series_updated(series_key) except Exception as e: - logger.warning(f"Failed to broadcast series update: {e}") + logger.warning("Failed to broadcast series update: %s", e) return episodes_added diff --git a/src/server/services/background_loader_service.py b/src/server/services/background_loader_service.py index fdd439e..6415e6d 100644 --- a/src/server/services/background_loader_service.py +++ b/src/server/services/background_loader_service.py @@ -188,7 +188,7 @@ class BackgroundLoaderService: """ # Check if task already exists if key in self.active_tasks: - logger.debug(f"Task for series {key} already exists, skipping") + logger.debug("Task for series %s already exists, skipping", key) return task = SeriesLoadingTask( @@ -202,7 +202,7 @@ class BackgroundLoaderService: self.active_tasks[key] = task await self.task_queue.put(task) - logger.info(f"Added loading task for series: {key}") + logger.info("Added loading task for series: %s", key) # Broadcast initial status await self._broadcast_status(task) @@ -277,7 +277,7 @@ class BackgroundLoaderService: Args: worker_id: Unique identifier for this worker instance """ - logger.info(f"Background worker {worker_id} started processing tasks") + logger.info("Background worker %s started processing tasks", worker_id) while not self._shutdown: try: @@ -301,14 +301,14 @@ class BackgroundLoaderService: # No task available, continue loop continue except asyncio.CancelledError: - logger.info(f"Worker {worker_id} task cancelled") + logger.info("Worker %s task cancelled", worker_id) break except Exception as e: - logger.exception(f"Error in background worker {worker_id}: {e}") + logger.exception("Error in background worker %s: %s", worker_id, e) # Continue processing other tasks continue - logger.info(f"Background worker {worker_id} stopped") + logger.info("Background worker %s stopped", worker_id) async def _load_series_data(self, task: SeriesLoadingTask) -> None: """Load all missing data for a series. @@ -362,10 +362,10 @@ class BackgroundLoaderService: # Broadcast completion await self._broadcast_status(task) - logger.info(f"Successfully loaded all data for series: {task.key}") + logger.info("Successfully loaded all data for series: %s", task.key) except Exception as e: - logger.exception(f"Error loading series data: {e}") + logger.exception("Error loading series data: %s", e) task.status = LoadingStatus.FAILED task.error = str(e) task.completed_at = datetime.now(timezone.utc) @@ -400,14 +400,14 @@ class BackgroundLoaderService: # Check if directory exists if series_dir.exists() and series_dir.is_dir(): - logger.debug(f"Found series directory: {series_dir}") + logger.debug("Found series directory: %s", series_dir) return series_dir else: - logger.warning(f"Series directory not found: {series_dir}") + logger.warning("Series directory not found: %s", series_dir) return None except Exception as e: - logger.error(f"Error finding series directory for {task.key}: {e}") + logger.error("Error finding series directory for %s: %s", task.key, e) return None async def _scan_series_episodes(self, series_dir: Path, task: SeriesLoadingTask) -> Dict[str, List[str]]: @@ -440,13 +440,13 @@ class BackgroundLoaderService: if episodes: episodes_by_season[season_name] = episodes - logger.debug(f"Found {len(episodes)} episodes in {season_name}") + logger.debug("Found %s episodes in %s", len(episodes), season_name) - logger.info(f"Scanned {len(episodes_by_season)} seasons for {task.key}") + logger.info("Scanned %s seasons for %s", len(episodes_by_season), task.key) return episodes_by_season except Exception as e: - logger.error(f"Error scanning episodes for {task.key}: {e}") + logger.error("Error scanning episodes for %s: %s", task.key, e) return {} async def _load_episodes(self, task: SeriesLoadingTask, db: Any) -> None: @@ -466,7 +466,7 @@ class BackgroundLoaderService: # Find series directory without full rescan series_dir = await self._find_series_directory(task) if not series_dir: - logger.error(f"Cannot load episodes - directory not found for {task.key}") + logger.error("Cannot load episodes - directory not found for %s", task.key) task.progress["episodes"] = False return @@ -474,7 +474,7 @@ class BackgroundLoaderService: episodes_by_season = await self._scan_series_episodes(series_dir, task) if not episodes_by_season: - logger.warning(f"No episodes found for {task.key}") + logger.warning("No episodes found for %s", task.key) task.progress["episodes"] = False return @@ -489,10 +489,10 @@ class BackgroundLoaderService: series_db.loading_status = "loading_episodes" await db.commit() - logger.info(f"Episodes loaded for series: {task.key} ({len(episodes_by_season)} seasons)") + logger.info("Episodes loaded for series: %s (%s seasons)", task.key, len(episodes_by_season)) except Exception as e: - logger.exception(f"Failed to load episodes for {task.key}: {e}") + logger.exception("Failed to load episodes for %s: %s", task.key, e) raise async def _load_nfo_and_images(self, task: SeriesLoadingTask, db: Any) -> bool: @@ -521,7 +521,7 @@ class BackgroundLoaderService: # Check if NFO already exists if self.series_app.nfo_service.has_nfo(task.folder): - logger.info(f"NFO already exists for {task.key}, skipping creation") + logger.info("NFO already exists for %s, skipping creation", task.key) # Update task progress task.progress["nfo"] = True @@ -536,19 +536,19 @@ class BackgroundLoaderService: if not series_db.has_nfo: series_db.has_nfo = True series_db.nfo_created_at = datetime.now(timezone.utc) - logger.info(f"Updated database with existing NFO for {task.key}") + logger.info("Updated database with existing NFO for %s", task.key) if not series_db.logo_loaded: series_db.logo_loaded = True if not series_db.images_loaded: series_db.images_loaded = True await db.commit() - logger.info(f"Existing NFO found and database updated for series: {task.key}") + logger.info("Existing NFO found and database updated for series: %s", task.key) return False # NFO doesn't exist, create it await self._broadcast_status(task, "Generating NFO file...") - logger.info(f"Creating new NFO for {task.key}") + logger.info("Creating new NFO for %s", task.key) # Use existing NFOService to create NFO with all images # This reuses all existing TMDB API logic and image downloading @@ -577,11 +577,11 @@ class BackgroundLoaderService: series_db.loading_status = "loading_nfo" await db.commit() - logger.info(f"NFO and images created and loaded for series: {task.key}") + logger.info("NFO and images created and loaded for series: %s", task.key) return True except Exception as e: - logger.exception(f"Failed to load NFO/images for {task.key}: {e}") + logger.exception("Failed to load NFO/images for %s: %s", task.key, e) # Don't fail the entire task if NFO fails task.progress["nfo"] = False task.progress["logo"] = False @@ -611,7 +611,7 @@ class BackgroundLoaderService: # Scan for missing episodes using the targeted scan method # This populates the episodeDict without triggering a full rescan - logger.info(f"Scanning missing episodes for {task.key}") + logger.info("Scanning missing episodes for %s", task.key) missing_episodes = self.series_app.serie_scanner.scan_single_series( key=task.key, folder=task.folder @@ -628,12 +628,12 @@ class BackgroundLoaderService: # Notify anime_service to sync episodes to database # Use sync_single_series_after_scan which gets data from serie_scanner.keyDict if self.anime_service: - logger.debug(f"Calling anime_service.sync_single_series_after_scan for {task.key}") + logger.debug("Calling anime_service.sync_single_series_after_scan for %s", task.key) await self.anime_service.sync_single_series_after_scan(task.key) else: - logger.warning(f"anime_service not available, episodes will not be synced to DB for {task.key}") + logger.warning("anime_service not available, episodes will not be synced to DB for %s", task.key) else: - logger.info(f"No missing episodes found for {task.key}") + logger.info("No missing episodes found for %s", task.key) # Update series status in database from src.server.database.service import AnimeSeriesService @@ -648,7 +648,7 @@ class BackgroundLoaderService: task.progress["episodes"] = True except Exception as e: - logger.exception(f"Failed to scan missing episodes for {task.key}: {e}") + logger.exception("Failed to scan missing episodes for %s: %s", task.key, e) task.progress["episodes"] = False async def _broadcast_status( diff --git a/src/server/services/cache_service.py b/src/server/services/cache_service.py index 19fc803..0df5463 100644 --- a/src/server/services/cache_service.py +++ b/src/server/services/cache_service.py @@ -170,14 +170,17 @@ class InMemoryCacheBackend(CacheBackend): """Get value from cache.""" async with self._lock: if key not in self.cache: + logger.debug("Cache miss for key: %s", key) return None item = self.cache[key] if self._is_expired(item): + logger.debug("Cache expired for key: %s", key) del self.cache[key] return None + logger.debug("Cache hit for key: %s", key) return item["value"] async def set( @@ -196,6 +199,7 @@ class InMemoryCacheBackend(CacheBackend): "expiry": expiry, "created": datetime.utcnow(), } + logger.debug("Cached key: %s (ttl=%s)", key, ttl) return True async def delete(self, key: str) -> bool: @@ -203,7 +207,9 @@ class InMemoryCacheBackend(CacheBackend): async with self._lock: if key in self.cache: del self.cache[key] + logger.debug("Deleted cache key: %s", key) return True + logger.debug("Cache delete skipped; key not found: %s", key) return False async def exists(self, key: str) -> bool: @@ -223,6 +229,7 @@ class InMemoryCacheBackend(CacheBackend): """Clear all cached values.""" async with self._lock: self.cache.clear() + logger.debug("Cleared in-memory cache") return True async def get_many(self, keys: List[str]) -> Dict[str, Any]: @@ -281,13 +288,14 @@ class RedisCacheBackend(CacheBackend): import aioredis self._redis = await aioredis.create_redis_pool(self.redis_url) + logger.debug("Connected to Redis at %s", self.redis_url) except ImportError: logger.error( "aioredis not installed. Install with: pip install aioredis" ) raise except Exception as e: - logger.error(f"Failed to connect to Redis: {e}") + logger.error("Failed to connect to Redis: %s", e) raise return self._redis @@ -308,7 +316,7 @@ class RedisCacheBackend(CacheBackend): return pickle.loads(data) except Exception as e: - logger.error(f"Redis get error: {e}") + logger.error("Redis get error: %s", e) return None async def set( @@ -327,7 +335,7 @@ class RedisCacheBackend(CacheBackend): return True except Exception as e: - logger.error(f"Redis set error: {e}") + logger.error("Redis set error: %s", e) return False async def delete(self, key: str) -> bool: @@ -338,7 +346,7 @@ class RedisCacheBackend(CacheBackend): return result > 0 except Exception as e: - logger.error(f"Redis delete error: {e}") + logger.error("Redis delete error: %s", e) return False async def exists(self, key: str) -> bool: @@ -348,7 +356,7 @@ class RedisCacheBackend(CacheBackend): return await redis.exists(self._make_key(key)) except Exception as e: - logger.error(f"Redis exists error: {e}") + logger.error("Redis exists error: %s", e) return False async def clear(self) -> bool: @@ -361,7 +369,7 @@ class RedisCacheBackend(CacheBackend): return True except Exception as e: - logger.error(f"Redis clear error: {e}") + logger.error("Redis clear error: %s", e) return False async def get_many(self, keys: List[str]) -> Dict[str, Any]: @@ -379,7 +387,7 @@ class RedisCacheBackend(CacheBackend): return result except Exception as e: - logger.error(f"Redis get_many error: {e}") + logger.error("Redis get_many error: %s", e) return {} async def set_many( @@ -392,7 +400,7 @@ class RedisCacheBackend(CacheBackend): return True except Exception as e: - logger.error(f"Redis set_many error: {e}") + logger.error("Redis set_many error: %s", e) return False async def delete_pattern(self, pattern: str) -> int: @@ -409,7 +417,7 @@ class RedisCacheBackend(CacheBackend): return 0 except Exception as e: - logger.error(f"Redis delete_pattern error: {e}") + logger.error("Redis delete_pattern error: %s", e) return 0 async def close(self) -> None: diff --git a/src/server/services/config_service.py b/src/server/services/config_service.py index da38fb1..0f0e5eb 100644 --- a/src/server/services/config_service.py +++ b/src/server/services/config_service.py @@ -8,6 +8,7 @@ This service handles: """ import json +import logging import shutil from datetime import datetime from pathlib import Path @@ -15,6 +16,8 @@ from typing import Dict, List, Optional from src.server.models.config import AppConfig, ConfigUpdate, ValidationResult +logger = logging.getLogger(__name__) + class ConfigServiceError(Exception): """Base exception for configuration service errors.""" @@ -136,7 +139,7 @@ class ConfigService: self.create_backup() except ConfigBackupError as e: # Log but don't fail save operation - print(f"Warning: Failed to create backup: {e}") + logger.warning("Failed to create backup: %s", e) # Save configuration with version data = config.model_dump() diff --git a/src/server/services/initialization_service.py b/src/server/services/initialization_service.py index 8aa136e..ac16334 100644 --- a/src/server/services/initialization_service.py +++ b/src/server/services/initialization_service.py @@ -342,7 +342,7 @@ async def perform_nfo_scan_if_needed(progress_service=None): if not settings.tmdb_api_key else "Skipped - NFO features disabled" ) - logger.info(f"NFO scan skipped: {message}") + logger.info("NFO scan skipped: %s", message) if progress_service: await progress_service.complete_progress( diff --git a/src/server/services/notification_service.py b/src/server/services/notification_service.py index 86f4c09..e01f4b6 100644 --- a/src/server/services/notification_service.py +++ b/src/server/services/notification_service.py @@ -151,7 +151,7 @@ class EmailNotificationService: start_tls=True, ) - logger.info(f"Email notification sent to {to_address}") + logger.info("Email notification sent to %s", to_address) return True except ImportError: @@ -160,7 +160,7 @@ class EmailNotificationService: ) return False except Exception as e: - logger.error(f"Failed to send email notification: {e}") + logger.error("Failed to send email notification: %s", e) return False @@ -205,7 +205,7 @@ class WebhookNotificationService: timeout=aiohttp.ClientTimeout(total=self.timeout), ) as response: if response.status < 400: - logger.info(f"Webhook notification sent to {url}") + logger.info("Webhook notification sent to %s", url) return True else: logger.warning( @@ -213,9 +213,9 @@ class WebhookNotificationService: ) except asyncio.TimeoutError: - logger.warning(f"Webhook timeout (attempt {attempt + 1}/{self.max_retries}): {url}") + logger.warning("Webhook timeout (attempt %s/%s): %s", attempt + 1, self.max_retries, url) except Exception as e: - logger.error(f"Failed to send webhook (attempt {attempt + 1}/{self.max_retries}): {e}") + logger.error("Failed to send webhook (attempt %s/%s): %s", attempt + 1, self.max_retries, e) if attempt < self.max_retries - 1: await asyncio.sleep(2 ** attempt) # Exponential backoff @@ -436,7 +436,7 @@ class NotificationService: await self.in_app_service.add_notification(notification) results["in_app"] = True except Exception as e: - logger.error(f"Failed to send in-app notification: {e}") + logger.error("Failed to send in-app notification: %s", e) results["in_app"] = False # Send email notification @@ -452,7 +452,7 @@ class NotificationService: ) results["email"] = success except Exception as e: - logger.error(f"Failed to send email notification: {e}") + logger.error("Failed to send email notification: %s", e) results["email"] = False # Send webhook notifications @@ -476,7 +476,7 @@ class NotificationService: success = await self.webhook_service.send_webhook(str(url), payload) webhook_results.append(success) except Exception as e: - logger.error(f"Failed to send webhook notification to {url}: {e}") + logger.error("Failed to send webhook notification to %s: %s", url, e) webhook_results.append(False) results["webhook"] = all(webhook_results) if webhook_results else False diff --git a/src/server/utils/log_manager.py b/src/server/utils/log_manager.py index 0f71a76..67b8c38 100644 --- a/src/server/utils/log_manager.py +++ b/src/server/utils/log_manager.py @@ -82,7 +82,7 @@ class LogManager: log_path = self.log_dir / log_file if not log_path.exists(): - logger.warning(f"Log file not found: {log_file}") + logger.warning("Log file not found: %s", log_file) return False stat = log_path.stat() @@ -99,10 +99,10 @@ class LogManager: # Compress the rotated file self._compress_log(rotated_path) - logger.info(f"Rotated log file: {log_file} -> {rotated_name}") + logger.info("Rotated log file: %s -> %s", log_file, rotated_name) return True except Exception as e: - logger.error(f"Failed to rotate log file {log_file}: {e}") + logger.error("Failed to rotate log file %s: %s", log_file, e) return False def _compress_log(self, log_path: Path) -> bool: @@ -122,10 +122,10 @@ class LogManager: shutil.copyfileobj(f_in, f_out) log_path.unlink() - logger.debug(f"Compressed log file: {log_path.name}") + logger.debug("Compressed log file: %s", log_path.name) return True except Exception as e: - logger.error(f"Failed to compress log {log_path}: {e}") + logger.error("Failed to compress log %s: %s", log_path, e) return False def archive_old_logs( @@ -160,10 +160,10 @@ class LogManager: f"Failed to archive {log_file.filename}: {e}" ) - logger.info(f"Archived {archived_count} old log files") + logger.info("Archived %s old log files", archived_count) return archived_count except Exception as e: - logger.error(f"Failed to archive logs: {e}") + logger.error("Failed to archive logs: %s", e) return 0 def search_logs( @@ -209,7 +209,7 @@ class LogManager: ) return results except Exception as e: - logger.error(f"Failed to search logs: {e}") + logger.error("Failed to search logs: %s", e) return {} def export_logs( @@ -243,7 +243,7 @@ class LogManager: arcname=log_file.filename, ) - logger.info(f"Exported logs to: {tar_path}") + logger.info("Exported logs to: %s", tar_path) return True else: # Concatenate all logs @@ -253,10 +253,10 @@ class LogManager: with open(log_file.path, "r") as in_f: out_f.write(in_f.read()) - logger.info(f"Exported logs to: {output_path}") + logger.info("Exported logs to: %s", output_path) return True except Exception as e: - logger.error(f"Failed to export logs: {e}") + logger.error("Failed to export logs: %s", e) return False def get_log_stats(self) -> Dict[str, Any]: @@ -294,7 +294,7 @@ class LogManager: "newest_file": log_files[0].filename, } except Exception as e: - logger.error(f"Failed to get log stats: {e}") + logger.error("Failed to get log stats: %s", e) return {} def cleanup_logs( @@ -330,16 +330,16 @@ class LogManager: log_file.path.unlink() total_size -= log_file.size_bytes deleted_count += 1 - logger.debug(f"Deleted log file: {log_file.filename}") + logger.debug("Deleted log file: %s", log_file.filename) except Exception as e: logger.warning( f"Failed to delete {log_file.filename}: {e}" ) - logger.info(f"Cleaned up {deleted_count} log files") + logger.info("Cleaned up %s log files", deleted_count) return deleted_count except Exception as e: - logger.error(f"Failed to cleanup logs: {e}") + logger.error("Failed to cleanup logs: %s", e) return 0 def set_log_level(self, logger_name: str, level: str) -> bool: @@ -357,10 +357,10 @@ class LogManager: target_logger = logging.getLogger(logger_name) target_logger.setLevel(log_level) - logger.info(f"Set {logger_name} log level to {level}") + logger.info("Set %s log level to %s", logger_name, level) return True except Exception as e: - logger.error(f"Failed to set log level: {e}") + logger.error("Failed to set log level: %s", e) return False diff --git a/src/server/utils/logging.py b/src/server/utils/logging.py index eb6e611..1eec8a4 100644 --- a/src/server/utils/logging.py +++ b/src/server/utils/logging.py @@ -416,9 +416,9 @@ def cleanup_old_logs(log_dir: Union[str, Path], try: if log_file.stat().st_mtime < cutoff_time: log_file.unlink() - logger.info(f"Deleted old log file: {log_file}") + logger.info("Deleted old log file: %s", log_file) except Exception as e: - logger.error(f"Failed to delete log file {log_file}: {e}") + logger.error("Failed to delete log file %s: %s", log_file, e) # Initialize default logging configuration diff --git a/src/server/utils/metrics.py b/src/server/utils/metrics.py index 501e513..61c54f4 100644 --- a/src/server/utils/metrics.py +++ b/src/server/utils/metrics.py @@ -161,7 +161,7 @@ class MetricsCollector: Duration in seconds. """ if timer_name not in self._timers: - logger.warning(f"Timer {timer_name} not started") + logger.warning("Timer %s not started", timer_name) return 0.0 duration = time.time() - self._timers[timer_name] diff --git a/src/server/utils/system.py b/src/server/utils/system.py index f0b5e2a..23cae6e 100644 --- a/src/server/utils/system.py +++ b/src/server/utils/system.py @@ -60,7 +60,7 @@ class SystemUtilities: path=path, ) except Exception as e: - logger.error(f"Failed to get disk usage for {path}: {e}") + logger.error("Failed to get disk usage for %s: %s", path, e) return None @staticmethod @@ -93,7 +93,7 @@ class SystemUtilities: return disk_infos except Exception as e: - logger.error(f"Failed to get all disk usage: {e}") + logger.error("Failed to get all disk usage: %s", e) return [] @staticmethod @@ -115,7 +115,7 @@ class SystemUtilities: path = Path(directory) if not path.exists(): - logger.warning(f"Directory not found: {directory}") + logger.warning("Directory not found: %s", directory) return 0 deleted_count = 0 @@ -130,16 +130,16 @@ class SystemUtilities: try: file_path.unlink() deleted_count += 1 - logger.debug(f"Deleted file: {file_path}") + logger.debug("Deleted file: %s", file_path) except Exception as e: logger.warning( f"Failed to delete {file_path}: {e}" ) - logger.info(f"Cleaned up {deleted_count} files from {directory}") + logger.info("Cleaned up %s files from %s", deleted_count, directory) return deleted_count except Exception as e: - logger.error(f"Failed to cleanup directory {directory}: {e}") + logger.error("Failed to cleanup directory %s: %s", directory, e) return 0 @staticmethod @@ -171,12 +171,12 @@ class SystemUtilities: f"Deleted empty directory: {dir_path}" ) except Exception as e: - logger.debug(f"Cannot delete {dir_path}: {e}") + logger.debug("Cannot delete %s: %s", dir_path, e) - logger.info(f"Cleaned up {deleted_count} empty directories") + logger.info("Cleaned up %s empty directories", deleted_count) return deleted_count except Exception as e: - logger.error(f"Failed to cleanup empty directories: {e}") + logger.error("Failed to cleanup empty directories: %s", e) return 0 @staticmethod @@ -201,7 +201,7 @@ class SystemUtilities: return total_size except Exception as e: - logger.error(f"Failed to get directory size for {directory}: {e}") + logger.error("Failed to get directory size for %s: %s", directory, e) return 0 @staticmethod @@ -232,7 +232,7 @@ class SystemUtilities: ), ) except Exception as e: - logger.error(f"Failed to get process info for {pid}: {e}") + logger.error("Failed to get process info for %s: %s", pid, e) return None @staticmethod @@ -260,7 +260,7 @@ class SystemUtilities: return processes except Exception as e: - logger.error(f"Failed to get all processes: {e}") + logger.error("Failed to get all processes: %s", e) return [] @staticmethod @@ -285,7 +285,7 @@ class SystemUtilities: "python_version": platform.python_version(), } except Exception as e: - logger.error(f"Failed to get system info: {e}") + logger.error("Failed to get system info: %s", e) return {} @staticmethod @@ -308,7 +308,7 @@ class SystemUtilities: "dropped_out": net_io.dropout, } except Exception as e: - logger.error(f"Failed to get network info: {e}") + logger.error("Failed to get network info: %s", e) return {} @staticmethod @@ -330,7 +330,7 @@ class SystemUtilities: dest_path = Path(dest) if not src_path.exists(): - logger.error(f"Source file not found: {src}") + logger.error("Source file not found: %s", src) return False # Create temporary file @@ -342,10 +342,10 @@ class SystemUtilities: # Atomic rename temp_path.replace(dest_path) - logger.debug(f"Atomically copied {src} to {dest}") + logger.debug("Atomically copied %s to %s", src, dest) return True except Exception as e: - logger.error(f"Failed to copy file {src} to {dest}: {e}") + logger.error("Failed to copy file %s to %s: %s", src, dest, e) return False diff --git a/tests/api/test_concurrent_anime_add.py b/tests/api/test_concurrent_anime_add.py index dc24ff1..a400023 100644 --- a/tests/api/test_concurrent_anime_add.py +++ b/tests/api/test_concurrent_anime_add.py @@ -4,12 +4,15 @@ This test verifies that the /api/anime/add endpoint can handle multiple concurrent requests without blocking. """ import asyncio +import logging import time from unittest.mock import AsyncMock, MagicMock, patch import pytest from httpx import ASGITransport, AsyncClient +logger = logging.getLogger(__name__) + from src.server.fastapi_app import app from src.server.services.auth_service import auth_service from src.server.services.background_loader_service import get_background_loader_service @@ -103,7 +106,7 @@ async def test_concurrent_anime_add_requests(authenticated_client): f"indicating possible blocking issues" ) - print(f"3 concurrent anime add requests completed in {total_time:.2f}s") + logger.info("3 concurrent anime add requests completed in %.2fs", total_time) @pytest.mark.asyncio @@ -130,4 +133,4 @@ async def test_same_anime_concurrent_add(authenticated_client): keys = [r.json().get("key") for r in responses] assert keys[0] == keys[1], "Both responses should have the same key" - print(f"Concurrent same-anime requests handled correctly: {statuses}") + logger.info("Concurrent same-anime requests handled correctly: %s", statuses) diff --git a/tests/performance/test_nfo_batch_performance.py b/tests/performance/test_nfo_batch_performance.py index fe25ab6..2c110c9 100644 --- a/tests/performance/test_nfo_batch_performance.py +++ b/tests/performance/test_nfo_batch_performance.py @@ -4,6 +4,7 @@ This module tests the performance characteristics of batch NFO creation including concurrent operations, TMDB API request optimization, and memory usage. """ import asyncio +import logging import time from pathlib import Path from typing import List @@ -15,6 +16,8 @@ from src.core.services.nfo_service import NFOService from src.server.api.nfo import batch_create_nfo from src.server.models.nfo import NFOBatchCreateRequest +logger = logging.getLogger(__name__) + class TestConcurrentNFOCreation: """Test performance of concurrent NFO creation operations.""" @@ -83,8 +86,11 @@ class TestConcurrentNFOCreation: # Concurrent should take roughly (num_series / 5) * 0.1 = 0.2s assert elapsed_time < 1.0, "Concurrency not providing speedup" - print(f"\nPerformance: {num_series} series in {elapsed_time:.2f}s") - print(f"Rate: {num_series / elapsed_time:.2f} series/second") + logger.info("Batch NFO creation completed", extra={"num_series": num_series, "elapsed_s": elapsed_time}) + logger.debug( + "Batch NFO creation rate", + extra={"series_per_second": num_series / elapsed_time}, + ) @pytest.mark.asyncio async def test_concurrent_nfo_creation_50_series(self): diff --git a/tests/performance/test_websocket_load.py b/tests/performance/test_websocket_load.py index 0a016a7..addc8e9 100644 --- a/tests/performance/test_websocket_load.py +++ b/tests/performance/test_websocket_load.py @@ -4,6 +4,7 @@ This module tests the performance characteristics of WebSocket connections including concurrent clients, message throughput, and progress update throttling. """ import asyncio +import logging import time from typing import List from unittest.mock import AsyncMock, Mock @@ -12,6 +13,8 @@ import pytest from src.server.services.websocket_service import WebSocketService +logger = logging.getLogger(__name__) + class MockWebSocket: """Mock WebSocket client for testing.""" @@ -82,8 +85,14 @@ class TestWebSocketConcurrentClients: for i in range(num_clients): await websocket_service.disconnect(f"client_{i:03d}") - print(f"\n100 clients: Broadcast in {elapsed_time:.2f}s") - print(f"Average per client: {elapsed_time / num_clients * 1000:.2f}ms") + logger.info("Broadcast completed for %d clients", num_clients, extra={"elapsed_s": elapsed_time}) + logger.debug( + "Broadcast performance per client", + extra={ + "num_clients": num_clients, + "avg_ms_per_client": elapsed_time / num_clients * 1000, + }, + ) @pytest.mark.asyncio async def test_200_concurrent_clients_scalability(self): @@ -114,7 +123,7 @@ class TestWebSocketConcurrentClients: for i in range(num_clients): await websocket_service.disconnect(f"client_{i:03d}") - print(f"\n200 clients: Broadcast in {elapsed_time:.2f}s") + logger.info("Broadcast completed for %d clients", num_clients, extra={"elapsed_s": elapsed_time}) @pytest.mark.asyncio async def test_connection_pool_efficiency(self): @@ -144,8 +153,8 @@ class TestWebSocketConcurrentClients: for i in range(num_clients): await websocket_service.disconnect(f"client_{i:02d}") - print(f"\nConnected {num_clients} clients in {connection_time:.3f}s") - print(f"Average: {connection_time / num_clients * 1000:.2f}ms per connection") + logger.info("Connected %d clients in %.3fs", num_clients, connection_time) + logger.info("Average: %.2fms per connection", connection_time / num_clients * 1000) class TestMessageThroughput: @@ -192,8 +201,13 @@ class TestMessageThroughput: for i in range(num_clients): await websocket_service.disconnect(f"client_{i}") - print(f"\nThroughput: {messages_per_second:.2f} messages/second") - print(f"Total: {num_messages} messages to {num_clients} clients in {elapsed_time:.2f}s") + logger.info("Throughput: %.2f messages/second", messages_per_second) + logger.info( + "Total: %d messages to %d clients in %.2fs", + num_messages, + num_clients, + elapsed_time, + ) @pytest.mark.asyncio async def test_high_frequency_updates(self): @@ -234,7 +248,7 @@ class TestMessageThroughput: for i in range(5): await websocket_service.disconnect(f"client_{i}") - print(f"\nHigh-frequency: {updates_per_second:.2f} updates/second") + logger.info("High-frequency: %.2f updates/second", updates_per_second) @pytest.mark.asyncio async def test_burst_message_handling(self): @@ -275,7 +289,7 @@ class TestMessageThroughput: for i in range(num_clients): await websocket_service.disconnect(f"client_{i:02d}") - print(f"\nBurst: {num_messages} messages in {elapsed_time:.2f}s") + logger.info("Burst: %d messages in %.2fs", num_messages, elapsed_time) class TestProgressUpdateThrottling: @@ -313,7 +327,10 @@ class TestProgressUpdateThrottling: await websocket_service.disconnect("test_client") - print(f"\nThrottling: {len(client.received_messages)} updates sent (100 possible)") + logger.info( + "Throttling: %d updates sent (100 possible)", + len(client.received_messages), + ) @pytest.mark.asyncio async def test_throttling_reduces_network_load(self): @@ -356,7 +373,11 @@ class TestProgressUpdateThrottling: for i in range(10): await websocket_service.disconnect(f"client_{i}") - print(f"\nThrottling: {throttled_updates}/1000 updates sent ({reduction_percent:.1f}% reduction)") + logger.info( + "Throttling: %d/1000 updates sent (%.1f%% reduction)", + throttled_updates, + reduction_percent, + ) class TestRoomIsolation: @@ -402,7 +423,7 @@ class TestRoomIsolation: for i in range(clients_per_room): await websocket_service.disconnect(f"{room}_client_{i:02d}") - print(f"\nRoom isolation: 3 rooms × 30 clients in {elapsed_time:.2f}s") + logger.info("Room isolation: 3 rooms × 30 clients in %.2fs", elapsed_time) @pytest.mark.asyncio async def test_selective_room_broadcast_performance(self): @@ -435,7 +456,7 @@ class TestRoomIsolation: for i in range(clients_per_room): await websocket_service.disconnect(f"{room}_{i:02d}") - print(f"\nSelective broadcast: 25/100 clients in {elapsed_time:.3f}s") + logger.info("Selective broadcast: 25/100 clients in %.3fs", elapsed_time) class TestConnectionStability: @@ -472,7 +493,7 @@ class TestConnectionStability: # All connections should be cleaned up assert len(websocket_service.manager._active_connections) == 0 - print(f"\nRapid cycles: {cycles_per_second:.2f} cycles/second") + logger.info("Rapid cycles: %.2f cycles/second", cycles_per_second) @pytest.mark.asyncio async def test_concurrent_connect_disconnect(self): @@ -497,7 +518,7 @@ class TestConnectionStability: # All should be cleaned up assert len(websocket_service.manager._active_connections) == 0 - print(f"\nConcurrent ops: 30 clients in {elapsed_time:.2f}s") + logger.info("Concurrent ops: 30 clients in %.2fs", elapsed_time) class TestMemoryEfficiency: @@ -533,8 +554,8 @@ class TestMemoryEfficiency: for i in range(100): await websocket_service.disconnect(f"mem_client_{i:03d}") - print(f"\nMemory: {memory_increase_mb:.2f}MB for 100 connections") - print(f"Per connection: {per_connection_kb:.2f}KB") + logger.info("Memory: %.2fMB for 100 connections", memory_increase_mb) + logger.info("Per connection: %.2fKB", per_connection_kb) @pytest.mark.asyncio async def test_message_queue_memory_efficiency(self): @@ -567,5 +588,5 @@ class TestMemoryEfficiency: await websocket_service.disconnect("queue_test") - print(f"\nMessage queue: {total_size} bytes for 100 messages") - print(f"Average: {total_size / 100:.2f} bytes/message") + logger.info("Message queue: %d bytes for 100 messages", total_size) + logger.info("Average: %.2f bytes/message", total_size / 100) diff --git a/tests/unit/test_nfo_update_parsing.py b/tests/unit/test_nfo_update_parsing.py index 0100a20..48083dd 100644 --- a/tests/unit/test_nfo_update_parsing.py +++ b/tests/unit/test_nfo_update_parsing.py @@ -1,6 +1,7 @@ """Unit test for NFOService.update_tvshow_nfo() - tests XML parsing logic.""" import asyncio +import logging import shutil import tempfile from pathlib import Path @@ -8,6 +9,8 @@ from pathlib import Path import pytest from lxml import etree +logger = logging.getLogger(__name__) + from src.core.services.nfo_service import NFOService from src.core.services.tmdb_client import TMDBAPIError @@ -51,7 +54,7 @@ def test_parse_nfo_with_uniqueid(): break assert tmdb_id == 1429, f"Expected TMDB ID 1429, got {tmdb_id}" - print(f"✓ Successfully parsed TMDB ID from uniqueid: {tmdb_id}") + logger.info("Successfully parsed TMDB ID from uniqueid: %s", tmdb_id) finally: shutil.rmtree(temp_dir) @@ -92,7 +95,7 @@ def test_parse_nfo_with_tmdbid_element(): tmdb_id = int(tmdbid_elem.text) assert tmdb_id == 12345, f"Expected TMDB ID 12345, got {tmdb_id}" - print(f"✓ Successfully parsed TMDB ID from tmdbid element: {tmdb_id}") + logger.info("Successfully parsed TMDB ID from tmdbid element: %s", tmdb_id) finally: shutil.rmtree(temp_dir) @@ -131,7 +134,7 @@ def test_parse_nfo_without_tmdb_id(): tmdb_id = int(tmdbid_elem.text) assert tmdb_id is None, "Should not have found TMDB ID" - print("✓ Correctly identified NFO without TMDB ID") + logger.info("Correctly identified NFO without TMDB ID") finally: shutil.rmtree(temp_dir) @@ -157,22 +160,23 @@ def test_parse_invalid_xml(): tree = etree.parse(str(nfo_path)) assert False, "Should have raised XMLSyntaxError" except etree.XMLSyntaxError: - print("✓ Correctly raised XMLSyntaxError for invalid XML") + logger.info("Correctly raised XMLSyntaxError for invalid XML") finally: shutil.rmtree(temp_dir) if __name__ == "__main__": - print("Testing NFO XML parsing logic...") - print() - + logging.basicConfig(level=logging.INFO, format="%(message)s") + logger.info("Testing NFO XML parsing logic...") + logger.info("") + test_parse_nfo_with_uniqueid() test_parse_nfo_with_tmdbid_element() test_parse_nfo_without_tmdb_id() test_parse_invalid_xml() - - print() - print("=" * 60) - print("✓ ALL TESTS PASSED") - print("=" * 60) + + logger.info("") + logger.info("%s", "=" * 60) + logger.info("ALL TESTS PASSED") + logger.info("%s", "=" * 60) diff --git a/tests/unit/test_parallel_anime_add.py b/tests/unit/test_parallel_anime_add.py index 78b914c..0603c63 100644 --- a/tests/unit/test_parallel_anime_add.py +++ b/tests/unit/test_parallel_anime_add.py @@ -5,11 +5,14 @@ each other. The background loader should process multiple series simultaneously rather than sequentially. """ import asyncio +import logging from datetime import datetime, timezone from unittest.mock import AsyncMock, MagicMock, patch import pytest +logger = logging.getLogger(__name__) + from src.server.services.background_loader_service import ( BackgroundLoaderService, LoadingStatus, @@ -162,9 +165,9 @@ async def test_parallel_anime_additions( f"(indicating sequential processing)" ) - print(f"✓ Parallel execution verified:") - print(f" - Start time difference: {start_diff:.3f}s") - print(f" - Total duration: {total_duration:.3f}s") + logger.info("Parallel execution verified") + logger.info("Start time difference: %.3fs", start_diff) + logger.info("Total duration: %.3fs", total_duration) @pytest.mark.asyncio