lukas.pupkalipinski/Aniworld
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

chore: apply pending code updates

Browse Source
This commit is contained in:
Lukas
2026-03-17 11:39:27 +01:00
parent e5fae0a0a2
commit 92bd55ada1
45 changed files with 2236 additions and 2130 deletions
Download Patch File Download Diff File Expand all files Collapse all files

34
Docker/test_vpn.py
View File

@@ -18,11 +18,14 @@ Usage:
sudo python3 test_vpn.py sudo python3 test_vpn.py
""" """
import logging
import subprocess import subprocess
import time import time
import unittest import unittest
import os import os
logger = logging.getLogger(__name__)
IMAGE_NAME = "vpn-wireguard-test" IMAGE_NAME = "vpn-wireguard-test"
CONTAINER_NAME = "vpn-test-container" CONTAINER_NAME = "vpn-test-container"
CONFIG_FILE = os.path.join(os.path.dirname(os.path.abspath(__file__)), "wg0.conf") 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 ── # ── 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() 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" assert cls.host_ip, "Could not determine host public IP"
# ── 2. Build the image ── # ── 2. Build the image ──
print(f"[setup] Building image '{IMAGE_NAME}'...") logger.info("Building image '%s'...", IMAGE_NAME)
result = run( result = run(
["podman", "build", "-t", IMAGE_NAME, BUILD_DIR], ["podman", "build", "-t", IMAGE_NAME, BUILD_DIR],
timeout=180, 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}" assert result.returncode == 0, f"Build failed:\n{result.stderr}"
print("[setup] Image built successfully.") logger.info("Image built successfully.")
# ── 3. Start the container ── # ── 3. Start the container ──
print(f"[setup] Starting container '{CONTAINER_NAME}'...") logger.info("Starting container '%s'...", CONTAINER_NAME)
result = run( result = run(
[ [
"podman", "run", "-d", "podman", "run", "-d",
@@ -96,7 +102,7 @@ class TestVPNImage(unittest.TestCase):
) )
assert result.returncode == 0, f"Container failed to start:\n{result.stderr}" assert result.returncode == 0, f"Container failed to start:\n{result.stderr}"
cls.container_id = result.stdout.strip() 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 # Verify it's running
inspect = run( inspect = run(
@@ -106,17 +112,17 @@ class TestVPNImage(unittest.TestCase):
assert inspect.stdout.strip() == "true", "Container is not running" assert inspect.stdout.strip() == "true", "Container is not running"
# ── 4. Wait for VPN to come up ── # ── 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) vpn_up = cls._wait_for_vpn_cls(STARTUP_TIMEOUT)
assert vpn_up, f"VPN did not come up within {STARTUP_TIMEOUT}s" 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 @classmethod
def tearDownClass(cls): def tearDownClass(cls):
"""Stop and remove the container.""" """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) subprocess.run(["podman", "rm", "-f", CONTAINER_NAME], capture_output=True, check=False)
print("[teardown] Done.") logger.info("Cleanup complete.")
@classmethod @classmethod
def _wait_for_vpn_cls(cls, timeout: int = STARTUP_TIMEOUT) -> bool: 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): def test_01_ip_differs_from_host(self):
"""Public IP inside VPN is different from host IP.""" """Public IP inside VPN is different from host IP."""
vpn_ip = self._get_vpn_ip() vpn_ip = self._get_vpn_ip()
print(f"\n[test] VPN public IP: {vpn_ip}") logger.info("VPN public IP: %s", vpn_ip)
print(f"[test] Host public IP: {self.host_ip}") logger.info("Host public IP: %s", self.host_ip)
self.assertTrue(vpn_ip, "Could not fetch IP from inside the container") self.assertTrue(vpn_ip, "Could not fetch IP from inside the container")
self.assertNotEqual( self.assertNotEqual(
@@ -178,7 +184,7 @@ class TestVPNImage(unittest.TestCase):
result.returncode, 0, result.returncode, 0,
"Traffic went through even with WireGuard down — kill switch is NOT working!", "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__": if __name__ == "__main__":

32
docs/instructions.md
View File

@@ -101,26 +101,20 @@ conda run -n AniWorld python -m uvicorn src.server.fastapi_app:app --host 127.0.
For each task completed: For each task completed:
- [x] Implementation follows coding standards - [ ] Implementation follows coding standards
- [x] Unit tests written and passing - [ ] Unit tests written and passing
- [x] Integration tests passing - [ ] Integration tests passing
- [x] Documentation updated - [ ] Documentation updated
- [x] Error handling implemented - [ ] Error handling implemented
- [x] Logging added - [ ] Logging added
- [x] Security considerations addressed - [ ] Security considerations addressed
- [x] Performance validated - [ ] Performance validated
- [x] Code reviewed - [ ] Code reviewed
- [x] Task marked as complete in instructions.md - [ ] Task marked as complete in instructions.md
- [x] Infrastructure.md updated and other docs - [ ] Infrastructure.md updated and other docs
- [x] Changes committed to git; keep your messages in git short and clear - [ ] Changes committed to git; keep your messages in git short and clear
- [x] Take the next task - [ ] Take the next task
--- ---
## TODO List: ## 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.

197
src/cli/nfo_cli.py
View File

@@ -5,6 +5,7 @@ and checking NFO metadata files.
""" """
import asyncio import asyncio
import logging
import sys import sys
from pathlib import Path 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.config.settings import settings
from src.core.services.series_manager_service import SeriesManagerService from src.core.services.series_manager_service import SeriesManagerService
logger = logging.getLogger(__name__)
async def scan_and_create_nfo(): async def scan_and_create_nfo():
"""Scan all series and create missing NFO files.""" """Scan all series and create missing NFO files."""
print("=" * 70) logger.info("%s", "=" * 70)
print("NFO Auto-Creation Tool") logger.info("NFO Auto-Creation Tool")
print("=" * 70) logger.info("%s", "=" * 70)
if not settings.tmdb_api_key: if not settings.tmdb_api_key:
print("\n❌ Error: TMDB_API_KEY not configured") logger.error("TMDB_API_KEY not configured")
print(" Set TMDB_API_KEY in .env file or environment") logger.error("Set TMDB_API_KEY in .env file or environment")
print(" Get API key from: https://www.themoviedb.org/settings/api") logger.error("Get API key from: https://www.themoviedb.org/settings/api")
return 1 return 1
if not settings.anime_directory: if not settings.anime_directory:
print("\n❌ Error: ANIME_DIRECTORY not configured") logger.error("ANIME_DIRECTORY not configured")
return 1 return 1
print(f"\nAnime Directory: {settings.anime_directory}") logger.info("Anime Directory: %s", settings.anime_directory)
print(f"Auto-create NFO: {settings.nfo_auto_create}") logger.info("Auto-create NFO: %s", settings.nfo_auto_create)
print(f"Update on scan: {settings.nfo_update_on_scan}") logger.info("Update on scan: %s", settings.nfo_update_on_scan)
print(f"Download poster: {settings.nfo_download_poster}") logger.info("Download poster: %s", settings.nfo_download_poster)
print(f"Download logo: {settings.nfo_download_logo}") logger.info("Download logo: %s", settings.nfo_download_logo)
print(f"Download fanart: {settings.nfo_download_fanart}") logger.info("Download fanart: %s", settings.nfo_download_fanart)
if not settings.nfo_auto_create: if not settings.nfo_auto_create:
print("\n⚠️ Warning: NFO_AUTO_CREATE is set to False") logger.warning("NFO_AUTO_CREATE is set to False")
print(" Enable it in .env to auto-create NFO files") logger.warning("Enable it in .env to auto-create NFO files")
print("\n Continuing anyway to demonstrate functionality...") logger.info("Continuing anyway to demonstrate functionality...")
# Override for demonstration # Override for demonstration
settings.nfo_auto_create = True settings.nfo_auto_create = True
print("\nInitializing series manager...") logger.info("Initializing series manager...")
manager = SeriesManagerService.from_settings() manager = SeriesManagerService.from_settings()
# Get series list first # Get series list first
serie_list = manager.get_serie_list() serie_list = manager.get_serie_list()
all_series = serie_list.get_all() 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: 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 return 0
# Show series without NFO # Show series without NFO
@@ -65,24 +68,24 @@ async def scan_and_create_nfo():
series_without_nfo.append(serie) series_without_nfo.append(serie)
if series_without_nfo: 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 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: 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: else:
print("\n✅ All series already have NFO files!") logger.info("All series already have NFO files")
if not settings.nfo_update_on_scan: 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 return 0
print("\nProcessing NFO files...") logger.info("Processing NFO files...")
print("(This may take a while depending on the number of series)") logger.info("This may take a while depending on the number of series")
try: try:
await manager.scan_and_process_nfo() await manager.scan_and_process_nfo()
print("\n✅ NFO processing complete!") logger.info("NFO processing complete")
# Show updated stats # Show updated stats
serie_list.load_series() # Reload to get updated stats serie_list.load_series() # Reload to get updated stats
@@ -92,16 +95,16 @@ async def scan_and_create_nfo():
series_with_logo = [s for s in all_series if s.has_logo()] 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()] series_with_fanart = [s for s in all_series if s.has_fanart()]
print("\nFinal Statistics:") logger.info("Final statistics", extra={
print(f" Series with NFO: {len(series_with_nfo)}/{len(all_series)}") "total_series": len(all_series),
print(f" Series with poster: {len(series_with_poster)}/{len(all_series)}") "with_nfo": len(series_with_nfo),
print(f" Series with logo: {len(series_with_logo)}/{len(all_series)}") "with_poster": len(series_with_poster),
print(f" Series with fanart: {len(series_with_fanart)}/{len(all_series)}") "with_logo": len(series_with_logo),
"with_fanart": len(series_with_fanart),
})
except Exception as e: except Exception:
print(f"\n❌ Error: {e}") logger.exception("Failed to process NFO files")
import traceback
traceback.print_exc()
return 1 return 1
finally: finally:
await manager.close() await manager.close()
@@ -111,15 +114,15 @@ async def scan_and_create_nfo():
async def check_nfo_status(): async def check_nfo_status():
"""Check NFO status for all series.""" """Check NFO status for all series."""
print("=" * 70) logger.info("%s", "=" * 70)
print("NFO Status Check") logger.info("NFO Status Check")
print("=" * 70) logger.info("%s", "=" * 70)
if not settings.anime_directory: if not settings.anime_directory:
print("\n❌ Error: ANIME_DIRECTORY not configured") logger.error("ANIME_DIRECTORY not configured")
return 1 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) # Create series list (no NFO service needed for status check)
from src.core.entities.SerieList import SerieList from src.core.entities.SerieList import SerieList
@@ -127,10 +130,10 @@ async def check_nfo_status():
all_series = serie_list.get_all() all_series = serie_list.get_all()
if not all_series: if not all_series:
print("\n⚠️ No series found") logger.warning("No series found")
return 0 return 0
print(f"\nTotal series: {len(all_series)}") logger.info("Total series: %d", len(all_series))
# Categorize series # Categorize series
with_nfo = [] with_nfo = []
@@ -142,47 +145,61 @@ async def check_nfo_status():
else: else:
without_nfo.append(serie) without_nfo.append(serie)
print(f"\nWith NFO: {len(with_nfo)} ({len(with_nfo) * 100 // len(all_series)}%)") logger.info(
print(f"Without NFO: {len(without_nfo)} ({len(without_nfo) * 100 // len(all_series)}%)") "Series NFO coverage",
extra={
"with_nfo": len(with_nfo),
"without_nfo": len(without_nfo),
"total": len(all_series),
},
)
if without_nfo: if without_nfo:
print("\nSeries missing NFO:") logger.info("Series missing NFO: %d", len(without_nfo))
for serie in without_nfo[:10]: 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: 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 # Media file statistics
with_poster = sum(1 for s in all_series if s.has_poster()) 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_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()) with_fanart = sum(1 for s in all_series if s.has_fanart())
print("\nMedia Files:") logger.info(
print(f" Posters: {with_poster}/{len(all_series)} ({with_poster * 100 // len(all_series)}%)") "Media file coverage",
print(f" Logos: {with_logo}/{len(all_series)} ({with_logo * 100 // len(all_series)}%)") extra={
print(f" Fanart: {with_fanart}/{len(all_series)} ({with_fanart * 100 // len(all_series)}%)") "posters": with_poster,
"logos": with_logo,
"fanart": with_fanart,
"total": len(all_series),
},
)
return 0 return 0
async def update_nfo_files(): async def update_nfo_files():
"""Update existing NFO files with fresh data from TMDB.""" """Update existing NFO files with fresh data from TMDB."""
print("=" * 70) logger.info("%s", "=" * 70)
print("NFO Update Tool") logger.info("NFO Update Tool")
print("=" * 70) logger.info("%s", "=" * 70)
if not settings.tmdb_api_key: if not settings.tmdb_api_key:
print("\n❌ Error: TMDB_API_KEY not configured") logger.error("TMDB_API_KEY not configured")
print(" Set TMDB_API_KEY in .env file or environment") logger.error("Set TMDB_API_KEY in .env file or environment")
print(" Get API key from: https://www.themoviedb.org/settings/api") logger.error("Get API key from: https://www.themoviedb.org/settings/api")
return 1 return 1
if not settings.anime_directory: if not settings.anime_directory:
print("\n❌ Error: ANIME_DIRECTORY not configured") logger.error("ANIME_DIRECTORY not configured")
return 1 return 1
print(f"\nAnime Directory: {settings.anime_directory}") logger.info("Anime Directory: %s", settings.anime_directory)
print(f"Download media: {settings.nfo_download_poster or settings.nfo_download_logo or settings.nfo_download_fanart}") logger.info(
"Download media: %s",
settings.nfo_download_poster or settings.nfo_download_logo or settings.nfo_download_fanart,
)
# Get series with NFO # Get series with NFO
from src.core.entities.SerieList import SerieList from src.core.entities.SerieList import SerieList
@@ -191,20 +208,20 @@ async def update_nfo_files():
series_with_nfo = [s for s in all_series if s.has_nfo()] series_with_nfo = [s for s in all_series if s.has_nfo()]
if not series_with_nfo: if not series_with_nfo:
print("\n⚠️ No series with NFO files found") logger.warning("No series with NFO files found")
print(" Run 'scan' command first to create NFO files") logger.info("Run 'scan' command first to create NFO files")
return 0 return 0
print(f"\nFound {len(series_with_nfo)} series with NFO files") logger.info("Found %d series with NFO files", len(series_with_nfo))
print("Updating NFO files with fresh data from TMDB...") logger.info("Updating NFO files with fresh data from TMDB...")
print("(This may take a while)") logger.info("This may take a while")
# Initialize NFO service using factory # Initialize NFO service using factory
from src.core.services.nfo_factory import create_nfo_service from src.core.services.nfo_factory import create_nfo_service
try: try:
nfo_service = create_nfo_service() nfo_service = create_nfo_service()
except ValueError as e: except ValueError as e:
print(f"\nError: {e}") logger.error("Error creating NFO service: %s", e)
return 1 return 1
success_count = 0 success_count = 0
@@ -212,7 +229,7 @@ async def update_nfo_files():
try: try:
for i, serie in enumerate(series_with_nfo, 1): 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: try:
await nfo_service.update_tvshow_nfo( await nfo_service.update_tvshow_nfo(
@@ -221,27 +238,25 @@ async def update_nfo_files():
settings.nfo_download_poster or settings.nfo_download_poster or
settings.nfo_download_logo or settings.nfo_download_logo or
settings.nfo_download_fanart settings.nfo_download_fanart
) ),
) )
print(f" ✅ Updated successfully") logger.info("Updated successfully: %s", serie.name)
success_count += 1 success_count += 1
# Small delay to respect API rate limits # Small delay to respect API rate limits
await asyncio.sleep(0.5) await asyncio.sleep(0.5)
except Exception as e: except Exception as e:
print(f" ❌ Error: {e}") logger.exception("Failed to update NFO for %s", serie.name)
error_count += 1 error_count += 1
print("\n" + "=" * 70) logger.info("%s", "=" * 70)
print(f"✅ Update complete!") logger.info("Update complete")
print(f" Success: {success_count}") logger.info("Success: %d", success_count)
print(f" Errors: {error_count}") logger.info("Errors: %d", error_count)
except Exception as e: except Exception:
print(f"\n❌ Fatal error: {e}") logger.exception("Fatal error during NFO update")
import traceback
traceback.print_exc()
return 1 return 1
finally: finally:
await nfo_service.close() await nfo_service.close()
@@ -251,16 +266,18 @@ async def update_nfo_files():
def main(): def main():
"""Main CLI entry point.""" """Main CLI entry point."""
logging.basicConfig(level=logging.INFO, format="%(message)s")
if len(sys.argv) < 2: if len(sys.argv) < 2:
print("NFO Management Tool") logger.info("NFO Management Tool")
print("\nUsage:") logger.info("\nUsage:")
print(" python -m src.cli.nfo_cli scan # Scan and create missing NFO files") logger.info(" 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") logger.info(" 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") logger.info(" python -m src.cli.nfo_cli update # Update existing NFO files with fresh data")
print("\nConfiguration:") logger.info("\nConfiguration:")
print(" Set TMDB_API_KEY in .env file") logger.info(" Set TMDB_API_KEY in .env file")
print(" Set NFO_AUTO_CREATE=true to enable auto-creation") logger.info(" Set NFO_AUTO_CREATE=true to enable auto-creation")
print(" Set NFO_UPDATE_ON_SCAN=true to update existing NFOs during scan") logger.info(" Set NFO_UPDATE_ON_SCAN=true to update existing NFOs during scan")
return 1 return 1
command = sys.argv[1].lower() command = sys.argv[1].lower()
@@ -272,8 +289,8 @@ def main():
elif command == "update": elif command == "update":
return asyncio.run(update_nfo_files()) return asyncio.run(update_nfo_files())
else: else:
print(f"Unknown command: {command}") logger.error("Unknown command: %s", command)
print("Use 'scan', 'status', or 'update'") logger.info("Use 'scan', 'status', or 'update'")
return 1 return 1

24
src/core/entities/SerieList.py
View File

@@ -121,11 +121,11 @@ class SerieList:
def load_series(self) -> None: def load_series(self) -> None:
"""Populate the in-memory map with metadata discovered on disk.""" """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: try:
entries: Iterable[str] = os.listdir(self.directory) entries: Iterable[str] = os.listdir(self.directory)
except OSError as error: except OSError as error:
logging.error( logger.error(
"Unable to scan directory %s: %s", "Unable to scan directory %s: %s",
self.directory, self.directory,
error, error,
@@ -145,7 +145,7 @@ class SerieList:
for anime_folder in entries: for anime_folder in entries:
anime_path = os.path.join(self.directory, anime_folder, "data") anime_path = os.path.join(self.directory, anime_folder, "data")
if os.path.isfile(anime_path): 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) serie = self._load_data(anime_folder, anime_path)
if serie: if serie:
@@ -159,7 +159,7 @@ class SerieList:
nfo_stats["with_nfo"] += 1 nfo_stats["with_nfo"] += 1
else: else:
nfo_stats["without_nfo"] += 1 nfo_stats["without_nfo"] += 1
logging.debug( logger.debug(
"Series '%s' (key: %s) is missing tvshow.nfo", "Series '%s' (key: %s) is missing tvshow.nfo",
serie.name, serie.name,
serie.key serie.key
@@ -173,7 +173,7 @@ class SerieList:
media_stats["with_poster"] += 1 media_stats["with_poster"] += 1
else: else:
media_stats["without_poster"] += 1 media_stats["without_poster"] += 1
logging.debug( logger.debug(
"Series '%s' (key: %s) is missing poster.jpg", "Series '%s' (key: %s) is missing poster.jpg",
serie.name, serie.name,
serie.key serie.key
@@ -184,7 +184,7 @@ class SerieList:
media_stats["with_logo"] += 1 media_stats["with_logo"] += 1
else: else:
media_stats["without_logo"] += 1 media_stats["without_logo"] += 1
logging.debug( logger.debug(
"Series '%s' (key: %s) is missing logo.png", "Series '%s' (key: %s) is missing logo.png",
serie.name, serie.name,
serie.key serie.key
@@ -195,7 +195,7 @@ class SerieList:
media_stats["with_fanart"] += 1 media_stats["with_fanart"] += 1
else: else:
media_stats["without_fanart"] += 1 media_stats["without_fanart"] += 1
logging.debug( logger.debug(
"Series '%s' (key: %s) is missing fanart.jpg", "Series '%s' (key: %s) is missing fanart.jpg",
serie.name, serie.name,
serie.key serie.key
@@ -203,20 +203,20 @@ class SerieList:
continue continue
logging.warning( logger.warning(
"Skipping folder %s because no metadata file was found", "Skipping folder %s because no metadata file was found",
anime_folder, anime_folder,
) )
# Log summary statistics # Log summary statistics
if nfo_stats["total"] > 0: if nfo_stats["total"] > 0:
logging.info( logger.info(
"NFO scan complete: %d series total, %d with NFO, %d without NFO", "NFO scan complete: %d series total, %d with NFO, %d without NFO",
nfo_stats["total"], nfo_stats["total"],
nfo_stats["with_nfo"], nfo_stats["with_nfo"],
nfo_stats["without_nfo"] nfo_stats["without_nfo"]
) )
logging.info( logger.info(
"Media scan complete: Poster (%d/%d), Logo (%d/%d), Fanart (%d/%d)", "Media scan complete: Poster (%d/%d), Logo (%d/%d), Fanart (%d/%d)",
media_stats["with_poster"], media_stats["with_poster"],
nfo_stats["total"], nfo_stats["total"],
@@ -241,14 +241,14 @@ class SerieList:
serie = Serie.load_from_file(data_path) serie = Serie.load_from_file(data_path)
# Store by key, not folder # Store by key, not folder
self.keyDict[serie.key] = serie self.keyDict[serie.key] = serie
logging.debug( logger.debug(
"Successfully loaded metadata for %s (key: %s)", "Successfully loaded metadata for %s (key: %s)",
anime_folder, anime_folder,
serie.key serie.key
) )
return serie return serie
except (OSError, JSONDecodeError, KeyError, ValueError) as error: except (OSError, JSONDecodeError, KeyError, ValueError) as error:
logging.error( logger.error(
"Failed to load metadata for folder %s from %s: %s", "Failed to load metadata for folder %s from %s: %s",
anime_folder, anime_folder,
data_path, data_path,

10
src/core/entities/series.py
View File

@@ -64,6 +64,16 @@ class Serie:
f"episodeDict={self.episodeDict}{year_str})" 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 @property
def key(self) -> str: def key(self) -> str:
""" """

21
src/core/error_handler.py
View File

@@ -55,7 +55,8 @@ class RecoveryStrategies:
if attempt == max_retries - 1: if attempt == max_retries - 1:
raise raise
logger.warning( logger.warning(
f"Network error on attempt {attempt + 1}, retrying..." "Network error on attempt %d, retrying...",
attempt + 1,
) )
continue continue
@@ -72,7 +73,8 @@ class RecoveryStrategies:
if attempt == max_retries - 1: if attempt == max_retries - 1:
raise raise
logger.warning( logger.warning(
f"Download error on attempt {attempt + 1}, retrying..." "Download error on attempt %d, retrying...",
attempt + 1,
) )
continue continue
@@ -92,7 +94,7 @@ class FileCorruptionDetector:
# Video files should be at least 1MB # Video files should be at least 1MB
return file_size > 1024 * 1024 return file_size > 1024 * 1024
except Exception as e: except Exception as e:
logger.error(f"Error checking file validity: {e}") logger.error("Error checking file validity: %s", e)
return False return False
@@ -123,13 +125,18 @@ def with_error_recovery(
last_error = e last_error = e
if attempt < max_retries - 1: if attempt < max_retries - 1:
logger.warning( logger.warning(
f"Error in {context} (attempt {attempt + 1}/" "Error in %s (attempt %d/%d): %s, retrying...",
f"{max_retries}): {e}, retrying..." context,
attempt + 1,
max_retries,
e,
) )
else: else:
logger.error( logger.error(
f"Error in {context} failed after {max_retries} " "Error in %s failed after %d attempts: %s",
f"attempts: {e}" context,
max_retries,
e,
) )
if last_error: if last_error:

8
src/core/interfaces/callbacks.py
View File

@@ -12,6 +12,8 @@ from dataclasses import dataclass, field
from enum import Enum from enum import Enum
from typing import Any, Dict, Optional from typing import Any, Dict, Optional
logger = logging.getLogger(__name__)
class OperationType(str, Enum): class OperationType(str, Enum):
"""Types of operations that can report progress.""" """Types of operations that can report progress."""
@@ -313,7 +315,7 @@ class CallbackManager:
callback.on_progress(context) callback.on_progress(context)
except Exception as e: except Exception as e:
# Log but don't let callback errors break the operation # Log but don't let callback errors break the operation
logging.error( logger.error(
"Error in progress callback %s: %s", "Error in progress callback %s: %s",
callback, callback,
e, e,
@@ -332,7 +334,7 @@ class CallbackManager:
callback.on_error(context) callback.on_error(context)
except Exception as e: except Exception as e:
# Log but don't let callback errors break the operation # Log but don't let callback errors break the operation
logging.error( logger.error(
"Error in error callback %s: %s", "Error in error callback %s: %s",
callback, callback,
e, e,
@@ -351,7 +353,7 @@ class CallbackManager:
callback.on_completion(context) callback.on_completion(context)
except Exception as e: except Exception as e:
# Log but don't let callback errors break the operation # Log but don't let callback errors break the operation
logging.error( logger.error(
"Error in completion callback %s: %s", "Error in completion callback %s: %s",
callback, callback,
e, e,

166
src/core/providers/aniworld_provider.py
View File

@@ -42,9 +42,9 @@ def _cleanup_temp_file(temp_path: str) -> None:
if os.path.exists(path): if os.path.exists(path):
try: try:
os.remove(path) os.remove(path)
logging.debug(f"Removed temp file: {path}") logger.debug("Removed temp file: %s", path)
except OSError as exc: except OSError as exc:
logging.warning(f"Failed to remove temp file {path}: {exc}") logger.warning("Failed to remove temp file %s: %s", path, exc)
# Imported shared provider configuration # Imported shared provider configuration
from .provider_config import ( from .provider_config import (
@@ -56,6 +56,8 @@ from .provider_config import (
ProviderType, ProviderType,
) )
logger = logging.getLogger(__name__)
# Configure persistent loggers but don't add duplicate handlers when module # Configure persistent loggers but don't add duplicate handlers when module
# is imported multiple times (common in test environments). # is imported multiple times (common in test environments).
# Use absolute paths for log files to prevent security issues # Use absolute paths for log files to prevent security issues
@@ -142,16 +144,16 @@ class AniworldLoader(Loader):
def clear_cache(self): def clear_cache(self):
"""Clear the cached HTML data.""" """Clear the cached HTML data."""
logging.debug("Clearing HTML cache") logger.debug("Clearing HTML cache")
self._KeyHTMLDict = {} self._KeyHTMLDict = {}
self._EpisodeHTMLDict = {} self._EpisodeHTMLDict = {}
logging.debug("HTML cache cleared successfully") logger.debug("HTML cache cleared successfully")
def remove_from_cache(self): def remove_from_cache(self):
"""Remove episode HTML from cache.""" """Remove episode HTML from cache."""
logging.debug("Removing episode HTML from cache") logger.debug("Removing episode HTML from cache")
self._EpisodeHTMLDict = {} self._EpisodeHTMLDict = {}
logging.debug("Episode HTML cache cleared") logger.debug("Episode HTML cache cleared")
def search(self, word: str) -> list: def search(self, word: str) -> list:
"""Search for anime series. """Search for anime series.
@@ -162,30 +164,30 @@ class AniworldLoader(Loader):
Returns: Returns:
List of found series List of found series
""" """
logging.info(f"Searching for anime with keyword: '{word}'") logger.info("Searching for anime with keyword: '%s'", word)
search_url = ( search_url = (
f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}" f"{self.ANIWORLD_TO}/ajax/seriesSearch?keyword={quote(word)}"
) )
logging.debug(f"Search URL: {search_url}") logger.debug("Search URL: %s", search_url)
anime_list = self.fetch_anime_list(search_url) anime_list = self.fetch_anime_list(search_url)
logging.info(f"Found {len(anime_list)} anime series for keyword '{word}'") logger.info("Found %s anime series for keyword '%s'", len(anime_list), word)
return anime_list return anime_list
def fetch_anime_list(self, url: str) -> list: def fetch_anime_list(self, url: str) -> list:
logging.debug(f"Fetching anime list from URL: {url}") logger.debug("Fetching anime list from URL: %s", url)
response = self.session.get(url, timeout=self.DEFAULT_REQUEST_TIMEOUT) response = self.session.get(url, timeout=self.DEFAULT_REQUEST_TIMEOUT)
response.raise_for_status() response.raise_for_status()
logging.debug(f"Response status code: {response.status_code}") logger.debug("Response status code: %s", response.status_code)
clean_text = response.text.strip() clean_text = response.text.strip()
try: try:
decoded_data = json.loads(html.unescape(clean_text)) decoded_data = json.loads(html.unescape(clean_text))
logging.debug(f"Successfully decoded JSON data on first attempt") logger.debug("Successfully decoded JSON data on first attempt")
return decoded_data if isinstance(decoded_data, list) else [] return decoded_data if isinstance(decoded_data, list) else []
except json.JSONDecodeError: except json.JSONDecodeError:
logging.warning("Initial JSON decode failed, attempting cleanup") logger.warning("Initial JSON decode failed, attempting cleanup")
try: try:
# Remove BOM and problematic characters # Remove BOM and problematic characters
clean_text = clean_text.encode('utf-8').decode('utf-8-sig') clean_text = clean_text.encode('utf-8').decode('utf-8-sig')
@@ -193,10 +195,10 @@ class AniworldLoader(Loader):
clean_text = re.sub(r'[\x00-\x1F\x7F-\x9F]', '', clean_text) clean_text = re.sub(r'[\x00-\x1F\x7F-\x9F]', '', clean_text)
# Parse the new text # Parse the new text
decoded_data = json.loads(clean_text) decoded_data = json.loads(clean_text)
logging.debug("Successfully decoded JSON after cleanup") logger.debug("Successfully decoded JSON after cleanup")
return decoded_data if isinstance(decoded_data, list) else [] return decoded_data if isinstance(decoded_data, list) else []
except (requests.RequestException, json.JSONDecodeError) as exc: except (requests.RequestException, json.JSONDecodeError) as exc:
logging.error(f"Failed to decode anime list from {url}: {exc}") logger.error("Failed to decode anime list from %s: %s", url, exc)
raise ValueError("Could not get valid anime: ") from exc raise ValueError("Could not get valid anime: ") from exc
def _get_language_key(self, language: str) -> int: def _get_language_key(self, language: str) -> int:
@@ -214,7 +216,7 @@ class AniworldLoader(Loader):
language_code = 2 language_code = 2
if language == "German Sub": if language == "German Sub":
language_code = 3 language_code = 3
logging.debug(f"Converted language '{language}' to code {language_code}") logger.debug("Converted language '%s' to code %s", language, language_code)
return language_code return language_code
def is_language( def is_language(
@@ -225,7 +227,7 @@ class AniworldLoader(Loader):
language: str = "German Dub" language: str = "German Dub"
) -> bool: ) -> bool:
"""Check if episode is available in specified language.""" """Check if episode is available in specified language."""
logging.debug(f"Checking if S{season:02}E{episode:03} ({key}) is available in {language}") logger.debug("Checking if S%02dE%03d (%s) is available in %s", season, episode, key, language)
language_code = self._get_language_key(language) language_code = self._get_language_key(language)
episode_soup = BeautifulSoup( episode_soup = BeautifulSoup(
@@ -244,7 +246,7 @@ class AniworldLoader(Loader):
languages.append(int(lang_key)) languages.append(int(lang_key))
is_available = language_code in languages 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}") logger.debug("Available languages for S%02dE%03d: %s, requested: %s, available: %s", season, episode, languages, language_code, is_available)
return is_available return is_available
def download( def download(
@@ -270,15 +272,15 @@ class AniworldLoader(Loader):
Returns: Returns:
bool: True if download succeeded, False otherwise bool: True if download succeeded, False otherwise
""" """
logging.info( logger.info(
f"Starting download for S{season:02}E{episode:03} " "Starting download for S%02dE%03d (%s) in %s",
f"({key}) in {language}" season, episode, key, language
) )
sanitized_anime_title = ''.join( sanitized_anime_title = ''.join(
char for char in self.get_title(key) char for char in self.get_title(key)
if char not in self.INVALID_PATH_CHARS if char not in self.INVALID_PATH_CHARS
) )
logging.debug(f"Sanitized anime title: {sanitized_anime_title}") logger.debug("Sanitized anime title: %s", sanitized_anime_title)
if season == 0: if season == 0:
output_file = ( output_file = (
@@ -298,26 +300,26 @@ class AniworldLoader(Loader):
f"Season {season}" f"Season {season}"
) )
output_path = os.path.join(folder_path, output_file) output_path = os.path.join(folder_path, output_file)
logging.debug(f"Output path: {output_path}") logger.debug("Output path: %s", output_path)
os.makedirs(os.path.dirname(output_path), exist_ok=True) os.makedirs(os.path.dirname(output_path), exist_ok=True)
temp_dir = "./Temp/" temp_dir = "./Temp/"
os.makedirs(os.path.dirname(temp_dir), exist_ok=True) os.makedirs(os.path.dirname(temp_dir), exist_ok=True)
temp_path = os.path.join(temp_dir, output_file) temp_path = os.path.join(temp_dir, output_file)
logging.debug(f"Temporary path: {temp_path}") logger.debug("Temporary path: %s", temp_path)
for provider in self.SUPPORTED_PROVIDERS: for provider in self.SUPPORTED_PROVIDERS:
logging.debug(f"Attempting download with provider: {provider}") logger.debug("Attempting download with provider: %s", provider)
link, header = self._get_direct_link_from_provider( link, header = self._get_direct_link_from_provider(
season, episode, key, language season, episode, key, language
) )
logging.debug("Direct link obtained from provider") logger.debug("Direct link obtained from provider")
cancel_flag = self._cancel_flag cancel_flag = self._cancel_flag
def events_progress_hook(d): def events_progress_hook(d):
if cancel_flag.is_set(): if cancel_flag.is_set():
logging.info("Cancellation detected in progress hook") logger.info("Cancellation detected in progress hook")
raise DownloadCancelled("Download cancelled by user") raise DownloadCancelled("Download cancelled by user")
# Fire the event for progress # Fire the event for progress
self.events.download_progress(d) self.events.download_progress(d)
@@ -334,55 +336,51 @@ class AniworldLoader(Loader):
if header: if header:
ydl_opts['http_headers'] = header ydl_opts['http_headers'] = header
logging.debug("Using custom headers for download") logger.debug("Using custom headers for download")
try: try:
logging.debug("Starting YoutubeDL download") logger.debug("Starting YoutubeDL download")
logging.debug(f"Download link: {link[:100]}...") logger.debug("Download link: %s...", link[:100])
logging.debug(f"YDL options: {ydl_opts}") logger.debug("YDL options: %s", ydl_opts)
with YoutubeDL(ydl_opts) as ydl: with YoutubeDL(ydl_opts) as ydl:
info = ydl.extract_info(link, download=True) info = ydl.extract_info(link, download=True)
logging.debug( logger.debug(
f"Download info: " "Download info: title=%s, filesize=%s",
f"title={info.get('title')}, " info.get('title'), info.get('filesize')
f"filesize={info.get('filesize')}"
) )
if os.path.exists(temp_path): if os.path.exists(temp_path):
logging.debug("Moving file from temp to final destination") logger.debug("Moving file from temp to final destination")
# Use copyfile instead of copy to avoid metadata permission issues # Use copyfile instead of copy to avoid metadata permission issues
shutil.copyfile(temp_path, output_path) shutil.copyfile(temp_path, output_path)
os.remove(temp_path) os.remove(temp_path)
logging.info( logger.info("Download completed successfully: %s", output_file)
f"Download completed successfully: {output_file}"
)
self.clear_cache() self.clear_cache()
return True return True
else: else:
logging.error( logger.error("Download failed: temp file not found at %s", temp_path)
f"Download failed: temp file not found at {temp_path}"
)
self.clear_cache() self.clear_cache()
return False return False
except BrokenPipeError as e: except BrokenPipeError as e:
logging.error( logger.error(
f"Broken pipe error with provider {provider}: {e}. " "Broken pipe error with provider %s: %s. "
f"This usually means the stream connection was closed." "This usually means the stream connection was closed.",
provider, e
) )
_cleanup_temp_file(temp_path) _cleanup_temp_file(temp_path)
continue continue
except Exception as e: except Exception as e:
logging.error( logger.error(
f"YoutubeDL download failed with provider {provider}: " "YoutubeDL download failed with provider %s: %s: %s",
f"{type(e).__name__}: {e}" provider, type(e).__name__, e
) )
_cleanup_temp_file(temp_path) _cleanup_temp_file(temp_path)
continue continue
break break
# If we get here, all providers failed # If we get here, all providers failed
logging.error("All download providers failed") logger.error("All download providers failed")
_cleanup_temp_file(temp_path) _cleanup_temp_file(temp_path)
self.clear_cache() self.clear_cache()
return False return False
@@ -393,7 +391,7 @@ class AniworldLoader(Loader):
def get_title(self, key: str) -> str: def get_title(self, key: str) -> str:
"""Get anime title from series key.""" """Get anime title from series key."""
logging.debug(f"Getting title for key: {key}") logger.debug("Getting title for key: %s", key)
soup = BeautifulSoup( soup = BeautifulSoup(
self._get_key_html(key).content, self._get_key_html(key).content,
'html.parser' 'html.parser'
@@ -405,10 +403,10 @@ class AniworldLoader(Loader):
span_tag = h1_tag.find('span') if h1_tag else None span_tag = h1_tag.find('span') if h1_tag else None
if span_tag: if span_tag:
title = span_tag.text title = span_tag.text
logging.debug(f"Found title: {title}") logger.debug("Found title: %s", title)
return title return title
logging.warning(f"No title found for key: {key}") logger.warning("No title found for key: %s", key)
return "" return ""
def get_year(self, key: str) -> int | None: def get_year(self, key: str) -> int | None:
@@ -423,7 +421,7 @@ class AniworldLoader(Loader):
Returns: Returns:
int or None: Release year if found, None otherwise int or None: Release year if found, None otherwise
""" """
logging.debug(f"Getting year for key: {key}") logger.debug("Getting year for key: %s", key)
try: try:
soup = BeautifulSoup( soup = BeautifulSoup(
self._get_key_html(key).content, self._get_key_html(key).content,
@@ -439,7 +437,7 @@ class AniworldLoader(Loader):
match = re.search(r'(\d{4})', text) match = re.search(r'(\d{4})', text)
if match: if match:
year = int(match.group(1)) year = int(match.group(1))
logging.debug(f"Found year in metadata: {year}") logger.debug("Found year in metadata: %s", year)
return year return year
# Try alternative: look for year in genre/info section # Try alternative: look for year in genre/info section
@@ -449,14 +447,14 @@ class AniworldLoader(Loader):
match = re.search(r'\b(19\d{2}|20\d{2})\b', text) match = re.search(r'\b(19\d{2}|20\d{2})\b', text)
if match: if match:
year = int(match.group(1)) year = int(match.group(1))
logging.debug(f"Found year in info section: {year}") logger.debug("Found year in info section: %s", year)
return year return year
logging.debug(f"No year found for key: {key}") logger.debug("No year found for key: %s", key)
return None return None
except Exception as e: except Exception as e:
logging.warning(f"Error extracting year for key {key}: {e}") logger.warning("Error extracting year for key %s: %s", key, e)
return None return None
def _get_key_html(self, key: str): def _get_key_html(self, key: str):
@@ -469,18 +467,18 @@ class AniworldLoader(Loader):
Cached or fetched HTML response Cached or fetched HTML response
""" """
if key in self._KeyHTMLDict: if key in self._KeyHTMLDict:
logging.debug(f"Using cached HTML for key: {key}") logger.debug("Using cached HTML for key: %s", key)
return self._KeyHTMLDict[key] return self._KeyHTMLDict[key]
# Sanitize key parameter for URL # Sanitize key parameter for URL
safe_key = quote(key, safe='') safe_key = quote(key, safe='')
url = f"{self.ANIWORLD_TO}/anime/stream/{safe_key}" url = f"{self.ANIWORLD_TO}/anime/stream/{safe_key}"
logging.debug(f"Fetching HTML for key: {key} from {url}") logger.debug("Fetching HTML for key: %s from %s", key, url)
self._KeyHTMLDict[key] = self.session.get( self._KeyHTMLDict[key] = self.session.get(
url, url,
timeout=self.DEFAULT_REQUEST_TIMEOUT timeout=self.DEFAULT_REQUEST_TIMEOUT
) )
logging.debug(f"Cached HTML for key: {key}") logger.debug("Cached HTML for key: %s", key)
return self._KeyHTMLDict[key] return self._KeyHTMLDict[key]
def _get_episode_html(self, season: int, episode: int, key: str): def _get_episode_html(self, season: int, episode: int, key: str):
@@ -499,14 +497,14 @@ class AniworldLoader(Loader):
""" """
# Validate season and episode numbers # Validate season and episode numbers
if season < 1 or season > 999: if season < 1 or season > 999:
logging.error(f"Invalid season number: {season}") logger.error("Invalid season number: %s", season)
raise ValueError(f"Invalid season number: {season}") raise ValueError(f"Invalid season number: {season}")
if episode < 1 or episode > 9999: if episode < 1 or episode > 9999:
logging.error(f"Invalid episode number: {episode}") logger.error("Invalid episode number: %s", episode)
raise ValueError(f"Invalid episode number: {episode}") raise ValueError(f"Invalid episode number: {episode}")
if key in self._EpisodeHTMLDict: if key in self._EpisodeHTMLDict:
logging.debug(f"Using cached HTML for S{season:02}E{episode:03} ({key})") logger.debug("Using cached HTML for S%02dE%03d (%s)", season, episode, key)
return self._EpisodeHTMLDict[(key, season, episode)] return self._EpisodeHTMLDict[(key, season, episode)]
# Sanitize key parameter for URL # Sanitize key parameter for URL
@@ -515,10 +513,10 @@ class AniworldLoader(Loader):
f"{self.ANIWORLD_TO}/anime/stream/{safe_key}/" f"{self.ANIWORLD_TO}/anime/stream/{safe_key}/"
f"staffel-{season}/episode-{episode}" f"staffel-{season}/episode-{episode}"
) )
logging.debug(f"Fetching episode HTML from: {link}") logger.debug("Fetching episode HTML from: %s", link)
html = self.session.get(link, timeout=self.DEFAULT_REQUEST_TIMEOUT) html = self.session.get(link, timeout=self.DEFAULT_REQUEST_TIMEOUT)
self._EpisodeHTMLDict[(key, season, episode)] = html self._EpisodeHTMLDict[(key, season, episode)] = html
logging.debug(f"Cached episode HTML for S{season:02}E{episode:03} ({key})") logger.debug("Cached episode HTML for S%02dE%03d (%s)", season, episode, key)
return self._EpisodeHTMLDict[(key, season, episode)] return self._EpisodeHTMLDict[(key, season, episode)]
def _get_provider_from_html( def _get_provider_from_html(
@@ -538,7 +536,7 @@ class AniworldLoader(Loader):
2: 'https://aniworld.to/redirect/1766405'}, 2: 'https://aniworld.to/redirect/1766405'},
} }
""" """
logging.debug(f"Extracting providers from HTML for S{season:02}E{episode:03} ({key})") logger.debug("Extracting providers from HTML for S%02dE%03d (%s)", season, episode, key)
soup = BeautifulSoup( soup = BeautifulSoup(
self._get_episode_html(season, episode, key).content, self._get_episode_html(season, episode, key).content,
'html.parser' 'html.parser'
@@ -550,7 +548,7 @@ class AniworldLoader(Loader):
) )
if not episode_links: if not episode_links:
logging.warning(f"No episode links found for S{season:02}E{episode:03} ({key})") logger.warning("No episode links found for S%02dE%03d (%s)", season, episode, key)
return providers return providers
for link in episode_links: for link in episode_links:
@@ -578,9 +576,9 @@ class AniworldLoader(Loader):
providers[provider_name][lang_key] = ( providers[provider_name][lang_key] = (
f"{self.ANIWORLD_TO}{redirect_link}" f"{self.ANIWORLD_TO}{redirect_link}"
) )
logging.debug(f"Found provider: {provider_name}, lang_key: {lang_key}") logger.debug("Found provider: %s, lang_key: %s", provider_name, lang_key)
logging.debug(f"Total providers found: {len(providers)}") logger.debug("Total providers found: %s", len(providers))
return providers return providers
def _get_redirect_link( def _get_redirect_link(
@@ -591,7 +589,7 @@ class AniworldLoader(Loader):
language: str = "German Dub" language: str = "German Dub"
): ):
"""Get redirect link for episode in specified language.""" """Get redirect link for episode in specified language."""
logging.debug(f"Getting redirect link for S{season:02}E{episode:03} ({key}) in {language}") logger.debug("Getting redirect link for S%02dE%03d (%s) in %s", season, episode, key, language)
language_code = self._get_language_key(language) language_code = self._get_language_key(language)
if self.is_language(season, episode, key, language): if self.is_language(season, episode, key, language):
for (provider_name, lang_dict) in ( for (provider_name, lang_dict) in (
@@ -600,9 +598,9 @@ class AniworldLoader(Loader):
).items() ).items()
): ):
if language_code in lang_dict: if language_code in lang_dict:
logging.debug(f"Found redirect link with provider: {provider_name}") logger.debug("Found redirect link with provider: %s", provider_name)
return (lang_dict[language_code], 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}") logger.warning("No redirect link found for S%02dE%03d (%s) in %s", season, episode, key, language)
return None return None
def _get_embeded_link( def _get_embeded_link(
@@ -613,18 +611,18 @@ class AniworldLoader(Loader):
language: str = "German Dub" language: str = "German Dub"
): ):
"""Get embedded link from redirect link.""" """Get embedded link from redirect link."""
logging.debug(f"Getting embedded link for S{season:02}E{episode:03} ({key}) in {language}") logger.debug("Getting embedded link for S%02dE%03d (%s) in %s", season, episode, key, language)
redirect_link, provider_name = ( redirect_link, provider_name = (
self._get_redirect_link(season, episode, key, language) self._get_redirect_link(season, episode, key, language)
) )
logging.debug(f"Redirect link: {redirect_link}, provider: {provider_name}") logger.debug("Redirect link: %s, provider: %s", redirect_link, provider_name)
embeded_link = self.session.get( embeded_link = self.session.get(
redirect_link, redirect_link,
timeout=self.DEFAULT_REQUEST_TIMEOUT, timeout=self.DEFAULT_REQUEST_TIMEOUT,
headers={'User-Agent': self.RANDOM_USER_AGENT} headers={'User-Agent': self.RANDOM_USER_AGENT}
).url ).url
logging.debug(f"Embedded link: {embeded_link}") logger.debug("Embedded link: %s", embeded_link)
return embeded_link return embeded_link
def _get_direct_link_from_provider( def _get_direct_link_from_provider(
@@ -635,15 +633,15 @@ class AniworldLoader(Loader):
language: str = "German Dub" language: str = "German Dub"
): ):
"""Get direct download link from streaming provider.""" """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}") logger.debug("Getting direct link from provider for S%02dE%03d (%s) in %s", season, episode, key, language)
embeded_link = self._get_embeded_link( embeded_link = self._get_embeded_link(
season, episode, key, language season, episode, key, language
) )
if embeded_link is None: if embeded_link is None:
logging.error(f"No embedded link found for S{season:02}E{episode:03} ({key})") logger.error("No embedded link found for S%02dE%03d (%s)", season, episode, key)
return None return None
logging.debug(f"Using VOE provider to extract direct link") logger.debug("Using VOE provider to extract direct link")
return self.Providers.GetProvider( return self.Providers.GetProvider(
"VOE" "VOE"
).get_link(embeded_link, self.DEFAULT_REQUEST_TIMEOUT) ).get_link(embeded_link, self.DEFAULT_REQUEST_TIMEOUT)
@@ -657,23 +655,23 @@ class AniworldLoader(Loader):
Returns: Returns:
Dictionary mapping season numbers to episode counts Dictionary mapping season numbers to episode counts
""" """
logging.info(f"Getting season and episode count for slug: {slug}") logger.info("Getting season and episode count for slug: %s", slug)
# Sanitize slug parameter for URL # Sanitize slug parameter for URL
safe_slug = quote(slug, safe='') safe_slug = quote(slug, safe='')
base_url = f"{self.ANIWORLD_TO}/anime/stream/{safe_slug}/" base_url = f"{self.ANIWORLD_TO}/anime/stream/{safe_slug}/"
logging.debug(f"Base URL: {base_url}") logger.debug("Base URL: %s", base_url)
response = requests.get(base_url, timeout=self.DEFAULT_REQUEST_TIMEOUT) response = requests.get(base_url, timeout=self.DEFAULT_REQUEST_TIMEOUT)
soup = BeautifulSoup(response.content, 'html.parser') soup = BeautifulSoup(response.content, 'html.parser')
season_meta = soup.find('meta', itemprop='numberOfSeasons') season_meta = soup.find('meta', itemprop='numberOfSeasons')
number_of_seasons = int(season_meta['content']) if season_meta else 0 number_of_seasons = int(season_meta['content']) if season_meta else 0
logging.info(f"Found {number_of_seasons} seasons for '{slug}'") logger.info("Found %s seasons for '%s'", number_of_seasons, slug)
episode_counts = {} episode_counts = {}
for season in range(1, number_of_seasons + 1): for season in range(1, number_of_seasons + 1):
season_url = f"{base_url}staffel-{season}" season_url = f"{base_url}staffel-{season}"
logging.debug(f"Fetching episodes for season {season} from: {season_url}") logger.debug("Fetching episodes for season %s from: %s", season, season_url)
response = requests.get( response = requests.get(
season_url, season_url,
timeout=self.DEFAULT_REQUEST_TIMEOUT, timeout=self.DEFAULT_REQUEST_TIMEOUT,
@@ -688,7 +686,7 @@ class AniworldLoader(Loader):
) )
episode_counts[season] = len(unique_links) episode_counts[season] = len(unique_links)
logging.debug(f"Season {season} has {episode_counts[season]} episodes") logger.debug("Season %s has %s episodes", season, episode_counts[season])
logging.info(f"Episode count retrieval complete for '{slug}': {episode_counts}") logger.info("Episode count retrieval complete for '%s': %s", slug, episode_counts)
return episode_counts return episode_counts

12
src/core/providers/config_manager.py
View File

@@ -87,7 +87,7 @@ class ProviderConfigManager:
settings: Provider settings to apply. settings: Provider settings to apply.
""" """
self._provider_settings[provider_name] = settings 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( def update_provider_settings(
self, provider_name: str, **kwargs self, provider_name: str, **kwargs
@@ -106,7 +106,7 @@ class ProviderConfigManager:
self._provider_settings[provider_name] = ProviderSettings( self._provider_settings[provider_name] = ProviderSettings(
name=provider_name, **kwargs 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 return True
settings = self._provider_settings[provider_name] settings = self._provider_settings[provider_name]
@@ -152,7 +152,7 @@ class ProviderConfigManager:
""" """
if provider_name in self._provider_settings: if provider_name in self._provider_settings:
self._provider_settings[provider_name].enabled = True self._provider_settings[provider_name].enabled = True
logger.info(f"Enabled provider: {provider_name}") logger.info("Enabled provider: %s", provider_name)
return True return True
return False return False
@@ -167,7 +167,7 @@ class ProviderConfigManager:
""" """
if provider_name in self._provider_settings: if provider_name in self._provider_settings:
self._provider_settings[provider_name].enabled = False self._provider_settings[provider_name].enabled = False
logger.info(f"Disabled provider: {provider_name}") logger.info("Disabled provider: %s", provider_name)
return True return True
return False return False
@@ -224,7 +224,7 @@ class ProviderConfigManager:
value: Setting value. value: Setting value.
""" """
self._global_settings[key] = 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]: def get_all_global_settings(self) -> Dict[str, Any]:
"""Get all global settings. """Get all global settings.
@@ -307,7 +307,7 @@ class ProviderConfigManager:
with open(config_path, "w", encoding="utf-8") as f: with open(config_path, "w", encoding="utf-8") as f:
json.dump(data, f, indent=2) json.dump(data, f, indent=2)
logger.info(f"Saved configuration to {config_path}") logger.info("Saved configuration to %s", config_path)
return True return True
except Exception as e: except Exception as e:

45
src/core/providers/enhanced_provider.py
View File

@@ -172,29 +172,32 @@ class EnhancedAniWorldLoader(Loader):
def _setup_logging(self): def _setup_logging(self):
"""Setup specialized logging for download errors and missing keys.""" """Setup specialized logging for download errors and missing keys."""
# Download error logger # Determine project root so log files land in a predictable location
self.download_error_logger = logging.getLogger("DownloadErrors") # regardless of the working directory at runtime.
download_error_handler = logging.FileHandler( _project_root = Path(__file__).parent.parent.parent.parent
"../../download_errors.log" _logs_dir = _project_root / "logs"
) _logs_dir.mkdir(parents=True, exist_ok=True)
download_error_handler.setLevel(logging.ERROR)
download_error_formatter = logging.Formatter( formatter = logging.Formatter(
'%(asctime)s - %(name)s - %(levelname)s - %(message)s' '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
) )
download_error_handler.setFormatter(download_error_formatter)
# Download error logger — records every failed download attempt
self.download_error_logger = logging.getLogger("DownloadErrors")
if not self.download_error_logger.handlers: if not self.download_error_logger.handlers:
self.download_error_logger.addHandler(download_error_handler) 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) self.download_error_logger.setLevel(logging.ERROR)
# No key found logger # No-key logger — records episodes for which no stream key was found
self.nokey_logger = logging.getLogger("NoKeyFound") 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: if not self.nokey_logger.handlers:
self.nokey_logger.addHandler(nokey_handler) 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) self.nokey_logger.setLevel(logging.ERROR)
def ClearCache(self): def ClearCache(self):
@@ -221,7 +224,7 @@ class EnhancedAniWorldLoader(Loader):
try: try:
return self._fetch_anime_list_with_recovery(search_url) return self._fetch_anime_list_with_recovery(search_url)
except Exception as e: except Exception as e:
self.logger.error(f"Search failed for term '{word}': {e}") self.logger.error("Search failed for term '%s': %s", word, e)
raise RetryableError(f"Search failed: {e}") from e raise RetryableError(f"Search failed: {e}") from e
def _fetch_anime_list_with_recovery(self, url: str) -> list: def _fetch_anime_list_with_recovery(self, url: str) -> list:
@@ -622,7 +625,7 @@ class EnhancedAniWorldLoader(Loader):
self.logger.warning(warn_msg) self.logger.warning(warn_msg)
except Exception as e: except Exception as e:
self.logger.warning(f"Provider {provider_name} failed: {e}") self.logger.warning("Provider %s failed: %s", provider_name, e)
# Clean up any partial temp files left by this failed attempt # Clean up any partial temp files left by this failed attempt
_cleanup_temp_file(temp_path, self.logger) _cleanup_temp_file(temp_path, self.logger)
self.download_stats['retried_downloads'] += 1 self.download_stats['retried_downloads'] += 1
@@ -641,7 +644,7 @@ class EnhancedAniWorldLoader(Loader):
ydl.download([link]) ydl.download([link])
return True return True
except Exception as e: except Exception as e:
self.logger.error(f"yt-dlp download failed: {e}") self.logger.error("yt-dlp download failed: %s", e)
raise DownloadError(f"Download failed: {e}") from e raise DownloadError(f"Download failed: {e}") from e
@with_error_recovery(max_retries=2, context="get_title") @with_error_recovery(max_retries=2, context="get_title")
@@ -658,11 +661,11 @@ class EnhancedAniWorldLoader(Loader):
if span: if span:
return span.text.strip() return span.text.strip()
self.logger.warning(f"Could not extract title for key: {key}") self.logger.warning("Could not extract title for key: %s", key)
return f"Unknown_Title_{key}" return f"Unknown_Title_{key}"
except Exception as e: except Exception as e:
self.logger.error(f"Failed to get title for key {key}: {e}") self.logger.error("Failed to get title for key %s: %s", key, e)
raise RetryableError(f"Title extraction failed: {e}") from e raise RetryableError(f"Title extraction failed: {e}") from e
def GetSiteKey(self) -> str: def GetSiteKey(self) -> str:
@@ -959,7 +962,7 @@ class EnhancedAniWorldLoader(Loader):
return episode_counts return episode_counts
except Exception as e: except Exception as e:
self.logger.error(f"Failed to get episode counts for {slug}: {e}") self.logger.error("Failed to get episode counts for %s: %s", slug, e)
raise RetryableError(f"Episode count retrieval failed: {e}") from e raise RetryableError(f"Episode count retrieval failed: {e}") from e
def get_download_statistics(self) -> Dict[str, Any]: def get_download_statistics(self) -> Dict[str, Any]:

2
src/core/providers/failover.py
View File

@@ -207,7 +207,7 @@ class ProviderFailover:
""" """
if provider_name not in self._providers: if provider_name not in self._providers:
self._providers.append(provider_name) 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: def remove_provider(self, provider_name: str) -> bool:
"""Remove a provider from the failover chain. """Remove a provider from the failover chain.

6
src/core/providers/health_monitor.py
View File

@@ -151,7 +151,7 @@ class ProviderHealthMonitor:
except asyncio.CancelledError: except asyncio.CancelledError:
break break
except Exception as e: 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) await asyncio.sleep(self._health_check_interval)
async def _perform_health_checks(self) -> None: async def _perform_health_checks(self) -> None:
@@ -314,7 +314,7 @@ class ProviderHealthMonitor:
) )
best_provider = available[0][0] best_provider = available[0][0]
logger.debug(f"Best provider selected: {best_provider}") logger.debug("Best provider selected: %s", best_provider)
return best_provider return best_provider
def _get_recent_metrics( def _get_recent_metrics(
@@ -355,7 +355,7 @@ class ProviderHealthMonitor:
provider_name=provider_name provider_name=provider_name
) )
self._request_history[provider_name].clear() 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 return True
def get_health_summary(self) -> Dict[str, Any]: def get_health_summary(self) -> Dict[str, Any]:

30
src/core/services/nfo_service.py
View File

@@ -134,21 +134,21 @@ class NFOService:
clean_name, extracted_year = self._extract_year_from_name(serie_name) clean_name, extracted_year = self._extract_year_from_name(serie_name)
if year is None and extracted_year is not None: if year is None and extracted_year is not None:
year = extracted_year 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 # Use clean name for search
search_name = clean_name 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 folder_path = self.anime_directory / serie_folder
if not folder_path.exists(): 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) folder_path.mkdir(parents=True, exist_ok=True)
async with self.tmdb_client: async with self.tmdb_client:
# Search for TV show with clean name (without year) # 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) search_results = await self.tmdb_client.search_tv_show(search_name)
if not search_results.get("results"): 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_show = self._find_best_match(search_results["results"], search_name, year)
tv_id = tv_show["id"] 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 # Get detailed information with multi-language image support
details = await self.tmdb_client.get_tv_show_details( details = await self.tmdb_client.get_tv_show_details(
@@ -190,7 +190,7 @@ class NFOService:
# Save NFO file # Save NFO file
nfo_path = folder_path / "tvshow.nfo" nfo_path = folder_path / "tvshow.nfo"
nfo_path.write_text(nfo_xml, encoding="utf-8") 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 # Download media files
await self._download_media_files( await self._download_media_files(
@@ -227,7 +227,7 @@ class NFOService:
if not nfo_path.exists(): if not nfo_path.exists():
raise FileNotFoundError(f"NFO file not found: {nfo_path}") 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 # Parse existing NFO to extract TMDB ID
try: try:
@@ -253,7 +253,7 @@ class NFOService:
f"Delete the NFO and create a new one instead." 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: except etree.XMLSyntaxError as e:
raise TMDBAPIError(f"Invalid XML in NFO file: {e}") raise TMDBAPIError(f"Invalid XML in NFO file: {e}")
@@ -262,7 +262,7 @@ class NFOService:
# Fetch fresh data from TMDB # Fetch fresh data from TMDB
async with self.tmdb_client: 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( details = await self.tmdb_client.get_tv_show_details(
tmdb_id, tmdb_id,
append_to_response="credits,external_ids,images" append_to_response="credits,external_ids,images"
@@ -286,7 +286,7 @@ class NFOService:
# Save updated NFO file # Save updated NFO file
nfo_path.write_text(nfo_xml, encoding="utf-8") 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 # Re-download media files if requested
if download_media: if download_media:
@@ -318,7 +318,7 @@ class NFOService:
result = {"tmdb_id": None, "tvdb_id": None} result = {"tmdb_id": None, "tvdb_id": None}
if not nfo_path.exists(): 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 return result
try: try:
@@ -375,9 +375,9 @@ class NFOService:
) )
except etree.XMLSyntaxError as e: 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 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 return result
@@ -480,7 +480,7 @@ class NFOService:
for result in results: for result in results:
first_air_date = result.get("first_air_date", "") first_air_date = result.get("first_air_date", "")
if first_air_date.startswith(str(year)): 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 result
# Return first result (usually best match) # Return first result (usually best match)
@@ -545,7 +545,7 @@ class NFOService:
skip_existing=True skip_existing=True
) )
logger.info(f"Media download results: {results}") logger.info("Media download results: %s", results)
return results return results

8
src/core/services/series_manager_service.py
View File

@@ -136,7 +136,7 @@ class SeriesManagerService:
# If NFO exists, parse IDs and update database # If NFO exists, parse IDs and update database
if nfo_exists: 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) ids = self.nfo_service.parse_nfo_ids(nfo_path)
if ids["tmdb_id"] or ids["tvdb_id"]: if ids["tmdb_id"] or ids["tvdb_id"]:
@@ -203,14 +203,14 @@ class SeriesManagerService:
download_logo=self.download_logo, download_logo=self.download_logo,
download_fanart=self.download_fanart 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: elif nfo_exists:
logger.debug( logger.debug(
f"NFO exists for '{serie_name}', skipping download" f"NFO exists for '{serie_name}', skipping download"
) )
except TMDBAPIError as e: 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: except Exception as e:
logger.error( logger.error(
f"Unexpected error processing NFO for '{serie_name}': {e}", f"Unexpected error processing NFO for '{serie_name}': {e}",
@@ -246,7 +246,7 @@ class SeriesManagerService:
logger.info("No series found in database to process") logger.info("No series found in database to process")
return 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 # Create tasks for concurrent processing
# Each task creates its own database session # Each task creates its own database session

20
src/core/services/tmdb_client.py
View File

@@ -107,7 +107,7 @@ class TMDBClient:
# Cache key for deduplication # Cache key for deduplication
cache_key = f"{endpoint}:{str(sorted(params.items()))}" cache_key = f"{endpoint}:{str(sorted(params.items()))}"
if cache_key in self._cache: 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] return self._cache[cache_key]
delay = 1 delay = 1
@@ -121,7 +121,7 @@ class TMDBClient:
if self.session is None: if self.session is None:
raise TMDBAPIError("Session is not available") 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: async with self.session.get(url, params=params, timeout=aiohttp.ClientTimeout(total=60)) as resp:
if resp.status == 401: if resp.status == 401:
raise TMDBAPIError("Invalid TMDB API key") raise TMDBAPIError("Invalid TMDB API key")
@@ -130,7 +130,7 @@ class TMDBClient:
elif resp.status == 429: elif resp.status == 429:
# Rate limit - wait longer # Rate limit - wait longer
retry_after = int(resp.headers.get('Retry-After', delay * 2)) 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) await asyncio.sleep(retry_after)
continue continue
@@ -142,26 +142,26 @@ class TMDBClient:
except asyncio.TimeoutError as e: except asyncio.TimeoutError as e:
last_error = e last_error = e
if attempt < max_retries - 1: 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) await asyncio.sleep(delay)
delay *= 2 delay *= 2
else: 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: except (aiohttp.ClientError, AttributeError) as e:
last_error = e last_error = e
# If connector/session was closed, try to recreate it # If connector/session was closed, try to recreate it
if "Connector is closed" in str(e) or isinstance(e, AttributeError): 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 self.session = None
await self._ensure_session() await self._ensure_session()
if attempt < max_retries - 1: 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) await asyncio.sleep(delay)
delay *= 2 delay *= 2
else: 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}") 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}" url = f"{self.image_base_url}/{size}{image_path}"
try: 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: async with self.session.get(url, timeout=aiohttp.ClientTimeout(total=60)) as resp:
resp.raise_for_status() resp.raise_for_status()
@@ -286,7 +286,7 @@ class TMDBClient:
with open(local_path, "wb") as f: with open(local_path, "wb") as f:
f.write(await resp.read()) 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: except aiohttp.ClientError as e:
raise TMDBAPIError(f"Failed to download image: {e}") raise TMDBAPIError(f"Failed to download image: {e}")

33
src/core/utils/image_downloader.py
View File

@@ -125,7 +125,7 @@ class ImageDownloader:
# Check if file already exists # Check if file already exists
if skip_existing and local_path.exists(): if skip_existing and local_path.exists():
if local_path.stat().st_size >= self.min_file_size: 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 return True
# Ensure parent directory exists # Ensure parent directory exists
@@ -137,15 +137,16 @@ class ImageDownloader:
for attempt in range(self.max_retries): for attempt in range(self.max_retries):
try: try:
logger.debug( logger.debug(
f"Downloading image from {url} " "Downloading image from %s (attempt %d)",
f"(attempt {attempt + 1})" url,
attempt + 1,
) )
# Use persistent session # Use persistent session
session = self._get_session() session = self._get_session()
async with session.get(url) as resp: async with session.get(url) as resp:
if resp.status == 404: if resp.status == 404:
logger.warning(f"Image not found: {url}") logger.warning("Image not found: %s", url)
return False return False
resp.raise_for_status() resp.raise_for_status()
@@ -168,21 +169,25 @@ class ImageDownloader:
local_path.unlink(missing_ok=True) local_path.unlink(missing_ok=True)
raise ImageDownloadError("Image validation failed") raise ImageDownloadError("Image validation failed")
logger.info(f"Downloaded image to {local_path}") logger.info("Downloaded image to %s", local_path)
return True return True
except (aiohttp.ClientError, IOError, ImageDownloadError) as e: except (aiohttp.ClientError, IOError, ImageDownloadError) as e:
last_error = e last_error = e
if attempt < self.max_retries - 1: if attempt < self.max_retries - 1:
logger.warning( logger.warning(
f"Download failed (attempt {attempt + 1}): {e}, " "Download failed (attempt %d): %s, retrying in %s",
f"retrying in {delay}s" attempt + 1,
e,
delay,
) )
await asyncio.sleep(delay) await asyncio.sleep(delay)
delay *= 2 delay *= 2
else: else:
logger.error( logger.error(
f"Download failed after {self.max_retries} attempts: {e}" "Download failed after %d attempts: %s",
self.max_retries,
e,
) )
raise ImageDownloadError( raise ImageDownloadError(
@@ -211,7 +216,7 @@ class ImageDownloader:
try: try:
return await self.download_image(url, local_path, skip_existing) return await self.download_image(url, local_path, skip_existing)
except ImageDownloadError as e: except ImageDownloadError as e:
logger.warning(f"Failed to download poster: {e}") logger.warning("Failed to download poster: %s", e)
return False return False
async def download_logo( async def download_logo(
@@ -236,7 +241,7 @@ class ImageDownloader:
try: try:
return await self.download_image(url, local_path, skip_existing) return await self.download_image(url, local_path, skip_existing)
except ImageDownloadError as e: except ImageDownloadError as e:
logger.warning(f"Failed to download logo: {e}") logger.warning("Failed to download logo: %s", e)
return False return False
async def download_fanart( async def download_fanart(
@@ -261,7 +266,7 @@ class ImageDownloader:
try: try:
return await self.download_image(url, local_path, skip_existing) return await self.download_image(url, local_path, skip_existing)
except ImageDownloadError as e: except ImageDownloadError as e:
logger.warning(f"Failed to download fanart: {e}") logger.warning("Failed to download fanart: %s", e)
return False return False
def validate_image(self, image_path: Path) -> bool: def validate_image(self, image_path: Path) -> bool:
@@ -280,13 +285,13 @@ class ImageDownloader:
# Check file size # Check file size
if image_path.stat().st_size < self.min_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 False
return True return True
except Exception as e: 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 return False
async def download_all_media( async def download_all_media(
@@ -341,7 +346,7 @@ class ImageDownloader:
for (media_type, _), result in zip(tasks, task_results): for (media_type, _), result in zip(tasks, task_results):
if isinstance(result, Exception): 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 results[media_type] = False
else: else:
results[media_type] = result results[media_type] = result

2
src/core/utils/nfo_generator.py
View File

@@ -209,5 +209,5 @@ def validate_nfo_xml(xml_string: str) -> bool:
etree.fromstring(xml_string.encode('utf-8')) etree.fromstring(xml_string.encode('utf-8'))
return True return True
except etree.XMLSyntaxError as e: except etree.XMLSyntaxError as e:
logger.error(f"Invalid NFO XML: {e}") logger.error("Invalid NFO XML: %s", e)
return False return False

22
src/infrastructure/security/config_encryption.py
View File

@@ -36,10 +36,10 @@ class ConfigEncryption:
def _ensure_key_exists(self) -> None: def _ensure_key_exists(self) -> None:
"""Ensure encryption key exists or create one.""" """Ensure encryption key exists or create one."""
if not self.key_file.exists(): 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() self._generate_new_key()
else: 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: def _generate_new_key(self) -> None:
"""Generate and store a new encryption key.""" """Generate and store a new encryption key."""
@@ -56,7 +56,7 @@ class ConfigEncryption:
logger.info("Generated new encryption key") logger.info("Generated new encryption key")
except IOError as e: except IOError as e:
logger.error(f"Failed to generate encryption key: {e}") logger.error("Failed to generate encryption key: %s", e)
raise raise
def _load_key(self) -> bytes: def _load_key(self) -> bytes:
@@ -77,7 +77,7 @@ class ConfigEncryption:
key = self.key_file.read_bytes() key = self.key_file.read_bytes()
return key return key
except IOError as e: except IOError as e:
logger.error(f"Failed to load encryption key: {e}") logger.error("Failed to load encryption key: %s", e)
raise raise
def _get_cipher(self) -> Fernet: def _get_cipher(self) -> Fernet:
@@ -117,7 +117,7 @@ class ConfigEncryption:
return encrypted_str return encrypted_str
except Exception as e: except Exception as e:
logger.error(f"Failed to encrypt value: {e}") logger.error("Failed to encrypt value: %s", e)
raise raise
def decrypt_value(self, encrypted_value: str) -> str: def decrypt_value(self, encrypted_value: str) -> str:
@@ -149,7 +149,7 @@ class ConfigEncryption:
return decrypted_str return decrypted_str
except Exception as e: except Exception as e:
logger.error(f"Failed to decrypt value: {e}") logger.error("Failed to decrypt value: %s", e)
raise raise
def encrypt_config(self, config: Dict[str, Any]) -> Dict[str, Any]: def encrypt_config(self, config: Dict[str, Any]) -> Dict[str, Any]:
@@ -191,9 +191,9 @@ class ConfigEncryption:
'encrypted': True, 'encrypted': True,
'value': self.encrypt_value(value) 'value': self.encrypt_value(value)
} }
logger.debug(f"Encrypted config field: {key}") logger.debug("Encrypted config field: %s", key)
except Exception as e: 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 encrypted_config[key] = value
else: else:
encrypted_config[key] = value encrypted_config[key] = value
@@ -222,9 +222,9 @@ class ConfigEncryption:
decrypted_config[key] = self.decrypt_value( decrypted_config[key] = self.decrypt_value(
value['value'] value['value']
) )
logger.debug(f"Decrypted config field: {key}") logger.debug("Decrypted config field: %s", key)
except Exception as e: 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 decrypted_config[key] = None
else: else:
decrypted_config[key] = value decrypted_config[key] = value
@@ -248,7 +248,7 @@ class ConfigEncryption:
if self.key_file.exists(): if self.key_file.exists():
backup_path = self.key_file.with_suffix('.key.bak') backup_path = self.key_file.with_suffix('.key.bak')
self.key_file.rename(backup_path) 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 # Generate new key
if new_key_file: if new_key_file:

4
src/infrastructure/security/database_integrity.py
View File

@@ -276,13 +276,13 @@ class DatabaseIntegrityChecker:
removed += 1 removed += 1
self.session.commit() self.session.commit()
logger.info(f"Removed {removed} orphaned records") logger.info("Removed %s orphaned records", removed)
return removed return removed
except Exception as e: except Exception as e:
self.session.rollback() self.session.rollback()
logger.error(f"Error removing orphaned records: {e}") logger.error("Error removing orphaned records: %s", e)
raise raise

27
src/infrastructure/security/file_integrity.py
View File

@@ -39,13 +39,15 @@ class FileIntegrityManager:
self.checksums = json.load(f) self.checksums = json.load(f)
count = len(self.checksums) count = len(self.checksums)
logger.info( 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: except (json.JSONDecodeError, IOError) as e:
logger.error(f"Failed to load checksums: {e}") logger.error("Failed to load checksums: %s", e)
self.checksums = {} self.checksums = {}
else: 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 = {} self.checksums = {}
def _save_checksums(self) -> None: def _save_checksums(self) -> None:
@@ -56,10 +58,12 @@ class FileIntegrityManager:
json.dump(self.checksums, f, indent=2) json.dump(self.checksums, f, indent=2)
count = len(self.checksums) count = len(self.checksums)
logger.debug( logger.debug(
f"Saved {count} checksums to {self.checksum_file}" "Saved %d checksums to %s",
count,
self.checksum_file,
) )
except IOError as e: except IOError as e:
logger.error(f"Failed to save checksums: {e}") logger.error("Failed to save checksums: %s", e)
def calculate_checksum( def calculate_checksum(
self, file_path: Path, algorithm: str = "sha256" self, file_path: Path, algorithm: str = "sha256"
@@ -94,12 +98,15 @@ class FileIntegrityManager:
checksum = hash_obj.hexdigest() checksum = hash_obj.hexdigest()
filename = file_path.name filename = file_path.name
logger.debug( logger.debug(
f"Calculated {algorithm} checksum for {filename}: {checksum}" "Calculated %s checksum for %s: %s",
algorithm,
filename,
checksum,
) )
return checksum return checksum
except IOError as e: 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 raise
def store_checksum( def store_checksum(
@@ -126,7 +133,7 @@ class FileIntegrityManager:
self.checksums[key] = checksum self.checksums[key] = checksum
self._save_checksums() self._save_checksums()
logger.info(f"Stored checksum for {file_path.name}") logger.info("Stored checksum for %s", file_path.name)
return checksum return checksum
def verify_checksum( def verify_checksum(
@@ -197,10 +204,10 @@ class FileIntegrityManager:
if key in self.checksums: if key in self.checksums:
del self.checksums[key] del self.checksums[key]
self._save_checksums() self._save_checksums()
logger.info(f"Removed checksum for {file_path.name}") logger.info("Removed checksum for %s", file_path.name)
return True return True
else: 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 return False
def has_checksum(self, file_path: Path) -> bool: def has_checksum(self, file_path: Path) -> bool:

4
src/server/api/anime.py
View File

@@ -724,9 +724,9 @@ async def add_series(
if series_app and hasattr(series_app, 'loader'): if series_app and hasattr(series_app, 'loader'):
try: try:
year = series_app.loader.get_year(key) 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: 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 # Create folder name with year if available
if year: if year:

8
src/server/api/health.py
View File

@@ -91,7 +91,7 @@ async def check_database_health(db: AsyncSession) -> DatabaseHealth:
message="Database connection successful", message="Database connection successful",
) )
except Exception as e: except Exception as e:
logger.error(f"Database health check failed: {e}") logger.error("Database health check failed: %s", e)
return DatabaseHealth( return DatabaseHealth(
status="unhealthy", status="unhealthy",
connection_time_ms=0, connection_time_ms=0,
@@ -121,7 +121,7 @@ async def check_filesystem_health() -> Dict[str, Any]:
"message": "Filesystem check completed", "message": "Filesystem check completed",
} }
except Exception as e: except Exception as e:
logger.error(f"Filesystem health check failed: {e}") logger.error("Filesystem health check failed: %s", e)
return { return {
"status": "unhealthy", "status": "unhealthy",
"message": f"Filesystem check failed: {str(e)}", "message": f"Filesystem check failed: {str(e)}",
@@ -164,7 +164,7 @@ def get_system_metrics() -> SystemMetrics:
uptime_seconds=uptime_seconds, uptime_seconds=uptime_seconds,
) )
except Exception as e: except Exception as e:
logger.error(f"System metrics collection failed: {e}") logger.error("System metrics collection failed: %s", e)
raise HTTPException( raise HTTPException(
status_code=500, detail=f"Failed to collect system metrics: {str(e)}" 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, startup_time=startup_time,
) )
except Exception as e: 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") raise HTTPException(status_code=500, detail="Health check failed")

8
src/server/api/nfo.py
View File

@@ -243,7 +243,7 @@ async def get_missing_nfo(
) )
except Exception as e: 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( raise HTTPException(
status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR,
detail=f"Failed to get missing NFOs: {str(e)}" detail=f"Failed to get missing NFOs: {str(e)}"
@@ -334,7 +334,7 @@ async def check_nfo(
except HTTPException: except HTTPException:
raise raise
except Exception as e: 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( raise HTTPException(
status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR,
detail=f"Failed to check NFO: {str(e)}" detail=f"Failed to check NFO: {str(e)}"
@@ -429,7 +429,7 @@ async def create_nfo(
except HTTPException: except HTTPException:
raise raise
except TMDBAPIError as e: 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( raise HTTPException(
status_code=status.HTTP_503_SERVICE_UNAVAILABLE, status_code=status.HTTP_503_SERVICE_UNAVAILABLE,
detail=f"TMDB API error: {str(e)}" detail=f"TMDB API error: {str(e)}"
@@ -524,7 +524,7 @@ async def update_nfo(
except HTTPException: except HTTPException:
raise raise
except TMDBAPIError as e: 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( raise HTTPException(
status_code=status.HTTP_503_SERVICE_UNAVAILABLE, status_code=status.HTTP_503_SERVICE_UNAVAILABLE,
detail=f"TMDB API error: {str(e)}" detail=f"TMDB API error: {str(e)}"

8
src/server/config/logging_config.py
View File

@@ -95,10 +95,10 @@ def setup_logging() -> Dict[str, logging.Logger]:
# Log initial setup # Log initial setup
root_logger.info("=" * 80) root_logger.info("=" * 80)
root_logger.info("FastAPI Server Logging Initialized") root_logger.info("FastAPI Server Logging Initialized")
root_logger.info(f"Log Level: {settings.log_level.upper()}") root_logger.info("Log Level: %s", settings.log_level.upper())
root_logger.info(f"Server Log: {server_log_file.absolute()}") root_logger.info("Server Log: %s", server_log_file.absolute())
root_logger.info(f"Error Log: {error_log_file.absolute()}") root_logger.info("Error Log: %s", error_log_file.absolute())
root_logger.info(f"Access Log: {access_log_file.absolute()}") root_logger.info("Access Log: %s", access_log_file.absolute())
root_logger.info("=" * 80) root_logger.info("=" * 80)
return { return {

8
src/server/database/connection.py
View File

@@ -88,7 +88,7 @@ async def init_db() -> None:
try: try:
# Get database URL # Get database URL
db_url = _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 # Build engine kwargs based on database type
is_sqlite = "sqlite" in db_url is_sqlite = "sqlite" in db_url
@@ -143,7 +143,7 @@ async def init_db() -> None:
logger.info("Database initialization complete") logger.info("Database initialization complete")
except Exception as e: except Exception as e:
logger.error(f"Failed to initialize database: {e}") logger.error("Failed to initialize database: %s", e)
raise raise
@@ -171,7 +171,7 @@ async def close_db() -> None:
conn.commit() conn.commit()
logger.info("SQLite WAL checkpoint completed") logger.info("SQLite WAL checkpoint completed")
except Exception as e: except Exception as e:
logger.warning(f"WAL checkpoint failed (non-critical): {e}") logger.warning("WAL checkpoint failed (non-critical): %s", e)
if _engine: if _engine:
logger.info("Closing async database engine...") logger.info("Closing async database engine...")
@@ -188,7 +188,7 @@ async def close_db() -> None:
logger.info("Database connections closed") logger.info("Database connections closed")
except Exception as e: except Exception as e:
logger.error(f"Error closing database: {e}") logger.error("Error closing database: %s", e)
def get_engine() -> AsyncEngine: def get_engine() -> AsyncEngine:

26
src/server/database/init.py
View File

@@ -98,7 +98,7 @@ async def initialize_database(
seed_data=True seed_data=True
) )
if result["success"]: if result["success"]:
logger.info(f"Database initialized: {result['schema_version']}") logger.info("Database initialized: %s", result['schema_version'])
""" """
if engine is None: if engine is None:
engine = get_engine() engine = get_engine()
@@ -117,7 +117,7 @@ async def initialize_database(
if create_schema: if create_schema:
tables = await create_database_schema(engine) tables = await create_database_schema(engine)
result["tables_created"] = tables result["tables_created"] = tables
logger.info(f"Created {len(tables)} tables") logger.info("Created %s tables", len(tables))
# Validate schema if requested # Validate schema if requested
if validate_schema: if validate_schema:
@@ -148,7 +148,7 @@ async def initialize_database(
return result return result
except Exception as e: 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 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] created_tables = [t for t in new_tables if t not in existing_tables]
if created_tables: if created_tables:
logger.info(f"Created tables: {', '.join(created_tables)}") logger.info("Created tables: %s", ', '.join(created_tables))
else: else:
logger.info("All tables already exist") logger.info("All tables already exist")
return new_tables return new_tables
except Exception as e: 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 raise RuntimeError(f"Schema creation failed: {e}") from e
@@ -295,7 +295,7 @@ async def validate_database_schema(
return result return result
except Exception as e: except Exception as e:
logger.error(f"Schema validation failed: {e}", exc_info=True) logger.exception("Schema validation failed: %s", e)
return { return {
"valid": False, "valid": False,
"missing_tables": [], "missing_tables": [],
@@ -342,7 +342,7 @@ async def get_schema_version(engine: Optional[AsyncEngine] = None) -> str:
return "unknown" return "unknown"
except Exception as e: except Exception as e:
logger.error(f"Failed to get schema version: {e}") logger.error("Failed to get schema version: %s", e)
return "error" 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") logger.info("Data will be populated via normal application usage")
except Exception as e: 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 raise
@@ -484,12 +484,12 @@ async def check_database_health(
f"(connectivity: {result['connectivity_ms']}ms)" f"(connectivity: {result['connectivity_ms']}ms)"
) )
else: else:
logger.warning(f"Database health issues: {result['issues']}") logger.warning("Database health issues: %s", result['issues'])
return result return result
except Exception as e: except Exception as e:
logger.error(f"Database health check failed: {e}") logger.error("Database health check failed: %s", e)
return { return {
"healthy": False, "healthy": False,
"accessible": False, "accessible": False,
@@ -547,13 +547,13 @@ async def create_database_backup(
backup_path = backup_dir / f"aniworld_{timestamp}.db" backup_path = backup_dir / f"aniworld_{timestamp}.db"
try: try:
logger.info(f"Creating database backup: {backup_path}") logger.info("Creating database backup: %s", backup_path)
shutil.copy2(db_path, 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 return backup_path
except Exception as e: 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 raise RuntimeError(f"Backup creation failed: {e}") from e

22
src/server/database/service.py
View File

@@ -107,7 +107,7 @@ class AnimeSeriesService:
db.add(series) db.add(series)
await db.flush() await db.flush()
await db.refresh(series) 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 return series
@staticmethod @staticmethod
@@ -205,7 +205,7 @@ class AnimeSeriesService:
await db.flush() await db.flush()
await db.refresh(series) 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 return series
@staticmethod @staticmethod
@@ -226,7 +226,7 @@ class AnimeSeriesService:
) )
deleted = result.rowcount > 0 deleted = result.rowcount > 0
if deleted: if deleted:
logger.info(f"Deleted anime series with id={series_id}") logger.info("Deleted anime series with id=%s", series_id)
return deleted return deleted
@staticmethod @staticmethod
@@ -701,7 +701,7 @@ class EpisodeService:
updated_count += 1 updated_count += 1
await db.flush() 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 return updated_count
@@ -850,7 +850,7 @@ class DownloadQueueService:
await db.flush() await db.flush()
await db.refresh(item) 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 return item
@staticmethod @staticmethod
@@ -869,7 +869,7 @@ class DownloadQueueService:
) )
deleted = result.rowcount > 0 deleted = result.rowcount > 0
if deleted: 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 return deleted
@staticmethod @staticmethod
@@ -931,7 +931,7 @@ class DownloadQueueService:
) )
count = result.rowcount count = result.rowcount
logger.info(f"Bulk deleted {count} download queue items") logger.info("Bulk deleted %s download queue items", count)
return count return count
@@ -952,7 +952,7 @@ class DownloadQueueService:
""" """
result = await db.execute(delete(DownloadQueueItem)) result = await db.execute(delete(DownloadQueueItem))
count = result.rowcount count = result.rowcount
logger.info(f"Cleared all {count} download queue items") logger.info("Cleared all %s download queue items", count)
return count return count
@@ -1006,7 +1006,7 @@ class UserSessionService:
db.add(session) db.add(session)
await db.flush() await db.flush()
await db.refresh(session) await db.refresh(session)
logger.info(f"Created user session: {session_id}") logger.info("Created user session: %s", session_id)
return session return session
@staticmethod @staticmethod
@@ -1093,7 +1093,7 @@ class UserSessionService:
session.revoke() session.revoke()
await db.flush() await db.flush()
logger.info(f"Revoked user session: {session_id}") logger.info("Revoked user session: %s", session_id)
return True return True
@staticmethod @staticmethod
@@ -1115,7 +1115,7 @@ class UserSessionService:
) )
) )
count = result.rowcount count = result.rowcount
logger.info(f"Cleaned up {count} expired sessions") logger.info("Cleaned up %s expired sessions", count)
return count return count
@staticmethod @staticmethod

4
src/server/fastapi_app.py
View File

@@ -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.") logger.info("All series data is complete. No background loading needed.")
except Exception as e: 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: 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 @asynccontextmanager

29
src/server/middleware/error_handler.py
View File

@@ -74,7 +74,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle authentication errors (401).""" """Handle authentication errors (401)."""
logger.warning( logger.warning(
f"Authentication error: {exc.message}", "Authentication error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -94,7 +95,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle authorization errors (403).""" """Handle authorization errors (403)."""
logger.warning( logger.warning(
f"Authorization error: {exc.message}", "Authorization error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -114,7 +116,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle validation errors (422).""" """Handle validation errors (422)."""
logger.info( logger.info(
f"Validation error: {exc.message}", "Validation error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -134,7 +137,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle bad request errors (400).""" """Handle bad request errors (400)."""
logger.info( logger.info(
f"Bad request error: {exc.message}", "Bad request error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -154,7 +158,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle not found errors (404).""" """Handle not found errors (404)."""
logger.info( logger.info(
f"Not found error: {exc.message}", "Not found error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -174,7 +179,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle conflict errors (409).""" """Handle conflict errors (409)."""
logger.info( logger.info(
f"Conflict error: {exc.message}", "Conflict error: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -194,7 +200,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle rate limit errors (429).""" """Handle rate limit errors (429)."""
logger.warning( logger.warning(
f"Rate limit exceeded: {exc.message}", "Rate limit exceeded: %s",
exc.message,
extra={"details": exc.details, "path": str(request.url.path)}, extra={"details": exc.details, "path": str(request.url.path)},
) )
return JSONResponse( return JSONResponse(
@@ -214,7 +221,8 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle generic API exceptions.""" """Handle generic API exceptions."""
logger.error( logger.error(
f"API error: {exc.message}", "API error: %s",
exc.message,
extra={ extra={
"error_code": exc.error_code, "error_code": exc.error_code,
"details": exc.details, "details": exc.details,
@@ -238,12 +246,13 @@ def register_exception_handlers(app: FastAPI) -> None:
) -> JSONResponse: ) -> JSONResponse:
"""Handle unexpected exceptions.""" """Handle unexpected exceptions."""
logger.exception( logger.exception(
f"Unexpected error: {str(exc)}", "Unexpected error: %s",
str(exc),
extra={"path": str(request.url.path)}, extra={"path": str(request.url.path)},
) )
# Log full traceback for debugging # 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 generic error response for security
return JSONResponse( return JSONResponse(

12
src/server/middleware/security.py
View File

@@ -315,11 +315,11 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware):
None if malicious content detected, sanitized value otherwise None if malicious content detected, sanitized value otherwise
""" """
if self.check_sql_injection and self._check_sql_injection(value): 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 return None
if self.check_xss and self._check_xss(value): 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 None
return value return value
@@ -341,7 +341,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware):
content_type content_type
and not any(ct in content_type for ct in self.allowed_content_types) 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( return JSONResponse(
status_code=415, status_code=415,
content={"detail": "Unsupported Media Type"}, content={"detail": "Unsupported Media Type"},
@@ -350,7 +350,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware):
# Check request size # Check request size
content_length = request.headers.get("content-length") content_length = request.headers.get("content-length")
if content_length and int(content_length) > self.max_request_size: 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( return JSONResponse(
status_code=413, status_code=413,
content={"detail": "Request Entity Too Large"}, content={"detail": "Request Entity Too Large"},
@@ -361,7 +361,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware):
if isinstance(value, str): if isinstance(value, str):
sanitized = self._sanitize_value(value) sanitized = self._sanitize_value(value)
if sanitized is None: if sanitized is None:
logger.warning(f"Malicious query parameter detected: {key}") logger.warning("Malicious query parameter detected: %s", key)
return JSONResponse( return JSONResponse(
status_code=400, status_code=400,
content={"detail": "Malicious request detected"}, content={"detail": "Malicious request detected"},
@@ -372,7 +372,7 @@ class RequestSanitizationMiddleware(BaseHTTPMiddleware):
if isinstance(value, str): if isinstance(value, str):
sanitized = self._sanitize_value(value) sanitized = self._sanitize_value(value)
if sanitized is None: if sanitized is None:
logger.warning(f"Malicious path parameter detected: {key}") logger.warning("Malicious path parameter detected: %s", key)
return JSONResponse( return JSONResponse(
status_code=400, status_code=400,
content={"detail": "Malicious request detected"}, content={"detail": "Malicious request detected"},

8
src/server/services/anime_service.py
View File

@@ -945,12 +945,12 @@ class AnimeService:
# Get the serie from in-memory cache # Get the serie from in-memory cache
if not hasattr(self._app, 'list') or not hasattr(self._app.list, 'keyDict'): 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 return 0
serie = self._app.list.keyDict.get(series_key) serie = self._app.list.keyDict.get(series_key)
if not serie: 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 return 0
episodes_added = 0 episodes_added = 0
@@ -959,7 +959,7 @@ class AnimeService:
# Get series from database # Get series from database
series_db = await AnimeSeriesService.get_by_key(db, series_key) series_db = await AnimeSeriesService.get_by_key(db, series_key)
if not series_db: 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 return 0
# Get existing episodes from database # Get existing episodes from database
@@ -1000,7 +1000,7 @@ class AnimeService:
try: try:
await self._broadcast_series_updated(series_key) await self._broadcast_series_updated(series_key)
except Exception as e: 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 return episodes_added

58
src/server/services/background_loader_service.py
View File

@@ -188,7 +188,7 @@ class BackgroundLoaderService:
""" """
# Check if task already exists # Check if task already exists
if key in self.active_tasks: 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 return
task = SeriesLoadingTask( task = SeriesLoadingTask(
@@ -202,7 +202,7 @@ class BackgroundLoaderService:
self.active_tasks[key] = task self.active_tasks[key] = task
await self.task_queue.put(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 # Broadcast initial status
await self._broadcast_status(task) await self._broadcast_status(task)
@@ -277,7 +277,7 @@ class BackgroundLoaderService:
Args: Args:
worker_id: Unique identifier for this worker instance 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: while not self._shutdown:
try: try:
@@ -301,14 +301,14 @@ class BackgroundLoaderService:
# No task available, continue loop # No task available, continue loop
continue continue
except asyncio.CancelledError: except asyncio.CancelledError:
logger.info(f"Worker {worker_id} task cancelled") logger.info("Worker %s task cancelled", worker_id)
break break
except Exception as e: 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 processing other tasks
continue 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: async def _load_series_data(self, task: SeriesLoadingTask) -> None:
"""Load all missing data for a series. """Load all missing data for a series.
@@ -362,10 +362,10 @@ class BackgroundLoaderService:
# Broadcast completion # Broadcast completion
await self._broadcast_status(task) 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: 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.status = LoadingStatus.FAILED
task.error = str(e) task.error = str(e)
task.completed_at = datetime.now(timezone.utc) task.completed_at = datetime.now(timezone.utc)
@@ -400,14 +400,14 @@ class BackgroundLoaderService:
# Check if directory exists # Check if directory exists
if series_dir.exists() and series_dir.is_dir(): 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 return series_dir
else: else:
logger.warning(f"Series directory not found: {series_dir}") logger.warning("Series directory not found: %s", series_dir)
return None return None
except Exception as e: 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 return None
async def _scan_series_episodes(self, series_dir: Path, task: SeriesLoadingTask) -> Dict[str, List[str]]: async def _scan_series_episodes(self, series_dir: Path, task: SeriesLoadingTask) -> Dict[str, List[str]]:
@@ -440,13 +440,13 @@ class BackgroundLoaderService:
if episodes: if episodes:
episodes_by_season[season_name] = 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 return episodes_by_season
except Exception as e: 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 {} return {}
async def _load_episodes(self, task: SeriesLoadingTask, db: Any) -> None: async def _load_episodes(self, task: SeriesLoadingTask, db: Any) -> None:
@@ -466,7 +466,7 @@ class BackgroundLoaderService:
# Find series directory without full rescan # Find series directory without full rescan
series_dir = await self._find_series_directory(task) series_dir = await self._find_series_directory(task)
if not series_dir: 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 task.progress["episodes"] = False
return return
@@ -474,7 +474,7 @@ class BackgroundLoaderService:
episodes_by_season = await self._scan_series_episodes(series_dir, task) episodes_by_season = await self._scan_series_episodes(series_dir, task)
if not episodes_by_season: 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 task.progress["episodes"] = False
return return
@@ -489,10 +489,10 @@ class BackgroundLoaderService:
series_db.loading_status = "loading_episodes" series_db.loading_status = "loading_episodes"
await db.commit() 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: 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 raise
async def _load_nfo_and_images(self, task: SeriesLoadingTask, db: Any) -> bool: async def _load_nfo_and_images(self, task: SeriesLoadingTask, db: Any) -> bool:
@@ -521,7 +521,7 @@ class BackgroundLoaderService:
# Check if NFO already exists # Check if NFO already exists
if self.series_app.nfo_service.has_nfo(task.folder): 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 # Update task progress
task.progress["nfo"] = True task.progress["nfo"] = True
@@ -536,19 +536,19 @@ class BackgroundLoaderService:
if not series_db.has_nfo: if not series_db.has_nfo:
series_db.has_nfo = True series_db.has_nfo = True
series_db.nfo_created_at = datetime.now(timezone.utc) 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: if not series_db.logo_loaded:
series_db.logo_loaded = True series_db.logo_loaded = True
if not series_db.images_loaded: if not series_db.images_loaded:
series_db.images_loaded = True series_db.images_loaded = True
await db.commit() 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 return False
# NFO doesn't exist, create it # NFO doesn't exist, create it
await self._broadcast_status(task, "Generating NFO file...") 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 # Use existing NFOService to create NFO with all images
# This reuses all existing TMDB API logic and image downloading # This reuses all existing TMDB API logic and image downloading
@@ -577,11 +577,11 @@ class BackgroundLoaderService:
series_db.loading_status = "loading_nfo" series_db.loading_status = "loading_nfo"
await db.commit() 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 return True
except Exception as e: 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 # Don't fail the entire task if NFO fails
task.progress["nfo"] = False task.progress["nfo"] = False
task.progress["logo"] = False task.progress["logo"] = False
@@ -611,7 +611,7 @@ class BackgroundLoaderService:
# Scan for missing episodes using the targeted scan method # Scan for missing episodes using the targeted scan method
# This populates the episodeDict without triggering a full rescan # 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( missing_episodes = self.series_app.serie_scanner.scan_single_series(
key=task.key, key=task.key,
folder=task.folder folder=task.folder
@@ -628,12 +628,12 @@ class BackgroundLoaderService:
# Notify anime_service to sync episodes to database # Notify anime_service to sync episodes to database
# Use sync_single_series_after_scan which gets data from serie_scanner.keyDict # Use sync_single_series_after_scan which gets data from serie_scanner.keyDict
if self.anime_service: 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) await self.anime_service.sync_single_series_after_scan(task.key)
else: 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: 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 # Update series status in database
from src.server.database.service import AnimeSeriesService from src.server.database.service import AnimeSeriesService
@@ -648,7 +648,7 @@ class BackgroundLoaderService:
task.progress["episodes"] = True task.progress["episodes"] = True
except Exception as e: 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 task.progress["episodes"] = False
async def _broadcast_status( async def _broadcast_status(

26
src/server/services/cache_service.py
View File

@@ -170,14 +170,17 @@ class InMemoryCacheBackend(CacheBackend):
"""Get value from cache.""" """Get value from cache."""
async with self._lock: async with self._lock:
if key not in self.cache: if key not in self.cache:
logger.debug("Cache miss for key: %s", key)
return None return None
item = self.cache[key] item = self.cache[key]
if self._is_expired(item): if self._is_expired(item):
logger.debug("Cache expired for key: %s", key)
del self.cache[key] del self.cache[key]
return None return None
logger.debug("Cache hit for key: %s", key)
return item["value"] return item["value"]
async def set( async def set(
@@ -196,6 +199,7 @@ class InMemoryCacheBackend(CacheBackend):
"expiry": expiry, "expiry": expiry,
"created": datetime.utcnow(), "created": datetime.utcnow(),
} }
logger.debug("Cached key: %s (ttl=%s)", key, ttl)
return True return True
async def delete(self, key: str) -> bool: async def delete(self, key: str) -> bool:
@@ -203,7 +207,9 @@ class InMemoryCacheBackend(CacheBackend):
async with self._lock: async with self._lock:
if key in self.cache: if key in self.cache:
del self.cache[key] del self.cache[key]
logger.debug("Deleted cache key: %s", key)
return True return True
logger.debug("Cache delete skipped; key not found: %s", key)
return False return False
async def exists(self, key: str) -> bool: async def exists(self, key: str) -> bool:
@@ -223,6 +229,7 @@ class InMemoryCacheBackend(CacheBackend):
"""Clear all cached values.""" """Clear all cached values."""
async with self._lock: async with self._lock:
self.cache.clear() self.cache.clear()
logger.debug("Cleared in-memory cache")
return True return True
async def get_many(self, keys: List[str]) -> Dict[str, Any]: async def get_many(self, keys: List[str]) -> Dict[str, Any]:
@@ -281,13 +288,14 @@ class RedisCacheBackend(CacheBackend):
import aioredis import aioredis
self._redis = await aioredis.create_redis_pool(self.redis_url) self._redis = await aioredis.create_redis_pool(self.redis_url)
logger.debug("Connected to Redis at %s", self.redis_url)
except ImportError: except ImportError:
logger.error( logger.error(
"aioredis not installed. Install with: pip install aioredis" "aioredis not installed. Install with: pip install aioredis"
) )
raise raise
except Exception as e: except Exception as e:
logger.error(f"Failed to connect to Redis: {e}") logger.error("Failed to connect to Redis: %s", e)
raise raise
return self._redis return self._redis
@@ -308,7 +316,7 @@ class RedisCacheBackend(CacheBackend):
return pickle.loads(data) return pickle.loads(data)
except Exception as e: except Exception as e:
logger.error(f"Redis get error: {e}") logger.error("Redis get error: %s", e)
return None return None
async def set( async def set(
@@ -327,7 +335,7 @@ class RedisCacheBackend(CacheBackend):
return True return True
except Exception as e: except Exception as e:
logger.error(f"Redis set error: {e}") logger.error("Redis set error: %s", e)
return False return False
async def delete(self, key: str) -> bool: async def delete(self, key: str) -> bool:
@@ -338,7 +346,7 @@ class RedisCacheBackend(CacheBackend):
return result > 0 return result > 0
except Exception as e: except Exception as e:
logger.error(f"Redis delete error: {e}") logger.error("Redis delete error: %s", e)
return False return False
async def exists(self, key: str) -> bool: async def exists(self, key: str) -> bool:
@@ -348,7 +356,7 @@ class RedisCacheBackend(CacheBackend):
return await redis.exists(self._make_key(key)) return await redis.exists(self._make_key(key))
except Exception as e: except Exception as e:
logger.error(f"Redis exists error: {e}") logger.error("Redis exists error: %s", e)
return False return False
async def clear(self) -> bool: async def clear(self) -> bool:
@@ -361,7 +369,7 @@ class RedisCacheBackend(CacheBackend):
return True return True
except Exception as e: except Exception as e:
logger.error(f"Redis clear error: {e}") logger.error("Redis clear error: %s", e)
return False return False
async def get_many(self, keys: List[str]) -> Dict[str, Any]: async def get_many(self, keys: List[str]) -> Dict[str, Any]:
@@ -379,7 +387,7 @@ class RedisCacheBackend(CacheBackend):
return result return result
except Exception as e: except Exception as e:
logger.error(f"Redis get_many error: {e}") logger.error("Redis get_many error: %s", e)
return {} return {}
async def set_many( async def set_many(
@@ -392,7 +400,7 @@ class RedisCacheBackend(CacheBackend):
return True return True
except Exception as e: except Exception as e:
logger.error(f"Redis set_many error: {e}") logger.error("Redis set_many error: %s", e)
return False return False
async def delete_pattern(self, pattern: str) -> int: async def delete_pattern(self, pattern: str) -> int:
@@ -409,7 +417,7 @@ class RedisCacheBackend(CacheBackend):
return 0 return 0
except Exception as e: except Exception as e:
logger.error(f"Redis delete_pattern error: {e}") logger.error("Redis delete_pattern error: %s", e)
return 0 return 0
async def close(self) -> None: async def close(self) -> None:

5
src/server/services/config_service.py
View File

@@ -8,6 +8,7 @@ This service handles:
""" """
import json import json
import logging
import shutil import shutil
from datetime import datetime from datetime import datetime
from pathlib import Path from pathlib import Path
@@ -15,6 +16,8 @@ from typing import Dict, List, Optional
from src.server.models.config import AppConfig, ConfigUpdate, ValidationResult from src.server.models.config import AppConfig, ConfigUpdate, ValidationResult
logger = logging.getLogger(__name__)
class ConfigServiceError(Exception): class ConfigServiceError(Exception):
"""Base exception for configuration service errors.""" """Base exception for configuration service errors."""
@@ -136,7 +139,7 @@ class ConfigService:
self.create_backup() self.create_backup()
except ConfigBackupError as e: except ConfigBackupError as e:
# Log but don't fail save operation # 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 # Save configuration with version
data = config.model_dump() data = config.model_dump()

2
src/server/services/initialization_service.py
View File

@@ -342,7 +342,7 @@ async def perform_nfo_scan_if_needed(progress_service=None):
if not settings.tmdb_api_key if not settings.tmdb_api_key
else "Skipped - NFO features disabled" else "Skipped - NFO features disabled"
) )
logger.info(f"NFO scan skipped: {message}") logger.info("NFO scan skipped: %s", message)
if progress_service: if progress_service:
await progress_service.complete_progress( await progress_service.complete_progress(

16
src/server/services/notification_service.py
View File

@@ -151,7 +151,7 @@ class EmailNotificationService:
start_tls=True, start_tls=True,
) )
logger.info(f"Email notification sent to {to_address}") logger.info("Email notification sent to %s", to_address)
return True return True
except ImportError: except ImportError:
@@ -160,7 +160,7 @@ class EmailNotificationService:
) )
return False return False
except Exception as e: except Exception as e:
logger.error(f"Failed to send email notification: {e}") logger.error("Failed to send email notification: %s", e)
return False return False
@@ -205,7 +205,7 @@ class WebhookNotificationService:
timeout=aiohttp.ClientTimeout(total=self.timeout), timeout=aiohttp.ClientTimeout(total=self.timeout),
) as response: ) as response:
if response.status < 400: if response.status < 400:
logger.info(f"Webhook notification sent to {url}") logger.info("Webhook notification sent to %s", url)
return True return True
else: else:
logger.warning( logger.warning(
@@ -213,9 +213,9 @@ class WebhookNotificationService:
) )
except asyncio.TimeoutError: 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: 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: if attempt < self.max_retries - 1:
await asyncio.sleep(2 ** attempt) # Exponential backoff await asyncio.sleep(2 ** attempt) # Exponential backoff
@@ -436,7 +436,7 @@ class NotificationService:
await self.in_app_service.add_notification(notification) await self.in_app_service.add_notification(notification)
results["in_app"] = True results["in_app"] = True
except Exception as e: 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 results["in_app"] = False
# Send email notification # Send email notification
@@ -452,7 +452,7 @@ class NotificationService:
) )
results["email"] = success results["email"] = success
except Exception as e: 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 results["email"] = False
# Send webhook notifications # Send webhook notifications
@@ -476,7 +476,7 @@ class NotificationService:
success = await self.webhook_service.send_webhook(str(url), payload) success = await self.webhook_service.send_webhook(str(url), payload)
webhook_results.append(success) webhook_results.append(success)
except Exception as e: 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) webhook_results.append(False)
results["webhook"] = all(webhook_results) if webhook_results else False results["webhook"] = all(webhook_results) if webhook_results else False

34
src/server/utils/log_manager.py
View File

@@ -82,7 +82,7 @@ class LogManager:
log_path = self.log_dir / log_file log_path = self.log_dir / log_file
if not log_path.exists(): 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 return False
stat = log_path.stat() stat = log_path.stat()
@@ -99,10 +99,10 @@ class LogManager:
# Compress the rotated file # Compress the rotated file
self._compress_log(rotated_path) 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 return True
except Exception as e: 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 return False
def _compress_log(self, log_path: Path) -> bool: def _compress_log(self, log_path: Path) -> bool:
@@ -122,10 +122,10 @@ class LogManager:
shutil.copyfileobj(f_in, f_out) shutil.copyfileobj(f_in, f_out)
log_path.unlink() log_path.unlink()
logger.debug(f"Compressed log file: {log_path.name}") logger.debug("Compressed log file: %s", log_path.name)
return True return True
except Exception as e: 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 return False
def archive_old_logs( def archive_old_logs(
@@ -160,10 +160,10 @@ class LogManager:
f"Failed to archive {log_file.filename}: {e}" 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 return archived_count
except Exception as e: except Exception as e:
logger.error(f"Failed to archive logs: {e}") logger.error("Failed to archive logs: %s", e)
return 0 return 0
def search_logs( def search_logs(
@@ -209,7 +209,7 @@ class LogManager:
) )
return results return results
except Exception as e: except Exception as e:
logger.error(f"Failed to search logs: {e}") logger.error("Failed to search logs: %s", e)
return {} return {}
def export_logs( def export_logs(
@@ -243,7 +243,7 @@ class LogManager:
arcname=log_file.filename, arcname=log_file.filename,
) )
logger.info(f"Exported logs to: {tar_path}") logger.info("Exported logs to: %s", tar_path)
return True return True
else: else:
# Concatenate all logs # Concatenate all logs
@@ -253,10 +253,10 @@ class LogManager:
with open(log_file.path, "r") as in_f: with open(log_file.path, "r") as in_f:
out_f.write(in_f.read()) out_f.write(in_f.read())
logger.info(f"Exported logs to: {output_path}") logger.info("Exported logs to: %s", output_path)
return True return True
except Exception as e: except Exception as e:
logger.error(f"Failed to export logs: {e}") logger.error("Failed to export logs: %s", e)
return False return False
def get_log_stats(self) -> Dict[str, Any]: def get_log_stats(self) -> Dict[str, Any]:
@@ -294,7 +294,7 @@ class LogManager:
"newest_file": log_files[0].filename, "newest_file": log_files[0].filename,
} }
except Exception as e: except Exception as e:
logger.error(f"Failed to get log stats: {e}") logger.error("Failed to get log stats: %s", e)
return {} return {}
def cleanup_logs( def cleanup_logs(
@@ -330,16 +330,16 @@ class LogManager:
log_file.path.unlink() log_file.path.unlink()
total_size -= log_file.size_bytes total_size -= log_file.size_bytes
deleted_count += 1 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: except Exception as e:
logger.warning( logger.warning(
f"Failed to delete {log_file.filename}: {e}" 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 return deleted_count
except Exception as e: except Exception as e:
logger.error(f"Failed to cleanup logs: {e}") logger.error("Failed to cleanup logs: %s", e)
return 0 return 0
def set_log_level(self, logger_name: str, level: str) -> bool: 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 = logging.getLogger(logger_name)
target_logger.setLevel(log_level) 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 return True
except Exception as e: except Exception as e:
logger.error(f"Failed to set log level: {e}") logger.error("Failed to set log level: %s", e)
return False return False

4
src/server/utils/logging.py
View File

@@ -416,9 +416,9 @@ def cleanup_old_logs(log_dir: Union[str, Path],
try: try:
if log_file.stat().st_mtime < cutoff_time: if log_file.stat().st_mtime < cutoff_time:
log_file.unlink() 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: 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 # Initialize default logging configuration

2
src/server/utils/metrics.py
View File

@@ -161,7 +161,7 @@ class MetricsCollector:
Duration in seconds. Duration in seconds.
""" """
if timer_name not in self._timers: 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 return 0.0
duration = time.time() - self._timers[timer_name] duration = time.time() - self._timers[timer_name]

34
src/server/utils/system.py
View File

@@ -60,7 +60,7 @@ class SystemUtilities:
path=path, path=path,
) )
except Exception as e: 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 return None
@staticmethod @staticmethod
@@ -93,7 +93,7 @@ class SystemUtilities:
return disk_infos return disk_infos
except Exception as e: 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 [] return []
@staticmethod @staticmethod
@@ -115,7 +115,7 @@ class SystemUtilities:
path = Path(directory) path = Path(directory)
if not path.exists(): if not path.exists():
logger.warning(f"Directory not found: {directory}") logger.warning("Directory not found: %s", directory)
return 0 return 0
deleted_count = 0 deleted_count = 0
@@ -130,16 +130,16 @@ class SystemUtilities:
try: try:
file_path.unlink() file_path.unlink()
deleted_count += 1 deleted_count += 1
logger.debug(f"Deleted file: {file_path}") logger.debug("Deleted file: %s", file_path)
except Exception as e: except Exception as e:
logger.warning( logger.warning(
f"Failed to delete {file_path}: {e}" 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 return deleted_count
except Exception as e: 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 return 0
@staticmethod @staticmethod
@@ -171,12 +171,12 @@ class SystemUtilities:
f"Deleted empty directory: {dir_path}" f"Deleted empty directory: {dir_path}"
) )
except Exception as e: 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 return deleted_count
except Exception as e: except Exception as e:
logger.error(f"Failed to cleanup empty directories: {e}") logger.error("Failed to cleanup empty directories: %s", e)
return 0 return 0
@staticmethod @staticmethod
@@ -201,7 +201,7 @@ class SystemUtilities:
return total_size return total_size
except Exception as e: 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 return 0
@staticmethod @staticmethod
@@ -232,7 +232,7 @@ class SystemUtilities:
), ),
) )
except Exception as e: 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 return None
@staticmethod @staticmethod
@@ -260,7 +260,7 @@ class SystemUtilities:
return processes return processes
except Exception as e: except Exception as e:
logger.error(f"Failed to get all processes: {e}") logger.error("Failed to get all processes: %s", e)
return [] return []
@staticmethod @staticmethod
@@ -285,7 +285,7 @@ class SystemUtilities:
"python_version": platform.python_version(), "python_version": platform.python_version(),
} }
except Exception as e: except Exception as e:
logger.error(f"Failed to get system info: {e}") logger.error("Failed to get system info: %s", e)
return {} return {}
@staticmethod @staticmethod
@@ -308,7 +308,7 @@ class SystemUtilities:
"dropped_out": net_io.dropout, "dropped_out": net_io.dropout,
} }
except Exception as e: except Exception as e:
logger.error(f"Failed to get network info: {e}") logger.error("Failed to get network info: %s", e)
return {} return {}
@staticmethod @staticmethod
@@ -330,7 +330,7 @@ class SystemUtilities:
dest_path = Path(dest) dest_path = Path(dest)
if not src_path.exists(): if not src_path.exists():
logger.error(f"Source file not found: {src}") logger.error("Source file not found: %s", src)
return False return False
# Create temporary file # Create temporary file
@@ -342,10 +342,10 @@ class SystemUtilities:
# Atomic rename # Atomic rename
temp_path.replace(dest_path) temp_path.replace(dest_path)
logger.debug(f"Atomically copied {src} to {dest}") logger.debug("Atomically copied %s to %s", src, dest)
return True return True
except Exception as e: 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 return False

7
tests/api/test_concurrent_anime_add.py
View File

@@ -4,12 +4,15 @@ This test verifies that the /api/anime/add endpoint can handle
multiple concurrent requests without blocking. multiple concurrent requests without blocking.
""" """
import asyncio import asyncio
import logging
import time import time
from unittest.mock import AsyncMock, MagicMock, patch from unittest.mock import AsyncMock, MagicMock, patch
import pytest import pytest
from httpx import ASGITransport, AsyncClient from httpx import ASGITransport, AsyncClient
logger = logging.getLogger(__name__)
from src.server.fastapi_app import app from src.server.fastapi_app import app
from src.server.services.auth_service import auth_service from src.server.services.auth_service import auth_service
from src.server.services.background_loader_service import get_background_loader_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" 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 @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] keys = [r.json().get("key") for r in responses]
assert keys[0] == keys[1], "Both responses should have the same key" 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)

10
tests/performance/test_nfo_batch_performance.py
View File

@@ -4,6 +4,7 @@ This module tests the performance characteristics of batch NFO creation
including concurrent operations, TMDB API request optimization, and memory usage. including concurrent operations, TMDB API request optimization, and memory usage.
""" """
import asyncio import asyncio
import logging
import time import time
from pathlib import Path from pathlib import Path
from typing import List 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.api.nfo import batch_create_nfo
from src.server.models.nfo import NFOBatchCreateRequest from src.server.models.nfo import NFOBatchCreateRequest
logger = logging.getLogger(__name__)
class TestConcurrentNFOCreation: class TestConcurrentNFOCreation:
"""Test performance of concurrent NFO creation operations.""" """Test performance of concurrent NFO creation operations."""
@@ -83,8 +86,11 @@ class TestConcurrentNFOCreation:
# Concurrent should take roughly (num_series / 5) * 0.1 = 0.2s # Concurrent should take roughly (num_series / 5) * 0.1 = 0.2s
assert elapsed_time < 1.0, "Concurrency not providing speedup" assert elapsed_time < 1.0, "Concurrency not providing speedup"
print(f"\nPerformance: {num_series} series in {elapsed_time:.2f}s") logger.info("Batch NFO creation completed", extra={"num_series": num_series, "elapsed_s": elapsed_time})
print(f"Rate: {num_series / elapsed_time:.2f} series/second") logger.debug(
"Batch NFO creation rate",
extra={"series_per_second": num_series / elapsed_time},
)
@pytest.mark.asyncio @pytest.mark.asyncio
async def test_concurrent_nfo_creation_50_series(self): async def test_concurrent_nfo_creation_50_series(self):

59
tests/performance/test_websocket_load.py
View File

@@ -4,6 +4,7 @@ This module tests the performance characteristics of WebSocket connections
including concurrent clients, message throughput, and progress update throttling. including concurrent clients, message throughput, and progress update throttling.
""" """
import asyncio import asyncio
import logging
import time import time
from typing import List from typing import List
from unittest.mock import AsyncMock, Mock from unittest.mock import AsyncMock, Mock
@@ -12,6 +13,8 @@ import pytest
from src.server.services.websocket_service import WebSocketService from src.server.services.websocket_service import WebSocketService
logger = logging.getLogger(__name__)
class MockWebSocket: class MockWebSocket:
"""Mock WebSocket client for testing.""" """Mock WebSocket client for testing."""
@@ -82,8 +85,14 @@ class TestWebSocketConcurrentClients:
for i in range(num_clients): for i in range(num_clients):
await websocket_service.disconnect(f"client_{i:03d}") await websocket_service.disconnect(f"client_{i:03d}")
print(f"\n100 clients: Broadcast in {elapsed_time:.2f}s") logger.info("Broadcast completed for %d clients", num_clients, extra={"elapsed_s": elapsed_time})
print(f"Average per client: {elapsed_time / num_clients * 1000:.2f}ms") logger.debug(
"Broadcast performance per client",
extra={
"num_clients": num_clients,
"avg_ms_per_client": elapsed_time / num_clients * 1000,
},
)
@pytest.mark.asyncio @pytest.mark.asyncio
async def test_200_concurrent_clients_scalability(self): async def test_200_concurrent_clients_scalability(self):
@@ -114,7 +123,7 @@ class TestWebSocketConcurrentClients:
for i in range(num_clients): for i in range(num_clients):
await websocket_service.disconnect(f"client_{i:03d}") 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 @pytest.mark.asyncio
async def test_connection_pool_efficiency(self): async def test_connection_pool_efficiency(self):
@@ -144,8 +153,8 @@ class TestWebSocketConcurrentClients:
for i in range(num_clients): for i in range(num_clients):
await websocket_service.disconnect(f"client_{i:02d}") await websocket_service.disconnect(f"client_{i:02d}")
print(f"\nConnected {num_clients} clients in {connection_time:.3f}s") logger.info("Connected %d clients in %.3fs", num_clients, connection_time)
print(f"Average: {connection_time / num_clients * 1000:.2f}ms per connection") logger.info("Average: %.2fms per connection", connection_time / num_clients * 1000)
class TestMessageThroughput: class TestMessageThroughput:
@@ -192,8 +201,13 @@ class TestMessageThroughput:
for i in range(num_clients): for i in range(num_clients):
await websocket_service.disconnect(f"client_{i}") await websocket_service.disconnect(f"client_{i}")
print(f"\nThroughput: {messages_per_second:.2f} messages/second") logger.info("Throughput: %.2f messages/second", messages_per_second)
print(f"Total: {num_messages} messages to {num_clients} clients in {elapsed_time:.2f}s") logger.info(
"Total: %d messages to %d clients in %.2fs",
num_messages,
num_clients,
elapsed_time,
)
@pytest.mark.asyncio @pytest.mark.asyncio
async def test_high_frequency_updates(self): async def test_high_frequency_updates(self):
@@ -234,7 +248,7 @@ class TestMessageThroughput:
for i in range(5): for i in range(5):
await websocket_service.disconnect(f"client_{i}") 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 @pytest.mark.asyncio
async def test_burst_message_handling(self): async def test_burst_message_handling(self):
@@ -275,7 +289,7 @@ class TestMessageThroughput:
for i in range(num_clients): for i in range(num_clients):
await websocket_service.disconnect(f"client_{i:02d}") 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: class TestProgressUpdateThrottling:
@@ -313,7 +327,10 @@ class TestProgressUpdateThrottling:
await websocket_service.disconnect("test_client") 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 @pytest.mark.asyncio
async def test_throttling_reduces_network_load(self): async def test_throttling_reduces_network_load(self):
@@ -356,7 +373,11 @@ class TestProgressUpdateThrottling:
for i in range(10): for i in range(10):
await websocket_service.disconnect(f"client_{i}") 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: class TestRoomIsolation:
@@ -402,7 +423,7 @@ class TestRoomIsolation:
for i in range(clients_per_room): for i in range(clients_per_room):
await websocket_service.disconnect(f"{room}_client_{i:02d}") 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 @pytest.mark.asyncio
async def test_selective_room_broadcast_performance(self): async def test_selective_room_broadcast_performance(self):
@@ -435,7 +456,7 @@ class TestRoomIsolation:
for i in range(clients_per_room): for i in range(clients_per_room):
await websocket_service.disconnect(f"{room}_{i:02d}") 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: class TestConnectionStability:
@@ -472,7 +493,7 @@ class TestConnectionStability:
# All connections should be cleaned up # All connections should be cleaned up
assert len(websocket_service.manager._active_connections) == 0 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 @pytest.mark.asyncio
async def test_concurrent_connect_disconnect(self): async def test_concurrent_connect_disconnect(self):
@@ -497,7 +518,7 @@ class TestConnectionStability:
# All should be cleaned up # All should be cleaned up
assert len(websocket_service.manager._active_connections) == 0 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: class TestMemoryEfficiency:
@@ -533,8 +554,8 @@ class TestMemoryEfficiency:
for i in range(100): for i in range(100):
await websocket_service.disconnect(f"mem_client_{i:03d}") await websocket_service.disconnect(f"mem_client_{i:03d}")
print(f"\nMemory: {memory_increase_mb:.2f}MB for 100 connections") logger.info("Memory: %.2fMB for 100 connections", memory_increase_mb)
print(f"Per connection: {per_connection_kb:.2f}KB") logger.info("Per connection: %.2fKB", per_connection_kb)
@pytest.mark.asyncio @pytest.mark.asyncio
async def test_message_queue_memory_efficiency(self): async def test_message_queue_memory_efficiency(self):
@@ -567,5 +588,5 @@ class TestMemoryEfficiency:
await websocket_service.disconnect("queue_test") await websocket_service.disconnect("queue_test")
print(f"\nMessage queue: {total_size} bytes for 100 messages") logger.info("Message queue: %d bytes for 100 messages", total_size)
print(f"Average: {total_size / 100:.2f} bytes/message") logger.info("Average: %.2f bytes/message", total_size / 100)

24
tests/unit/test_nfo_update_parsing.py
View File

@@ -1,6 +1,7 @@
"""Unit test for NFOService.update_tvshow_nfo() - tests XML parsing logic.""" """Unit test for NFOService.update_tvshow_nfo() - tests XML parsing logic."""
import asyncio import asyncio
import logging
import shutil import shutil
import tempfile import tempfile
from pathlib import Path from pathlib import Path
@@ -8,6 +9,8 @@ from pathlib import Path
import pytest import pytest
from lxml import etree from lxml import etree
logger = logging.getLogger(__name__)
from src.core.services.nfo_service import NFOService from src.core.services.nfo_service import NFOService
from src.core.services.tmdb_client import TMDBAPIError from src.core.services.tmdb_client import TMDBAPIError
@@ -51,7 +54,7 @@ def test_parse_nfo_with_uniqueid():
break break
assert tmdb_id == 1429, f"Expected TMDB ID 1429, got {tmdb_id}" 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: finally:
shutil.rmtree(temp_dir) shutil.rmtree(temp_dir)
@@ -92,7 +95,7 @@ def test_parse_nfo_with_tmdbid_element():
tmdb_id = int(tmdbid_elem.text) tmdb_id = int(tmdbid_elem.text)
assert tmdb_id == 12345, f"Expected TMDB ID 12345, got {tmdb_id}" 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: finally:
shutil.rmtree(temp_dir) shutil.rmtree(temp_dir)
@@ -131,7 +134,7 @@ def test_parse_nfo_without_tmdb_id():
tmdb_id = int(tmdbid_elem.text) tmdb_id = int(tmdbid_elem.text)
assert tmdb_id is None, "Should not have found TMDB ID" 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: finally:
shutil.rmtree(temp_dir) shutil.rmtree(temp_dir)
@@ -157,22 +160,23 @@ def test_parse_invalid_xml():
tree = etree.parse(str(nfo_path)) tree = etree.parse(str(nfo_path))
assert False, "Should have raised XMLSyntaxError" assert False, "Should have raised XMLSyntaxError"
except etree.XMLSyntaxError: except etree.XMLSyntaxError:
print("✓ Correctly raised XMLSyntaxError for invalid XML") logger.info("Correctly raised XMLSyntaxError for invalid XML")
finally: finally:
shutil.rmtree(temp_dir) shutil.rmtree(temp_dir)
if __name__ == "__main__": if __name__ == "__main__":
print("Testing NFO XML parsing logic...") logging.basicConfig(level=logging.INFO, format="%(message)s")
print() logger.info("Testing NFO XML parsing logic...")
logger.info("")
test_parse_nfo_with_uniqueid() test_parse_nfo_with_uniqueid()
test_parse_nfo_with_tmdbid_element() test_parse_nfo_with_tmdbid_element()
test_parse_nfo_without_tmdb_id() test_parse_nfo_without_tmdb_id()
test_parse_invalid_xml() test_parse_invalid_xml()
print() logger.info("")
print("=" * 60) logger.info("%s", "=" * 60)
print("✓ ALL TESTS PASSED") logger.info("ALL TESTS PASSED")
print("=" * 60) logger.info("%s", "=" * 60)

9
tests/unit/test_parallel_anime_add.py
View File

@@ -5,11 +5,14 @@ each other. The background loader should process multiple series simultaneously
rather than sequentially. rather than sequentially.
""" """
import asyncio import asyncio
import logging
from datetime import datetime, timezone from datetime import datetime, timezone
from unittest.mock import AsyncMock, MagicMock, patch from unittest.mock import AsyncMock, MagicMock, patch
import pytest import pytest
logger = logging.getLogger(__name__)
from src.server.services.background_loader_service import ( from src.server.services.background_loader_service import (
BackgroundLoaderService, BackgroundLoaderService,
LoadingStatus, LoadingStatus,
@@ -162,9 +165,9 @@ async def test_parallel_anime_additions(
f"(indicating sequential processing)" f"(indicating sequential processing)"
) )
print(f"✓ Parallel execution verified:") logger.info("Parallel execution verified")
print(f" - Start time difference: {start_diff:.3f}s") logger.info("Start time difference: %.3fs", start_diff)
print(f" - Total duration: {total_duration:.3f}s") logger.info("Total duration: %.3fs", total_duration)
@pytest.mark.asyncio @pytest.mark.asyncio