From a69a26852e62763ec306bba38a561669ff0258ee Mon Sep 17 00:00:00 2001 From: Harvey <64276030+HabiRabbu@users.noreply.github.com> Date: Tue, 14 Apr 2026 00:02:38 +0100 Subject: [PATCH] Cut down unnecessary logging (#48) * Cut down unnecessary logging * fix format etc * fix checks * fix tests --- backend/api/v1/routes/albums.py | 3 - backend/api/v1/routes/artists.py | 1 - backend/api/v1/routes/cache.py | 3 - backend/api/v1/routes/cache_status.py | 3 - backend/api/v1/routes/covers.py | 2 - backend/api/v1/routes/discover.py | 4 - backend/api/v1/routes/home.py | 3 - backend/api/v1/routes/lastfm.py | 9 - backend/api/v1/routes/playlists.py | 3 - backend/api/v1/routes/queue.py | 3 - backend/api/v1/routes/requests.py | 3 - backend/api/v1/routes/search.py | 10 +- backend/api/v1/routes/settings.py | 13 -- backend/api/v1/routes/status.py | 3 - backend/api/v1/routes/youtube.py | 4 - backend/core/config.py | 7 +- backend/core/dependencies/cache_providers.py | 8 +- backend/core/dependencies/cleanup.py | 6 +- .../core/dependencies/service_providers.py | 10 - backend/core/exception_handlers.py | 1 - backend/core/tasks.py | 73 +----- backend/infrastructure/cache/disk_cache.py | 7 +- backend/infrastructure/cache/memory_cache.py | 11 - backend/infrastructure/degradation.py | 10 - backend/infrastructure/http/client.py | 3 - backend/infrastructure/http/deduplication.py | 3 - backend/infrastructure/http/disconnect.py | 4 - backend/infrastructure/logging_helper.py | 43 ---- .../infrastructure/persistence/_database.py | 3 - .../infrastructure/persistence/genre_index.py | 5 +- .../infrastructure/persistence/library_db.py | 4 +- .../persistence/sync_state_store.py | 3 - .../persistence/youtube_store.py | 5 +- .../infrastructure/queue/priority_queue.py | 5 - backend/infrastructure/queue/queue_store.py | 3 - backend/infrastructure/queue/request_queue.py | 25 +- backend/infrastructure/resilience/retry.py | 66 +----- backend/main.py | 7 +- backend/repositories/audiodb_repository.py | 23 -- backend/repositories/coverart_album.py | 18 +- backend/repositories/coverart_artist.py | 26 --- backend/repositories/coverart_disk_cache.py | 40 +--- backend/repositories/coverart_repository.py | 31 +-- backend/repositories/jellyfin_repository.py | 14 +- backend/repositories/lastfm_repository.py | 8 - backend/repositories/lidarr/album.py | 50 +--- backend/repositories/lidarr/artist.py | 26 +-- backend/repositories/lidarr/base.py | 16 +- backend/repositories/lidarr/config.py | 3 - backend/repositories/lidarr/history.py | 19 +- backend/repositories/lidarr/library.py | 20 +- .../repositories/listenbrainz_repository.py | 25 -- backend/repositories/musicbrainz_album.py | 4 - backend/repositories/musicbrainz_artist.py | 2 +- backend/repositories/musicbrainz_base.py | 3 - backend/repositories/navidrome_models.py | 3 - backend/repositories/navidrome_repository.py | 3 - backend/repositories/playlist_repository.py | 7 +- backend/repositories/youtube.py | 8 +- backend/services/album_service.py | 26 +-- backend/services/artist_discovery_service.py | 16 -- backend/services/artist_service.py | 13 -- backend/services/audiodb_browse_queue.py | 11 +- backend/services/audiodb_image_service.py | 42 ---- backend/services/cache_service.py | 13 -- backend/services/cache_status_service.py | 6 - backend/services/discover/homepage_service.py | 36 +-- backend/services/discover/queue_service.py | 15 -- backend/services/discover_queue_manager.py | 16 -- .../services/genre_cover_prewarm_service.py | 2 - backend/services/home/facade.py | 1 - backend/services/home/genre_service.py | 11 +- backend/services/lastfm_auth_service.py | 3 - backend/services/library_service.py | 19 +- backend/services/local_files_service.py | 7 +- backend/services/navidrome_library_service.py | 24 -- backend/services/playlist_service.py | 8 - backend/services/precache/album_phase.py | 6 - backend/services/precache/artist_phase.py | 9 - backend/services/precache/audiodb_phase.py | 23 -- backend/services/precache/orchestrator.py | 26 +-- backend/services/preferences_service.py | 17 -- backend/services/requests_page_service.py | 4 - backend/services/scrobble_service.py | 23 -- backend/services/status_service.py | 3 - backend/services/youtube_service.py | 7 +- backend/tests/routes/test_search_routes.py | 25 -- .../services/test_source_playlist_import.py | 3 +- backend/tests/test_phase9_observability.py | 216 +----------------- .../lib/components/DiscoverQueueModal.svelte | 14 +- .../lib/components/YouTubeDetailModal.svelte | 3 +- frontend/src/lib/player/NativeAudioSource.ts | 1 - .../lib/player/jellyfinPlaybackApi.spec.ts | 17 +- .../src/lib/player/jellyfinPlaybackApi.ts | 8 +- .../src/lib/player/navidromePlaybackApi.ts | 22 +- .../lib/queries/IndexedDbPersister.svelte.ts | 5 - frontend/src/lib/stores/imageSettings.ts | 4 +- frontend/src/lib/stores/library.ts | 3 +- frontend/src/lib/stores/preferences.ts | 7 +- frontend/src/lib/utils/localStorageCache.ts | 9 +- frontend/src/routes/+layout.ts | 4 +- .../src/routes/library/albums/+page.svelte | 9 +- .../src/routes/library/artists/+page.svelte | 5 +- 103 files changed, 127 insertions(+), 1343 deletions(-) diff --git a/backend/api/v1/routes/albums.py b/backend/api/v1/routes/albums.py index 9cc7b54..411f5ef 100644 --- a/backend/api/v1/routes/albums.py +++ b/backend/api/v1/routes/albums.py @@ -1,4 +1,3 @@ -import logging from typing import Optional from fastapi import APIRouter, BackgroundTasks, Depends, HTTPException, Query, Request, status @@ -16,8 +15,6 @@ from infrastructure.msgspec_fastapi import MsgSpecRoute import msgspec.structs -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/albums", tags=["album"]) diff --git a/backend/api/v1/routes/artists.py b/backend/api/v1/routes/artists.py index 0ff48eb..3d4d9b2 100644 --- a/backend/api/v1/routes/artists.py +++ b/backend/api/v1/routes/artists.py @@ -167,7 +167,6 @@ async def get_artist_monitoring_status( try: return await artist_service.get_artist_monitoring_status(artist_id) except Exception: # noqa: BLE001 - logger.debug("Failed to fetch monitoring status for %s", artist_id, exc_info=True) return ArtistMonitoringStatus(in_lidarr=False, monitored=False, auto_download=False) diff --git a/backend/api/v1/routes/cache.py b/backend/api/v1/routes/cache.py index 2e318c3..b351b6b 100644 --- a/backend/api/v1/routes/cache.py +++ b/backend/api/v1/routes/cache.py @@ -1,4 +1,3 @@ -import logging from fastapi import APIRouter, Depends, HTTPException from api.v1.schemas.cache import CacheStats, CacheClearResponse @@ -6,8 +5,6 @@ from core.dependencies import get_cache_service from infrastructure.msgspec_fastapi import MsgSpecRoute from services.cache_service import CacheService -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/cache", tags=["cache"]) diff --git a/backend/api/v1/routes/cache_status.py b/backend/api/v1/routes/cache_status.py index 5855983..a385009 100644 --- a/backend/api/v1/routes/cache_status.py +++ b/backend/api/v1/routes/cache_status.py @@ -1,5 +1,4 @@ import asyncio -import logging from fastapi import APIRouter, Depends from fastapi.responses import StreamingResponse import msgspec @@ -9,8 +8,6 @@ from core.dependencies import get_cache_status_service from infrastructure.msgspec_fastapi import MsgSpecRoute from services.cache_status_service import CacheStatusService -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/cache/sync", tags=["cache"]) diff --git a/backend/api/v1/routes/covers.py b/backend/api/v1/routes/covers.py index 2084621..2f14c3f 100644 --- a/backend/api/v1/routes/covers.py +++ b/backend/api/v1/routes/covers.py @@ -1,4 +1,3 @@ -import logging import hashlib from typing import Optional from fastapi import APIRouter, HTTPException, Path, Query, Depends, Request @@ -8,7 +7,6 @@ from infrastructure.msgspec_fastapi import MsgSpecRoute from repositories.coverart_repository import CoverArtRepository router = APIRouter(route_class=MsgSpecRoute, prefix="/covers", tags=["covers"]) -log = logging.getLogger(__name__) _ALLOWED_SIZES = {"250", "500", "1200"} _SIZE_ALIAS_NONE = {"", "original", "full", "max", "largest"} diff --git a/backend/api/v1/routes/discover.py b/backend/api/v1/routes/discover.py index f6f7378..8e97dd0 100644 --- a/backend/api/v1/routes/discover.py +++ b/backend/api/v1/routes/discover.py @@ -1,4 +1,3 @@ -import logging from typing import Literal from fastapi import APIRouter, Depends, HTTPException, Query, Response from api.v1.schemas.discover import ( @@ -28,8 +27,6 @@ from repositories.youtube import YouTubeRepository from services.discover_service import DiscoverService from services.discover_queue_manager import DiscoverQueueManager -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/discover", tags=["discover"]) @@ -63,7 +60,6 @@ async def get_discover_queue( resolved = source or discover_service.resolve_source(None) cached = await queue_manager.consume_queue(resolved) if cached: - logger.info("Serving pre-built discover queue (source=%s, items=%d)", resolved, len(cached.items)) return cached effective_count = min(count, 20) if count is not None else None return await queue_manager.build_hydrated_queue(resolved, effective_count) diff --git a/backend/api/v1/routes/home.py b/backend/api/v1/routes/home.py index 22a7d26..540ec4e 100644 --- a/backend/api/v1/routes/home.py +++ b/backend/api/v1/routes/home.py @@ -1,4 +1,3 @@ -import logging from typing import Literal from fastapi import APIRouter, Depends, Query, HTTPException from api.v1.schemas.home import ( @@ -20,8 +19,6 @@ import msgspec.structs from services.home_service import HomeService from services.home_charts_service import HomeChartsService -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/home", tags=["home"]) diff --git a/backend/api/v1/routes/lastfm.py b/backend/api/v1/routes/lastfm.py index be3a516..ab88986 100644 --- a/backend/api/v1/routes/lastfm.py +++ b/backend/api/v1/routes/lastfm.py @@ -39,10 +39,6 @@ async def request_auth_token( ) token, auth_url = await auth_service.request_token(settings.api_key) - logger.info( - "Last.fm auth token requested", - extra={"step": "token_requested", "status": "success"}, - ) return LastFmAuthTokenResponse(token=token, auth_url=auth_url) except HTTPException: raise @@ -83,11 +79,6 @@ async def exchange_auth_session( get_lastfm_repository.cache_clear() get_lastfm_auth_service.cache_clear() clear_lastfm_dependent_caches() - logger.info( - "Last.fm session exchanged for user %s", - username, - extra={"step": "session_exchanged", "status": "success"}, - ) return LastFmAuthSessionResponse( username=username, diff --git a/backend/api/v1/routes/playlists.py b/backend/api/v1/routes/playlists.py index 4fc7f17..c16fe1d 100644 --- a/backend/api/v1/routes/playlists.py +++ b/backend/api/v1/routes/playlists.py @@ -1,4 +1,3 @@ -import logging from fastapi import APIRouter, File, UploadFile from fastapi.responses import FileResponse @@ -25,8 +24,6 @@ from core.dependencies import JellyfinLibraryServiceDep, LocalFilesServiceDep, N from core.exceptions import PlaylistNotFoundError from infrastructure.msgspec_fastapi import MsgSpecBody, MsgSpecRoute -logger = logging.getLogger(__name__) - router = APIRouter( route_class=MsgSpecRoute, prefix="/playlists", diff --git a/backend/api/v1/routes/queue.py b/backend/api/v1/routes/queue.py index 924a8a3..d9db1d3 100644 --- a/backend/api/v1/routes/queue.py +++ b/backend/api/v1/routes/queue.py @@ -1,12 +1,9 @@ -import logging from fastapi import APIRouter, Depends, HTTPException from api.v1.schemas.request import QueueItem from core.dependencies import get_lidarr_repository from infrastructure.msgspec_fastapi import MsgSpecRoute from repositories.lidarr import LidarrRepository -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/queue", tags=["queue"]) diff --git a/backend/api/v1/routes/requests.py b/backend/api/v1/routes/requests.py index 163c315..8e2c357 100644 --- a/backend/api/v1/routes/requests.py +++ b/backend/api/v1/routes/requests.py @@ -1,12 +1,9 @@ -import logging from fastapi import APIRouter, Depends from api.v1.schemas.request import AlbumRequest, RequestAcceptedResponse, QueueStatusResponse from core.dependencies import get_request_service from infrastructure.msgspec_fastapi import MsgSpecBody, MsgSpecRoute from services.request_service import RequestService -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/requests", tags=["requests"]) diff --git a/backend/api/v1/routes/search.py b/backend/api/v1/routes/search.py index 2eda16c..4e2558c 100644 --- a/backend/api/v1/routes/search.py +++ b/backend/api/v1/routes/search.py @@ -1,5 +1,3 @@ -import logging -import time from fastapi import APIRouter, Query, Path, BackgroundTasks, Depends, Request from core.exceptions import ClientDisconnectedError from api.v1.schemas.search import ( @@ -18,8 +16,6 @@ from services.search_service import SearchService from services.search_enrichment_service import SearchEnrichmentService from repositories.coverart_repository import CoverArtRepository -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/search", tags=["search"]) @@ -79,11 +75,7 @@ async def suggest( stripped = q.strip() if len(stripped) < 2: return SuggestResponse() - start = time.monotonic() - result = await search_service.suggest(query=stripped, limit=limit) - elapsed_ms = (time.monotonic() - start) * 1000 - logger.debug("Suggest query_len=%d results=%d time_ms=%.1f", len(stripped), len(result.results), elapsed_ms) - return result + return await search_service.suggest(query=stripped, limit=limit) @router.get("/{bucket}", response_model=SearchBucketResponse) diff --git a/backend/api/v1/routes/settings.py b/backend/api/v1/routes/settings.py index e0b4fbb..692b7d2 100644 --- a/backend/api/v1/routes/settings.py +++ b/backend/api/v1/routes/settings.py @@ -60,7 +60,6 @@ async def update_preferences( try: preferences_service.save_preferences(preferences) total_cleared = await settings_service.clear_caches_for_preference_change() - logger.info(f"Updated user preferences. Cleared {total_cleared} cache entries.") return preferences except ConfigurationError as e: logger.warning(f"Configuration error updating preferences: {e}") @@ -81,7 +80,6 @@ async def update_lidarr_settings( ): try: preferences_service.save_lidarr_settings(lidarr_settings) - logger.info(f"Updated Lidarr settings: sync_frequency={lidarr_settings.sync_frequency}") return lidarr_settings except ConfigurationError as e: logger.warning(f"Configuration error updating Lidarr settings: {e}") @@ -132,7 +130,6 @@ async def update_advanced_settings( ) preferences_service.save_advanced_settings(backend_settings) await settings_service.on_coverart_settings_changed() - logger.info("Updated advanced settings") saved = preferences_service.get_advanced_settings() return AdvancedSettingsFrontend.from_backend(saved) except ConfigurationError as e: @@ -162,7 +159,6 @@ async def update_lidarr_connection( preferences_service.save_lidarr_connection(settings) reset_lidarr_circuit_breaker() await settings_service.on_lidarr_settings_changed() - logger.info("Updated Lidarr connection settings") return settings except ConfigurationError as e: logger.warning(f"Configuration error updating Lidarr connection: {e}") @@ -242,7 +238,6 @@ async def update_jellyfin_settings( try: preferences_service.save_jellyfin_connection(settings) await settings_service.on_jellyfin_settings_changed() - logger.info("Updated Jellyfin connection settings") return settings except ConfigurationError as e: logger.warning(f"Configuration error updating Jellyfin settings: {e}") @@ -275,7 +270,6 @@ async def update_navidrome_settings( try: preferences_service.save_navidrome_connection(settings) await settings_service.on_navidrome_settings_changed(enabled=settings.enabled) - logger.info("Updated Navidrome connection settings") return preferences_service.get_navidrome_connection() except ConfigurationError as e: logger.warning("Configuration error updating Navidrome settings: %s", e) @@ -354,7 +348,6 @@ async def update_listenbrainz_settings( try: preferences_service.save_listenbrainz_connection(settings) await settings_service.on_listenbrainz_settings_changed() - logger.info("Updated ListenBrainz connection settings") return settings except ConfigurationError as e: logger.warning(f"Configuration error updating ListenBrainz settings: {e}") @@ -386,7 +379,6 @@ async def update_youtube_settings( try: preferences_service.save_youtube_connection(settings) await settings_service.on_youtube_settings_changed() - logger.info("Updated YouTube connection settings") return settings except ConfigurationError as e: logger.warning(f"Configuration error updating YouTube settings: {e}") @@ -418,7 +410,6 @@ async def update_home_settings( try: preferences_service.save_home_settings(settings) await settings_service.clear_home_cache() - logger.info("Updated home settings") return settings except ConfigurationError as e: logger.warning(f"Configuration error updating home settings: {e}") @@ -441,7 +432,6 @@ async def update_local_files_settings( try: preferences_service.save_local_files_connection(settings) await settings_service.on_local_files_settings_changed() - logger.info("Updated local files settings") return settings except ConfigurationError as e: logger.warning("Configuration error updating local files settings: %s", e) @@ -473,7 +463,6 @@ async def update_lastfm_settings( try: preferences_service.save_lastfm_connection(settings) await settings_service.on_lastfm_settings_changed() - logger.info("Updated Last.fm connection settings") saved = preferences_service.get_lastfm_connection() return LastFmConnectionSettingsResponse.from_settings(saved) except ConfigurationError as e: @@ -504,7 +493,6 @@ async def update_scrobble_settings( ): try: preferences_service.save_scrobble_settings(settings) - logger.info("Updated scrobble settings") return preferences_service.get_scrobble_settings() except ConfigurationError as e: logger.warning("Configuration error updating scrobble settings: %s", e) @@ -528,7 +516,6 @@ async def update_primary_music_source( preferences_service.save_primary_music_source(settings) await settings_service.clear_home_cache() await settings_service.clear_source_resolution_cache() - logger.info("Updated primary music source to %s", settings.source) return preferences_service.get_primary_music_source() except ConfigurationError as e: logger.warning("Configuration error updating primary music source: %s", e) diff --git a/backend/api/v1/routes/status.py b/backend/api/v1/routes/status.py index c225ef0..ded6bd5 100644 --- a/backend/api/v1/routes/status.py +++ b/backend/api/v1/routes/status.py @@ -1,12 +1,9 @@ -import logging from fastapi import APIRouter, Depends from api.v1.schemas.common import StatusReport from core.dependencies import get_status_service from infrastructure.msgspec_fastapi import MsgSpecRoute from services.status_service import StatusService -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/status", tags=["status"]) diff --git a/backend/api/v1/routes/youtube.py b/backend/api/v1/routes/youtube.py index b1159a8..f58b7c1 100644 --- a/backend/api/v1/routes/youtube.py +++ b/backend/api/v1/routes/youtube.py @@ -1,5 +1,3 @@ -import logging - from fastapi import APIRouter, Response from api.v1.schemas.discover import YouTubeQuotaResponse @@ -18,8 +16,6 @@ from api.v1.schemas.youtube import ( from core.dependencies import YouTubeServiceDep from infrastructure.msgspec_fastapi import MsgSpecBody, MsgSpecRoute -logger = logging.getLogger(__name__) - router = APIRouter(route_class=MsgSpecRoute, prefix="/youtube", tags=["YouTube"]) diff --git a/backend/core/config.py b/backend/core/config.py index 53ccfd4..f6ed35e 100644 --- a/backend/core/config.py +++ b/backend/core/config.py @@ -138,7 +138,7 @@ class Settings(BaseSettings): validated_values: dict[str, object] = {} for key, value in config_data.items(): if key not in model_fields: - logger.warning("Unknown config key '%s' — ignoring", key) + logger.warning("Unknown config key '%s', ignoring", key) continue try: field_info = model_fields[key] @@ -173,11 +173,10 @@ class Settings(BaseSettings): # Dry-run cross-field validation on merged candidate state self._validate_merged(validated_values) - # All validation passed — apply atomically + # All validation passed; apply atomically. for key, value in validated_values.items(): setattr(self, key, value) - logger.info(f"Loaded configuration from {self.config_file_path}") except (ConfigurationError, ValueError): raise except msgspec.DecodeError as e: @@ -225,7 +224,6 @@ class Settings(BaseSettings): }, } atomic_write_json(self.config_file_path, config_data) - logger.info(f"Created default config at {self.config_file_path}") def save_to_file(self) -> None: try: @@ -252,7 +250,6 @@ class Settings(BaseSettings): atomic_write_json(self.config_file_path, config_data) - logger.info(f"Saved config to {self.config_file_path}") except Exception as e: logger.error(f"Failed to save config: {e}") raise diff --git a/backend/core/dependencies/cache_providers.py b/backend/core/dependencies/cache_providers.py index c47838f..6449a53 100644 --- a/backend/core/dependencies/cache_providers.py +++ b/backend/core/dependencies/cache_providers.py @@ -1,8 +1,7 @@ -"""Tier 2 — Cache layer, persistence stores, and foundation providers.""" +"""Tier 2 - Cache layer, persistence stores, and foundation providers.""" from __future__ import annotations -import logging import threading from core.config import get_settings @@ -18,15 +17,11 @@ from infrastructure.persistence import ( from ._registry import singleton -logger = logging.getLogger(__name__) - - @singleton def get_cache() -> CacheInterface: preferences_service = get_preferences_service() advanced = preferences_service.get_advanced_settings() max_entries = advanced.memory_cache_max_entries - logger.info(f"Initialized RAM cache with max {max_entries} entries") return InMemoryCache(max_entries=max_entries) @@ -36,7 +31,6 @@ def get_disk_cache() -> DiskMetadataCache: preferences_service = get_preferences_service() advanced = preferences_service.get_advanced_settings() cache_dir = settings.cache_dir / "metadata" - logger.info(f"Initialized disk metadata cache at {cache_dir}") return DiskMetadataCache( base_path=cache_dir, recent_metadata_max_size_mb=advanced.recent_metadata_max_size_mb, diff --git a/backend/core/dependencies/cleanup.py b/backend/core/dependencies/cleanup.py index 915a9dc..6c955e9 100644 --- a/backend/core/dependencies/cleanup.py +++ b/backend/core/dependencies/cleanup.py @@ -54,7 +54,7 @@ def clear_listenbrainz_dependent_caches() -> None: async def init_app_state(app) -> None: - logger.info("Application state initialized") + pass async def cleanup_app_state() -> None: @@ -74,7 +74,5 @@ async def cleanup_app_state() -> None: except (AttributeError, RuntimeError, OSError) as exc: logger.error("Failed to shut down genre prewarm service during cleanup: %s", exc) - # Automatic cleanup via registry — no manual list needed + # Automatic cleanup via registry; no manual list needed. clear_all_singletons() - - logger.info("Application state cleaned up") diff --git a/backend/core/dependencies/service_providers.py b/backend/core/dependencies/service_providers.py index ff8302a..03579cf 100644 --- a/backend/core/dependencies/service_providers.py +++ b/backend/core/dependencies/service_providers.py @@ -124,7 +124,6 @@ def make_on_queue_import(memory_cache, disk_cache, library_db): }) except Exception as ex: # noqa: BLE001 logger.warning("Queue import: failed to upsert album %s: %s", record.musicbrainz_id[:8], ex) - logger.info("Queue import: invalidated caches for album=%s", record.musicbrainz_id[:8]) return on_queue_import @@ -143,8 +142,6 @@ def make_processor(lidarr_repo, memory_cache, disk_cache, cover_repo, request_hi is_monitored = bool(result.get("monitored")) if is_monitored: - logger.info(f"Album {album_mbid[:8]}... successfully monitored - promoting cache entries to persistent") - try: await disk_cache.promote_album_to_persistent(album_mbid) await cover_repo.promote_cover_to_persistent(album_mbid, identifier_type="album") @@ -156,7 +153,6 @@ def make_processor(lidarr_repo, memory_cache, disk_cache, cover_repo, request_hi await disk_cache.promote_artist_to_persistent(artist_mbid) await cover_repo.promote_cover_to_persistent(artist_mbid, identifier_type="artist") - logger.info(f"Cache promotion complete for album {album_mbid[:8]}...") except Exception as e: # noqa: BLE001 logger.error(f"Failed to promote cache entries for album {album_mbid[:8]}...: {e}") else: @@ -173,7 +169,6 @@ def make_processor(lidarr_repo, memory_cache, disk_cache, cover_repo, request_hi ) await memory_cache.delete(f"{ARTIST_INFO_PREFIX}{record.artist_mbid}") await disk_cache.delete_artist(record.artist_mbid) - logger.info("Applied deferred artist monitoring for %s", record.artist_mbid[:8]) break except Exception: # noqa: BLE001 if attempt == 0: @@ -284,11 +279,6 @@ def get_requests_page_service() -> "RequestsPageService": }) except Exception as ex: # noqa: BLE001 logger.warning("Failed to upsert album into library cache: %s", ex) - logger.info( - "Invalidated caches after import: album=%s artist=%s", - record.musicbrainz_id[:8], - (record.artist_mbid or "?")[:8], - ) request_queue = get_request_queue() library_service = get_library_service() diff --git a/backend/core/exception_handlers.py b/backend/core/exception_handlers.py index 8bcd475..9af29d4 100644 --- a/backend/core/exception_handlers.py +++ b/backend/core/exception_handlers.py @@ -97,5 +97,4 @@ async def request_validation_error_handler(request: Request, exc: RequestValidat async def client_disconnected_handler(request: Request, exc: ClientDisconnectedError) -> Response: - logger.debug("Client disconnected: %s %s", request.method, request.url.path) return Response(status_code=status.HTTP_204_NO_CONTENT) diff --git a/backend/core/tasks.py b/backend/core/tasks.py index e83aaec..a9c1c77 100644 --- a/backend/core/tasks.py +++ b/backend/core/tasks.py @@ -53,17 +53,13 @@ async def cleanup_disk_cache_periodically( while True: try: await asyncio.sleep(interval) - logger.debug("Running disk cache cleanup...") await disk_cache.cleanup_expired_recent() await disk_cache.enforce_recent_size_limits() await disk_cache.cleanup_expired_covers() await disk_cache.enforce_cover_size_limits() if cover_disk_cache: await cover_disk_cache.enforce_size_limit(force=True) - expired = await asyncio.to_thread(cover_disk_cache.cleanup_expired) - if expired: - logger.info("Cover expiry sweep removed %d expired covers", expired) - logger.debug("Disk cache cleanup complete") + await asyncio.to_thread(cover_disk_cache.cleanup_expired) except asyncio.CancelledError: break except Exception as e: @@ -114,17 +110,14 @@ async def sync_library_periodically( await asyncio.sleep(interval) - logger.info(f"Auto-syncing library (frequency: {sync_freq})") sync_success = False should_update_status = True try: result = await library_service.sync_library() if result.status == "skipped": - logger.info("Auto-sync skipped - sync already in progress") should_update_status = False continue sync_success = True - logger.info("Auto-sync completed successfully") except Exception as e: logger.error("Auto-sync library call failed: %s", e, exc_info=True) @@ -140,7 +133,6 @@ async def sync_library_periodically( preferences_service.save_lidarr_settings(updated_settings) except asyncio.CancelledError: - logger.info("Library sync task cancelled") break except Exception as e: logger.error("Library sync task failed: %s", e, exc_info=True) @@ -162,21 +154,16 @@ async def warm_library_cache( library_db: 'LibraryDB' ) -> None: try: - logger.info("Warming cache with recently-added library albums...") - await asyncio.sleep(5) albums_data = await library_db.get_albums() if not albums_data: - logger.info("No library albums to warm cache with") return max_warm = 30 albums_to_warm = albums_data[:max_warm] - logger.info(f"Warming cache with {len(albums_to_warm)} of {len(albums_data)} library albums (first {max_warm})") - warmed = 0 for i, album_data in enumerate(albums_to_warm): mbid = album_data.get('mbid') @@ -199,8 +186,6 @@ async def warm_library_cache( ) continue - logger.info(f"Cache warming complete: {warmed} albums fetched, {len(albums_to_warm) - warmed} already cached") - except Exception as e: logger.error("Library cache warming failed: %s", e, exc_info=True) @@ -215,9 +200,7 @@ async def warm_home_cache_periodically( try: for src in ("listenbrainz", "lastfm"): try: - logger.debug("Warming home page cache (source=%s)...", src) await home_service.get_home_data(source=src) - logger.debug("Home cache warming complete (source=%s)", src) except Exception as e: logger.error( "Home cache warming failed (source=%s): %s", @@ -226,7 +209,6 @@ async def warm_home_cache_periodically( exc_info=True, ) except asyncio.CancelledError: - logger.info("Home cache warming task cancelled") break await asyncio.sleep(interval) @@ -255,16 +237,13 @@ async def warm_genre_cache_periodically( try: cached_home = await home_service.get_cached_home_data(source=src) if not cached_home or not cached_home.genre_list or not cached_home.genre_list.items: - logger.debug("No cached home data for genre warming (source=%s), skipping", src) continue genre_names = [ g.name for g in cached_home.genre_list.items[:20] if isinstance(g, HomeGenre) ] if genre_names: - logger.debug("Warming genre cache (source=%s, %d genres)...", src, len(genre_names)) await home_service._genre.build_and_cache_genre_section(src, genre_names) - logger.debug("Genre cache warming complete (source=%s)", src) warmed += 1 except Exception as e: logger.error( @@ -274,7 +253,6 @@ async def warm_genre_cache_periodically( exc_info=True, ) except asyncio.CancelledError: - logger.info("Genre cache warming task cancelled") break if warmed == 0: @@ -305,9 +283,7 @@ async def warm_discover_cache_periodically( try: for src in ("listenbrainz", "lastfm"): try: - logger.info("Warming discover cache (source=%s)...", src) await discover_service.warm_cache(source=src) - logger.info("Discover cache warming complete (source=%s)", src) except Exception as e: logger.error( "Discover cache warming failed (source=%s): %s", @@ -321,13 +297,11 @@ async def warm_discover_cache_periodically( adv = preferences_service.get_advanced_settings() if adv.discover_queue_auto_generate and adv.discover_queue_warm_cycle_build: resolved = discover_service.resolve_source(None) - logger.info("Pre-building discover queue (source=%s)...", resolved) await queue_manager.start_build(resolved) except Exception as e: logger.error("Discover queue pre-build failed: %s", e, exc_info=True) except asyncio.CancelledError: - logger.info("Discover cache warming task cancelled") break await asyncio.sleep(interval) @@ -355,7 +329,6 @@ async def warm_jellyfin_mbid_index(jellyfin_repo: 'JellyfinRepository') -> None: await asyncio.sleep(8) try: index = await jellyfin_repo.build_mbid_index() - logger.info("Jellyfin MBID index warmed with %d entries", len(index)) except Exception as e: logger.error("Jellyfin MBID index warming failed: %s", e, exc_info=True) @@ -399,7 +372,6 @@ async def warm_artist_discovery_cache_periodically( try: artists = await library_db.get_artists() if not artists: - logger.debug("No library artists for discovery cache warming") await asyncio.sleep(interval) continue @@ -411,18 +383,10 @@ async def warm_artist_discovery_cache_periodically( await asyncio.sleep(interval) continue - logger.info( - "Warming artist discovery cache for %d library artists...", len(mbids) - ) cached = await artist_discovery_service.precache_artist_discovery( mbids, delay=delay ) - logger.info( - "Artist discovery cache warming complete: %d/%d artists refreshed", - cached, len(mbids), - ) except asyncio.CancelledError: - logger.info("Artist discovery cache warming task cancelled") break except Exception as e: logger.error("Artist discovery cache warming failed: %s", e, exc_info=True) @@ -472,13 +436,11 @@ async def warm_audiodb_cache_periodically( settings = preferences_service.get_advanced_settings() if not settings.audiodb_enabled: - logger.debug("AudioDB sweep skipped (audiodb_enabled=false)") continue artists = await library_db.get_artists() albums = await library_db.get_albums() if not artists and not albums: - logger.debug("AudioDB sweep: no library items") continue cursor = preferences_service.get_setting('audiodb_sweep_cursor') @@ -520,20 +482,13 @@ async def warm_audiodb_cache_periodically( if not items_needing_refresh: preferences_service.save_setting('audiodb_sweep_cursor', None) preferences_service.save_setting('audiodb_sweep_last_completed', time()) - logger.info("AudioDB sweep complete: all items up to date") continue - logger.info( - "audiodb.sweep action=start items=%d cursor=%s", - len(items_needing_refresh), cursor[:8] if cursor else 'start', - ) - processed = 0 bytes_ok = 0 bytes_fail = 0 for entity_type, mbid, data in items_needing_refresh: if not preferences_service.get_advanced_settings().audiodb_enabled: - logger.info("AudioDB disabled during sweep, stopping") break try: @@ -572,31 +527,15 @@ async def warm_audiodb_cache_periodically( if processed % _AUDIODB_SWEEP_CURSOR_PERSIST_INTERVAL == 0: preferences_service.save_setting('audiodb_sweep_cursor', mbid) - if processed % _AUDIODB_SWEEP_LOG_INTERVAL == 0: - logger.info( - "audiodb.sweep processed=%d total=%d cursor=%s bytes_ok=%d bytes_fail=%d remaining=%d", - processed, len(items_needing_refresh), mbid[:8], - bytes_ok, bytes_fail, len(items_needing_refresh) - processed, - ) - await asyncio.sleep(_AUDIODB_SWEEP_INTER_ITEM_DELAY) if processed >= len(items_needing_refresh): preferences_service.save_setting('audiodb_sweep_cursor', None) preferences_service.save_setting('audiodb_sweep_last_completed', time()) - logger.info( - "audiodb.sweep action=complete refreshed=%d bytes_ok=%d bytes_fail=%d", - processed, bytes_ok, bytes_fail, - ) else: preferences_service.save_setting('audiodb_sweep_cursor', mbid) - logger.info( - "audiodb.sweep action=interrupted processed=%d total=%d bytes_ok=%d bytes_fail=%d", - processed, len(items_needing_refresh), bytes_ok, bytes_fail, - ) except asyncio.CancelledError: - logger.info("AudioDB sweep task cancelled") break except Exception as e: logger.error("AudioDB sweep cycle failed: %s", e, exc_info=True) @@ -632,7 +571,6 @@ async def sync_request_statuses_periodically( try: await requests_page_service.sync_request_statuses() except asyncio.CancelledError: - logger.info("Request status sync task cancelled") break except Exception as e: logger.error("Periodic request status sync failed: %s", e, exc_info=True) @@ -673,10 +611,7 @@ async def demote_orphaned_covers_periodically( valid_hashes.add(get_cache_filename(f"artist_{mbid}", "img")) demoted = await asyncio.to_thread(cover_disk_cache.demote_orphaned, valid_hashes) - if demoted: - logger.info("Orphan cover demotion: %d covers demoted to expiring", demoted) except asyncio.CancelledError: - logger.info("Orphan cover demotion task cancelled") break except Exception as e: logger.error("Orphan cover demotion failed: %s", e, exc_info=True) @@ -710,13 +645,7 @@ async def prune_stores_periodically( pruned_requests = await request_history.prune_old_terminal_requests(request_retention_days) pruned_ignored = await mbid_store.prune_old_ignored_releases(ignored_retention_days) orphaned_yt = await youtube_store.delete_orphaned_track_links() - if pruned_requests or pruned_ignored or orphaned_yt: - logger.info( - "Store prune: requests=%d ignored_releases=%d youtube_orphans=%d", - pruned_requests, pruned_ignored, orphaned_yt, - ) except asyncio.CancelledError: - logger.info("Store prune task cancelled") break except Exception as e: logger.error("Store prune task failed: %s", e, exc_info=True) diff --git a/backend/infrastructure/cache/disk_cache.py b/backend/infrastructure/cache/disk_cache.py index 6d5224d..4e352ba 100644 --- a/backend/infrastructure/cache/disk_cache.py +++ b/backend/infrastructure/cache/disk_cache.py @@ -1,7 +1,6 @@ import asyncio import hashlib import json -import logging import shutil import time from pathlib import Path @@ -9,8 +8,6 @@ from typing import Any from infrastructure.serialization import to_jsonable -logger = logging.getLogger(__name__) - def _encode_json(value: Any) -> str: return json.dumps(value, ensure_ascii=True, separators=(",", ":")) @@ -204,8 +201,8 @@ class DiskMetadataCache: meta["last_accessed"] = time.time() try: meta_path.write_text(_encode_json(meta)) - except OSError as exc: - logger.debug("Failed to update disk cache access time for %s: %s", meta_path, exc) + except OSError: + pass return payload diff --git a/backend/infrastructure/cache/memory_cache.py b/backend/infrastructure/cache/memory_cache.py index 513499b..1f9fd35 100644 --- a/backend/infrastructure/cache/memory_cache.py +++ b/backend/infrastructure/cache/memory_cache.py @@ -1,13 +1,10 @@ import asyncio -import logging import sys import time from typing import Any, Optional from abc import ABC, abstractmethod from collections import OrderedDict -logger = logging.getLogger(__name__) - class CacheInterface(ABC): @abstractmethod @@ -84,8 +81,6 @@ class InMemoryCache(CacheInterface): if key not in self._cache and len(self._cache) >= self._max_entries: oldest_key, _ = self._cache.popitem(last=False) self._evictions += 1 - if self._evictions % 100 == 0: - logger.info(f"Cache LRU evictions: {self._evictions}, current size: {len(self._cache)}") self._cache[key] = CacheEntry(value, ttl_seconds) self._cache.move_to_end(key) @@ -104,9 +99,6 @@ class InMemoryCache(CacheInterface): for key in keys_to_remove: self._cache.pop(key, None) - if keys_to_remove: - logger.info(f"Cleared {len(keys_to_remove)} cache entries with prefix '{prefix}'") - return len(keys_to_remove) async def cleanup_expired(self) -> int: @@ -120,9 +112,6 @@ class InMemoryCache(CacheInterface): for key in expired_keys: self._cache.pop(key, None) - if expired_keys: - logger.debug(f"Cleaned up {len(expired_keys)} expired cache entries") - return len(expired_keys) def size(self) -> int: diff --git a/backend/infrastructure/degradation.py b/backend/infrastructure/degradation.py index a313a83..72957f7 100644 --- a/backend/infrastructure/degradation.py +++ b/backend/infrastructure/degradation.py @@ -9,13 +9,10 @@ call signatures. from __future__ import annotations import contextvars -import logging from typing import Literal from infrastructure.integration_result import IntegrationResult, IntegrationStatus -logger = logging.getLogger(__name__) - _degradation_ctx_var: contextvars.ContextVar[DegradationContext | None] = ( contextvars.ContextVar("degradation_ctx", default=None) ) @@ -34,13 +31,6 @@ class DegradationContext: prev = self._services.get(result.source) if prev is None or _severity(result.status) > _severity(prev): self._services[result.source] = result.status - if result.status != "ok": - logger.debug( - "Degradation recorded: source=%s status=%s msg=%s", - result.source, - result.status, - result.error_message, - ) def summary(self) -> dict[str, str]: """Return ``{source: status}`` for all recorded integrations.""" diff --git a/backend/infrastructure/http/client.py b/backend/infrastructure/http/client.py index cf91ed2..ed30404 100644 --- a/backend/infrastructure/http/client.py +++ b/backend/infrastructure/http/client.py @@ -1,10 +1,7 @@ import httpx -import logging from typing import Optional from core.config import Settings, get_settings -logger = logging.getLogger(__name__) - def _get_user_agent(settings: Optional[Settings] = None) -> str: if settings: diff --git a/backend/infrastructure/http/deduplication.py b/backend/infrastructure/http/deduplication.py index 8460842..7d68c9d 100644 --- a/backend/infrastructure/http/deduplication.py +++ b/backend/infrastructure/http/deduplication.py @@ -1,12 +1,9 @@ import asyncio -import logging from typing import TypeVar, Awaitable, Callable, Any from functools import wraps from core.exceptions import ClientDisconnectedError -logger = logging.getLogger(__name__) - T = TypeVar("T") _MAX_DEDUP_RETRIES = 1 diff --git a/backend/infrastructure/http/disconnect.py b/backend/infrastructure/http/disconnect.py index 0ad44e4..05b377a 100644 --- a/backend/infrastructure/http/disconnect.py +++ b/backend/infrastructure/http/disconnect.py @@ -1,12 +1,9 @@ from __future__ import annotations -import logging from collections.abc import Awaitable, Callable from core.exceptions import ClientDisconnectedError -logger = logging.getLogger(__name__) - DisconnectCallable = Callable[[], Awaitable[bool]] @@ -14,5 +11,4 @@ async def check_disconnected( is_disconnected: DisconnectCallable | None, ) -> None: if is_disconnected is not None and await is_disconnected(): - logger.debug("Client disconnected — aborting cover fetch") raise ClientDisconnectedError("Client disconnected") diff --git a/backend/infrastructure/logging_helper.py b/backend/infrastructure/logging_helper.py index 5fed9fa..e69de29 100644 --- a/backend/infrastructure/logging_helper.py +++ b/backend/infrastructure/logging_helper.py @@ -1,43 +0,0 @@ -import logging -from typing import Optional - -logger = logging.getLogger(__name__) - - -def format_mbid(mbid: str) -> str: - return f"{mbid[:8]}..." if len(mbid) >= 8 else mbid - - -def log_cache_hit(entity_type: str, mbid: str, source: Optional[str] = None) -> None: - source_info = f" from {source}" if source else "" - logger.info(f"Cache hit: {entity_type} {format_mbid(mbid)}{source_info}") - - -def log_cache_miss(entity_type: str, mbid: str, source: Optional[str] = None) -> None: - source_info = f" in {source}" if source else "" - logger.debug(f"Cache miss: {entity_type} {format_mbid(mbid)}{source_info}") - - -def log_fetch_start(entity_type: str, mbid: str, source: str) -> None: - logger.info(f"Fetching {entity_type} {format_mbid(mbid)} from {source}") - - -def log_fetch_success(entity_type: str, mbid: str, source: str) -> None: - logger.info(f"Fetch success: {entity_type} {format_mbid(mbid)} from {source}") - - -def log_fetch_failed(entity_type: str, mbid: str, source: str, reason: Optional[str] = None) -> None: - reason_info = f": {reason}" if reason else "" - logger.warning(f"Fetch failed: {entity_type} {format_mbid(mbid)} from {source}{reason_info}") - - -def log_image_fetch(action: str, entity_type: str, mbid: str, source: str) -> None: - logger.info(f"Image {action}: {entity_type} {format_mbid(mbid)} from {source}") - - -def log_http_error(entity_type: str, mbid: str, source: str, status_code: int) -> None: - logger.warning(f"HTTP {status_code}: {entity_type} {format_mbid(mbid)} from {source}") - - -def log_exception(entity_type: str, mbid: str, operation: str, error: Exception) -> None: - logger.error(f"Exception in {operation} for {entity_type} {format_mbid(mbid)}: {error}") diff --git a/backend/infrastructure/persistence/_database.py b/backend/infrastructure/persistence/_database.py index 5f01617..e0a9eb7 100644 --- a/backend/infrastructure/persistence/_database.py +++ b/backend/infrastructure/persistence/_database.py @@ -2,14 +2,11 @@ import asyncio import json -import logging import sqlite3 import threading from pathlib import Path from typing import Any, TypeVar -logger = logging.getLogger(__name__) - T = TypeVar("T") diff --git a/backend/infrastructure/persistence/genre_index.py b/backend/infrastructure/persistence/genre_index.py index 2abf6a3..fe5310f 100644 --- a/backend/infrastructure/persistence/genre_index.py +++ b/backend/infrastructure/persistence/genre_index.py @@ -1,6 +1,5 @@ -"""Domain 2 — Genre indexing persistence.""" +"""Domain 2 - Genre indexing persistence.""" -import logging import sqlite3 from typing import Any @@ -12,8 +11,6 @@ from infrastructure.persistence._database import ( _normalize, ) -logger = logging.getLogger(__name__) - LIBRARY_ARTISTS_TABLE = "library_artists" LIBRARY_ALBUMS_TABLE = "library_albums" diff --git a/backend/infrastructure/persistence/library_db.py b/backend/infrastructure/persistence/library_db.py index 693d67d..d0e8b67 100644 --- a/backend/infrastructure/persistence/library_db.py +++ b/backend/infrastructure/persistence/library_db.py @@ -42,9 +42,7 @@ def _safe_delete(conn: sqlite3.Connection, table: str) -> None: try: conn.execute(f'DELETE FROM "{table}"') except sqlite3.OperationalError as exc: - if "no such table" in str(exc): - logger.debug("Cross-domain table %s not yet created, skipping clear", table) - else: + if "no such table" not in str(exc): logger.warning("Unexpected error clearing cross-domain table %s: %s", table, exc) diff --git a/backend/infrastructure/persistence/sync_state_store.py b/backend/infrastructure/persistence/sync_state_store.py index 9d364f1..29903e3 100644 --- a/backend/infrastructure/persistence/sync_state_store.py +++ b/backend/infrastructure/persistence/sync_state_store.py @@ -1,6 +1,5 @@ """Domain 5: Sync lifecycle persistence.""" -import logging import sqlite3 import time from typing import Any @@ -13,8 +12,6 @@ from infrastructure.persistence._database import ( ) from infrastructure.serialization import to_jsonable -logger = logging.getLogger(__name__) - class SyncStateStore(PersistenceBase): """Owns tables: ``sync_state``, ``processed_items``.""" diff --git a/backend/infrastructure/persistence/youtube_store.py b/backend/infrastructure/persistence/youtube_store.py index 0faa5a0..1f33576 100644 --- a/backend/infrastructure/persistence/youtube_store.py +++ b/backend/infrastructure/persistence/youtube_store.py @@ -1,14 +1,11 @@ -"""Domain 3 — YouTube link persistence.""" +"""Domain 3 - YouTube link persistence.""" -import logging import sqlite3 from typing import Any from infrastructure.persistence._database import PersistenceBase from infrastructure.serialization import to_jsonable -logger = logging.getLogger(__name__) - class YouTubeStore(PersistenceBase): """Owns tables: ``youtube_links``, ``youtube_track_links``.""" diff --git a/backend/infrastructure/queue/priority_queue.py b/backend/infrastructure/queue/priority_queue.py index 36d157c..867a108 100644 --- a/backend/infrastructure/queue/priority_queue.py +++ b/backend/infrastructure/queue/priority_queue.py @@ -1,11 +1,8 @@ import asyncio -import logging from enum import IntEnum from typing import Optional from datetime import datetime -logger = logging.getLogger(__name__) - class RequestPriority(IntEnum): USER_INITIATED = 0 @@ -37,8 +34,6 @@ class PriorityQueueManager: self._user_activity_event = asyncio.Event() self._background_waiters = 0 self._initialized = True - - logger.info("PriorityQueueManager initialized: user=20, image=10, background=5") async def acquire_slot(self, priority: RequestPriority) -> asyncio.Semaphore: if priority == RequestPriority.USER_INITIATED: diff --git a/backend/infrastructure/queue/queue_store.py b/backend/infrastructure/queue/queue_store.py index fd1c05d..e739502 100644 --- a/backend/infrastructure/queue/queue_store.py +++ b/backend/infrastructure/queue/queue_store.py @@ -1,10 +1,7 @@ -import logging import sqlite3 import threading from pathlib import Path -logger = logging.getLogger(__name__) - class QueueStore: def __init__(self, db_path: Path | None = None) -> None: diff --git a/backend/infrastructure/queue/request_queue.py b/backend/infrastructure/queue/request_queue.py index 6e33312..08cb48b 100644 --- a/backend/infrastructure/queue/request_queue.py +++ b/backend/infrastructure/queue/request_queue.py @@ -75,7 +75,7 @@ class RequestQueue(QueueInterface): self._on_import_callback = on_import_callback async def add(self, album_mbid: str) -> dict: - """Blocking enqueue — waits for the result.""" + """Blocking enqueue that waits for the result.""" await self.start() request = QueuedRequest(album_mbid) @@ -90,7 +90,6 @@ class RequestQueue(QueueInterface): """Fire-and-forget enqueue. Returns True if enqueued, False if duplicate.""" async with self._enqueue_lock: if self._store and self._store.has_active_mbid(album_mbid): - logger.info("Duplicate request rejected for %s — already active", album_mbid[:8]) return False # Clear any prior cancellation so re-requests aren't silently dropped @@ -101,7 +100,6 @@ class RequestQueue(QueueInterface): if self._store: self._store.enqueue(request.job_id, album_mbid) await self._queue.put(request) - logger.info("Enqueued request for album %s (job %s)", album_mbid[:8], request.job_id[:8]) return True async def cancel(self, album_mbid: str) -> bool: @@ -112,8 +110,6 @@ class RequestQueue(QueueInterface): # Mark for skip - items already in the asyncio.Queue can't be removed, # so workers check this set before processing. self._cancelled_mbids.add(album_mbid.lower()) - if removed: - logger.info("Cancelled pending queue job for %s", album_mbid[:8]) return removed async def start(self) -> None: @@ -122,7 +118,6 @@ class RequestQueue(QueueInterface): for _ in range(self._concurrency - len(alive)): task = asyncio.create_task(self._process_queue()) self._worker_tasks.append(task) - logger.info("Queue processor started (%d workers)", self._concurrency) if not self._recovered: self._recovered = True self._recover_pending() @@ -135,12 +130,10 @@ class RequestQueue(QueueInterface): t.cancel() await asyncio.gather(*alive, return_exceptions=True) self._worker_tasks.clear() - logger.info("Queue processor stopped") async def drain(self, timeout: float = 30.0) -> None: try: await asyncio.wait_for(self._queue.join(), timeout=timeout) - logger.info("Queue drained successfully") except asyncio.TimeoutError: remaining = self._queue.qsize() logger.warning("Queue drain timeout: %d items remaining", remaining) @@ -183,9 +176,6 @@ class RequestQueue(QueueInterface): logger.warning("Queue full during recovery, %d items deferred to next restart", len(pending) - recovered) break - if recovered: - logger.info("Recovered %d pending jobs from store", recovered) - self._retry_dead_letters() async def _backfill_history(self, album_mbid: str) -> None: @@ -200,7 +190,6 @@ class RequestQueue(QueueInterface): artist_name="Unknown", album_title="Unknown", ) - logger.info("Backfilled history record for recovered job %s", album_mbid[:8]) except Exception as e: # noqa: BLE001 logger.warning("Failed to backfill history for %s: %s", album_mbid[:8], e) @@ -213,7 +202,6 @@ class RequestQueue(QueueInterface): # Don't overwrite a user-initiated cancellation existing = await self._request_history.async_get_record(album_mbid) if existing and existing.status == "cancelled": - logger.info("Skipping history update for %s — already cancelled", album_mbid[:8]) return payload = result.get("payload", {}) @@ -294,8 +282,6 @@ class RequestQueue(QueueInterface): self._store.remove_dead_letter(row["id"]) self._store.enqueue(row["id"], row["album_mbid"]) enqueued += 1 - if enqueued: - logger.info("Re-enqueued %d dead-letter jobs for retry", enqueued) async def _process_queue(self) -> None: while True: @@ -305,7 +291,6 @@ class RequestQueue(QueueInterface): # Skip items cancelled while sitting in the asyncio.Queue if request.album_mbid.lower() in self._cancelled_mbids: self._cancelled_mbids.discard(request.album_mbid.lower()) - logger.info("Skipping cancelled request %s", request.album_mbid[:8]) if not request.future.done(): request.future.cancel() self._queue.task_done() @@ -319,14 +304,7 @@ class RequestQueue(QueueInterface): if self._store: self._store.mark_processing(request.job_id) - queue_wait_ms = int((time.monotonic() - request.enqueued_at) * 1000) - logger.info( - "Processing request %s (queue_wait=%dms)", request.album_mbid[:8], queue_wait_ms - ) - try: - if request.recovered: - logger.info("Processing recovered job %s for album %s", request.job_id[:8], request.album_mbid[:8]) result = await self._processor(request.album_mbid) if not request.future.done(): request.future.set_result(result) @@ -353,7 +331,6 @@ class RequestQueue(QueueInterface): self._queue.task_done() except asyncio.CancelledError: - logger.info("Queue worker cancelled") break except Exception as e: # noqa: BLE001 logger.error("Queue worker error: %s", e) diff --git a/backend/infrastructure/resilience/retry.py b/backend/infrastructure/resilience/retry.py index 3d23f05..ca08476 100644 --- a/backend/infrastructure/resilience/retry.py +++ b/backend/infrastructure/resilience/retry.py @@ -63,10 +63,6 @@ class CircuitBreaker: def is_open(self) -> bool: if self.state == CircuitState.OPEN: if time.time() - self.last_failure_time > self.timeout: - logger.info( - "Circuit breaker '%s' transitioning to HALF_OPEN", - self.name, - ) previous_state = self.state self.state = CircuitState.HALF_OPEN self.success_count = 0 @@ -79,11 +75,6 @@ class CircuitBreaker: if self.state == CircuitState.HALF_OPEN: self.success_count += 1 if self.success_count >= self.success_threshold: - logger.info( - "Circuit breaker '%s' closing after %d successes", - self.name, - self.success_count, - ) previous_state = self.state self.state = CircuitState.CLOSED self.failure_count = 0 @@ -127,7 +118,6 @@ class CircuitBreaker: } def reset(self): - logger.info("Circuit breaker '%s' manually reset", self.name) previous_state = self.state self.state = CircuitState.CLOSED self.failure_count = 0 @@ -144,15 +134,11 @@ class CircuitBreaker: self.record_failure() async def atry_transition(self): - """Acquire lock and attempt OPEN→HALF_OPEN transition if timeout elapsed.""" + """Acquire the lock and attempt an OPEN -> HALF_OPEN transition if the timeout has elapsed.""" if self.state != CircuitState.OPEN: return async with self._lock: if self.state == CircuitState.OPEN and time.time() - self.last_failure_time > self.timeout: - logger.info( - "Circuit breaker '%s' transitioning to HALF_OPEN (locked)", - self.name, - ) previous_state = self.state self.state = CircuitState.HALF_OPEN self.success_count = 0 @@ -196,7 +182,6 @@ def with_retry( async def wrapper(*args: P.args, **kwargs: P.kwargs) -> T: service_name = circuit_breaker.name if circuit_breaker else "unknown" func_name = func.__name__ - start_time = time.time() if circuit_breaker: await circuit_breaker.atry_transition() @@ -215,54 +200,23 @@ def with_retry( last_exception = None for attempt in range(1, max_attempts + 1): - attempt_start = time.time() try: result = await func(*args, **kwargs) - elapsed_ms = int((time.time() - attempt_start) * 1000) - if circuit_breaker: await circuit_breaker.arecord_success() - if attempt > 1: - total_elapsed_ms = int((time.time() - start_time) * 1000) - logger.info( - "%s succeeded on attempt %d/%d", - func_name, - attempt, - max_attempts, - extra={ - "service_name": service_name, - "function": func_name, - "attempt": attempt, - "max_attempts": max_attempts, - "elapsed_ms": elapsed_ms, - "total_elapsed_ms": total_elapsed_ms, - } - ) - return result except retriable_exceptions as e: last_exception = e - elapsed_ms = int((time.time() - attempt_start) * 1000) if attempt >= max_attempts: - total_elapsed_ms = int((time.time() - start_time) * 1000) logger.error( "%s failed after %d attempts: %s", func_name, max_attempts, e, - extra={ - "service_name": service_name, - "function": func_name, - "attempt": attempt, - "max_attempts": max_attempts, - "elapsed_ms": elapsed_ms, - "total_elapsed_ms": total_elapsed_ms, - "error": str(e), - } ) break @@ -274,24 +228,6 @@ def with_retry( if jitter: delay *= (0.5 + random.random()) - logger.warning( - "%s attempt %d/%d failed: %s. Retrying in %.2fs...", - func_name, - attempt, - max_attempts, - e, - delay, - extra={ - "service_name": service_name, - "function": func_name, - "attempt": attempt, - "max_attempts": max_attempts, - "elapsed_ms": elapsed_ms, - "retry_delay_s": f"{delay:.2f}", - "error": str(e), - } - ) - await asyncio.sleep(delay) if circuit_breaker and last_exception: diff --git a/backend/main.py b/backend/main.py index 02eacad..ff8e31d 100644 --- a/backend/main.py +++ b/backend/main.py @@ -62,7 +62,6 @@ async def lifespan(app: FastAPI): settings = get_settings() configured_level = getattr(logging, settings.log_level, logging.INFO) logging.getLogger().setLevel(configured_level) - logger.info("Log level set to %s", settings.log_level) await init_app_state(app) @@ -94,14 +93,13 @@ async def lifespan(app: FastAPI): def handle_cache_warming_error(task: asyncio.Task): try: if task.cancelled(): - logger.info("Cache warming was cancelled") return exc = task.exception() if exc: logger.error("Cache warming failed: %s", exc, exc_info=exc) except asyncio.CancelledError: - logger.info("Cache warming was cancelled") + pass except Exception as e: # noqa: BLE001 logger.error("Error checking cache warming task: %s", e) @@ -118,7 +116,6 @@ async def lifespan(app: FastAPI): interrupted_state = await status_service.restore_from_persistence() if interrupted_state: - logger.info("Found interrupted library sync, scheduling resume...") async def resume_sync(): try: @@ -138,7 +135,7 @@ async def lifespan(app: FastAPI): await status_service.complete_sync(str(e)) resume_task = asyncio.create_task(resume_sync()) - resume_task.add_done_callback(lambda t: logger.info("Resume sync task completed") if not t.exception() else logger.error("Resume sync failed: %s", t.exception())) + resume_task.add_done_callback(lambda t: logger.error("Resume sync failed: %s", t.exception()) if t.exception() else None) TaskRegistry.get_instance().register("library-sync-resume", resume_task) from core.dependencies import get_home_service diff --git a/backend/repositories/audiodb_repository.py b/backend/repositories/audiodb_repository.py index a28e7f9..2b3382f 100644 --- a/backend/repositories/audiodb_repository.py +++ b/backend/repositories/audiodb_repository.py @@ -126,7 +126,6 @@ class AudioDBRepository: raise RateLimitedError("AudioDB rate limit exceeded", retry_after_seconds=60) if response.status_code == 404: - logger.debug("audiodb.request endpoint=%s status=404 elapsed_ms=%.1f", endpoint, elapsed_ms) return None if response.status_code != 200: @@ -139,7 +138,6 @@ class AudioDBRepository: except (msgspec.DecodeError, ValueError, TypeError): raise ExternalServiceError("AudioDB returned invalid JSON") - logger.debug("audiodb.request endpoint=%s status=200 elapsed_ms=%.1f", endpoint, elapsed_ms) return data except (ExternalServiceError, RateLimitedError): @@ -164,12 +162,10 @@ class AudioDBRepository: elapsed_ms = (time.monotonic() - t0) * 1000 if data is None: - logger.debug("audiodb.lookup entity=artist lookup_type=mbid mbid=%s found=false elapsed_ms=%.1f", mbid, elapsed_ms) return None item = _extract_first(data, "artists") if item is None: - logger.debug("audiodb.lookup entity=artist lookup_type=mbid mbid=%s found=false elapsed_ms=%.1f", mbid, elapsed_ms) return None try: @@ -178,7 +174,6 @@ class AudioDBRepository: logger.warning("audiodb.schema_error entity=artist lookup_type=mbid mbid=%s error=%s", mbid, exc) _record_degradation(f"Schema error for artist mbid {mbid}: {exc}") return None - logger.debug("audiodb.lookup entity=artist lookup_type=mbid mbid=%s found=true elapsed_ms=%.1f", mbid, elapsed_ms) return result async def get_album_by_mbid(self, mbid: str) -> AudioDBAlbumResponse | None: @@ -198,12 +193,10 @@ class AudioDBRepository: elapsed_ms = (time.monotonic() - t0) * 1000 if data is None: - logger.debug("audiodb.lookup entity=album lookup_type=mbid mbid=%s found=false elapsed_ms=%.1f", mbid, elapsed_ms) return None item = _extract_first(data, "album") if item is None: - logger.debug("audiodb.lookup entity=album lookup_type=mbid mbid=%s found=false elapsed_ms=%.1f", mbid, elapsed_ms) return None try: @@ -212,7 +205,6 @@ class AudioDBRepository: logger.warning("audiodb.schema_error entity=album lookup_type=mbid mbid=%s error=%s", mbid, exc) _record_degradation(f"Schema error for album mbid {mbid}: {exc}") return None - logger.debug("audiodb.lookup entity=album lookup_type=mbid mbid=%s found=true elapsed_ms=%.1f", mbid, elapsed_ms) return result async def search_artist_by_name(self, name: str) -> AudioDBArtistResponse | None: @@ -232,12 +224,10 @@ class AudioDBRepository: elapsed_ms = (time.monotonic() - t0) * 1000 if data is None: - logger.debug("audiodb.lookup entity=artist lookup_type=name name=%s found=false elapsed_ms=%.1f", name, elapsed_ms) return None item = _extract_first(data, "artists") if item is None: - logger.debug("audiodb.lookup entity=artist lookup_type=name name=%s found=false elapsed_ms=%.1f", name, elapsed_ms) return None try: @@ -246,7 +236,6 @@ class AudioDBRepository: logger.warning("audiodb.schema_error entity=artist lookup_type=name name=%s error=%s", name, exc) _record_degradation(f"Schema error for artist name search: {exc}") return None - logger.debug("audiodb.lookup entity=artist lookup_type=name name=%s found=true elapsed_ms=%.1f", name, elapsed_ms) return result async def search_album_by_name(self, artist: str, album: str) -> AudioDBAlbumResponse | None: @@ -266,18 +255,10 @@ class AudioDBRepository: elapsed_ms = (time.monotonic() - t0) * 1000 if data is None: - logger.debug( - "audiodb.lookup entity=album lookup_type=name artist=%s album=%s found=false elapsed_ms=%.1f", - artist, album, elapsed_ms, - ) return None item = _extract_first(data, "album") if item is None: - logger.debug( - "audiodb.lookup entity=album lookup_type=name artist=%s album=%s found=false elapsed_ms=%.1f", - artist, album, elapsed_ms, - ) return None try: @@ -291,8 +272,4 @@ class AudioDBRepository: ) _record_degradation(f"Schema error for album name search: {exc}") return None - logger.debug( - "audiodb.lookup entity=album lookup_type=name artist=%s album=%s found=true elapsed_ms=%.1f", - artist, album, elapsed_ms, - ) return result diff --git a/backend/repositories/coverart_album.py b/backend/repositories/coverart_album.py index b3fd23a..941eebd 100644 --- a/backend/repositories/coverart_album.py +++ b/backend/repositories/coverart_album.py @@ -91,7 +91,7 @@ class AlbumCoverFetcher: timeout=LOCAL_SOURCE_TIMEOUT_SECONDS, ) except TimeoutError: - logger.debug(f"Timed out local source lookup for release group {release_group_id[:8]}...") + pass if result: return result size_suffix = f"-{size}" if size else "" @@ -146,7 +146,6 @@ class AlbumCoverFetcher: ) -> tuple[bytes, str, str] | None: if self._audiodb_service is None: return None - logger.debug(f"[IMG:AudioDB] Fetching album image for {release_group_id[:8]}...") try: cached_images = await self._audiodb_service.fetch_and_cache_album_images(release_group_id) if cached_images is None or cached_images.is_negative or not cached_images.album_thumb_url: @@ -174,8 +173,8 @@ class AlbumCoverFetcher: except ClientDisconnectedError: raise except Exception as e: # noqa: BLE001 - logger.warning(f"[IMG:AudioDB] Exception for {release_group_id[:8]}: {e}") return None + async def _get_cover_from_best_release( self, release_group_id: str, @@ -231,7 +230,7 @@ class AlbumCoverFetcher: except ClientDisconnectedError: raise except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to fetch cover from best release: {e}") + return None return None async def _fetch_from_lidarr( @@ -249,7 +248,6 @@ class AlbumCoverFetcher: image_url = await self._lidarr_repo.get_album_image_url(release_group_id, size=size) if not image_url: return None - logger.debug(f"Fetching album cover from Lidarr: {release_group_id[:8]}...") response = await self._http_get( image_url, priority, @@ -266,7 +264,6 @@ class AlbumCoverFetcher: task.add_done_callback(_log_task_error) return (content, content_type, "lidarr") except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to fetch album cover from Lidarr for {release_group_id}: {e}") return None async def _fetch_from_jellyfin( @@ -303,7 +300,6 @@ class AlbumCoverFetcher: task.add_done_callback(_log_task_error) return (content, content_type, "jellyfin") except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to fetch album cover from Jellyfin for {musicbrainz_id}: {e}") return None async def fetch_release_cover( @@ -322,9 +318,7 @@ class AlbumCoverFetcher: except ClientDisconnectedError: raise except Exception as e: # noqa: BLE001 - logger.debug( - f"[IMG:AudioDB] Failed resolving release group for release {release_id[:8]}: {e}" - ) + pass result = None try: await check_disconnected(is_disconnected) @@ -333,7 +327,7 @@ class AlbumCoverFetcher: timeout=LOCAL_SOURCE_TIMEOUT_SECONDS, ) except TimeoutError: - logger.debug(f"Timed out local source lookup for release {release_id[:8]}...") + pass if result: return result if release_group_id: @@ -366,7 +360,7 @@ class AlbumCoverFetcher: except ClientDisconnectedError: raise except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to fetch release cover for {release_id}: {e}") + pass return None async def _fetch_release_local_sources( diff --git a/backend/repositories/coverart_artist.py b/backend/repositories/coverart_artist.py index c19f0ff..68b0f02 100644 --- a/backend/repositories/coverart_artist.py +++ b/backend/repositories/coverart_artist.py @@ -130,7 +130,6 @@ class ArtistImageFetcher: priority: RequestPriority = RequestPriority.IMAGE_FETCH, is_disconnected: DisconnectCallable | None = None, ) -> tuple[bytes, str, str] | None: - logger.info(f"[IMG] Fetching artist image for {artist_id[:8]}... (size={size})") result = None had_transient_failure = False last_transient_error: Exception | None = None @@ -140,12 +139,9 @@ class ArtistImageFetcher: except TRANSIENT_FETCH_EXCEPTIONS as exc: had_transient_failure = True last_transient_error = exc - logger.warning(f"[IMG:AudioDB] Transient fetch failure for {artist_id[:8]}...: {exc}") result = None if result: - logger.info(f"[IMG] SUCCESS from AudioDB for {artist_id[:8]}...") return result - logger.info(f"[IMG] AudioDB failed for {artist_id[:8]}..., trying local sources") try: await check_disconnected(is_disconnected) local_result, local_transient = await asyncio.wait_for( @@ -156,27 +152,21 @@ class ArtistImageFetcher: had_transient_failure = True result = local_result except TimeoutError: - logger.debug(f"[IMG] Timed out local source lookup for {artist_id[:8]}...") had_transient_failure = True last_transient_error = TimeoutError( f"Timed out local source lookup for {artist_id}" ) if result: - logger.info(f"[IMG] SUCCESS from local source for {artist_id[:8]}...") return result - logger.info(f"[IMG] Local sources missed for {artist_id[:8]}..., trying Wikidata") try: await check_disconnected(is_disconnected) result = await self._fetch_from_wikidata(artist_id, size, file_path, priority=priority) except TRANSIENT_FETCH_EXCEPTIONS as exc: had_transient_failure = True last_transient_error = exc - logger.warning(f"[IMG] Transient Wikidata fetch failure for {artist_id[:8]}...: {exc}") result = None if result: - logger.info(f"[IMG] SUCCESS from Wikidata for {artist_id[:8]}...") return result - logger.info(f"[IMG] FAILED: No image found for {artist_id[:8]}... from any source") if had_transient_failure: raise TransientImageFetchError( f"Transient failure while fetching artist image for {artist_id}" @@ -196,7 +186,6 @@ class ArtistImageFetcher: result = await self._fetch_from_lidarr(artist_id, size, file_path, priority=priority) except TRANSIENT_FETCH_EXCEPTIONS as exc: had_transient_failure = True - logger.warning(f"[IMG:Lidarr] Transient failure for {artist_id[:8]}: {exc}") result = None if result: @@ -206,7 +195,6 @@ class ArtistImageFetcher: result = await self._fetch_from_jellyfin(artist_id, file_path, priority=priority) except TRANSIENT_FETCH_EXCEPTIONS as exc: had_transient_failure = True - logger.warning(f"[IMG:Jellyfin] Transient failure for {artist_id[:8]}: {exc}") result = None return result, had_transient_failure @@ -219,7 +207,6 @@ class ArtistImageFetcher: ) -> tuple[bytes, str, str] | None: if self._audiodb_service is None: return None - logger.debug(f"[IMG:AudioDB] Fetching artist image for {artist_id[:8]}...") try: images = await self._audiodb_service.fetch_and_cache_artist_images(artist_id) if images is None or images.is_negative or not images.thumb_url: @@ -248,7 +235,6 @@ class ArtistImageFetcher: except TRANSIENT_FETCH_EXCEPTIONS: raise except Exception as e: # noqa: BLE001 - logger.warning(f"[IMG:AudioDB] Exception for {artist_id[:8]}: {e}") return None async def _fetch_from_lidarr( @@ -259,23 +245,19 @@ class ArtistImageFetcher: priority: RequestPriority = RequestPriority.IMAGE_FETCH, ) -> tuple[bytes, str, str] | None: if not self._lidarr_repo: - logger.debug(f"[IMG:Lidarr] No Lidarr repo configured for {artist_id[:8]}") return None if not self._lidarr_repo.is_configured(): return None try: image_url = await self._lidarr_repo.get_artist_image_url(artist_id, size=size or 250) if not image_url: - logger.info(f"[IMG:Lidarr] No image URL returned for {artist_id[:8]}") return None - logger.info(f"[IMG:Lidarr] Fetching from URL for {artist_id[:8]}...") response = await self._http_get( image_url, priority, source="lidarr", ) if response.status_code != 200: - logger.warning(f"[IMG:Lidarr] HTTP {response.status_code} for {artist_id[:8]}") return None content_type = response.headers.get("content-type", "") if not _is_valid_image_content_type(content_type): @@ -288,7 +270,6 @@ class ArtistImageFetcher: except TRANSIENT_FETCH_EXCEPTIONS: raise except Exception as e: # noqa: BLE001 - logger.warning(f"[IMG:Lidarr] Exception for {artist_id[:8]}: {e}") return None async def _fetch_from_jellyfin( @@ -327,7 +308,6 @@ class ArtistImageFetcher: except TRANSIENT_FETCH_EXCEPTIONS: raise except Exception as e: # noqa: BLE001 - logger.warning(f"[IMG:Jellyfin] Exception for {artist_id[:8]}: {e}") return None async def _fetch_from_wikidata( @@ -349,7 +329,6 @@ class ArtistImageFetcher: match = re.search(r'/(?:wiki|entity)/(Q\d+)', wikidata_url) wikidata_id = match.group(1) if match else None if not wikidata_id: - logger.debug(f"Could not parse Wikidata Q-id from URL: {wikidata_url}") return None api_url = ( f"https://www.wikidata.org/w/api.php" @@ -432,14 +411,11 @@ class ArtistImageFetcher: return None async def _lookup_wikidata_url(self, artist_id: str) -> str | None: - logger.info(f"[IMG:Wikidata] Looking up wikidata URL for {artist_id[:8]}...") if not self._mb_repo: - logger.warning(f"[IMG:Wikidata] MusicBrainz repository not available for {artist_id}") return None try: artist_data = await self._mb_repo.get_artist_relations(artist_id) if not artist_data: - logger.info(f"[IMG:Wikidata] No artist data from MB for {artist_id[:8]}") return None url_relations = artist_data.get("relations", []) if url_relations: @@ -449,7 +425,6 @@ class ArtistImageFetcher: url_obj = url_rel.get("url", {}) target = url_obj.get("resource", "") if isinstance(url_obj, dict) else "" if typ == "wikidata" and target: - logger.info(f"[IMG:Wikidata] Found URL for {artist_id[:8]}: {target}") return target external_links = artist_data.get("external_links") or artist_data.get("external_links_list") if external_links: @@ -462,7 +437,6 @@ class ArtistImageFetcher: ext_url = None if ext_type == "wikidata" and ext_url: return ext_url - logger.info(f"[IMG:Wikidata] No wikidata link found for {artist_id[:8]}") return None except TRANSIENT_FETCH_EXCEPTIONS: raise diff --git a/backend/repositories/coverart_disk_cache.py b/backend/repositories/coverart_disk_cache.py index cedd4be..89e3e80 100644 --- a/backend/repositories/coverart_disk_cache.py +++ b/backend/repositories/coverart_disk_cache.py @@ -101,8 +101,8 @@ class CoverDiskCache: await asyncio.gather(write_content(), write_meta(), write_wikidata()) await self.enforce_size_limit() - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to write disk cache: {e}") + except Exception: # noqa: BLE001 + pass async def write_negative( self, @@ -121,8 +121,8 @@ class CoverDiskCache: meta_path = file_path.with_suffix(".meta.json") async with aiofiles.open(meta_path, "w") as f: await f.write(_encode_json(meta)) - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to write negative disk cache: {e}") + except Exception: # noqa: BLE001 + pass async def is_negative(self, file_path: Path) -> bool: meta_path = file_path.with_suffix(".meta.json") @@ -147,8 +147,7 @@ class CoverDiskCache: task = asyncio.create_task(self._update_meta_access(meta_path, meta)) task.add_done_callback(_log_task_error) return True - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to read negative disk cache: {e}") + except Exception: # noqa: BLE001 return False async def read( @@ -199,8 +198,7 @@ class CoverDiskCache: task = asyncio.create_task(self._update_meta_access(file_path.with_suffix('.meta.json'), meta)) task.add_done_callback(_log_task_error) return content, content_type, extra_data if extra_data else None - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to read disk cache: {e}") + except Exception: # noqa: BLE001 return None async def _update_meta_access(self, meta_file: Path, meta: dict) -> None: @@ -210,8 +208,8 @@ class CoverDiskCache: meta['last_accessed'] = datetime.now().timestamp() async with aiofiles.open(meta_file, 'w') as f: await f.write(_encode_json(meta)) - except OSError as exc: - logger.debug("Failed to update coverart disk cache meta %s: %s", meta_file, exc) + except OSError: + pass async def get_content_hash(self, file_path: Path) -> Optional[str]: meta_path = file_path.with_suffix('.meta.json') @@ -249,8 +247,7 @@ class CoverDiskCache: meta['content_sha1'] = content_hash await self._update_meta_access(meta_path, meta) return content_hash - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to get disk cache content hash: {e}") + except Exception: # noqa: BLE001 return None async def enforce_size_limit(self, force: bool = False) -> int: @@ -311,13 +308,6 @@ class CoverDiskCache: if bytes_freed >= bytes_to_free: break - if bytes_freed > 0: - logger.info( - "Evicted %d bytes from cover cache (target max=%d bytes)", - bytes_freed, - self.max_size_bytes, - ) - return bytes_freed async def delete_by_identifiers(self, identifiers: list[tuple[str, str]]) -> int: @@ -334,7 +324,7 @@ class CoverDiskCache: return count def cleanup_expired(self) -> int: - """Sync — call via asyncio.to_thread() from background tasks.""" + """Synchronous helper for background tasks via asyncio.to_thread().""" count = 0 now = datetime.now().timestamp() if not self.cache_dir.exists(): @@ -350,12 +340,10 @@ class CoverDiskCache: meta_path.unlink(missing_ok=True) (self.cache_dir / f"{stem}.wikidata").unlink(missing_ok=True) count += 1 - if count: - logger.info("Expired cover cache cleanup: removed %d entries", count) return count def demote_orphaned(self, valid_hashes: set[str]) -> int: - """Sync — call via asyncio.to_thread() from background tasks.""" + """Synchronous helper for background tasks via asyncio.to_thread().""" count = 0 now = datetime.now().timestamp() if not self.cache_dir.exists(): @@ -377,8 +365,6 @@ class CoverDiskCache: except Exception: # noqa: BLE001 continue count += 1 - if count: - logger.info("Demoted %d orphaned monitored covers to expiring", count) return count def get_file_path(self, identifier: str, suffix: str) -> Path: @@ -412,8 +398,6 @@ class CoverDiskCache: meta.pop('expires_at', None) async with aiofiles.open(meta_path, 'w') as f: await f.write(_encode_json(meta)) - logger.debug(f"Promoted cover cache to persistent: {identifier_type}={identifier}, size={size}") return True - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to promote cover cache to persistent: {e}") + except Exception: # noqa: BLE001 return False diff --git a/backend/repositories/coverart_repository.py b/backend/repositories/coverart_repository.py index 7cf008a..6f342f3 100644 --- a/backend/repositories/coverart_repository.py +++ b/backend/repositories/coverart_repository.py @@ -224,7 +224,7 @@ class CoverArtRepository: task = asyncio.create_task(self._disk_cache.enforce_size_limit(force=True)) task.add_done_callback(_log_task_error) except RuntimeError: - logger.debug("No running event loop to enforce cover cache size at initialization") + pass @property def disk_cache(self) -> CoverDiskCache: @@ -497,11 +497,9 @@ class CoverArtRepository: file_path = self._disk_cache.get_file_path(identifier, "img") if cached_memory := await self._memory_get(identifier, "img"): - logger.debug(f"Cache HIT (memory): Artist image {artist_id[:8]}...") return cached_memory if cached := await self._disk_cache.read(file_path, ["source", "wikidata_id"]): - logger.debug(f"Cache HIT (disk): Artist image {artist_id[:8]}...") source = "wikidata" if cached[2] and isinstance(cached[2], dict): source = cached[2].get("source") or source @@ -512,12 +510,10 @@ class CoverArtRepository: if size and size != 250: fallback_identifier = f"artist_{artist_id}_250" if cached_memory := await self._memory_get(fallback_identifier, "img"): - logger.debug(f"Cache HIT (memory - fallback 250px): Artist image {artist_id[:8]}...") return cached_memory fallback_path = self._disk_cache.get_file_path(fallback_identifier, "img") if cached := await self._disk_cache.read(fallback_path, ["source", "wikidata_id"]): - logger.debug(f"Cache HIT (disk - fallback 250px): Artist image {artist_id[:8]}...") source = "wikidata" if cached[2] and isinstance(cached[2], dict): source = cached[2].get("source") or source @@ -526,11 +522,8 @@ class CoverArtRepository: return result if await self._disk_cache.is_negative(file_path): - logger.debug(f"Cache HIT (disk-negative): Artist image {artist_id[:8]}...") return None - logger.debug(f"Cache MISS (disk): Artist image {artist_id[:8]}... - fetching from Wikidata") - dedupe_key = f"artist:img:{artist_id}:{size}" try: result = await _deduplicator.dedupe( @@ -540,11 +533,6 @@ class CoverArtRepository: except ClientDisconnectedError: raise except (TransientImageFetchError, CircuitOpenError, httpx.HTTPError, ExternalServiceError, RateLimitedError) as e: - logger.warning( - "Transient artist image fetch failure for %s: %s", - artist_id[:8], - e, - ) _record_degradation(f"Artist image fetch failed for {artist_id[:8]}: {e}") return None @@ -572,11 +560,9 @@ class CoverArtRepository: file_path = self._disk_cache.get_file_path(identifier, suffix) if cached_memory := await self._memory_get(identifier, suffix): - logger.debug(f"Cache HIT (memory): Album cover {release_group_id[:8]}...") return cached_memory if cached := await self._disk_cache.read(file_path, ["source"]): - logger.debug(f"Cache HIT (disk): Album cover {release_group_id[:8]}...") source = "cover-art-archive" if cached[2] and isinstance(cached[2], dict): source = cached[2].get("source") or source @@ -585,11 +571,8 @@ class CoverArtRepository: return result if await self._disk_cache.is_negative(file_path): - logger.debug(f"Cache HIT (disk-negative): Album cover {release_group_id[:8]}...") return None - logger.debug(f"Cache MISS (disk): Album cover {release_group_id[:8]}... - fetching from CoverArtArchive") - dedupe_key = f"cover:rg:{release_group_id}:{size}" result = await _deduplicator.dedupe( dedupe_key, @@ -619,7 +602,6 @@ class CoverArtRepository: file_path = self._disk_cache.get_file_path(identifier, suffix) if cached_memory := await self._memory_get(identifier, suffix): - logger.debug(f"Cache HIT (memory): Release cover {release_id[:8]}...") return cached_memory if cached := await self._disk_cache.read(file_path, ["source"]): @@ -631,7 +613,6 @@ class CoverArtRepository: return result if await self._disk_cache.is_negative(file_path): - logger.debug(f"Cache HIT (disk-negative): Release cover {release_id[:8]}...") return None dedupe_key = f"cover:rel:{release_id}:{size}" @@ -678,16 +659,10 @@ class CoverArtRepository: async with semaphore: try: await self.get_release_group_cover(album_id, size) - except Exception as e: # noqa: BLE001 - error_msg = str(e) - if "Invalid" in error_msg or "MBID" in error_msg: - logger.warning(f"Invalid MBID in batch prefetch: {album_id} - {e}") - else: - logger.debug(f"Failed to prefetch cover for {album_id}: {e}") + except Exception: # noqa: BLE001 + pass - logger.info(f"Batch prefetching {len(valid_album_ids)} covers with max {max_concurrent} concurrent requests") await asyncio.gather(*[fetch_with_limit(aid) for aid in valid_album_ids], return_exceptions=True) - logger.debug(f"Completed batch prefetch of {len(valid_album_ids)} covers") async def promote_cover_to_persistent(self, identifier: str, identifier_type: str = "album") -> bool: return await self._disk_cache.promote_to_persistent(identifier, identifier_type) diff --git a/backend/repositories/jellyfin_repository.py b/backend/repositories/jellyfin_repository.py index 19fbecd..bb0b184 100644 --- a/backend/repositories/jellyfin_repository.py +++ b/backend/repositories/jellyfin_repository.py @@ -549,7 +549,6 @@ class JellyfinRepository: ): return item except Exception as e: # noqa: BLE001 - logger.debug(f"MBID search fallback failed for {musicbrainz_id}: {e}") _record_degradation(f"Album MBID search fallback failed: {e}") return None @@ -563,7 +562,6 @@ class JellyfinRepository: if item.provider_ids.get("MusicBrainzArtist") == musicbrainz_id: return item except Exception as e: # noqa: BLE001 - logger.debug(f"Artist MBID search fallback failed for {musicbrainz_id}: {e}") _record_degradation(f"Artist MBID search fallback failed: {e}") return None @@ -665,9 +663,6 @@ class JellyfinRepository: ) if sqlite_index: await self._cache.set(cache_key, sqlite_index, ttl_seconds=3600) - logger.info( - f"Loaded MBID index from SQLite with {len(sqlite_index)} entries" - ) return sqlite_index index: dict[str, str] = {} @@ -714,7 +709,6 @@ class JellyfinRepository: await self._cache.set(cache_key, index, ttl_seconds=3600) if self._mbid_store: await self._mbid_store.save_jellyfin_mbid_index(index) - logger.info(f"Built Jellyfin MBID index with {len(index)} entries") except Exception as e: # noqa: BLE001 logger.error(f"Failed to build MBID index: {e}") _record_degradation(f"Failed to build MBID index: {e}") @@ -1056,11 +1050,9 @@ class JellyfinRepository: raw_play_session_id = result.get("PlaySessionId") if not raw_play_session_id: - logger.warning( - "PlaybackInfo returned null PlaySessionId", - extra={"item_id": item_id}, - ) - play_session_id = raw_play_session_id or "" + play_session_id = "" + else: + play_session_id = raw_play_session_id media_sources = result.get("MediaSources") or [] if not media_sources: raise ExternalServiceError(f"Playback info missing media sources for {item_id}") diff --git a/backend/repositories/lastfm_repository.py b/backend/repositories/lastfm_repository.py index edf6c83..d205689 100644 --- a/backend/repositories/lastfm_repository.py +++ b/backend/repositories/lastfm_repository.py @@ -274,10 +274,6 @@ class LastFmRepository: signed=True, http_method="POST", ) - logger.info( - "Now playing reported to Last.fm", - extra={"artist": artist, "track": track}, - ) return True async def scrobble( @@ -306,10 +302,6 @@ class LastFmRepository: signed=True, http_method="POST", ) - logger.info( - "Scrobble submitted to Last.fm", - extra={"artist": artist, "track": track, "timestamp": timestamp}, - ) return True diff --git a/backend/repositories/lidarr/album.py b/backend/repositories/lidarr/album.py index 0dc897c..94d6aba 100644 --- a/backend/repositories/lidarr/album.py +++ b/backend/repositories/lidarr/album.py @@ -102,7 +102,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): cover_url = constructed_url if cover_url: - logger.debug(f"[Lidarr:Album] Found cover for {album_mbid[:8]}: {cover_url[:60]}...") await self._cache.set(cache_key, cover_url, ttl_seconds=3600) return cover_url @@ -110,7 +109,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): return None except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to get album image from Lidarr for {album_mbid}: {e}") return None async def get_album_details(self, album_mbid: str) -> Optional[dict[str, Any]]: @@ -193,11 +191,9 @@ class LidarrAlbumRepository(LidarrHistoryRepository): } await self._cache.set(cache_key, result, ttl_seconds=300) - logger.debug(f"[Lidarr] Fetched album details for {album_mbid[:8]}") return result except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to get album details from Lidarr for {album_mbid}: {e}") return None async def get_album_tracks(self, album_id: int) -> list[dict[str, Any]]: @@ -231,11 +227,9 @@ class LidarrAlbumRepository(LidarrHistoryRepository): tracks.sort(key=lambda t: (t["disc_number"], t["track_number"])) await self._cache.set(cache_key, tracks, ttl_seconds=300) - logger.debug(f"[Lidarr] Fetched {len(tracks)} tracks for album ID {album_id}") return tracks except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to get tracks from Lidarr for album ID {album_id}: {e}") return [] async def get_track_file(self, track_file_id: int) -> dict[str, Any] | None: @@ -277,7 +271,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): items = await self._get("/api/v1/album", params={"foreignAlbumId": album_mbid}) return items[0] if items else None except Exception as e: # noqa: BLE001 - logger.warning(f"Error getting album by foreign ID {album_mbid}: {e}") return None _ALBUM_MUTABLE_FIELDS = frozenset({"monitored"}) @@ -298,7 +291,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): params = {"deleteFiles": str(delete_files).lower(), "addImportListExclusion": "false"} await self._delete(f"/api/v1/album/{album_id}", params=params) await self._invalidate_album_list_caches() - logger.info(f"Deleted album ID {album_id} (deleteFiles={delete_files})") return True except Exception as e: logger.error(f"Failed to delete album {album_id}: {e}") @@ -380,11 +372,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): is_monitored = album_obj.get("monitored", False) if has_files and is_monitored: - total_ms = int((time.monotonic() - t0) * 1000) - logger.info( - "add_album timing: album=%s artist_ensure=%dms total=%dms (already downloaded)", - musicbrainz_id[:8], artist_ensure_ms, total_ms, - ) await self._invalidate_album_list_caches() return { "message": f"Album already downloaded: {album_title}", @@ -396,8 +383,8 @@ class LidarrAlbumRepository(LidarrHistoryRepository): try: await self._post_command({"name": "AlbumSearch", "albumIds": [album_id]}) - except ExternalServiceError as exc: - logger.warning("Failed to queue AlbumSearch for %s: %s", musicbrainz_id, exc) + except ExternalServiceError: + pass await self._unmonitor_auto_monitored_albums( artist_id, musicbrainz_id, album_id, pre_add_monitored_ids @@ -405,19 +392,13 @@ class LidarrAlbumRepository(LidarrHistoryRepository): await self._invalidate_album_list_caches() await self._cache.clear_prefix(f"{LIDARR_PREFIX}artists:mbids") - total_ms = int((time.monotonic() - t0) * 1000) - logger.info( - "add_album timing: album=%s artist_ensure=%dms total=%dms (existing album, monitor+search)", - musicbrainz_id[:8], artist_ensure_ms, total_ms, - ) - return { "message": f"Album monitored & search triggered: {album_title}", "monitored": True, "payload": album_obj, } - # Album doesn't exist yet — wait for indexing after artist add/refresh + # The album does not exist yet, so wait for indexing after the artist add or refresh. if artist_created: await self._wait_for_artist_commands_to_complete(artist_id, timeout=120.0) @@ -469,7 +450,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): except ExternalServiceError as e: err_str = str(e).lower() if "already exists" in err_str: - logger.info("Album %s already exists per Lidarr, fetching", musicbrainz_id) album_obj = await self._get_album_by_foreign_id(musicbrainz_id) if album_obj: if not album_obj.get("monitored"): @@ -483,7 +463,7 @@ class LidarrAlbumRepository(LidarrHistoryRepository): elif "post failed" in err_str or "405" in err_str or "metadata" in err_str: raise ExternalServiceError( f"Lidarr rejected '{album_title}' ({album_type}" - f"{' — ' + ', '.join(secondary_types) if secondary_types else ''}). " + f"{': ' + ', '.join(secondary_types) if secondary_types else ''}). " f"Your Metadata Profile probably excludes {album_type}s. " f"Go to Lidarr > Settings > Profiles > Metadata Profiles and enable '{album_type}'." ) @@ -508,8 +488,8 @@ class LidarrAlbumRepository(LidarrHistoryRepository): try: await self._post_command({"name": "AlbumSearch", "albumIds": [album_id]}) - except ExternalServiceError as exc: - logger.warning("Failed to queue AlbumSearch for %s: %s", musicbrainz_id, exc) + except ExternalServiceError: + pass # Unmonitor albums that Lidarr auto-monitored during the add await self._unmonitor_auto_monitored_albums( @@ -521,12 +501,6 @@ class LidarrAlbumRepository(LidarrHistoryRepository): await self._invalidate_album_list_caches() await self._cache.clear_prefix(f"{LIDARR_PREFIX}artists:mbids") - total_ms = int((time.monotonic() - t0) * 1000) - logger.info( - "add_album timing: album=%s artist_ensure=%dms total=%dms (new album, created=%s)", - musicbrainz_id[:8], artist_ensure_ms, total_ms, artist_created, - ) - return { "message": f"Album added & monitored: {album_title}", "monitored": True, @@ -560,8 +534,8 @@ class LidarrAlbumRepository(LidarrHistoryRepository): if not has_running_commands: break - except Exception as e: # noqa: BLE001 - logger.warning(f"Error checking command status: {e}") + except Exception: # noqa: BLE001 + pass await asyncio.sleep(5.0) @@ -627,9 +601,5 @@ class LidarrAlbumRepository(LidarrHistoryRepository): "/api/v1/album/monitor", {"albumIds": to_unmonitor, "monitored": False}, ) - logger.info( - "Unmonitored %d auto-monitored albums for artist %d (kept requested %s)", - len(to_unmonitor), artist_id, requested_mbid[:8], - ) - except ExternalServiceError as exc: - logger.warning("Failed to unmonitor auto-monitored albums: %s", exc) + except ExternalServiceError: + pass diff --git a/backend/repositories/lidarr/artist.py b/backend/repositories/lidarr/artist.py index d045163..adc8ce8 100644 --- a/backend/repositories/lidarr/artist.py +++ b/backend/repositories/lidarr/artist.py @@ -16,17 +16,11 @@ class LidarrArtistRepository(LidarrBase): cache_key = f"{LIDARR_ARTIST_IMAGE_PREFIX}{artist_mbid}:{size or 'orig'}" cached_url = await self._cache.get(cache_key) if cached_url is not None: - if cached_url: - logger.debug(f"[Lidarr:Image] Cache HIT for {artist_mbid[:8]}") - else: - logger.debug(f"[Lidarr:Image] Cache HIT (negative) for {artist_mbid[:8]}") return cached_url if cached_url else None - logger.info(f"[Lidarr:Image] Cache MISS - querying Lidarr for {artist_mbid[:8]}") try: data = await self._get("/api/v1/artist", params={"mbId": artist_mbid}) if not data or not isinstance(data, list) or len(data) == 0: - logger.info(f"[Lidarr:Image] Artist not found in Lidarr for {artist_mbid[:8]}") await self._cache.set(cache_key, "", ttl_seconds=300) return None @@ -34,10 +28,8 @@ class LidarrArtistRepository(LidarrBase): artist_id = artist.get("id") artist_name = artist.get("artistName", "Unknown") images = artist.get("images", []) - logger.debug(f"[Lidarr:Image] Found artist '{artist_name}' (id={artist_id}) with {len(images)} images") if not artist_id or not images: - logger.info(f"[Lidarr:Image] No images for {artist_mbid[:8]} ({artist_name})") await self._cache.set(cache_key, "", ttl_seconds=300) return None @@ -63,7 +55,6 @@ class LidarrArtistRepository(LidarrBase): image_url = poster_url or fanart_url if image_url: - logger.info(f"[Lidarr:Image] Found image for {artist_mbid[:8]} ({artist_name}): {image_url[:60]}...") await self._cache.set(cache_key, image_url, ttl_seconds=3600) return image_url @@ -72,7 +63,6 @@ class LidarrArtistRepository(LidarrBase): return None except Exception as e: # noqa: BLE001 - logger.warning(f"[Lidarr:Image] Exception for {artist_mbid[:8]}: {e}") return None async def get_artist_details(self, artist_mbid: str) -> Optional[dict[str, Any]]: @@ -119,11 +109,9 @@ class LidarrArtistRepository(LidarrBase): } await self._cache.set(cache_key, result, ttl_seconds=300) - logger.debug(f"[Lidarr] Fetched artist details for {artist_mbid[:8]}") return result except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to get artist details from Lidarr for {artist_mbid}: {e}") return None async def get_artist_albums(self, artist_mbid: str) -> list[dict[str, Any]]: @@ -193,25 +181,21 @@ class LidarrArtistRepository(LidarrBase): albums.sort(key=lambda a: a.get("release_date") or "", reverse=True) await self._cache.set(cache_key, albums, ttl_seconds=300) - logger.debug(f"[Lidarr] Fetched {len(albums)} albums for artist {artist_mbid[:8]}") return albums except Exception as e: # noqa: BLE001 - logger.debug(f"Failed to get artist albums from Lidarr for {artist_mbid}: {e}") return [] async def _get_artist_by_id(self, artist_id: int) -> Optional[dict[str, Any]]: try: return await self._get(f"/api/v1/artist/{artist_id}") except Exception as e: # noqa: BLE001 - logger.warning(f"Error getting artist {artist_id}: {e}") return None async def delete_artist(self, artist_id: int, delete_files: bool = False) -> bool: try: params = {"deleteFiles": str(delete_files).lower(), "addImportListExclusion": "false"} await self._delete(f"/api/v1/artist/{artist_id}", params=params) - logger.info(f"Deleted artist ID {artist_id} (deleteFiles={delete_files})") return True except Exception as e: logger.error(f"Failed to delete artist {artist_id}: {e}") @@ -243,10 +227,6 @@ class LidarrArtistRepository(LidarrBase): cache_key = f"{LIDARR_ARTIST_DETAILS_PREFIX}{artist_mbid}" await self._cache.delete(cache_key) - logger.info( - "Updated artist %s monitoring: monitored=%s, monitorNewItems=%s", - artist_mbid[:8], monitored, monitor_new_items, - ) return {"monitored": monitored, "auto_download": monitor_new_items == "all"} async def _ensure_artist_exists( @@ -256,10 +236,9 @@ class LidarrArtistRepository(LidarrBase): try: items = await self._get("/api/v1/artist", params={"mbId": artist_mbid}) if items: - logger.info("Artist already exists: %s", items[0].get("artistName")) return items[0], False except ExternalServiceError as exc: - logger.debug("Failed to query existing Lidarr artist %s: %s", artist_mbid, exc) + pass try: roots = await self._get("/api/v1/rootfolder") @@ -300,19 +279,16 @@ class LidarrArtistRepository(LidarrBase): try: created = await self._post("/api/v1/artist", payload) artist_id = created["id"] - logger.info("Created artist %s (ID: %s), triggering refresh", artist_name, artist_id) await self._await_command( {"name": "RefreshArtist", "artistId": artist_id}, timeout=180.0, ) - logger.info("Artist %s refresh complete", artist_name) return created, True except ExternalServiceError as exc: err_str = str(exc).lower() if "already exists" in err_str or "409" in err_str: - logger.info("Artist %s was added concurrently, retrying GET", artist_mbid) items = await self._get("/api/v1/artist", params={"mbId": artist_mbid}) if items: return items[0], False diff --git a/backend/repositories/lidarr/base.py b/backend/repositories/lidarr/base.py index f12f79f..20ad940 100644 --- a/backend/repositories/lidarr/base.py +++ b/backend/repositories/lidarr/base.py @@ -1,6 +1,5 @@ import asyncio import httpx -import logging import msgspec import time from typing import Any, Optional @@ -11,8 +10,6 @@ from infrastructure.cache.memory_cache import CacheInterface from infrastructure.http.deduplication import get_deduplicator from infrastructure.resilience.retry import with_retry, CircuitBreaker -logger = logging.getLogger(__name__) - _lidarr_circuit_breaker = CircuitBreaker( failure_threshold=5, success_threshold=2, @@ -157,8 +154,7 @@ class LidarrBase: async def _post_command(self, body: dict[str, Any]) -> Any: try: return await self._post("/api/v1/command", body) - except ExternalServiceError as exc: - logger.warning("Failed to post Lidarr command %s: %s", body.get("name"), exc) + except ExternalServiceError: return None async def _get_command(self, cmd_id: int) -> Any: @@ -180,8 +176,7 @@ class LidarrBase: try: status = await self._get_command(cmd_id) last_status = status - except ExternalServiceError as exc: - logger.debug("Lidarr command %s status poll failed: %s", cmd_id, exc) + except ExternalServiceError: continue state = (status or {}).get("status") or (status or {}).get("state") @@ -189,8 +184,7 @@ class LidarrBase: return status return last_status - except ExternalServiceError as exc: - logger.warning("Failed to await Lidarr command %s: %s", body.get("name"), exc) + except ExternalServiceError: return None async def _wait_for( @@ -207,8 +201,8 @@ class LidarrBase: last = await fetch_coro_factory() if stop(last): return last - except ExternalServiceError as exc: - logger.debug("Lidarr wait_for poll failed: %s", exc) + except ExternalServiceError: + pass await asyncio.sleep(poll) return last diff --git a/backend/repositories/lidarr/config.py b/backend/repositories/lidarr/config.py index f2fa6ca..d3364ab 100644 --- a/backend/repositories/lidarr/config.py +++ b/backend/repositories/lidarr/config.py @@ -1,12 +1,9 @@ -import logging from typing import Any from models.common import ServiceStatus from models.request import QueueItem from infrastructure.cache.cache_keys import LIDARR_PREFIX from .base import LidarrBase -logger = logging.getLogger(__name__) - LIDARR_QUEUE_KEY = f"{LIDARR_PREFIX}queue" LIDARR_QUEUE_TTL = 30 diff --git a/backend/repositories/lidarr/history.py b/backend/repositories/lidarr/history.py index 4d3b7e5..510ace7 100644 --- a/backend/repositories/lidarr/history.py +++ b/backend/repositories/lidarr/history.py @@ -12,7 +12,6 @@ class LidarrHistoryRepository(LidarrBase): async def get_recently_imported(self, limit: int = 20) -> list[LibraryAlbum]: try: album_dates: dict[str, tuple[int, dict]] = {} - try: params = { "page": 1, @@ -52,16 +51,13 @@ class LidarrHistoryRepository(LidarrBase): 'album_data': album_data, 'artist_data': record.get("artist", {}) }) - - logger.info(f"Found {len(album_dates)} unique albums from {len(history_data.get('records', []))} history records") - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to get history data: {e}") + except Exception: # noqa: BLE001 + pass if len(album_dates) < limit * 2: album_dates = await self._supplement_with_album_dates(album_dates, limit) if not album_dates: - logger.warning("No albums found with dates from either history or track files") return [] sorted_albums = sorted(album_dates.items(), key=lambda x: x[1][0], reverse=True) @@ -111,10 +107,8 @@ class LidarrHistoryRepository(LidarrBase): 'album_data': album, 'artist_data': album.get("artist", {}) }) - - logger.info(f"Total {len(album_dates)} unique albums after supplementing with album dates") - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to supplement with album data: {e}") + except Exception: # noqa: BLE001 + pass return album_dates @@ -153,7 +147,6 @@ class LidarrHistoryRepository(LidarrBase): artist_mbid=artist_mbid, date_added=date_added, ) - ) + ) - logger.info(f"Retrieved {len(out)} recently added albums (merged from history and track files)") - return out + return out diff --git a/backend/repositories/lidarr/library.py b/backend/repositories/lidarr/library.py index 0a6d11d..65df908 100644 --- a/backend/repositories/lidarr/library.py +++ b/backend/repositories/lidarr/library.py @@ -1,4 +1,3 @@ -import logging from datetime import datetime from typing import Any, TYPE_CHECKING from models.library import LibraryAlbum, LibraryGroupedAlbum, LibraryGroupedArtist @@ -16,8 +15,6 @@ from .base import LidarrBase if TYPE_CHECKING: from infrastructure.persistence.request_history import RequestHistoryStore -logger = logging.getLogger(__name__) - class LidarrLibraryRepository(LidarrBase): _request_history_store: "RequestHistoryStore | None" = None @@ -63,8 +60,8 @@ class LidarrLibraryRepository(LidarrBase): try: dt = datetime.fromisoformat(added_str.replace('Z', '+00:00')) date_added = int(dt.timestamp()) - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to parse date_added '{added_str}' for album '{item.get('title')}': {e}") + except Exception: # noqa: BLE001 + pass out.append( LibraryAlbum( @@ -80,9 +77,6 @@ class LidarrLibraryRepository(LidarrBase): ) ) - if filtered_count > 0: - logger.info(f"Filtered out {filtered_count} unmonitored albums from library") - await self._cache.set(cache_key, out, ttl_seconds=300) return out @@ -115,8 +109,8 @@ class LidarrLibraryRepository(LidarrBase): try: dt = datetime.fromisoformat(added_str.replace('Z', '+00:00')) date_added = int(dt.timestamp()) - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to parse date_added '{added_str}' for artist '{artist_name}': {e}") + except Exception: # noqa: BLE001 + pass if artist_mbid not in artists_dict: artists_dict[artist_mbid] = { @@ -131,9 +125,6 @@ class LidarrLibraryRepository(LidarrBase): date_added < artists_dict[artist_mbid]['date_added']): artists_dict[artist_mbid]['date_added'] = date_added - if filtered_count > 0: - logger.info(f"Filtered out {filtered_count} unmonitored albums from artist extraction") - result = list(artists_dict.values()) await self._cache.set(cache_key, result, ttl_seconds=300) return result @@ -235,8 +226,7 @@ class LidarrLibraryRepository(LidarrBase): if self._request_history_store is not None: try: return await self._request_history_store.async_get_active_mbids() - except Exception as e: # noqa: BLE001 - logger.warning("RequestHistoryStore unavailable, falling back to empty set: %s", e) + except Exception: # noqa: BLE001 return set() return set() diff --git a/backend/repositories/listenbrainz_repository.py b/backend/repositories/listenbrainz_repository.py index dd10e98..ba0e319 100644 --- a/backend/repositories/listenbrainz_repository.py +++ b/backend/repositories/listenbrainz_repository.py @@ -1,6 +1,5 @@ import asyncio import httpx -import logging from typing import Any import msgspec @@ -22,8 +21,6 @@ from repositories.listenbrainz_models import ( from infrastructure.degradation import try_get_degradation_context from infrastructure.integration_result import IntegrationResult -logger = logging.getLogger(__name__) - _SOURCE = "listenbrainz" @@ -590,11 +587,6 @@ class ListenBrainzRepository: result = await self._get(f"/1/popularity/top-release-groups-for-artist/{artist_mbid}") if not result or not isinstance(result, list): - logger.info( - "LB top-release-groups returned empty/non-list for %s (type=%s)", - artist_mbid[:8], - type(result).__name__, - ) return [] release_groups = [] @@ -663,10 +655,6 @@ class ListenBrainzRepository: "payload": [{"track_metadata": track_metadata}], } await self._post("/1/submit-listens", payload, require_auth=True) - logger.info( - "Now playing reported to ListenBrainz", - extra={"artist": artist_name, "track": track_name}, - ) return True async def submit_single_listen( @@ -696,14 +684,6 @@ class ListenBrainzRepository: ], } await self._post("/1/submit-listens", payload, require_auth=True) - logger.info( - "Scrobble submitted to ListenBrainz", - extra={ - "artist": artist_name, - "track": track_name, - "listened_at": listened_at, - }, - ) return True async def get_recommendation_playlists( @@ -790,9 +770,4 @@ class ListenBrainzRepository: if tracks: await self._cache.set(cache_key, playlist, ttl_seconds=21600) - logger.info( - "Fetched recommendation playlist: %s (%d tracks)", - playlist.title, - len(tracks), - ) return playlist diff --git a/backend/repositories/musicbrainz_album.py b/backend/repositories/musicbrainz_album.py index b9cad1e..cb9aee0 100644 --- a/backend/repositories/musicbrainz_album.py +++ b/backend/repositories/musicbrainz_album.py @@ -288,7 +288,6 @@ class MusicBrainzAlbumMixin: cache_key = f"{MB_RELEASE_TO_RG_PREFIX}{release_id}" cached = await self._cache.get(cache_key) if cached is not None: - logger.debug(f"[MB] Cache hit for release {release_id[:8]}: '{cached[:8] if cached else 'empty'}'") return cached if cached != "" else None dedupe_key = f"{MB_RELEASE_TO_RG_PREFIX}{release_id}" @@ -303,7 +302,6 @@ class MusicBrainzAlbumMixin: cache_key: str, ) -> str | None: try: - logger.debug(f"[MB] Fetching release group for release {release_id[:8]}") result = await mb_api_get( f"/release/{release_id}", params={"inc": "release-groups+recordings"}, @@ -312,7 +310,6 @@ class MusicBrainzAlbumMixin: ) rg = result.release_group rg_id = rg.get("id") - logger.debug(f"[MB] Resolved release {release_id[:8]} -> release_group {rg_id}") await self._cache.set(cache_key, rg_id or "", ttl_seconds=86400) positions: dict[str, list[int]] = {} @@ -330,7 +327,6 @@ class MusicBrainzAlbumMixin: return rg_id except Exception as e: # noqa: BLE001 - logger.warning(f"[MB] Failed to get release group for release {release_id[:8]}: {e}") _record_mb_degradation(f"release-to-rg lookup failed: {e}") await self._cache.set(cache_key, "", ttl_seconds=3600) return None diff --git a/backend/repositories/musicbrainz_artist.py b/backend/repositories/musicbrainz_artist.py index 613d87d..64203eb 100644 --- a/backend/repositories/musicbrainz_artist.py +++ b/backend/repositories/musicbrainz_artist.py @@ -255,7 +255,7 @@ class MusicBrainzArtistMixin: try: await self.get_release_group_by_id(rg_id, priority=RequestPriority.BACKGROUND_SYNC) except (CircuitOpenError, ExternalServiceError, httpx.HTTPError) as exc: - logger.debug("Failed to warm release group cache for %s: %s", rg_id, exc) + pass async def get_artist_release_groups( self, diff --git a/backend/repositories/musicbrainz_base.py b/backend/repositories/musicbrainz_base.py index dd417df..31b92cd 100644 --- a/backend/repositories/musicbrainz_base.py +++ b/backend/repositories/musicbrainz_base.py @@ -1,4 +1,3 @@ -import logging from typing import Any, TypeVar import httpx @@ -10,8 +9,6 @@ from infrastructure.resilience.rate_limiter import TokenBucketRateLimiter from infrastructure.queue.priority_queue import RequestPriority, get_priority_queue from infrastructure.http.deduplication import RequestDeduplicator -logger = logging.getLogger(__name__) - MB_API_BASE = "https://musicbrainz.org/ws/2" mb_circuit_breaker = CircuitBreaker( diff --git a/backend/repositories/navidrome_models.py b/backend/repositories/navidrome_models.py index c4fcfd3..cf702cb 100644 --- a/backend/repositories/navidrome_models.py +++ b/backend/repositories/navidrome_models.py @@ -1,6 +1,5 @@ from __future__ import annotations -import logging from collections.abc import AsyncIterator from typing import Any @@ -8,8 +7,6 @@ import msgspec from core.exceptions import NavidromeApiError, NavidromeAuthError, NavidromeSubsonicError -logger = logging.getLogger(__name__) - class SubsonicArtist(msgspec.Struct): id: str diff --git a/backend/repositories/navidrome_repository.py b/backend/repositories/navidrome_repository.py index a73928b..7f5271b 100644 --- a/backend/repositories/navidrome_repository.py +++ b/backend/repositories/navidrome_repository.py @@ -264,7 +264,6 @@ class NavidromeRepository: await self._request("/rest/ping") return True except Exception: # noqa: BLE001 - logger.debug("Navidrome ping failed", exc_info=True) _record_degradation("Navidrome ping failed") return False @@ -537,7 +536,6 @@ class NavidromeRepository: await self._request("/rest/scrobble", params) return True except Exception: # noqa: BLE001 - logger.warning("Navidrome scrobble failed", exc_info=True) _record_degradation("Navidrome scrobble failed") return False @@ -547,7 +545,6 @@ class NavidromeRepository: await self._request("/rest/scrobble", params) return True except Exception: # noqa: BLE001 - logger.warning("Navidrome now-playing report failed", exc_info=True) _record_degradation("Navidrome now-playing report failed") return False diff --git a/backend/repositories/playlist_repository.py b/backend/repositories/playlist_repository.py index dd4a253..d515000 100644 --- a/backend/repositories/playlist_repository.py +++ b/backend/repositories/playlist_repository.py @@ -1,5 +1,4 @@ import json -import logging import sqlite3 import threading from datetime import datetime, timezone @@ -7,8 +6,6 @@ from pathlib import Path from typing import Optional from uuid import uuid4 -logger = logging.getLogger(__name__) - _UNSET = object() @@ -694,8 +691,8 @@ class PlaylistRepository: if conn is not None: try: conn.close() - except sqlite3.Error as exc: - logger.warning("Failed to close playlist repository connection: %s", exc) + except sqlite3.Error: + pass self._local.conn = None diff --git a/backend/repositories/youtube.py b/backend/repositories/youtube.py index dd65451..5c4f863 100644 --- a/backend/repositories/youtube.py +++ b/backend/repositories/youtube.py @@ -71,16 +71,16 @@ class YouTubeRepository: self._daily_count = 0 self._quota_date = today self._save_quota() - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to load YouTube quota state: {e}") + except Exception: # noqa: BLE001 + pass def _save_quota(self) -> None: quota_file = get_quota_file_path() try: quota_file.parent.mkdir(parents=True, exist_ok=True) quota_file.write_bytes(msgspec.json.encode(YouTubeQuotaState(date=self._quota_date, count=self._daily_count))) - except Exception as e: # noqa: BLE001 - logger.warning(f"Failed to save YouTube quota state: {e}") + except Exception: # noqa: BLE001 + pass def configure(self, api_key: str) -> None: self._api_key = api_key diff --git a/backend/services/album_service.py b/backend/services/album_service.py index 1a9f906..0e1a2c2 100644 --- a/backend/services/album_service.py +++ b/backend/services/album_service.py @@ -125,14 +125,10 @@ class AlbumService: async def _get_cached_album_info(self, release_group_id: str, cache_key: str) -> Optional[AlbumInfo]: cached_info = await self._cache.get(cache_key) if cached_info: - logger.info(f"Cache HIT (RAM): Album {release_group_id[:8]}... - instant load") return await self._revalidate_library_status(release_group_id, cached_info) - logger.debug(f"Cache MISS (RAM): Album {release_group_id[:8]}...") - disk_data = await self._disk_cache.get_album(release_group_id) if disk_data: - logger.info(f"Cache HIT (Disk): Album {release_group_id[:8]}... - loading from persistent cache") album_info = msgspec.convert(disk_data, AlbumInfo, strict=False) album_info = await self._revalidate_library_status(release_group_id, album_info) advanced_settings = self._preferences_service.get_advanced_settings() @@ -140,7 +136,6 @@ class AlbumService: await self._cache.set(cache_key, album_info, ttl_seconds=ttl) return album_info - logger.debug(f"Cache MISS (Disk): Album {release_group_id[:8]}...") return None async def _revalidate_library_status(self, release_group_id: str, album_info: AlbumInfo) -> AlbumInfo: @@ -159,10 +154,6 @@ class AlbumService: self._revalidation_timestamps[release_group_id] = time.monotonic() current_in_library = self._check_lidarr_in_library(lidarr_album) if current_in_library != album_info.in_library: - logger.info( - f"Library status changed for album {release_group_id[:8]}...: " - f"{album_info.in_library} -> {current_in_library}, updating caches" - ) album_info.in_library = current_in_library await self._save_album_to_cache(release_group_id, album_info) return album_info @@ -173,7 +164,6 @@ class AlbumService: ttl = advanced_settings.cache_ttl_album_library if album_info.in_library else advanced_settings.cache_ttl_album_non_library await self._cache.set(cache_key, album_info, ttl_seconds=ttl) await self._disk_cache.set_album(release_group_id, album_info, is_monitored=album_info.in_library, ttl_seconds=ttl if not album_info.in_library else None) - logger.info(f"Cached {'library' if album_info.in_library else 'non-library'} album {release_group_id[:8]}... for {ttl // 3600}h") def _check_lidarr_in_library(self, lidarr_album: dict | None) -> bool: if lidarr_album and lidarr_album.get("monitored", False): @@ -189,7 +179,7 @@ class AlbumService: return await self.get_album_info(release_group_id) except Exception: # noqa: BLE001 - logger.debug(f"Background album cache warm failed for {release_group_id[:8]}") + pass async def refresh_album(self, release_group_id: str) -> AlbumInfo: release_group_id = validate_mbid(release_group_id, "album") @@ -200,7 +190,6 @@ class AlbumService: self._revalidation_timestamps.pop(release_group_id, None) self._album_in_flight.pop(release_group_id, None) - logger.info("Cleared all caches for album %s", release_group_id[:8]) return await self.get_album_info(release_group_id) async def get_album_info(self, release_group_id: str, monitored_mbids: set[str] = None) -> AlbumInfo: @@ -248,10 +237,8 @@ class AlbumService: lidarr_album = await self._lidarr_repo.get_album_details(release_group_id) if self._lidarr_repo.is_configured() else None in_library = self._check_lidarr_in_library(lidarr_album) if in_library and lidarr_album: - logger.info(f"Using Lidarr as primary source for album {release_group_id[:8]}") album_info = await self._build_album_from_lidarr(release_group_id, lidarr_album) else: - logger.info(f"Using MusicBrainz as primary source for album {release_group_id[:8]}") album_info = await self._build_album_from_musicbrainz(release_group_id, monitored_mbids) album_info = await self._apply_audiodb_album_images( album_info, release_group_id, album_info.artist_name, album_info.title, @@ -306,7 +293,6 @@ class AlbumService: lidarr_album = await self._lidarr_repo.get_album_details(release_group_id) if self._lidarr_repo.is_configured() else None in_library = self._check_lidarr_in_library(lidarr_album) if lidarr_album and lidarr_album.get("monitored", False): - logger.info(f"[BASIC] Using Lidarr for album {release_group_id[:8]}") basic = AlbumBasicInfo(**lidarr_to_basic_info(lidarr_album, release_group_id, in_library, is_requested=is_requested)) if not basic.album_thumb_url: basic.album_thumb_url = await self._get_audiodb_album_thumb( @@ -314,7 +300,6 @@ class AlbumService: allow_fetch=False, ) return basic - logger.info(f"[BASIC] Using MusicBrainz for album {release_group_id[:8]}") release_group = await self._fetch_release_group(release_group_id) if lidarr_album is None: cached_album = await self._library_db.get_album_by_mbid(release_group_id) @@ -356,7 +341,6 @@ class AlbumService: in_library = lidarr_album is not None and lidarr_album.get("monitored", False) if in_library and lidarr_album: - logger.info(f"[TRACKS] Using Lidarr for album {release_group_id[:8]}") album_id = lidarr_album.get("id") tracks = [] total_length = 0 @@ -384,7 +368,6 @@ class AlbumService: country=None, ) - logger.info(f"[TRACKS] Using MusicBrainz for album {release_group_id[:8]}") release_group = await self._fetch_release_group(release_group_id) ranked_releases = get_ranked_releases(release_group) @@ -519,7 +502,6 @@ class AlbumService: country = None if not tracks: - logger.debug(f"No tracks from Lidarr for album {release_group_id[:8]}, falling back to MusicBrainz") try: release_group = await self._fetch_release_group(release_group_id) ranked_releases = get_ranked_releases(release_group) @@ -586,12 +568,6 @@ class AlbumService: cached_album = await self._library_db.get_album_by_mbid(release_group_id) in_library = cached_album is not None - if in_library: - logger.info(f"Cache HIT (library DB): Album {release_group_id[:8]}... is in library") - else: - logger.debug(f"Cache MISS (library DB): Album {release_group_id[:8]}... not in library") - - logger.info(f"API CALL (MusicBrainz): Fetching album {release_group_id[:8]}...") release_group = await self._fetch_release_group(release_group_id) primary_release = find_primary_release(release_group) artist_name, artist_id = extract_artist_info(release_group) diff --git a/backend/services/artist_discovery_service.py b/backend/services/artist_discovery_service.py index c3b9c99..48a0f61 100644 --- a/backend/services/artist_discovery_service.py +++ b/backend/services/artist_discovery_service.py @@ -165,10 +165,8 @@ class ArtistDiscoveryService: recordings = await self._lb_repo.get_artist_top_recordings(artist_mbid, count=count) release_ids = [r.release_mbid for r in recordings if r.release_mbid] - logger.info(f"Top songs for {artist_mbid}: {len(recordings)} recordings, {len(release_ids)} with release_mbid") rg_map = await self._resolve_release_groups(release_ids) - logger.info(f"Resolved {len(rg_map)} release groups from {len(release_ids)} releases") songs = [] for r in recordings[:count]: @@ -235,7 +233,6 @@ class ArtistDiscoveryService: try: release_groups = await self._lb_repo.get_artist_top_release_groups(artist_mbid, count=count) if not release_groups: - logger.info("ListenBrainz returned no release groups for %s", artist_mbid[:8]) fallback_albums = await self._get_top_albums_from_recordings_fallback( artist_mbid, count ) @@ -414,7 +411,6 @@ class ArtistDiscoveryService: ) -> int: global _discovery_precache_running if _discovery_precache_running: - logger.info("Discovery precache already running, skipping duplicate invocation") return 0 _discovery_precache_running = True @@ -511,9 +507,6 @@ class ArtistDiscoveryService: artist_name = (mbid_to_name or {}).get(mbid, mbid[:8]) await status_service.update_progress(local_progress, current_item=artist_name, generation=generation) - if local_progress % 10 == 0: - logger.info("Discovery precache progress: %d/%d artists", local_progress, len(artist_mbids)) - return True except Exception as e: # noqa: BLE001 logger.warning("Failed to precache discovery for %s: %s", mbid[:8], e) @@ -550,19 +543,12 @@ class ArtistDiscoveryService: chunk = max(discovery_concurrency * 4, 20) for i in range(0, len(artist_mbids), chunk): if status_service and status_service.is_cancelled(): - logger.info("Discovery precache cancelled by user") break batch = artist_mbids[i:i + chunk] batch_tasks = [asyncio.create_task(process_artist_with_timeout(i + j, mbid)) for j, mbid in enumerate(batch)] if batch_tasks: await asyncio.gather(*batch_tasks, return_exceptions=True) - logger.info( - "Discovery precache complete: %d/%d artists refreshed (%d source fetches)", - cached_count, - len(artist_mbids), - source_fetches, - ) return cached_count async def _resolve_release_groups(self, release_ids: list[str]) -> dict[str, str]: @@ -570,7 +556,6 @@ class ArtistDiscoveryService: return {} unique_ids = list(dict.fromkeys(release_ids)) - logger.info(f"Resolving {len(unique_ids)} unique release IDs to release groups (from {len(release_ids)} total)") tasks = [self._mb_repo.get_release_group_id_from_release(rid) for rid in unique_ids] results = await asyncio.gather(*tasks, return_exceptions=True) @@ -586,7 +571,6 @@ class ArtistDiscoveryService: errors += 1 logger.warning(f"Resolution returned None/empty for {rid}") - logger.info(f"Release group resolution: {len(rg_map)} succeeded, {errors} failed") return rg_map async def _get_similar_artists_lastfm( diff --git a/backend/services/artist_service.py b/backend/services/artist_service.py index 1448a0a..915f3c8 100644 --- a/backend/services/artist_service.py +++ b/backend/services/artist_service.py @@ -106,10 +106,7 @@ class ArtistService: new_artist_in_library = result.musicbrainz_id and result.musicbrainz_id.lower() in artist_mbids if new_artist_in_library != result.in_library: result.in_library = new_artist_in_library - changed = True - if changed: - logger.info("Revalidated library status for cached artist %s", (result.musicbrainz_id or "")[:8]) return result async def _get_library_artist_mbids(self) -> set[str]: @@ -223,10 +220,8 @@ class ArtistService: lidarr_artist = await self._lidarr_repo.get_artist_details(artist_id) if self._lidarr_repo.is_configured() else None in_library = lidarr_artist is not None and lidarr_artist.get("monitored", False) if in_library and lidarr_artist: - logger.info(f"Using Lidarr as primary source for artist {artist_id[:8]}") artist_info = await self._build_artist_from_lidarr(artist_id, lidarr_artist, library_album_mbids) else: - logger.info(f"Using MusicBrainz as primary source for artist {artist_id[:8]}") artist_info = await self._build_artist_from_musicbrainz(artist_id, library_artist_mbids, library_album_mbids) if lidarr_artist is not None: artist_info.in_lidarr = True @@ -327,7 +322,6 @@ class ArtistService: release_group_count = len(lidarr_albums) if need_musicbrainz: - logger.debug(f"Fetching supplementary data from MusicBrainz for artist {artist_id[:8]}") try: mb_artist = result_map.get("mb_artist") if isinstance(mb_artist, Exception): @@ -426,7 +420,6 @@ class ArtistService: future: asyncio.Future[ArtistInfo] = loop.create_future() self._artist_basic_in_flight[artist_id] = future try: - logger.debug(f"Cache MISS (Disk): Artist {artist_id[:8]}... - fetching from API") artist_info = await self._build_artist_from_musicbrainz(artist_id, include_extended=False, include_releases=False) artist_info = await self._apply_audiodb_artist_images( artist_info, artist_id, artist_info.name, allow_fetch=False, @@ -481,9 +474,7 @@ class ArtistService: cache_key = f"{ARTIST_INFO_PREFIX}{artist_id}" cached_info = await self._cache.get(cache_key) if cached_info: - logger.debug(f"Cache HIT (RAM): Artist {artist_id[:8]}...") return cached_info - logger.debug(f"Cache MISS (RAM): Artist {artist_id[:8]}...") disk_data = await self._disk_cache.get_artist(artist_id) if disk_data: try: @@ -492,7 +483,6 @@ class ArtistService: logger.warning(f"Corrupt disk cache for artist {artist_id[:8]}, clearing: {e}") await self._disk_cache.delete_artist(artist_id) return None - logger.debug(f"Cache HIT (Disk): Artist {artist_id[:8]}...") ttl = self._get_artist_ttl(artist_info.in_library) await self._cache.set(cache_key, artist_info, ttl_seconds=ttl) return artist_info @@ -518,7 +508,6 @@ class ArtistService: cache_key = f"{ARTIST_INFO_PREFIX}{artist_id}" cached_info = await self._cache.get(cache_key) if cached_info and cached_info.description is not None: - logger.debug(f"Extended info cache HIT: Artist {artist_id[:8]}...") return ArtistExtendedInfo(description=cached_info.description, image=cached_info.image) mb_artist = await self._mb_repo.get_artist_by_id(artist_id) if not mb_artist: @@ -555,7 +544,6 @@ class ArtistService: included_secondary_types = set(t.lower() for t in prefs.secondary_types) if in_library and offset == 0: - logger.debug(f"Using Lidarr for artist releases {artist_id[:8]}") lidarr_albums = await self._lidarr_repo.get_artist_albums(artist_id) albums, singles, eps = self._categorize_lidarr_albums(lidarr_albums, album_mbids, requested_mbids=requested_mbids) @@ -569,7 +557,6 @@ class ArtistService: has_more=False ) - logger.debug(f"Using MusicBrainz for artist releases {artist_id[:8]}") release_groups, total_count = await self._mb_repo.get_artist_release_groups( artist_id, offset, limit ) diff --git a/backend/services/audiodb_browse_queue.py b/backend/services/audiodb_browse_queue.py index 101ebfb..b29552a 100644 --- a/backend/services/audiodb_browse_queue.py +++ b/backend/services/audiodb_browse_queue.py @@ -102,15 +102,6 @@ class AudioDBBrowseQueue: ) processed += 1 - logger.debug( - "audiodb.browse_queue action=processed entity_type=%s mbid=%s", - item.entity_type, item.mbid[:8], - ) - if processed % _BROWSE_QUEUE_LOG_INTERVAL == 0: - logger.info( - "audiodb.browse_queue processed=%d queue_depth=%d", - processed, self._queue.qsize(), - ) except Exception as e: logger.error( "audiodb.browse_queue action=item_error entity_type=%s mbid=%s error=%s", @@ -124,4 +115,4 @@ class AudioDBBrowseQueue: await asyncio.sleep(_BROWSE_QUEUE_INTER_ITEM_DELAY) except asyncio.CancelledError: - logger.info("AudioDB browse queue consumer cancelled (processed=%d)", processed) + pass diff --git a/backend/services/audiodb_image_service.py b/backend/services/audiodb_image_service.py index e1a73b3..0c4fdec 100644 --- a/backend/services/audiodb_image_service.py +++ b/backend/services/audiodb_image_service.py @@ -63,7 +63,6 @@ class AudioDBImageService: raw = await self._disk_cache.get_audiodb_artist(mbid) if raw is None: - logger.debug("audiodb.cache action=miss entity_type=artist mbid=%s lookup_source=mbid", mbid) return None try: @@ -73,10 +72,6 @@ class AudioDBImageService: await self._disk_cache.delete_entity("audiodb_artist", mbid) return None - logger.debug( - "audiodb.cache action=hit entity_type=artist mbid=%s lookup_source=%s is_negative=%s", - mbid, images.lookup_source, images.is_negative, - ) await self._mem_set("artist", mbid, images) return images @@ -92,7 +87,6 @@ class AudioDBImageService: raw = await self._disk_cache.get_audiodb_album(mbid) if raw is None: - logger.debug("audiodb.cache action=miss entity_type=album mbid=%s lookup_source=mbid", mbid) return None try: @@ -102,10 +96,6 @@ class AudioDBImageService: await self._disk_cache.delete_entity("audiodb_album", mbid) return None - logger.debug( - "audiodb.cache action=hit entity_type=album mbid=%s lookup_source=%s is_negative=%s", - mbid, images.lookup_source, images.is_negative, - ) await self._mem_set("album", mbid, images) return images @@ -151,10 +141,6 @@ class AudioDBImageService: mbid, images, is_monitored=is_monitored, ttl_seconds=ttl, ) await self._mem_set("artist", mbid, images) - logger.debug( - "audiodb.cache action=write entity_type=artist mbid=%s lookup_source=mbid is_negative=false ttl=%d", - mbid, ttl, - ) return images negative = AudioDBArtistImages.negative(lookup_source="mbid") @@ -162,10 +148,6 @@ class AudioDBImageService: mbid, negative, is_monitored=False, ttl_seconds=ttl_not_found, ) await self._mem_set("artist", mbid, negative) - logger.debug( - "audiodb.cache action=write entity_type=artist mbid=%s lookup_source=mbid is_negative=true ttl=%d", - mbid, ttl_not_found, - ) else: negative = cached @@ -183,10 +165,6 @@ class AudioDBImageService: mbid, images, is_monitored=is_monitored, ttl_seconds=ttl, ) await self._mem_set("artist", mbid, images) - logger.debug( - "audiodb.cache action=write entity_type=artist mbid=%s is_negative=false lookup_source=name ttl=%d", - mbid, ttl, - ) return images negative_name = AudioDBArtistImages.negative(lookup_source="name") @@ -194,10 +172,6 @@ class AudioDBImageService: mbid, negative_name, is_monitored=False, ttl_seconds=ttl_not_found, ) await self._mem_set("artist", mbid, negative_name) - logger.debug( - "audiodb.cache action=write entity_type=artist mbid=%s is_negative=true lookup_source=name ttl=%d", - mbid, ttl_not_found, - ) return negative_name return negative @@ -249,10 +223,6 @@ class AudioDBImageService: mbid, images, is_monitored=is_monitored, ttl_seconds=ttl, ) await self._mem_set("album", mbid, images) - logger.debug( - "audiodb.cache action=write entity_type=album mbid=%s lookup_source=mbid is_negative=false ttl=%d", - mbid, ttl, - ) return images negative = AudioDBAlbumImages.negative(lookup_source="mbid") @@ -260,10 +230,6 @@ class AudioDBImageService: mbid, negative, is_monitored=False, ttl_seconds=ttl_not_found, ) await self._mem_set("album", mbid, negative) - logger.debug( - "audiodb.cache action=write entity_type=album mbid=%s lookup_source=mbid is_negative=true ttl=%d", - mbid, ttl_not_found, - ) else: negative = cached @@ -292,10 +258,6 @@ class AudioDBImageService: mbid, images, is_monitored=is_monitored, ttl_seconds=ttl, ) await self._mem_set("album", mbid, images) - logger.debug( - "audiodb.cache action=write entity_type=album mbid=%s is_negative=false lookup_source=name ttl=%d", - mbid, ttl, - ) return images negative_name = AudioDBAlbumImages.negative(lookup_source="name") @@ -303,10 +265,6 @@ class AudioDBImageService: mbid, negative_name, is_monitored=False, ttl_seconds=ttl_not_found, ) await self._mem_set("album", mbid, negative_name) - logger.debug( - "audiodb.cache action=write entity_type=album mbid=%s is_negative=true lookup_source=name ttl=%d", - mbid, ttl_not_found, - ) return negative_name return negative diff --git a/backend/services/cache_service.py b/backend/services/cache_service.py index 9b6aaeb..c2fe5aa 100644 --- a/backend/services/cache_service.py +++ b/backend/services/cache_service.py @@ -78,7 +78,6 @@ class CacheService: if result.returncode == 0: lines = result.stdout.strip() disk_count = len(lines.split('\n')) if lines else 0 - logger.debug(f"Disk cache stats calculated via subprocess: {disk_count} files, {disk_bytes} bytes") else: du_available = False except (subprocess.TimeoutExpired, subprocess.SubprocessError, ValueError) as e: @@ -138,8 +137,6 @@ class CacheService: self._cached_stats = None - logger.info(f"Cleared {entries_before} memory cache entries") - return CacheClearResponse( success=True, message=f"Successfully cleared {entries_before} memory cache entries", @@ -168,8 +165,6 @@ class CacheService: if file_path.is_file(): file_path.unlink() files_cleared += 1 - - logger.info(f"Cleared {metadata_count} metadata files and {files_cleared} cover image files from disk") files_cleared += self._clear_genre_disk_cache() self._cached_stats = None @@ -209,8 +204,6 @@ class CacheService: disk_files += self._clear_genre_disk_cache() self._cached_stats = None - logger.info(f"Cleared all cache: {memory_entries} memory entries, {metadata_count} metadata files, {disk_files} cover files (library DB preserved)") - return CacheClearResponse( success=True, message=f"Successfully cleared {memory_entries} memory entries, {metadata_count} metadata files, and {disk_files} cover files (library database preserved)", @@ -238,8 +231,6 @@ class CacheService: self._cached_stats = None - logger.info(f"Cleared {files_cleared} cover image files from disk") - return CacheClearResponse( success=True, message=f"Successfully cleared {files_cleared} cover images", @@ -265,8 +256,6 @@ class CacheService: self._cached_stats = None - logger.info(f"Cleared library cache: {artists_before} artists, {albums_before} albums") - return CacheClearResponse( success=True, message=f"Successfully cleared library database: {artists_before} artists, {albums_before} albums", @@ -294,8 +283,6 @@ class CacheService: self._cached_stats = None - logger.info(f"Cleared AudioDB cache: {count_before} disk entries, {memory_cleared} memory entries") - return CacheClearResponse( success=True, message=f"Successfully cleared {count_before} AudioDB cache entries and {memory_cleared} memory entries", diff --git a/backend/services/cache_status_service.py b/backend/services/cache_status_service.py index ecff812..f9b1d49 100644 --- a/backend/services/cache_status_service.py +++ b/backend/services/cache_status_service.py @@ -139,7 +139,6 @@ class CacheStatusService: total_albums=total_albums, processed_albums=0 ) - logger.info(f"Cache sync started: {phase} ({total_items} items)") if self._sync_state_store: try: @@ -220,7 +219,6 @@ class CacheStatusService: self._progress.processed_items = 0 self._progress.current_item = None await self.broadcast_progress() - logger.info(f"Phase skipped (already cached): {phase}") await asyncio.sleep(0.5) def get_last_progress_at(self) -> float: @@ -270,7 +268,6 @@ class CacheStatusService: return is_success = error_message is None status = 'completed' if is_success else 'failed' - logger.info(f"Cache sync {status}: {self._progress.phase}") if self._sync_state_store: try: @@ -375,9 +372,6 @@ class CacheStatusService: try: state = await self._sync_state_store.get_sync_state() if state and state.get('status') == 'running': - logger.info(f"Found interrupted sync: phase={state.get('phase')}, " - f"artists={state.get('processed_artists')}/{state.get('total_artists')}, " - f"albums={state.get('processed_albums')}/{state.get('total_albums')}") phase = state.get('phase') if phase == 'albums': diff --git a/backend/services/discover/homepage_service.py b/backend/services/discover/homepage_service.py index da36e71..52844a7 100644 --- a/backend/services/discover/homepage_service.py +++ b/backend/services/discover/homepage_service.py @@ -134,7 +134,6 @@ class DiscoverHomepageService: if self._memory_cache and self._has_meaningful_content(response): cache_key = self._integration.get_discover_cache_key(resolved) await self._memory_cache.set(cache_key, response, DISCOVER_CACHE_TTL) - logger.info("Discover data built and cached for source=%s", resolved) elif not self._has_meaningful_content(response): logger.warning("Discover build produced no meaningful content, keeping existing cache") except Exception as e: # noqa: BLE001 @@ -220,11 +219,6 @@ class DiscoverHomepageService: results = await self._execute_tasks(tasks) - logger.info( - "Discover data fetch results: %s", - {k: "ok" if v is not None else "empty" for k, v in results.items()}, - ) - response = DiscoverResponse( integration_status=self._integration.get_integration_status(), ) @@ -236,7 +230,6 @@ class DiscoverHomepageService: resolved_source=resolved_source, ) await self._enrich_because_sections_audiodb(response.because_you_listen_to) - logger.info("because_you_listen_to: %d sections", len(response.because_you_listen_to)) response.fresh_releases = self._build_fresh_releases(results, library_mbids) @@ -313,22 +306,6 @@ class DiscoverHomepageService: response.service_prompts = self._build_service_prompts() - sections_status = { - "because": len(response.because_you_listen_to), - "fresh_releases": response.fresh_releases is not None, - "missing_essentials": response.missing_essentials is not None, - "rediscover": response.rediscover is not None, - "artists_you_might_like": response.artists_you_might_like is not None, - "popular_in_genres": response.popular_in_your_genres is not None, - "genre_list": response.genre_list is not None, - "globally_trending": response.globally_trending is not None, - "weekly_exploration": response.weekly_exploration is not None, - "lastfm_weekly_artist_chart": getattr(response, "lastfm_weekly_artist_chart", None) is not None, - "lastfm_weekly_album_chart": getattr(response, "lastfm_weekly_album_chart", None) is not None, - "lastfm_recent_scrobbles": getattr(response, "lastfm_recent_scrobbles", None) is not None, - } - logger.info("Discover build complete (source=%s): %s", resolved_source, sections_status) - return response async def _get_seed_artists( @@ -406,11 +383,6 @@ class DiscoverHomepageService: logger.warning(f"Failed to get Jellyfin seed artists: {e}") continue - logger.info( - "Seed artists found: %d — %s", - len(seeds), - [(s.artist_name, s.artist_mbids[0][:8] if s.artist_mbids else "?") for s in seeds], - ) return seeds async def _enrich_because_sections_audiodb( @@ -1053,7 +1025,7 @@ class DiscoverHomepageService: service="listenbrainz", title="Connect ListenBrainz", description="Get recommendations from your listening history, find similar artists, and keep an eye on your top genres. Connect Last.fm too if you want global listener stats.", - icon="🎵", + icon="LB", color="primary", features=["Personalized recommendations", "Similar artists", "Listening stats", "Genre insights"], )) @@ -1062,7 +1034,7 @@ class DiscoverHomepageService: service="jellyfin", title="Connect Jellyfin", description="Use your play history to surface favorites and sharpen recommendations.", - icon="📺", + icon="JF", color="secondary", features=["Rediscover favorites", "Play statistics", "Listening history", "Better recommendations"], )) @@ -1071,7 +1043,7 @@ class DiscoverHomepageService: service="lidarr-connection", title="Connect Lidarr", description="Spot gaps in your collection and keep your library in sync.", - icon="🎶", + icon="LD", color="accent", features=["Missing essentials", "Library management", "Album requests", "Collection tracking"], )) @@ -1080,7 +1052,7 @@ class DiscoverHomepageService: service="lastfm", title="Connect Last.fm", description="Track your listening, compare stats, and discover music that matches your taste.", - icon="🎸", + icon="FM", color="primary", features=["Scrobbling", "Global listener stats", "Artist recommendations", "Play history"], )) diff --git a/backend/services/discover/queue_service.py b/backend/services/discover/queue_service.py index 4e9844b..114e191 100644 --- a/backend/services/discover/queue_service.py +++ b/backend/services/discover/queue_service.py @@ -52,7 +52,6 @@ class DiscoverQueueService: if count is None: count = qs.queue_size resolved_source = self._integration.resolve_source(source) - logger.info("Building discover queue: requested_source=%s, resolved_source=%s", source, resolved_source) lb_enabled = self._integration.is_listenbrainz_enabled() jf_enabled = self._integration.is_jellyfin_enabled() lidarr_configured = self._integration.is_lidarr_configured() @@ -168,11 +167,6 @@ class DiscoverQueueService: logger.warning(f"Failed to get Jellyfin seed artists: {e}") continue - logger.info( - "Seed artists found: %d — %s", - len(seeds), - [(s.artist_name, s.artist_mbids[0][:8] if s.artist_mbids else "?") for s in seeds], - ) return seeds async def validate_queue_mbids(self, mbids: list[str]) -> list[str]: @@ -608,8 +602,6 @@ class DiscoverQueueService: similar_seed_pools = strategy_results[0] if isinstance(similar_seed_pools, list): candidate_pools.extend(similar_seed_pools) - pool_counts = [len(p) for p in similar_seed_pools] - logger.info("Strategy similar_seeds: %d pools, items per pool: %s", len(similar_seed_pools), pool_counts) elif isinstance(similar_seed_pools, Exception): logger.warning("Strategy similar_seeds FAILED: %s", similar_seed_pools) @@ -620,15 +612,8 @@ class DiscoverQueueService: continue if strategy_result: candidate_pools.append(strategy_result) - logger.info("Strategy %s: %d items", name, len(strategy_result)) - else: - logger.info("Strategy %s: 0 items", name) personalized = self._round_robin_select(candidate_pools, personalized_target) - logger.info( - "Personalized queue: %d items from %d pools (target=%d, wildcard_slots=%d)", - len(personalized), len(candidate_pools), personalized_target, wildcard_slots, - ) seen_mbids = {item.release_group_mbid.lower() for item in personalized} wildcard_count = max(wildcard_slots, count - len(personalized)) diff --git a/backend/services/discover_queue_manager.py b/backend/services/discover_queue_manager.py index 81fb2aa..145b4a9 100644 --- a/backend/services/discover_queue_manager.py +++ b/backend/services/discover_queue_manager.py @@ -174,17 +174,10 @@ class DiscoverQueueManager: async def _do_build(self, source: str) -> None: state = self._get_state(source) try: - logger.info("Background queue build started (source=%s)", source) queue = await self.build_hydrated_queue(source) state.queue = queue state.built_at = time.time() state.status = QueueBuildStatus.READY - logger.info( - "Background queue build complete (source=%s, items=%d, queue_id=%s)", - source, - len(queue.items), - queue.queue_id, - ) task = asyncio.create_task(self._prewarm_covers(queue, source)) from core.task_registry import TaskRegistry try: @@ -192,7 +185,6 @@ class DiscoverQueueManager: except RuntimeError: pass except asyncio.CancelledError: - logger.info("Background queue build cancelled (source=%s)", source) if state.status == QueueBuildStatus.BUILDING: state.status = QueueBuildStatus.IDLE raise @@ -229,20 +221,12 @@ class DiscoverQueueManager: return False results = await asyncio.gather(*(warm_one(m) for m in mbids), return_exceptions=True) - warmed = sum(1 for r in results if r is True) - logger.info( - "Pre-warmed %d/%d discover queue covers (source=%s)", - warmed, - len(mbids), - source, - ) async def consume_queue(self, source: str) -> DiscoverQueueResponse | None: state = self._get_state(source) if state.status != QueueBuildStatus.READY or state.queue is None: return None if self._is_stale(state): - logger.info("Discarding stale pre-built queue (source=%s)", source) state.queue = None state.status = QueueBuildStatus.IDLE state.built_at = 0.0 diff --git a/backend/services/genre_cover_prewarm_service.py b/backend/services/genre_cover_prewarm_service.py index f18a74b..69e6112 100644 --- a/backend/services/genre_cover_prewarm_service.py +++ b/backend/services/genre_cover_prewarm_service.py @@ -59,7 +59,6 @@ class GenreCoverPrewarmService: t.cancel() await asyncio.gather(*tasks, return_exceptions=True) self._active_genres.clear() - logger.info("GenreCoverPrewarmService shutdown complete (%d tasks cancelled)", len(tasks)) async def _prewarm( self, @@ -96,6 +95,5 @@ class GenreCoverPrewarmService: if i < len(all_album) - 1: await asyncio.sleep(_PREWARM_INTER_ITEM_DELAY) - logger.info("Pre-warmed %d/%d genre covers for '%s'", warmed, total, genre_name) except Exception as exc: # noqa: BLE001 logger.error("Genre cover pre-warm failed for '%s': %s", genre_name, exc) diff --git a/backend/services/home/facade.py b/backend/services/home/facade.py index 147f7ee..ef538ff 100644 --- a/backend/services/home/facade.py +++ b/backend/services/home/facade.py @@ -285,7 +285,6 @@ class HomeService: items=preview_items, ) except Exception as e: # noqa: BLE001 - logger.debug(f"Could not build discover preview: {e}") return None async def _resolve_release_mbids(self, release_ids: list[str]) -> dict[str, str]: diff --git a/backend/services/home/genre_service.py b/backend/services/home/genre_service.py index 1f8866d..d6fce9d 100644 --- a/backend/services/home/genre_service.py +++ b/backend/services/home/genre_service.py @@ -73,7 +73,7 @@ class GenreService: await self._memory_cache.set(cache_key, result, remaining) return result except Exception: # noqa: BLE001 - logger.debug("Failed to read genre section from disk for %s", source_key) + pass return None @@ -109,19 +109,12 @@ class GenreService: self._genre_build_locks[source_key] = asyncio.Lock() lock = self._genre_build_locks[source_key] if lock.locked(): - logger.debug("Genre section build already in progress for source=%s, skipping", source_key) return async with lock: try: - logger.debug( - "Building genre section for source=%s (%d genres)", - source_key, - len(genre_names), - ) genre_artists = await self.get_genre_artists_batch(genre_names) genre_artist_images = await self.resolve_genre_artist_images(genre_artists) await self.save_genre_section(source_key, genre_artists, genre_artist_images) - logger.debug("Genre section build complete for source=%s", source_key) except Exception as exc: # noqa: BLE001 logger.error("Genre section build failed for source=%s: %s", source_key, exc) @@ -185,8 +178,6 @@ class GenreService: for f in self._genre_section_dir.glob("*.json"): f.unlink(missing_ok=True) count += 1 - if count: - logger.info("Cleared %d genre section files from disk", count) return count async def resolve_genre_artist_images( diff --git a/backend/services/lastfm_auth_service.py b/backend/services/lastfm_auth_service.py index f1bc1cb..b89079c 100644 --- a/backend/services/lastfm_auth_service.py +++ b/backend/services/lastfm_auth_service.py @@ -1,4 +1,3 @@ -import logging import time import msgspec @@ -6,8 +5,6 @@ import msgspec from core.exceptions import ConfigurationError from repositories.protocols import LastFmRepositoryProtocol -logger = logging.getLogger(__name__) - MAX_PENDING_TOKENS = 5 TOKEN_TTL_SECONDS = 600 diff --git a/backend/services/library_service.py b/backend/services/library_service.py index cfe172c..be4e62e 100644 --- a/backend/services/library_service.py +++ b/backend/services/library_service.py @@ -105,7 +105,6 @@ class LibraryService: albums_data = await self._library_db.get_albums() if not albums_data: - logger.info("Library cache is empty, syncing from Lidarr") await self.sync_library() albums_data = await self._library_db.get_albums() @@ -174,7 +173,6 @@ class LibraryService: artists_data = await self._library_db.get_artists(limit=limit) if not artists_data: - logger.info("Artists cache is empty, syncing from Lidarr") await self.sync_library() artists_data = await self._library_db.get_artists(limit=limit) @@ -207,7 +205,6 @@ class LibraryService: ) if not albums_data and offset == 0 and not search: - logger.info("Library cache is empty, syncing from Lidarr") await self.sync_library() albums_data, total = await self._library_db.get_albums_paginated( limit=limit, offset=offset, sort_by=sort_by, sort_order=sort_order, search=search, @@ -248,7 +245,6 @@ class LibraryService: ) if not artists_data and offset == 0 and not search: - logger.info("Artists cache is empty, syncing from Lidarr") await self.sync_library() artists_data, total = await self._library_db.get_artists_paginated( limit=limit, offset=offset, sort_by=sort_by, sort_order=sort_order, search=search, @@ -279,7 +275,6 @@ class LibraryService: albums = [] if not albums: - logger.info("No recent imports from history, falling back to cache") albums_data = await self._library_db.get_recently_added(limit=limit) albums = [ @@ -320,7 +315,6 @@ class LibraryService: time_since_last_sync = current_time - self._last_sync_time if time_since_last_sync < self._global_sync_cooldown: remaining = int(self._global_sync_cooldown - time_since_last_sync) - logger.info(f"Global sync cooldown active ({remaining}s remaining). Skipping sync.") raise ExternalServiceError( f"Sync cooldown active. Please wait {remaining} seconds before syncing again." ) @@ -339,7 +333,6 @@ class LibraryService: await status_service.cancel_current_sync() await status_service.wait_for_completion() else: - logger.info("Library sync already in progress - skipping auto-sync") return SyncLibraryResponse(status="skipped", artists=0, albums=0) if self._sync_future is not None and not self._sync_future.done(): @@ -355,8 +348,6 @@ class LibraryService: sync_succeeded = False try: - logger.info("Starting library sync from Lidarr") - albums = await self._lidarr_repo.get_library() artists = await self._lidarr_repo.get_artists_from_library() @@ -378,7 +369,6 @@ class LibraryService: ] await self._library_db.save_library(artists, albums_data) - logger.info("Library cache updated - unmonitored items removed") now = time.time() self._last_sync_time = now @@ -398,7 +388,6 @@ class LibraryService: last_state = await self._sync_state_store.get_sync_state() if last_state and last_state.get('status') == 'failed': resume = True - logger.info("Previous sync failed, resuming from checkpoint") except Exception as e: # noqa: BLE001 logger.warning("Failed to check sync state for resume: %s", e) @@ -406,7 +395,6 @@ class LibraryService: try: await self._sync_state_store.clear_processed_items() await self._sync_state_store.clear_sync_state() - logger.info("Force full sync: cleared previous progress") except Exception as e: # noqa: BLE001 logger.warning("Failed to clear sync state for force_full: %s", e) @@ -421,7 +409,6 @@ class LibraryService: else: task_success = not t.cancelled() except asyncio.CancelledError: - logger.info("Precache task was cancelled") task_success = False finally: status_service.set_current_task(None) @@ -438,8 +425,6 @@ class LibraryService: task.add_done_callback(on_task_done) status_service.set_current_task(task) - logger.info(f"Library sync complete: {len(artists)} artists, {len(albums)} albums") - self._update_last_sync_timestamp() sync_started_at = self._preferences_service.get_lidarr_settings().last_sync or 0 @@ -489,7 +474,6 @@ class LibraryService: async def clear_cache(self) -> None: try: await self._library_db.clear() - logger.info("Library cache cleared") except Exception as e: # noqa: BLE001 logger.error(f"Failed to clear library cache: {e}") raise ExternalServiceError(f"Failed to clear library cache: {e}") @@ -557,7 +541,6 @@ class LibraryService: artist_details["id"], delete_files=delete_files ) artist_removed = True - logger.info(f"Auto-removed artist '{artist_name}' (no remaining albums)") except Exception as e: # noqa: BLE001 logger.warning( f"Album '{album_mbid}' removed but artist cleanup failed for '{artist_mbid}': {e}" @@ -628,7 +611,7 @@ class LibraryService: ) -> dict[str, tuple[str, str, str | None, float | None]]: """Resolve album MBID to {disc:track: (source, source_id, format, duration)}. - Priority: local → navidrome → jellyfin. + Priority: local -> navidrome -> jellyfin. Uses source_resolution cache (1h TTL). """ if self._memory_cache is None: diff --git a/backend/services/local_files_service.py b/backend/services/local_files_service.py index 77dc50a..b426432 100644 --- a/backend/services/local_files_service.py +++ b/backend/services/local_files_service.py @@ -100,19 +100,18 @@ class LocalFilesService: try: data = await self._lidarr.get_all_albums() except (ExternalServiceError, CircuitOpenError, ConnectionError, OSError): - # Stale-while-error: serve last-known data if Lidarr is down + # Serve the last cached data if Lidarr is unavailable. try: stale = await self._cache.get(f"{cache_key}:stale") except Exception: # noqa: BLE001 stale = None if stale is not None: - logger.warning("Lidarr unavailable — serving stale local album data") return stale raise result = data or [] if result: await self._cache.set(cache_key, result, ttl_seconds=self._ALBUM_LIST_TTL) - # Keep a long-lived stale copy for fallback (24h) + # Keep a longer-lived fallback copy for 24 hours. await self._cache.set(f"{cache_key}:stale", result, ttl_seconds=86400) return result @@ -636,6 +635,6 @@ class LocalFilesService: return LocalFilesVerifyResponse( success=True, - message=f"Connected — {track_count:,} audio files found", + message=f"Connected, found {track_count:,} audio files", track_count=track_count, ) diff --git a/backend/services/navidrome_library_service.py b/backend/services/navidrome_library_service.py index bf407c2..ffbb4fb 100644 --- a/backend/services/navidrome_library_service.py +++ b/backend/services/navidrome_library_service.py @@ -106,7 +106,6 @@ class NavidromeLibraryService: del self._album_mbid_cache[key] if stale_keys: self._dirty = True - logger.debug("navidrome.cache action=invalidate mbid=%s cleared_keys=%d", album_mbid[:8], len(stale_keys)) async def _resolve_album_mbid(self, name: str, artist: str) -> str | None: """Resolve a release-group MBID for an album via Lidarr library matching.""" @@ -180,7 +179,6 @@ class NavidromeLibraryService: await self._mbid_store.save_navidrome_album_mbid_index(serializable_albums) await self._mbid_store.save_navidrome_artist_mbid_index(serializable_artists) self._dirty = False - logger.debug("Persisted dirty Navidrome MBID cache to disk") except Exception: # noqa: BLE001 logger.warning("Failed to persist dirty Navidrome MBID cache", exc_info=True) @@ -763,10 +761,6 @@ class NavidromeLibraryService: norm_artist = _normalize(artist_name) if norm_artist and artist_mbid: self._lidarr_artist_index[norm_artist] = artist_mbid - logger.info( - "Built Lidarr matching indices: %d album entries, %d artist entries", - len(self._lidarr_album_index), len(self._lidarr_artist_index), - ) except Exception: # noqa: BLE001 logger.warning("Failed to build Lidarr matching indices", exc_info=True) @@ -779,10 +773,6 @@ class NavidromeLibraryService: self._album_mbid_cache.update(disk_albums) self._artist_mbid_cache.update(disk_artists) loaded_from_disk = True - logger.info( - "Loaded Navidrome MBID cache from disk: %d albums, %d artists", - len(disk_albums), len(disk_artists), - ) except Exception: # noqa: BLE001 logger.warning("Failed to load Navidrome MBID cache from disk", exc_info=True) @@ -821,11 +811,6 @@ class NavidromeLibraryService: del self._album_mbid_cache[key] for key in stale_artist_keys: del self._artist_mbid_cache[key] - if stale_album_keys or stale_artist_keys: - logger.info( - "Removed %d stale album and %d stale artist MBID entries", - len(stale_album_keys), len(stale_artist_keys), - ) resolved_albums = 0 resolved_artists = 0 @@ -881,11 +866,6 @@ class NavidromeLibraryService: if mbid: resolved_artists += 1 - logger.info( - "Navidrome MBID enrichment complete: %d new albums resolved, %d new artists resolved (loaded_from_disk=%s, lidarr_available=%s)", - resolved_albums, resolved_artists, loaded_from_disk, bool(self._lidarr_album_index), - ) - if self._mbid_store and (self._dirty or stale_album_keys or stale_artist_keys): try: serializable_albums = {k: (v if isinstance(v, str) else None) for k, v in self._album_mbid_cache.items()} @@ -893,10 +873,6 @@ class NavidromeLibraryService: await self._mbid_store.save_navidrome_album_mbid_index(serializable_albums) await self._mbid_store.save_navidrome_artist_mbid_index(serializable_artists) self._dirty = False - logger.info( - "Persisted Navidrome MBID cache to disk: %d albums, %d artists", - len(self._album_mbid_cache), len(self._artist_mbid_cache), - ) except Exception: # noqa: BLE001 logger.warning("Failed to persist Navidrome MBID cache to disk", exc_info=True) diff --git a/backend/services/playlist_service.py b/backend/services/playlist_service.py index 70677a0..dc628bd 100644 --- a/backend/services/playlist_service.py +++ b/backend/services/playlist_service.py @@ -88,7 +88,6 @@ class PlaylistService: if len(stripped) > MAX_NAME_LENGTH: raise InvalidPlaylistDataError(f"Playlist name must not exceed {MAX_NAME_LENGTH} characters") result = await self._repo.create_playlist(stripped, source_ref=source_ref) - logger.info("Playlist created: id=%s name=%s source_ref=%s", result.id, result.name, source_ref) return result async def get_by_source_ref(self, source_ref: str) -> PlaylistRecord | None: @@ -127,7 +126,6 @@ class PlaylistService: result = await self._repo.update_playlist(playlist_id, name=name) if result is None: raise PlaylistNotFoundError(f"Playlist {playlist_id} not found") - logger.info("Playlist updated: id=%s", playlist_id) return result async def update_playlist_with_detail( @@ -142,7 +140,6 @@ class PlaylistService: if not deleted: raise PlaylistNotFoundError(f"Playlist {playlist_id} not found") await asyncio.to_thread(self._delete_cover_file, playlist_id) - logger.info("Playlist deleted: id=%s", playlist_id) async def add_tracks( @@ -177,14 +174,12 @@ class PlaylistService: normalized_tracks.append(normalized) await self.get_playlist(playlist_id) result = await self._repo.add_tracks(playlist_id, normalized_tracks, position) - logger.info("Added %d tracks to playlist %s", len(result), playlist_id) return result async def remove_track(self, playlist_id: str, track_id: str) -> None: removed = await self._repo.remove_track(playlist_id, track_id) if not removed: raise PlaylistNotFoundError(f"Track {track_id} not found in playlist {playlist_id}") - logger.info("Removed track %s from playlist %s", track_id, playlist_id) async def remove_tracks(self, playlist_id: str, track_ids: list[str]) -> int: if not track_ids: @@ -192,7 +187,6 @@ class PlaylistService: removed = await self._repo.remove_tracks(playlist_id, track_ids) if not removed: raise PlaylistNotFoundError(f"No matching tracks found in playlist {playlist_id}") - logger.info("Removed %d tracks from playlist %s", removed, playlist_id) return removed async def reorder_track( @@ -203,7 +197,6 @@ class PlaylistService: result = await self._repo.reorder_track(playlist_id, track_id, new_position) if result is None: raise PlaylistNotFoundError(f"Track {track_id} not found in playlist {playlist_id}") - logger.info("Reordered track %s to position %d in playlist %s", track_id, result, playlist_id) return result async def update_track_source( @@ -259,7 +252,6 @@ class PlaylistService: ) if result is None: raise PlaylistNotFoundError(f"Track {track_id} not found in playlist {playlist_id}") - logger.info("Updated track source: track=%s playlist=%s", track_id, playlist_id) return result async def get_tracks(self, playlist_id: str) -> list[PlaylistTrackRecord]: diff --git a/backend/services/precache/album_phase.py b/backend/services/precache/album_phase.py index 978c9a1..7c3ab01 100644 --- a/backend/services/precache/album_phase.py +++ b/backend/services/precache/album_phase.py @@ -36,7 +36,6 @@ class AlbumPhase: generation: int = 0, ) -> None: from core.dependencies import get_album_service - logger.info(f"Pre-caching {len(release_group_ids)} new/missing release-groups") album_service = get_album_service() async def cache_rg(rgid: str, index: int) -> tuple[str, bool, bool]: @@ -77,7 +76,6 @@ class AlbumPhase: i = 0 while i < len(release_group_ids): if status_service.is_cancelled(): - logger.info("Album pre-caching cancelled by user") break batch_start = time.time() batch = release_group_ids[i:i + batch_size] @@ -117,10 +115,6 @@ class AlbumPhase: batch_size = min(batch_size + 1, max_batch) logger.debug(f"Increasing batch size to {batch_size} (fast: {avg_time_per_item:.2f}s/item)") next_i = i + len(batch) - if next_i % 30 == 0 or next_i >= len(release_group_ids): - percent = int((min(next_i, len(release_group_ids)) / len(release_group_ids)) * 100) - logger.info(f"Album progress: {min(next_i, len(release_group_ids))}/{len(release_group_ids)} ({percent}%) - metadata: {metadata_fetched}, covers: {covers_fetched} [batch: {batch_size}]") i = next_i await asyncio.sleep(advanced_settings.delay_albums) await status_service.persist_progress(force=True, generation=generation) - logger.info(f"Album pre-caching complete: metadata fetched={metadata_fetched}, covers fetched={covers_fetched}, total processed={len(release_group_ids)}") diff --git a/backend/services/precache/artist_phase.py b/backend/services/precache/artist_phase.py index f26eed1..50b29a9 100644 --- a/backend/services/precache/artist_phase.py +++ b/backend/services/precache/artist_phase.py @@ -38,7 +38,6 @@ class ArtistPhase: offset: int = 0, generation: int = 0, ) -> None: - logger.info(f"Pre-caching metadata+images for {len(artists)} artists") from core.dependencies import get_artist_service from infrastructure.validators import is_unknown_mbid artist_service = get_artist_service() @@ -52,8 +51,6 @@ class ArtistPhase: elif mbid.lower() not in seen_mbids: seen_mbids.add(mbid.lower()) unique_artists.append(a) - if len(unique_artists) < len(artists): - logger.info("Deduplicated %d artists to %d unique", len(artists), len(unique_artists)) artists = unique_artists async def cache_artist(artist: dict, index: int) -> str: @@ -96,7 +93,6 @@ class ArtistPhase: batch_size = advanced_settings.batch_artist_images for i in range(0, len(artists), batch_size): if status_service.is_cancelled(): - logger.info("Artist pre-caching cancelled by user") break batch = artists[i:i + batch_size] tasks = [cache_artist(artist, i + idx) for idx, artist in enumerate(batch)] @@ -114,14 +110,12 @@ class ArtistPhase: await status_service.persist_progress(generation=generation) await asyncio.sleep(advanced_settings.delay_artist) await status_service.persist_progress(force=True, generation=generation) - logger.info("Artist metadata+image pre-caching complete") await self._cache_artist_genres(artists) async def _cache_artist_genres(self, artists: list[dict]) -> None: from core.dependencies import get_artist_service artist_service = get_artist_service() artist_genres: dict[str, list[str]] = {} - logger.info(f"Extracting genre tags for {len(artists)} library artists") for artist in artists: mbid = artist.get('mbid') if not mbid: @@ -132,6 +126,3 @@ class ArtistPhase: artist_genres[mbid] = cached_info.tags[:10] if artist_genres: await self._genre_index.save_artist_genres(artist_genres) - logger.info(f"Cached genres for {len(artist_genres)} artists") - else: - logger.info("No artist genres found to cache") diff --git a/backend/services/precache/audiodb_phase.py b/backend/services/precache/audiodb_phase.py index 7d03d8a..42a914b 100644 --- a/backend/services/precache/audiodb_phase.py +++ b/backend/services/precache/audiodb_phase.py @@ -187,7 +187,6 @@ class AudioDBPhase: settings = self._preferences_service.get_advanced_settings() if not settings.audiodb_enabled: - logger.info("AudioDB pre-warming skipped (audiodb_enabled=false)") await status_service.skip_phase('audiodb_prewarm', generation=generation) return @@ -197,16 +196,11 @@ class AudioDBPhase: needed_artists, needed_albums = await self.check_cache_needs(artists, albums) total = len(needed_artists) + len(needed_albums) if total == 0: - logger.info("AudioDB prewarm: all items already cached") await status_service.skip_phase('audiodb_prewarm', generation=generation) return original_total = len(artists) + len(albums) initial_hit_rate = ((original_total - total) / original_total * 100) if original_total > 0 else 100 - logger.info( - "Phase 5 (AudioDB): Pre-warming %d items (%d artists, %d albums), %.0f%% already cached, concurrency=%d delay=%.1fs", - total, len(needed_artists), len(needed_albums), initial_hit_rate, concurrency, inter_item_delay, - ) await status_service.update_phase('audiodb_prewarm', total, generation=generation) needed_artists = self.sort_by_cover_priority(needed_artists, "artist") @@ -252,12 +246,6 @@ class AudioDBPhase: snap_ok, snap_fail = bytes_ok, bytes_fail await status_service.update_progress(local_processed, f"AudioDB: {name}", generation=generation) - if local_processed % _AUDIODB_PREWARM_LOG_INTERVAL == 0: - logger.info( - "audiodb.prewarm processed=%d total=%d initial_hit=%.0f%% bytes_ok=%d bytes_fail=%d remaining=%d", - local_processed, total, initial_hit_rate, snap_ok, snap_fail, total - local_processed, - ) - async def process_album(album: Any) -> None: nonlocal processed, bytes_ok, bytes_fail if status_service.is_cancelled(): @@ -294,12 +282,6 @@ class AudioDBPhase: snap_ok, snap_fail = bytes_ok, bytes_fail await status_service.update_progress(local_processed, f"AudioDB: {album_name or 'Unknown'}", generation=generation) - if local_processed % _AUDIODB_PREWARM_LOG_INTERVAL == 0: - logger.info( - "audiodb.prewarm processed=%d total=%d initial_hit=%.0f%% bytes_ok=%d bytes_fail=%d remaining=%d", - local_processed, total, initial_hit_rate, snap_ok, snap_fail, total - local_processed, - ) - chunk = max(concurrency * 4, 20) for i in range(0, len(needed_artists), chunk): if status_service.is_cancelled(): @@ -312,8 +294,3 @@ class AudioDBPhase: break batch = needed_albums[i:i + chunk] await asyncio.gather(*(process_album(a) for a in batch), return_exceptions=True) - - logger.info( - "audiodb.prewarm action=complete processed=%d total=%d bytes_ok=%d bytes_fail=%d", - processed, total, bytes_ok, bytes_fail, - ) diff --git a/backend/services/precache/orchestrator.py b/backend/services/precache/orchestrator.py index e720238..8dae105 100644 --- a/backend/services/precache/orchestrator.py +++ b/backend/services/precache/orchestrator.py @@ -152,30 +152,24 @@ class LibraryPrecacheService: skip_artists = False if resume: - logger.info("Resuming interrupted sync...") processed_artists = await self._sync_state_store.get_processed_items('artist') processed_albums = await self._sync_state_store.get_processed_items('album') state = await self._sync_state_store.get_sync_state() if state and state.get('phase') in ('albums', 'audiodb_prewarm'): skip_artists = True - logger.info(f"Resuming from {state.get('phase')} phase, {len(processed_albums)} albums already processed") else: - logger.info(f"Resuming from artists phase, {len(processed_artists)} artists already processed") + pass total_artists = len(artists) total_albums = len(albums) - logger.info(f"Starting pre-cache for {total_artists} monitored artists and {total_albums} monitored albums") - logger.info("Pre-fetching Lidarr library data...") album_service = get_album_service() library_artist_mbids = await self._lidarr_repo.get_artist_mbids() library_album_mbids = await self._lidarr_repo.get_library_mbids(include_release_ids=True) - logger.info(f"Lidarr data cached: {len(library_artist_mbids)} artists, {len(library_album_mbids)} albums") if not skip_artists: remaining_artists = [a for a in artists if a.get('mbid') not in processed_artists] - logger.info(f"Phase 1: Caching {len(remaining_artists)} artist metadata + images ({len(processed_artists)} already done)") if remaining_artists: generation = await status_service.start_sync('artists', len(remaining_artists), total_artists=total_artists, total_albums=total_albums) await self._artist_phase.precache_artist_images(remaining_artists, status_service, library_artist_mbids, library_album_mbids, len(processed_artists), generation=generation) @@ -184,9 +178,7 @@ class LibraryPrecacheService: await status_service.skip_phase('artists', generation=generation) else: generation = await status_service.start_sync('albums', 0, total_artists=total_artists, total_albums=total_albums) - logger.info("Resuming sync, skipping artists/discovery phases") if status_service.is_cancelled(): - logger.info("Pre-cache cancelled after Phase 1") return if self._artist_discovery_service and not skip_artists: @@ -195,7 +187,6 @@ class LibraryPrecacheService: if a.get('mbid') and not a.get('mbid', '').startswith('unknown_') )) if artist_mbids: - logger.info(f"Phase 1.5: Pre-caching discovery data (popular albums/songs/similar) for {len(artist_mbids)} library artists") await status_service.update_phase('discovery', len(artist_mbids), generation=generation) mbid_to_name = { a.get('mbid'): a.get('name', a.get('mbid', '')[:8]) @@ -217,7 +208,6 @@ class LibraryPrecacheService: await status_service.skip_phase('discovery', generation=generation) if status_service.is_cancelled(): - logger.info("Pre-cache cancelled after Phase 1.5") return monitored_mbids: set[str] = set() @@ -225,12 +215,9 @@ class LibraryPrecacheService: mbid = getattr(a, 'musicbrainz_id', None) if hasattr(a, 'musicbrainz_id') else a.get('mbid') if isinstance(a, dict) else None if not is_unknown_mbid(mbid): monitored_mbids.add(mbid.lower()) - logger.info(f"Phase 2: Collecting {len(monitored_mbids)} monitored album MBIDs (unmonitored albums will NOT be pre-cached)") deduped_release_groups = list(monitored_mbids) if status_service.is_cancelled(): - logger.info("Pre-cache cancelled after Phase 2") return - logger.info(f"Phase 3: Batch-checking which of {len(deduped_release_groups)} release-groups need caching...") items_needing_metadata = [] cache_checks = [] for rgid in deduped_release_groups: @@ -256,11 +243,6 @@ class LibraryPrecacheService: items_needing_covers.append(rgid) items_to_process = list(set(items_needing_metadata + items_needing_covers)) already_cached = len(deduped_release_groups) - len(items_to_process) - len(processed_albums) - logger.info( - f"Phase 3: {len(items_to_process)} items need caching " - f"({len(items_needing_metadata)} metadata, {len(items_needing_covers)} covers) - " - f"{already_cached} already cached, {len(processed_albums)} from previous run" - ) if items_to_process: await status_service.update_phase('albums', len(items_to_process), generation=generation) await self._album_phase.precache_album_data(items_to_process, monitored_mbids, status_service, library_album_mbids, len(processed_albums), generation=generation) @@ -268,21 +250,15 @@ class LibraryPrecacheService: await status_service.skip_phase('albums', generation=generation) if status_service.is_cancelled(): - logger.info("Pre-cache cancelled after albums phase") return try: - logger.info("Starting AudioDB image prewarm...") await self._audiodb_phase.precache_audiodb_data(artists, albums, status_service, generation=generation) - logger.info("AudioDB image prewarm complete") except Exception as e: # noqa: BLE001 logger.warning(f"AudioDB pre-warming failed (non-fatal): {e}") if not status_service.is_cancelled(): await status_service.complete_sync(generation=generation) - logger.info("Library resource pre-caching complete") - else: - logger.info("Library resource pre-caching complete (cancelled)") except Exception as e: logger.error(f"Error during pre-cache: {e}") raise diff --git a/backend/services/preferences_service.py b/backend/services/preferences_service.py index 6cd2898..e46bd43 100644 --- a/backend/services/preferences_service.py +++ b/backend/services/preferences_service.py @@ -90,7 +90,6 @@ class PreferencesService: def save_preferences(self, preferences: UserPreferences) -> None: try: self._save_section("user_preferences", preferences) - logger.info(f"Saved preferences to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save preferences: {e}") raise ConfigurationError(f"Failed to save preferences: {e}") @@ -101,7 +100,6 @@ class PreferencesService: def save_lidarr_settings(self, lidarr_settings: LidarrSettings) -> None: try: self._save_section("lidarr_settings", lidarr_settings) - logger.info(f"Saved Lidarr settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save Lidarr settings: {e}") raise ConfigurationError(f"Failed to save Lidarr settings: {e}") @@ -112,7 +110,6 @@ class PreferencesService: def save_advanced_settings(self, advanced_settings: AdvancedSettings) -> None: try: self._save_section("advanced_settings", advanced_settings) - logger.info(f"Saved advanced settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save advanced settings: {e}") raise ConfigurationError(f"Failed to save advanced settings: {e}") @@ -144,8 +141,6 @@ class PreferencesService: self._settings.quality_profile_id = settings.quality_profile_id self._settings.metadata_profile_id = settings.metadata_profile_id self._settings.root_folder_path = settings.root_folder_path - - logger.info(f"Saved Lidarr connection settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save Lidarr connection settings: {e}") raise ConfigurationError(f"Failed to save Lidarr connection settings: {e}") @@ -173,8 +168,6 @@ class PreferencesService: self._save_config(config) self._settings.jellyfin_url = settings.jellyfin_url - - logger.info(f"Saved Jellyfin connection settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save Jellyfin connection settings: {e}") raise ConfigurationError(f"Failed to save Jellyfin connection settings: {e}") @@ -216,7 +209,6 @@ class PreferencesService: "enabled": settings.enabled, } self._save_config(config) - logger.info("Saved Navidrome connection settings to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save Navidrome connection settings: %s", e) raise ConfigurationError(f"Failed to save Navidrome connection settings: {e}") @@ -286,8 +278,6 @@ class PreferencesService: "enabled": settings.enabled, } self._save_config(config) - - logger.info(f"Saved ListenBrainz connection settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save ListenBrainz connection settings: {e}") raise ConfigurationError(f"Failed to save ListenBrainz connection settings: {e}") @@ -319,7 +309,6 @@ class PreferencesService: "daily_quota_limit": settings.daily_quota_limit, } self._save_config(config) - logger.info(f"Saved YouTube connection settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save YouTube connection settings: {e}") raise ConfigurationError(f"Failed to save YouTube connection settings: {e}") @@ -330,7 +319,6 @@ class PreferencesService: def save_home_settings(self, settings: HomeSettings) -> None: try: self._save_section("home_settings", settings) - logger.info(f"Saved home settings to {self._config_path}") except Exception as e: # noqa: BLE001 logger.error(f"Failed to save home settings: {e}") raise ConfigurationError(f"Failed to save home settings: {e}") @@ -341,7 +329,6 @@ class PreferencesService: def save_local_files_connection(self, settings: LocalFilesConnectionSettings) -> None: try: self._save_section("local_files_settings", settings) - logger.info("Saved local files settings to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save local files settings: %s", e) raise ConfigurationError(f"Failed to save local files settings: {e}") @@ -381,7 +368,6 @@ class PreferencesService: enabled=enabled, ) self._save_section("lastfm_settings", resolved) - logger.info("Saved Last.fm connection settings to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save Last.fm connection settings: %s", e) raise ConfigurationError(f"Failed to save Last.fm connection settings: {e}") @@ -396,7 +382,6 @@ class PreferencesService: def save_scrobble_settings(self, settings: ScrobbleSettings) -> None: try: self._save_section("scrobble_settings", settings) - logger.info("Saved scrobble settings to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save scrobble settings: %s", e) raise ConfigurationError(f"Failed to save scrobble settings: {e}") @@ -407,7 +392,6 @@ class PreferencesService: def save_primary_music_source(self, settings: PrimaryMusicSourceSettings) -> None: try: self._save_section("primary_music_source", settings) - logger.info("Saved primary music source to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save primary music source: %s", e) raise ConfigurationError(f"Failed to save primary music source: {e}") @@ -418,7 +402,6 @@ class PreferencesService: def save_profile_settings(self, settings: ProfileSettings) -> None: try: self._save_section("profile_settings", settings) - logger.info("Saved profile settings to %s", self._config_path) except Exception as e: # noqa: BLE001 logger.error("Failed to save profile settings: %s", e) raise ConfigurationError(f"Failed to save profile settings: {e}") diff --git a/backend/services/requests_page_service.py b/backend/services/requests_page_service.py index 8b1af03..9ab4621 100644 --- a/backend/services/requests_page_service.py +++ b/backend/services/requests_page_service.py @@ -475,10 +475,6 @@ class RequestsPageService: await self._notify_import(record) return True if event_type == "albumImportIncomplete": - logger.info( - "Partial import detected for %s", - record.musicbrainz_id, - ) await self._request_history.async_update_status( record.musicbrainz_id, "incomplete", diff --git a/backend/services/scrobble_service.py b/backend/services/scrobble_service.py index 74483b4..5de9c9a 100644 --- a/backend/services/scrobble_service.py +++ b/backend/services/scrobble_service.py @@ -120,17 +120,6 @@ class ScrobbleService: services[service_name] = ServiceResult(success=True) any_success = True - logger.info( - "Now playing reported", - extra={ - "artist": request.artist_name, - "track": request.track_name, - "services": { - k: {"success": v.success, "error": v.error} - for k, v in services.items() - }, - }, - ) return ScrobbleResponse(accepted=any_success, services=services) async def submit_scrobble( @@ -205,16 +194,4 @@ class ScrobbleService: if any_success: self._record_dedup(dedup) - logger.info( - "Scrobble submitted", - extra={ - "artist": request.artist_name, - "track": request.track_name, - "timestamp": request.timestamp, - "services": { - k: {"success": v.success, "error": v.error} - for k, v in services.items() - }, - }, - ) return ScrobbleResponse(accepted=any_success, services=services) diff --git a/backend/services/status_service.py b/backend/services/status_service.py index ad3eda5..789ddab 100644 --- a/backend/services/status_service.py +++ b/backend/services/status_service.py @@ -1,9 +1,6 @@ -import logging from repositories.protocols import LidarrRepositoryProtocol from api.v1.schemas.common import StatusReport, ServiceStatus -logger = logging.getLogger(__name__) - class StatusService: def __init__(self, lidarr_repo: LidarrRepositoryProtocol): diff --git a/backend/services/youtube_service.py b/backend/services/youtube_service.py index 3a5d2a7..e67fbb3 100644 --- a/backend/services/youtube_service.py +++ b/backend/services/youtube_service.py @@ -1,4 +1,3 @@ -import logging import re import uuid from datetime import datetime, timezone @@ -12,8 +11,6 @@ from infrastructure.persistence import YouTubeStore from infrastructure.serialization import to_jsonable from repositories.protocols import YouTubeRepositoryProtocol -logger = logging.getLogger(__name__) - _VIDEO_ID_RE = re.compile( r'(?:youtube\.com/watch\?.*v=|youtu\.be/|youtube\.com/embed/)([a-zA-Z0-9_-]{11})' ) @@ -256,7 +253,7 @@ class YouTubeService: ) -> YouTubeLink: video_id = extract_video_id(youtube_url) if not video_id: - raise ValidationError("Invalid YouTube URL — could not extract video ID") + raise ValidationError("Invalid YouTube URL: could not extract a video ID") if not album_id: album_id = f"manual-{uuid.uuid4().hex[:12]}" @@ -289,7 +286,7 @@ class YouTubeService: if youtube_url: new_vid = extract_video_id(youtube_url) if not new_vid: - raise ValidationError("Invalid YouTube URL — could not extract video ID") + raise ValidationError("Invalid YouTube URL: could not extract a video ID") video_id = new_vid embed_url = f"https://www.youtube.com/embed/{new_vid}" diff --git a/backend/tests/routes/test_search_routes.py b/backend/tests/routes/test_search_routes.py index c5fe654..b19915d 100644 --- a/backend/tests/routes/test_search_routes.py +++ b/backend/tests/routes/test_search_routes.py @@ -1,5 +1,4 @@ import pytest -import logging from unittest.mock import AsyncMock, MagicMock from fastapi import FastAPI @@ -96,30 +95,6 @@ def test_suggest_whitespace_padded_valid_input_strips(client, mock_search_servic mock_search_service.suggest.assert_called_once_with(query="ab", limit=5) -def test_suggest_debug_log_contains_fields_without_query_text(client, mock_search_service, caplog): - """Debug log includes query_len, results, time_ms but not the raw query text.""" - mock_search_service.suggest = AsyncMock( - return_value=SuggestResponse(results=[ - SuggestResult( - type="artist", title="Muse", musicbrainz_id="mb-1", - in_library=False, requested=False, score=90, - ) - ]) - ) - - with caplog.at_level(logging.DEBUG, logger="api.v1.routes.search"): - response = client.get("/search/suggest?q=muse") - - assert response.status_code == 200 - log_messages = [r.message for r in caplog.records if "Suggest" in r.message] - assert len(log_messages) >= 1 - log_msg = log_messages[0] - assert "query_len=4" in log_msg - assert "results=1" in log_msg - assert "time_ms=" in log_msg - assert "muse" not in log_msg - - def test_search_response_tolerates_additive_score_field(): """Existing /api/search consumers tolerate the additive score field on SearchResult.""" mock_search_service = MagicMock() diff --git a/backend/tests/services/test_source_playlist_import.py b/backend/tests/services/test_source_playlist_import.py index 5d175ca..ca2f1db 100644 --- a/backend/tests/services/test_source_playlist_import.py +++ b/backend/tests/services/test_source_playlist_import.py @@ -5,6 +5,7 @@ from unittest.mock import AsyncMock, MagicMock, PropertyMock import pytest +from core.exceptions import ExternalServiceError from repositories.plex_models import PlexPlaylist, PlexTrack from repositories.navidrome_models import SubsonicPlaylist, SubsonicSong from repositories.jellyfin_models import JellyfinItem @@ -325,6 +326,6 @@ class TestJellyfinImportPlaylist: svc = _jellyfin_service(playlists=[pl], items=tracks) ps = _mock_playlist_service() ps.add_tracks = AsyncMock(side_effect=Exception("fail")) - with pytest.raises(Exception): + with pytest.raises(ExternalServiceError): await svc.import_playlist("jf-1", ps) ps.delete_playlist.assert_awaited_once_with("new-pl-1") diff --git a/backend/tests/test_phase9_observability.py b/backend/tests/test_phase9_observability.py index a0d31bb..d3f1815 100644 --- a/backend/tests/test_phase9_observability.py +++ b/backend/tests/test_phase9_observability.py @@ -1,16 +1,13 @@ """Phase 9 observability contract tests. -Verifies that every key log event fires with the required fields, and that -SSE / cache-stats wiring propagates AudioDB data end-to-end. +Verifies SSE / cache-stats wiring propagates AudioDB data end-to-end. """ from unittest.mock import AsyncMock, MagicMock, patch -import httpx import msgspec import pytest -from tests.helpers import assert_log_fields from repositories.audiodb_models import ( AudioDBArtistImages, AudioDBArtistResponse, @@ -71,191 +68,6 @@ def _make_image_service(settings=None, disk_cache=None, repo=None): ) - - -CACHE_REQUIRED_FIELDS = ["action", "entity_type", "mbid", "lookup_source"] - - -class TestCacheLogContract: - @pytest.mark.asyncio - async def test_miss_includes_lookup_source(self, caplog): - svc = _make_image_service() - with caplog.at_level("DEBUG"): - await svc.get_cached_artist_images(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=miss" in m for m in msgs) - - @pytest.mark.asyncio - async def test_corrupt_includes_lookup_source(self, caplog): - disk = AsyncMock() - disk.get_audiodb_artist = AsyncMock(return_value="not-a-dict") - disk.delete_entity = AsyncMock() - svc = _make_image_service(disk_cache=disk) - with caplog.at_level("DEBUG"): - await svc.get_cached_artist_images(TEST_MBID) - - msgs = assert_log_fields( - caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS, - ) - assert any("action=corrupt" in m for m in msgs) - - @pytest.mark.asyncio - async def test_hit_includes_lookup_source(self, caplog): - images = AudioDBArtistImages( - thumb_url="https://example.com/thumb.jpg", - is_negative=False, - lookup_source="mbid", - ) - raw = msgspec.structs.asdict(images) - disk = AsyncMock() - disk.get_audiodb_artist = AsyncMock(return_value=raw) - svc = _make_image_service(disk_cache=disk) - with caplog.at_level("DEBUG"): - await svc.get_cached_artist_images(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=hit" in m for m in msgs) - - @pytest.mark.asyncio - async def test_write_mbid_includes_lookup_source(self, caplog): - repo = AsyncMock() - repo.get_artist_by_mbid = AsyncMock(return_value=SAMPLE_ARTIST_RESP) - svc = _make_image_service(repo=repo) - with caplog.at_level("DEBUG"): - await svc.fetch_and_cache_artist_images(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=write" in m and "lookup_source=mbid" in m for m in msgs) - - @pytest.mark.asyncio - async def test_fetch_error_mbid_includes_lookup_source(self, caplog): - repo = AsyncMock() - repo.get_artist_by_mbid = AsyncMock(side_effect=Exception("network")) - svc = _make_image_service(repo=repo) - with caplog.at_level("DEBUG"): - await svc.fetch_and_cache_artist_images(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=fetch_error" in m and "lookup_source=mbid" in m for m in msgs) - - @pytest.mark.asyncio - async def test_album_miss_includes_lookup_source(self, caplog): - svc = _make_image_service() - with caplog.at_level("DEBUG"): - await svc.get_cached_album_images(TEST_ALBUM_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=miss" in m and "entity_type=album" in m for m in msgs) - - @pytest.mark.asyncio - async def test_album_write_mbid_includes_lookup_source(self, caplog): - repo = AsyncMock() - repo.get_album_by_mbid = AsyncMock(return_value=SAMPLE_ALBUM_RESP) - svc = _make_image_service(repo=repo) - with caplog.at_level("DEBUG"): - await svc.fetch_and_cache_album_images(TEST_ALBUM_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.cache", CACHE_REQUIRED_FIELDS) - assert any("action=write" in m and "entity_type=album" in m for m in msgs) - - - - -LOOKUP_REQUIRED_FIELDS = ["entity", "lookup_type", "found", "elapsed_ms"] - - -class TestLookupLogContract: - @pytest.fixture(autouse=True) - def _reset_resilience(self): - from repositories.audiodb_repository import _audiodb_circuit_breaker - _audiodb_circuit_breaker.reset() - yield - _audiodb_circuit_breaker.reset() - - @pytest.fixture(autouse=True) - def _stub_retry_sleep(self): - with patch("infrastructure.resilience.retry.asyncio.sleep", new=AsyncMock()): - yield - - def _make_repo(self): - from repositories.audiodb_repository import AudioDBRepository - client = AsyncMock(spec=httpx.AsyncClient) - prefs = MagicMock() - settings = MagicMock() - settings.audiodb_enabled = True - settings.audiodb_api_key = "test_key" - prefs.get_advanced_settings.return_value = settings - return AudioDBRepository( - http_client=client, - preferences_service=prefs, - api_key="test_key", - ) - - def _mock_response(self, status_code=200, json_data=None): - resp = MagicMock(spec=httpx.Response) - resp.status_code = status_code - resp.content = msgspec.json.encode(json_data or {}) - return resp - - @pytest.mark.asyncio - async def test_artist_mbid_found_logs_lookup(self, caplog): - repo = self._make_repo() - data = {"artists": [{ - "idArtist": "111239", "strArtist": "Coldplay", - "strMusicBrainzID": TEST_MBID, - "strArtistThumb": "https://example.com/thumb.jpg", - }]} - repo._client.get = AsyncMock(return_value=self._mock_response(200, data)) - with caplog.at_level("DEBUG"): - await repo.get_artist_by_mbid(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.lookup", LOOKUP_REQUIRED_FIELDS) - assert any("found=true" in m and "entity=artist" in m for m in msgs) - - @pytest.mark.asyncio - async def test_artist_mbid_not_found_logs_lookup(self, caplog): - repo = self._make_repo() - repo._client.get = AsyncMock(return_value=self._mock_response(200, {"artists": None})) - with caplog.at_level("DEBUG"): - await repo.get_artist_by_mbid(TEST_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.lookup", LOOKUP_REQUIRED_FIELDS) - assert any("found=false" in m for m in msgs) - - @pytest.mark.asyncio - async def test_album_mbid_found_logs_lookup(self, caplog): - repo = self._make_repo() - data = {"album": [{ - "idAlbum": "2115888", "strAlbum": "Parachutes", - "strMusicBrainzID": TEST_ALBUM_MBID, - "strAlbumThumb": "https://example.com/thumb.jpg", - }]} - repo._client.get = AsyncMock(return_value=self._mock_response(200, data)) - with caplog.at_level("DEBUG"): - await repo.get_album_by_mbid(TEST_ALBUM_MBID) - - msgs = assert_log_fields(caplog.records, "audiodb.lookup", LOOKUP_REQUIRED_FIELDS) - assert any("found=true" in m and "entity=album" in m for m in msgs) - - @pytest.mark.asyncio - async def test_name_search_logs_lookup(self, caplog): - repo = self._make_repo() - data = {"artists": [{ - "idArtist": "111239", "strArtist": "Coldplay", - "strMusicBrainzID": TEST_MBID, - "strArtistThumb": "https://example.com/thumb.jpg", - }]} - repo._client.get = AsyncMock(return_value=self._mock_response(200, data)) - with caplog.at_level("DEBUG"): - await repo.search_artist_by_name("Coldplay") - - msgs = assert_log_fields(caplog.records, "audiodb.lookup", LOOKUP_REQUIRED_FIELDS) - assert any("lookup_type=name" in m for m in msgs) - - - - class TestPrewarmLogContract: def _make_status_service(self): status = MagicMock() @@ -292,32 +104,6 @@ class TestPrewarmLogContract: audiodb_image_service=audiodb_svc, ) - @pytest.mark.asyncio - async def test_prewarm_progress_logs_fire(self, caplog): - svc = AsyncMock() - images = AudioDBArtistImages(thumb_url="https://x.com/t.jpg", is_negative=False) - svc.get_cached_artist_images = AsyncMock(return_value=None) - svc.get_cached_album_images = AsyncMock(return_value=None) - svc.fetch_and_cache_artist_images = AsyncMock(return_value=images) - svc.fetch_and_cache_album_images = AsyncMock(return_value=None) - - precache = self._make_precache_service(audiodb_svc=svc) - status = self._make_status_service() - - artists = [{"mbid": TEST_MBID, "name": f"Artist{i}"} for i in range(1)] - with caplog.at_level("DEBUG"): - with patch.object(precache, '_download_audiodb_bytes', new_callable=AsyncMock, return_value=True): - await precache._precache_audiodb_data(artists, [], status) - - complete_logs = [ - r.message for r in caplog.records - if r.message.startswith("audiodb.prewarm") and "action=complete" in r.message - ] - assert len(complete_logs) >= 1 - for msg in complete_logs: - assert "processed=" in msg - assert "total=" in msg - @pytest.mark.asyncio async def test_prewarm_calls_update_phase_audiodb(self): svc = AsyncMock() diff --git a/frontend/src/lib/components/DiscoverQueueModal.svelte b/frontend/src/lib/components/DiscoverQueueModal.svelte index 5a0c463..696b3d0 100644 --- a/frontend/src/lib/components/DiscoverQueueModal.svelte +++ b/frontend/src/lib/components/DiscoverQueueModal.svelte @@ -153,7 +153,6 @@ } } catch (e) { if (isAbortError(e)) return; - console.error('Failed to fetch discover queue:', e); } finally { loading = false; } @@ -177,7 +176,7 @@ await fetchNewQueue(); } } catch { - /* ignore validation errors */ + // ignore fetch failures } } @@ -224,7 +223,6 @@ return data; } catch (e) { if (isAbortError(e)) return null; - console.error('Failed to enrich item:', e); if (queue[index]?.release_group_mbid === mbid && !queue[index]?.enrichment) { queue[index] = { ...queue[index], enrichment: emptyEnrichment() }; } @@ -269,7 +267,7 @@ { signal: abortController?.signal } ); } catch { - /* continue regardless */ + // ignore request failure } queue = queue.filter((_, i) => i !== currentIndex); @@ -313,7 +311,7 @@ function truncateText(text: string, maxLen: number): string { if (text.length <= maxLen) return text; - return text.slice(0, maxLen).trimEnd() + '…'; + return text.slice(0, maxLen).trimEnd() + '...'; } function resetYtSearch() { @@ -327,7 +325,7 @@ signal: abortController?.signal }); } catch { - // YouTube not configured or network error — leave null + // ignore quota fetch failure } } @@ -369,7 +367,7 @@ {#if loading}
-

Building your discovery queue…

+

Building your discovery queue...

{:else if queue.length === 0}
@@ -395,7 +393,7 @@ {currentItem.album_name} {#if currentItem.is_wildcard} - ✨ + Wildcard {/if}
{#if artistNavigationMbid} diff --git a/frontend/src/lib/components/YouTubeDetailModal.svelte b/frontend/src/lib/components/YouTubeDetailModal.svelte index e5c6031..3ff91a7 100644 --- a/frontend/src/lib/components/YouTubeDetailModal.svelte +++ b/frontend/src/lib/components/YouTubeDetailModal.svelte @@ -107,10 +107,9 @@ const data = await api.global.get(API.youtube.trackLinks(albumId)); if (id !== fetchId) return; tracks = data.sort(compareDiscTrack); - } catch (e) { + } catch (_e) { if (id === fetchId) { trackError = true; - console.warn('Failed to fetch YouTube track links', e); } } finally { if (id === fetchId) loadingTracks = false; diff --git a/frontend/src/lib/player/NativeAudioSource.ts b/frontend/src/lib/player/NativeAudioSource.ts index 7525dfd..fe2d3a7 100644 --- a/frontend/src/lib/player/NativeAudioSource.ts +++ b/frontend/src/lib/player/NativeAudioSource.ts @@ -147,7 +147,6 @@ export class NativeAudioSource implements PlaybackSource { seekTo(seconds: number): void { if (!this.seekable) { - console.warn('[NativeAudio] seekTo ignored: stream is not seekable'); return; } const clamped = Math.max(0, seconds); diff --git a/frontend/src/lib/player/jellyfinPlaybackApi.spec.ts b/frontend/src/lib/player/jellyfinPlaybackApi.spec.ts index 6a7f004..c874e40 100644 --- a/frontend/src/lib/player/jellyfinPlaybackApi.spec.ts +++ b/frontend/src/lib/player/jellyfinPlaybackApi.spec.ts @@ -75,23 +75,17 @@ describe('jellyfinPlaybackApi', () => { }); }); - it('warns on network errors without throwing', async () => { - const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + it('returns false on network errors without throwing', async () => { mockPost.mockRejectedValueOnce(new Error('Network down')); await expect(api.reportProgress('item-1', 'sess-1', 10, false)).resolves.toBe(false); - expect(warnSpy).toHaveBeenCalledWith(expect.stringContaining('network error')); - warnSpy.mockRestore(); }); - it('warns on non-ok response without throwing', async () => { - const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + it('returns false on non-ok responses without throwing', async () => { const { ApiError } = await import('$lib/api/client'); mockPost.mockRejectedValueOnce(new ApiError(500, 'server_error', 'Internal error')); await expect(api.reportProgress('item-1', 'sess-1', 10, false)).resolves.toBe(false); - expect(warnSpy).toHaveBeenCalledWith(expect.stringContaining('500')); - warnSpy.mockRestore(); }); }); @@ -108,20 +102,17 @@ describe('jellyfinPlaybackApi', () => { }); }); - it('swallows errors silently', async () => { + it('returns false on errors', async () => { mockPost.mockRejectedValueOnce(new Error('Network down')); await expect(api.reportStop('item-1', 'sess-1', 60)).resolves.toBe(false); }); - it('warns on non-ok response without throwing', async () => { - const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {}); + it('returns false on non-ok responses without throwing', async () => { const { ApiError } = await import('$lib/api/client'); mockPost.mockRejectedValueOnce(new ApiError(502, 'bad_gateway', 'Bad gateway')); await expect(api.reportStop('item-1', 'sess-1', 60)).resolves.toBe(false); - expect(warnSpy).toHaveBeenCalledWith(expect.stringContaining('502')); - warnSpy.mockRestore(); }); }); }); diff --git a/frontend/src/lib/player/jellyfinPlaybackApi.ts b/frontend/src/lib/player/jellyfinPlaybackApi.ts index 729a9b9..2d68aa5 100644 --- a/frontend/src/lib/player/jellyfinPlaybackApi.ts +++ b/frontend/src/lib/player/jellyfinPlaybackApi.ts @@ -42,9 +42,7 @@ export async function reportProgress( is_paused: isPaused }); return true; - } catch (e) { - const detail = e instanceof ApiError ? String(e.status) : 'network error'; - console.warn(`[Jellyfin] progress report failed: ${detail}`); + } catch { return false; } } @@ -60,9 +58,7 @@ export async function reportStop( position_seconds: positionSeconds }); return true; - } catch (e) { - const detail = e instanceof ApiError ? String(e.status) : 'network error'; - console.warn(`[Jellyfin] stop report failed: ${detail}`); + } catch { return false; } } diff --git a/frontend/src/lib/player/navidromePlaybackApi.ts b/frontend/src/lib/player/navidromePlaybackApi.ts index 2f64933..0b3eca1 100644 --- a/frontend/src/lib/player/navidromePlaybackApi.ts +++ b/frontend/src/lib/player/navidromePlaybackApi.ts @@ -1,32 +1,26 @@ import { API } from '$lib/constants'; -import { api, ApiError } from '$lib/api/client'; +import { api } from '$lib/api/client'; export async function reportNavidromeScrobble(itemId: string): Promise { try { - const body = await api.global.post<{ status: string }>(API.stream.navidromeScrobble(itemId)); - if (body.status !== 'ok') { - console.warn('[Navidrome] scrobble reported error'); - } - } catch (e) { - const detail = e instanceof ApiError ? String(e.status) : 'network error'; - console.warn(`[Navidrome] scrobble failed: ${detail}`); + await api.global.post<{ status: string }>(API.stream.navidromeScrobble(itemId)); + } catch { + // best-effort scrobble } } export async function reportNavidromeNowPlaying(itemId: string): Promise { try { await api.global.post(API.stream.navidromeNowPlaying(itemId)); - } catch (e) { - const detail = e instanceof ApiError ? String(e.status) : 'network error'; - console.warn(`[Navidrome] now-playing failed: ${detail}`); + } catch { + // best-effort now-playing report } } export async function reportNavidromeStopped(itemId: string): Promise { try { await api.global.post(API.stream.navidromeStopped(itemId)); - } catch (e) { - const detail = e instanceof ApiError ? String(e.status) : 'network error'; - console.warn(`[Navidrome] stopped report failed: ${detail}`); + } catch { + // best-effort stopped report } } diff --git a/frontend/src/lib/queries/IndexedDbPersister.svelte.ts b/frontend/src/lib/queries/IndexedDbPersister.svelte.ts index 4fff9bb..7422901 100644 --- a/frontend/src/lib/queries/IndexedDbPersister.svelte.ts +++ b/frontend/src/lib/queries/IndexedDbPersister.svelte.ts @@ -6,11 +6,6 @@ import type { } from '@tanstack/svelte-query-persist-client'; import { del, entries, get, set } from 'idb-keyval'; -/** - * Creates an Indexed DB persister - * @see https://developer.mozilla.org/en-US/docs/Web/API/IndexedDB_API - * @see https://tanstack.com/query/latest/docs/framework/react/plugins/persistQueryClient#building-a-persister - */ export function createIDBPersister(idbValidKey: string = 'tanstackQuery') { return { persistClient: async (client: PersistedClient) => { diff --git a/frontend/src/lib/stores/imageSettings.ts b/frontend/src/lib/stores/imageSettings.ts index c644959..1f40649 100644 --- a/frontend/src/lib/stores/imageSettings.ts +++ b/frontend/src/lib/stores/imageSettings.ts @@ -26,8 +26,8 @@ async function load(): Promise { directRemoteImagesEnabled: data.direct_remote_images_enabled ?? true }); lastFetch = now; - } catch (e) { - console.warn('Failed to load image settings:', e); + } catch { + // use defaults on fetch failure } } diff --git a/frontend/src/lib/stores/library.ts b/frontend/src/lib/stores/library.ts index 058c682..2efa14e 100644 --- a/frontend/src/lib/stores/library.ts +++ b/frontend/src/lib/stores/library.ts @@ -102,8 +102,7 @@ function createLibraryStore() { })); cache.set({ mbids, requested }); - } catch (e) { - console.error('Failed to fetch library MBIDs:', e); + } catch { if (!background) { update((s) => ({ ...s, loading: false, initialized: true })); } diff --git a/frontend/src/lib/stores/preferences.ts b/frontend/src/lib/stores/preferences.ts index 9bea598..29a94cf 100644 --- a/frontend/src/lib/stores/preferences.ts +++ b/frontend/src/lib/stores/preferences.ts @@ -16,8 +16,8 @@ async function loadPreferences(): Promise { try { const prefs = await api.global.get(`${API_BASE}/settings/preferences`); set(prefs); - } catch (e) { - console.error('Failed to load preferences:', e); + } catch { + // use defaults on fetch failure } } @@ -29,8 +29,7 @@ async function savePreferences(prefs: UserPreferences): Promise { ); set(updated); return true; - } catch (e) { - console.error('Failed to save preferences:', e); + } catch { return false; } } diff --git a/frontend/src/lib/utils/localStorageCache.ts b/frontend/src/lib/utils/localStorageCache.ts index bf3abd0..c9600a3 100644 --- a/frontend/src/lib/utils/localStorageCache.ts +++ b/frontend/src/lib/utils/localStorageCache.ts @@ -73,7 +73,7 @@ export function createLocalStorageCache( return key.startsWith(keyPrefix); } - function isQuotaExceededError(error: unknown): boolean { + function _isQuotaExceededError(error: unknown): boolean { if (!(error instanceof DOMException)) return false; return ( error.code === 22 || @@ -128,10 +128,7 @@ export function createLocalStorageCache( try { localStorage.setItem(key, payload); return true; - } catch (error) { - if (!isQuotaExceededError(error)) { - console.warn(`[localStorageCache] Failed to write key "${key}":`, error); - } + } catch { return false; } } @@ -172,8 +169,6 @@ export function createLocalStorageCache( enforceMaxEntriesLimit(); return; } - - console.warn(`[localStorageCache] Storage quota exceeded for key "${key}".`); } function remove(suffix?: string): void { diff --git a/frontend/src/routes/+layout.ts b/frontend/src/routes/+layout.ts index 0842076..72af78d 100644 --- a/frontend/src/routes/+layout.ts +++ b/frontend/src/routes/+layout.ts @@ -3,7 +3,6 @@ import { API } from '$lib/constants'; import { DEFAULT_SOURCE, isMusicSource } from '$lib/stores/musicSource'; import type { LayoutLoad } from './$types'; -// Disable SSR, because we currently use only CSR export const ssr = false; export const prerender = false; @@ -15,8 +14,7 @@ export const load: LayoutLoad = async () => { return { primarySource }; - } catch (error) { - console.error('Error fetching primary music source:', error); + } catch { return { primarySource: DEFAULT_SOURCE }; diff --git a/frontend/src/routes/library/albums/+page.svelte b/frontend/src/routes/library/albums/+page.svelte index c467b90..6c2c3d3 100644 --- a/frontend/src/routes/library/albums/+page.svelte +++ b/frontend/src/routes/library/albums/+page.svelte @@ -71,7 +71,6 @@ } catch (e) { if (isAbortError(e)) return; if (id !== fetchId) return; - console.error("Couldn't load albums:", e); error = "Couldn't load albums"; } finally { if (id === fetchId) { @@ -170,10 +169,10 @@ onchange={handleSortChange} aria-label="Sort albums" > - - - - + + + + diff --git a/frontend/src/routes/library/artists/+page.svelte b/frontend/src/routes/library/artists/+page.svelte index 2abe398..fa7f294 100644 --- a/frontend/src/routes/library/artists/+page.svelte +++ b/frontend/src/routes/library/artists/+page.svelte @@ -67,7 +67,6 @@ } catch (e) { if (isAbortError(e)) return; if (id !== fetchId) return; - console.error("Couldn't load artists:", e); error = "Couldn't load artists"; } finally { if (id === fetchId) { @@ -163,8 +162,8 @@ onchange={handleSortChange} aria-label="Sort artists" > - - + +