diff --git a/.github/workflows/build-and-test.yml b/.github/workflows/build-and-test.yml index f94a3123..8c9b1a1c 100644 --- a/.github/workflows/build-and-test.yml +++ b/.github/workflows/build-and-test.yml @@ -2,6 +2,9 @@ name: Compile the app and run tests on: push: + branches-ignore: + - main + - dev jobs: sanity-check: @@ -21,6 +24,9 @@ jobs: - name: Install dependencies run: python -m pip install --upgrade pip && python -m pip install -r requirements-dev.txt + - name: Lint with ruff + run: python -m ruff check --output-format=github . + - name: Build app run: python -m compileall api core database services scripts web_server.py wsgi.py beatport_unified_scraper.py diff --git a/.github/workflows/cleanup-dev-images.yml b/.github/workflows/cleanup-dev-images.yml new file mode 100644 index 00000000..19597992 --- /dev/null +++ b/.github/workflows/cleanup-dev-images.yml @@ -0,0 +1,24 @@ +name: Cleanup old dev images + +on: + schedule: + # Weekly on Sunday at 6 AM UTC + - cron: '0 6 * * 0' + workflow_dispatch: + +jobs: + cleanup: + runs-on: ubuntu-latest + permissions: + packages: write + + steps: + - name: Delete old dev image tags + uses: actions/delete-package-versions@v5 + with: + package-name: soulsync + package-type: container + min-versions-to-keep: 10 + delete-only-pre-release-versions: false + # Only prune tags matching the dev nightly pattern (keep rolling + version tags) + ignore-versions: '^(dev|nightly|latest|\\d+\\.\\d+)$' diff --git a/.github/workflows/dev-nightly.yml b/.github/workflows/dev-nightly.yml new file mode 100644 index 00000000..d5312d29 --- /dev/null +++ b/.github/workflows/dev-nightly.yml @@ -0,0 +1,103 @@ +name: Dev Nightly Build + +on: + # Nightly at 4:00 AM UTC ā only if dev branch has new commits + schedule: + - cron: '0 4 * * *' + # Also build on every push to dev for immediate feedback + push: + branches: + - dev + # Manual trigger for testing + workflow_dispatch: + +jobs: + nightly: + runs-on: ubuntu-latest + # Skip scheduled runs if dev branch has no new commits in the last 24h + # (pushes and manual triggers always run) + permissions: + contents: read + packages: write + + steps: + - name: Checkout dev branch + uses: actions/checkout@v6 + with: + ref: dev + + - name: Set lowercase owner + run: echo "OWNER=${GITHUB_REPOSITORY_OWNER,,}" >> "$GITHUB_ENV" + + - name: Check for recent commits (scheduled only) + if: github.event_name == 'schedule' + id: recent + run: | + LAST_COMMIT=$(git log -1 --format=%ct) + NOW=$(date +%s) + DIFF=$(( NOW - LAST_COMMIT )) + if [ "$DIFF" -gt 86400 ]; then + echo "No commits in the last 24h, skipping build" + echo "skip=true" >> "$GITHUB_OUTPUT" + else + echo "skip=false" >> "$GITHUB_OUTPUT" + fi + + - name: Set up Python + if: steps.recent.outputs.skip != 'true' + uses: actions/setup-python@v6 + with: + python-version: "3.11" + cache: pip + cache-dependency-path: requirements-dev.txt + + - name: Install dependencies and run tests + if: steps.recent.outputs.skip != 'true' + env: + PYTHONPATH: ${{ github.workspace }} + run: | + python -m pip install --upgrade pip + python -m pip install -r requirements-dev.txt + python -m ruff check --output-format=github . + python -m compileall api core database services scripts web_server.py wsgi.py beatport_unified_scraper.py + python -m pytest + + - name: Set up QEMU + if: steps.recent.outputs.skip != 'true' + uses: docker/setup-qemu-action@v4 + + - name: Set up Docker Buildx + if: steps.recent.outputs.skip != 'true' + uses: docker/setup-buildx-action@v4 + + - name: Log in to GHCR + if: steps.recent.outputs.skip != 'true' + uses: docker/login-action@v4 + with: + registry: ghcr.io + username: ${{ env.OWNER }} + password: ${{ secrets.GITHUB_TOKEN }} + + - name: Generate build tag + if: steps.recent.outputs.skip != 'true' + id: tag + run: | + echo "date=$(date -u +%Y%m%d)" >> "$GITHUB_OUTPUT" + echo "short_sha=${GITHUB_SHA::7}" >> "$GITHUB_OUTPUT" + + - name: Build and push to GHCR + if: steps.recent.outputs.skip != 'true' + uses: docker/build-push-action@v7 + with: + context: . + platforms: linux/amd64,linux/arm64 + push: true + pull: true + cache-from: type=gha + cache-to: type=gha,mode=max + build-args: | + COMMIT_SHA=${{ github.sha }} + tags: | + ghcr.io/${{ env.OWNER }}/soulsync:dev + ghcr.io/${{ env.OWNER }}/soulsync:dev-${{ steps.tag.outputs.date }}-${{ steps.tag.outputs.short_sha }} + ${{ github.event_name == 'schedule' && format('ghcr.io/{0}/soulsync:nightly', env.OWNER) || '' }} diff --git a/.github/workflows/docker-publish.yml b/.github/workflows/docker-publish.yml index f12467cf..b18d1b26 100644 --- a/.github/workflows/docker-publish.yml +++ b/.github/workflows/docker-publish.yml @@ -1,6 +1,11 @@ name: Build and Push Docker Image on: + # Auto-build :latest on every push to main + push: + branches: + - main + # Manual trigger for tagged releases (e.g. 2.33) workflow_dispatch: inputs: version_tag: @@ -12,10 +17,17 @@ jobs: build-and-push: runs-on: ubuntu-latest + permissions: + contents: read + packages: write + steps: - name: Checkout code uses: actions/checkout@v6 + - name: Set lowercase owner + run: echo "OWNER=${GITHUB_REPOSITORY_OWNER,,}" >> "$GITHUB_ENV" + - name: Set up QEMU uses: docker/setup-qemu-action@v4 @@ -28,22 +40,32 @@ jobs: username: ${{ secrets.DOCKERHUB_USERNAME }} password: ${{ secrets.DOCKERHUB_TOKEN }} + - name: Log in to GHCR + uses: docker/login-action@v4 + with: + registry: ghcr.io + username: ${{ env.OWNER }} + password: ${{ secrets.GITHUB_TOKEN }} + - name: Build and push uses: docker/build-push-action@v7 with: context: . platforms: linux/amd64,linux/arm64 push: true - no-cache: true pull: true + cache-from: type=gha + cache-to: type=gha,mode=max build-args: | COMMIT_SHA=${{ github.sha }} tags: | boulderbadgedad/soulsync:latest - boulderbadgedad/soulsync:${{ inputs.version_tag }} + ghcr.io/${{ env.OWNER }}/soulsync:latest + ${{ inputs.version_tag && format('boulderbadgedad/soulsync:{0}', inputs.version_tag) || '' }} + ${{ inputs.version_tag && format('ghcr.io/{0}/soulsync:{1}', env.OWNER, inputs.version_tag) || '' }} - name: Announce release to Discord - if: success() + if: success() && inputs.version_tag env: DISCORD_WEBHOOK: ${{ secrets.DISCORD_ANNOUNCEMENTS_WEBHOOK }} run: | diff --git a/.gitignore b/.gitignore index 59d00f35..8266b83b 100644 --- a/.gitignore +++ b/.gitignore @@ -25,3 +25,5 @@ bin/ # Development compose/config files *.dev.yml +# Any hidden folders +**/.*/ diff --git a/Support/README-Docker.md b/Support/README-Docker.md index d52a4205..77d0f2d8 100644 --- a/Support/README-Docker.md +++ b/Support/README-Docker.md @@ -63,6 +63,7 @@ environment: - FLASK_ENV=production # Flask environment - PYTHONPATH=/app # Python path - SOULSYNC_CONFIG_PATH=/app/config/config.json # Config file location + - SOULSYNC_LOG_LEVEL=INFO # Optional startup log level override, takes precedence over the UI-configured log level - TZ=America/New_York # Timezone ``` @@ -268,4 +269,4 @@ services: - [ ] Configure firewall rules - [ ] Set up backup strategy - [ ] Test health checks -- [ ] Verify external service connectivity \ No newline at end of file +- [ ] Verify external service connectivity diff --git a/api/playlists.py b/api/playlists.py index 75754e85..369ba72d 100644 --- a/api/playlists.py +++ b/api/playlists.py @@ -138,7 +138,7 @@ def register_routes(bp): try: # Forward to the internal sync endpoint import requests as http_requests - internal_url = f"http://127.0.0.1:8008/api/sync/start" + internal_url = "http://127.0.0.1:8008/api/sync/start" resp = http_requests.post(internal_url, json={ "playlist_id": playlist_id, "playlist_name": playlist_name, diff --git a/beatport_unified_scraper.py b/beatport_unified_scraper.py index eced8d24..67daf909 100644 --- a/beatport_unified_scraper.py +++ b/beatport_unified_scraper.py @@ -7,6 +7,8 @@ Focused on extracting clean artist and track names for virtual playlists import requests from bs4 import BeautifulSoup import json +import logging +import os import time import re from urllib.parse import urljoin @@ -14,6 +16,39 @@ from typing import Dict, List, Optional import concurrent.futures from threading import Lock +from utils.logging_config import get_logger + + +logger = get_logger("beatport_scraper") +_BEATPORT_LOGGING_ENABLED = os.environ.get("SOULSYNC_BEATPORT_SCRAPER_LOGS", "").lower() in ("1", "true", "yes", "on") +if _BEATPORT_LOGGING_ENABLED: + logger.setLevel(logging.DEBUG) +else: + logger.setLevel(logging.CRITICAL + 1) + +def _beatport_log(message: str): + """Route scraper output through logging when explicitly enabled.""" + if not _BEATPORT_LOGGING_ENABLED: + return + + text = str(message) + stripped = text.strip() + + if not stripped: + return + + lowered = stripped.lower() + level = logging.DEBUG + + if lowered.startswith("error") or " exception" in lowered or lowered.startswith("failed") or " failed" in lowered: + level = logging.ERROR + elif lowered.startswith("could not") or lowered.startswith("couldn't"): + level = logging.WARNING + elif lowered.startswith("no ") and "found" not in lowered: + level = logging.WARNING + + logger.log(level, text) + class BeatportUnifiedScraper: def __init__(self): self.base_url = "https://beatport.com" @@ -127,7 +162,7 @@ class BeatportUnifiedScraper: response.raise_for_status() return BeautifulSoup(response.content, 'html.parser') except requests.RequestException as e: - print(f"Error fetching {url}: {e}") + _beatport_log(f"Error fetching {url}: {e}") return None def clean_artist_track_data(self, raw_artist: str, raw_title: str) -> Dict[str, str]: @@ -171,12 +206,12 @@ class BeatportUnifiedScraper: def discover_genres_from_homepage(self) -> List[Dict]: """Dynamically discover all genres from Beatport homepage dropdown""" - print("Discovering genres from Beatport homepage...") + _beatport_log("Discovering genres from Beatport homepage...") try: soup = self.get_page(self.base_url) if not soup: - print("Could not fetch homepage") + _beatport_log("Could not fetch homepage") return self.fallback_genres genres = [] @@ -185,14 +220,14 @@ class BeatportUnifiedScraper: genres_dropdown = soup.find('div', {'id': 'genres-dropdown-menu'}) if genres_dropdown: - print("Found genres-dropdown-menu") + _beatport_log("Found genres-dropdown-menu") # Look for the two main div containers as described genre_containers = genres_dropdown.find_all('div', recursive=False) - print(f"Found {len(genre_containers)} top-level containers in dropdown") + _beatport_log(f"Found {len(genre_containers)} top-level containers in dropdown") for container_idx, container in enumerate(genre_containers): - print(f"Processing container {container_idx + 1}") + _beatport_log(f"Processing container {container_idx + 1}") # Look specifically for .dropdown_menu classes dropdown_menus = container.find_all(class_='dropdown_menu') @@ -202,17 +237,17 @@ class BeatportUnifiedScraper: dropdown_menus = container.find_all(class_=re.compile(r'dropdown.*menu', re.I)) if not dropdown_menus: - print(f"No .dropdown_menu found in container {container_idx + 1}") + _beatport_log(f"No .dropdown_menu found in container {container_idx + 1}") continue for menu_idx, menu in enumerate(dropdown_menus): - print(f"Processing dropdown_menu {menu_idx + 1} in container {container_idx + 1}") + _beatport_log(f"Processing dropdown_menu {menu_idx + 1} in container {container_idx + 1}") # Look for
Could not initialize Spotify client. Check your credentials.
", 400 except Exception as e: - print(f"Error starting Spotify auth: {e}") + logger.error(f"Error starting Spotify auth: {e}") return f"{str(e)}
", 500 @app.route('/auth/tidal') @@ -7866,7 +7880,7 @@ def auth_tidal(): """ Initiates Tidal OAuth authentication flow """ - print("TIDAL AUTH ROUTE CALLED ") + logger.info("TIDAL AUTH ROUTE CALLED ") try: # Create a fresh tidal client to get OAuth URL from core.tidal_client import TidalClient @@ -7889,20 +7903,20 @@ def auth_tidal(): configured_redirect = config_manager.get('tidal.redirect_uri', '') if configured_redirect: temp_tidal_client.redirect_uri = configured_redirect - print(f"Using configured Tidal redirect_uri: {configured_redirect}") + logger.info(f"Using configured Tidal redirect_uri: {configured_redirect}") else: # Fallback: dynamically set based on request host (non-Docker local access) request_host = request.host.split(':')[0] if request_host not in ('127.0.0.1', 'localhost'): dynamic_redirect = f"http://{request_host}:8889/tidal/callback" temp_tidal_client.redirect_uri = dynamic_redirect - print(f"Tidal redirect_uri set from request host: {dynamic_redirect}") + logger.info(f"Tidal redirect_uri set from request host: {dynamic_redirect}") # Store PKCE + redirect_uri for callback to use the same values with tidal_oauth_lock: tidal_oauth_state["redirect_uri"] = temp_tidal_client.redirect_uri - print(f"Stored PKCE - verifier: {temp_tidal_client.code_verifier[:20]}... challenge: {temp_tidal_client.code_challenge[:20]}...") + logger.info(f"Stored PKCE - verifier: {temp_tidal_client.code_verifier[:20]}... challenge: {temp_tidal_client.code_challenge[:20]}...") # Store profile_id for per-profile auth profile_id = request.args.get('profile_id', '') @@ -7922,8 +7936,8 @@ def auth_tidal(): auth_url = f"{temp_tidal_client.auth_url}?" + urllib.parse.urlencode(params) - print(f"Generated Tidal OAuth URL: {auth_url}") - print(f"Redirect URI in URL: {params['redirect_uri']}") + logger.info(f"Generated Tidal OAuth URL: {auth_url}") + logger.info(f"Redirect URI in URL: {params['redirect_uri']}") add_activity_item("", "Tidal Auth Started", "Please complete OAuth in browser", "Now") @@ -7995,9 +8009,9 @@ def auth_tidal(): return f'Please visit this URL to authenticate:
After authentication, return to the app.
' except Exception as e: - print(f"Error starting Tidal auth: {e}") + logger.error(f"Error starting Tidal auth: {e}") import traceback - print(f"Full traceback: {traceback.format_exc()}") + logger.error(f"Full traceback: {traceback.format_exc()}") return f"{str(e)}
", 500 @@ -8014,19 +8028,19 @@ def spotify_callback(): if not auth_code: error = request.args.get('error') if error: - print(f"Spotify OAuth error on port 8008: Spotify returned error: {error}") + logger.error(f"Spotify OAuth error on port 8008: Spotify returned error: {error}") add_activity_item("", "Spotify Auth Failed", f"Spotify returned error: {error}", "Now") return f"Spotify returned error: {error}
", 400 # No code AND no error ā check if query params were stripped if request.args: - print(f"Spotify callback on port 8008 received unexpected params: {dict(request.args)}") + logger.info(f"Spotify callback on port 8008 received unexpected params: {dict(request.args)}") else: # Completely empty ā likely a healthcheck or spurious request pass return '', 204 - print(f"Spotify callback received on port 8008 with authorization code") + logger.info(f"Spotify callback received on port 8008 with authorization code") # Check for per-profile state parameter state = request.args.get('state', '') @@ -8034,7 +8048,7 @@ def spotify_callback(): if state and state.startswith('profile_'): try: profile_id_from_state = int(state.replace('profile_', '')) - print(f"Per-profile callback detected for profile {profile_id_from_state}") + logger.info(f"Per-profile callback detected for profile {profile_id_from_state}") except ValueError: pass @@ -8070,7 +8084,7 @@ def spotify_callback(): # Global callback (admin) config = config_manager.get_spotify_config() configured_uri = config.get('redirect_uri', "http://127.0.0.1:8888/callback") - print(f"Using redirect_uri for token exchange: {configured_uri}") + logger.info(f"Using redirect_uri for token exchange: {configured_uri}") auth_manager = SpotifyOAuth( client_id=config['client_id'], @@ -8105,7 +8119,7 @@ def spotify_callback(): else: raise Exception("Failed to exchange authorization code for access token") except Exception as e: - print(f"Spotify OAuth callback error on port 8008: {e}") + logger.error(f"Spotify OAuth callback error on port 8008: {e}") add_activity_item("", "Spotify Auth Failed", f"Token processing failed: {str(e)}", "Now") return f"{str(e)}
", 400 @@ -8208,7 +8222,7 @@ def tidal_callback(): add_activity_item("", "Tidal Auth Complete", f"Profile {profile_id_int} authenticated with Tidal", "Now") return "Your personal Tidal account is now connected. You can close this window.
" except Exception as profile_err: - print(f"Per-profile Tidal auth failed, falling back to global: {profile_err}") + logger.error(f"Per-profile Tidal auth failed, falling back to global: {profile_err}") # Global: Re-initialize the main global tidal_client instance with the new token tidal_client = TidalClient() @@ -8218,7 +8232,7 @@ def tidal_callback(): else: return "Could not exchange authorization code for a token. Please try again.
", 400 except Exception as e: - print(f"Error during Tidal token exchange: {e}") + logger.error(f"Error during Tidal token exchange: {e}") return f"An unexpected error occurred during the authentication process: {e}
", 500 @@ -8339,14 +8353,9 @@ def get_beatport_hero_tracks(): # SMART FILTERING - Remove duplicates and invalid tracks valid_tracks = [] seen_urls = set() - - logger.info(f"Processing {len(tracks)} raw tracks from scraper (SMART FILTERING)...") + filtered_reasons = collections.Counter() for i, track in enumerate(tracks): - logger.info(f" Track {i+1}: {track.get('title', 'NO_TITLE')} - {track.get('artist', 'NO_ARTIST')}") - logger.info(f" URL: {track.get('url', 'NO_URL')}") - logger.info(f" Image: {'YES' if track.get('image_url') else 'NO'}") - # Extract and clean basic data title = track.get('title', '').strip() artist = track.get('artist', '').strip() @@ -8391,7 +8400,7 @@ def get_beatport_hero_tracks(): skip_reasons.append("Duplicate URL") if not is_valid: - logger.info(f" Track {i+1} filtered out: {', '.join(skip_reasons)}") + filtered_reasons.update(skip_reasons) continue # Mark URL as seen for deduplication @@ -8434,7 +8443,16 @@ def get_beatport_hero_tracks(): break valid_tracks.append(track_data) - logger.info(f" Track {i+1} added: {title} - {artist}") + + sample_titles = [f"{t['title']} - {t['artist']}" for t in valid_tracks[:3]] + logger.debug( + "Beatport smart filter summary: raw=%s valid=%s filtered=%s reasons=%s sample=%s", + len(tracks), + len(valid_tracks), + len(tracks) - len(valid_tracks), + dict(filtered_reasons), + sample_titles, + ) logger.info(f"Retrieved {len(valid_tracks)} valid unique Beatport tracks (SMART FILTERING)") @@ -8620,17 +8638,17 @@ def get_beatport_featured_charts(): gridsliders = soup.select('[class*="GridSlider-style__Wrapper"]') featured_container = None - logger.info(f"Checking {len(gridsliders)} GridSlider containers for featured charts...") + logger.debug(f"Checking {len(gridsliders)} GridSlider containers for featured charts...") for container in gridsliders: h2 = container.select_one('h2') if h2: title = h2.get_text(strip=True).lower() - logger.info(f"Found section: '{h2.get_text(strip=True)}'") + logger.debug(f"Found section: '{h2.get_text(strip=True)}'") if 'featured' in title and 'chart' in title: featured_container = container - logger.info(f"FOUND FEATURED CHARTS: '{h2.get_text(strip=True)}'") + logger.debug(f"FOUND FEATURED CHARTS: '{h2.get_text(strip=True)}'") break if not featured_container: @@ -8645,7 +8663,7 @@ def get_beatport_featured_charts(): charts = [] chart_links = featured_container.select('a[href*="/chart/"]') - logger.info(f"Found {len(chart_links)} chart links in Featured Charts section") + logger.debug(f"Found {len(chart_links)} chart links in Featured Charts section") for i, link in enumerate(chart_links[:100]): # Limit to 100 for 10 slides chart_data = {} @@ -8713,7 +8731,7 @@ def get_beatport_featured_charts(): # Only add if we have meaningful data if 'name' in chart_data and 'url' in chart_data: charts.append(chart_data) - logger.info(f"Chart {len(charts)}: {chart_data['name']} by {chart_data['creator']}") + logger.debug(f"Chart {len(charts)}: {chart_data['name']} by {chart_data['creator']}") logger.info(f"Successfully extracted {len(charts)} featured charts") @@ -8769,12 +8787,12 @@ def get_beatport_dj_charts(): carousels = soup.select('[class*="Carousel-style__Wrapper"]') dj_container = None - logger.info(f"Checking {len(carousels)} Carousel containers for DJ charts...") + logger.debug(f"Checking {len(carousels)} Carousel containers for DJ charts...") # Based on test results, DJ charts are in the second carousel (index 1) with ~9 chart links for i, container in enumerate(carousels): chart_links = container.select('a[href*="/chart/"]') - logger.info(f"Carousel {i+1}: {len(chart_links)} chart links") + logger.debug(f"Carousel {i+1}: {len(chart_links)} chart links") # DJ charts container typically has 8-12 chart links (not 99+ like featured charts) if 5 <= len(chart_links) <= 15: @@ -8949,7 +8967,7 @@ def search_music(): return jsonify({"results": all_results}) except Exception as e: - print(f"Search error: {e}") + logger.error(f"Search error: {e}") return jsonify({"error": str(e)}), 500 @app.route('/api/enhanced-search', methods=['POST']) @@ -9633,16 +9651,16 @@ def download_music_video(): track_title = best.name if hasattr(best, 'release_date') and best.release_date: year = str(best.release_date)[:4] - print(f"[Music Video] Matched to: {artist_name} - {track_title} (confidence: {best_score:.2f})") + logger.info(f"[Music Video] Matched to: {artist_name} - {track_title} (confidence: {best_score:.2f})") else: # Parse artist from video title: "Artist - Title" pattern if ' - ' in raw_title: parts = raw_title.split(' - ', 1) artist_name = parts[0].strip() track_title = _re.sub(r'\s*[\(\[].*?[\)\]]', '', parts[1]).strip() - print(f"[Music Video] No metadata match, using parsed: {artist_name} - {track_title}") + logger.warning(f"[Music Video] No metadata match, using parsed: {artist_name} - {track_title}") except Exception as e: - print(f"[Music Video] Metadata lookup failed: {e}") + logger.error(f"[Music Video] Metadata lookup failed: {e}") if ' - ' in raw_title: parts = raw_title.split(' - ', 1) artist_name = parts[0].strip() @@ -9688,17 +9706,17 @@ def download_music_video(): _music_video_downloads[video_id]['status'] = 'completed' _music_video_downloads[video_id]['progress'] = 100 _music_video_downloads[video_id]['path'] = final_path - print(f"[Music Video] Downloaded: {artist_name} - {track_title} ā {final_path}") + logger.info(f"[Music Video] Downloaded: {artist_name} - {track_title} ā {final_path}") add_activity_item("", "Music Video Downloaded", f"{artist_name} - {track_title}", "Now") else: _music_video_downloads[video_id]['status'] = 'error' _music_video_downloads[video_id]['error'] = 'Download failed ā file not found' - print(f"[Music Video] Download failed for: {artist_name} - {track_title}") + logger.error(f"[Music Video] Download failed for: {artist_name} - {track_title}") except Exception as e: _music_video_downloads[video_id]['status'] = 'error' _music_video_downloads[video_id]['error'] = str(e) - print(f"[Music Video] Error: {e}") + logger.error(f"[Music Video] {e}") # Run in background thread import threading @@ -9891,11 +9909,11 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): file_path = os.path.join(root, file) # Fast path: if path aligns with expected directory structure, return now if api_dir_parts and _path_matches_api_dirs(file_path): - print(f"Found path-confirmed match in {location_name}: {file_path}") + logger.info(f"Found path-confirmed match in {location_name}: {file_path}") return file_path, 1.0 if not api_dir_parts: # No directory info to disambiguate ā return first match (original behavior) - print(f"Found exact match in {location_name}: {file_path}") + logger.info(f"Found exact match in {location_name}: {file_path}") return file_path, 1.0 exact_matches.append(file_path) continue @@ -9907,10 +9925,10 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): if stripped_stem != file_stem and stripped_stem + file_ext_part == target_basename: file_path = os.path.join(root, file) if api_dir_parts and _path_matches_api_dirs(file_path): - print(f"Found path-confirmed dedup match in {location_name}: {file_path}") + logger.info(f"Found path-confirmed dedup match in {location_name}: {file_path}") return file_path, 1.0 if not api_dir_parts: - print(f"Found dedup-suffix match in {location_name}: {file_path}") + logger.info(f"Found dedup-suffix match in {location_name}: {file_path}") return file_path, 1.0 exact_matches.append(file_path) continue @@ -9926,7 +9944,7 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): # Return best exact match (disambiguated by path), or fall back to fuzzy if exact_matches: if len(exact_matches) == 1: - print(f"Found exact match in {location_name}: {exact_matches[0]}") + logger.info(f"Found exact match in {location_name}: {exact_matches[0]}") return exact_matches[0], 1.0 # Multiple files share the basename ā pick the one whose path best # matches the expected directory structure from the Soulseek remote path @@ -9938,7 +9956,7 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): if score > best_score: best_score = score best = m - print(f"Found {len(exact_matches)} files named '{target_basename}' in {location_name}, picked best path match: {best}") + logger.info(f"Found {len(exact_matches)} files named '{target_basename}' in {location_name}, picked best path match: {best}") return best, 1.0 return best_fuzzy_path, highest_fuzzy_similarity @@ -9960,7 +9978,7 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): if downloads_similarity > 0.85: location = 'downloads' if downloads_similarity < 1.0: - print(f"Found fuzzy match in downloads ({downloads_similarity:.2f}): {best_downloads_path}") + logger.info(f"Found fuzzy match in downloads ({downloads_similarity:.2f}): {best_downloads_path}") return (best_downloads_path, location) # If not found in downloads and transfer_dir is provided, search there @@ -9971,7 +9989,7 @@ def _find_completed_file_robust(download_dir, api_filename, transfer_dir=None): if transfer_similarity > 0.85: location = 'transfer' if transfer_similarity < 1.0: - print(f"Found fuzzy match in transfer ({transfer_similarity:.2f}): {best_transfer_path}") + logger.info(f"Found fuzzy match in transfer ({transfer_similarity:.2f}): {best_transfer_path}") return (best_transfer_path, location) # Don't spam logs - file not found is common for completed/processed downloads @@ -10040,7 +10058,7 @@ def get_download_status(): with matched_context_lock: has_active_context = context_key in matched_downloads_context if has_active_context: - print(f"Orphaned key {context_key} has active context ā retry re-used same source, treating as active") + logger.warning(f"Orphaned key {context_key} has active context ā retry re-used same source, treating as active") _orphaned_download_keys.discard(context_key) # Fall through to normal processing below else: @@ -10051,10 +10069,10 @@ def get_download_status(): if found_path: try: os.remove(found_path) - print(f"Deleted orphaned download: {os.path.basename(found_path)}") + logger.warning(f"Deleted orphaned download: {os.path.basename(found_path)}") orphan_cleaned = True except Exception as e: - print(f"Failed to delete orphaned file (will retry next poll): {e}") + logger.error(f"Failed to delete orphaned file (will retry next poll): {e}") else: # File not on disk (already gone or never written) ā nothing to clean orphan_cleaned = True @@ -10078,11 +10096,11 @@ def get_download_status(): available_keys = list(matched_downloads_context.keys())[:5] if not context else None if context: - print(f"[Context Lookup] Found context for key: {context_key}") + logger.info(f"[Context Lookup] Found context for key: {context_key}") elif context_key not in _stale_transfer_keys: # Only log once per stale key to avoid spamming every poll cycle - print(f"[Context Lookup] No context found for key: {context_key}") - print(f" Available keys: {available_keys}...") + logger.warning(f"[Context Lookup] No context found for key: {context_key}") + logger.info(f" Available keys: {available_keys}...") _stale_transfer_keys.add(context_key) if context: @@ -10095,10 +10113,10 @@ def get_download_status(): # Prevent two contexts from claiming the same physical file _norm_path = os.path.normpath(found_path) if _norm_path in _files_claimed_this_cycle: - print(f"File already claimed by another context this cycle: {os.path.basename(found_path)} ā deferring to next poll") + logger.info(f"File already claimed by another context this cycle: {os.path.basename(found_path)} ā deferring to next poll") else: _files_claimed_this_cycle.add(_norm_path) - print(f"Found completed matched file on disk: {found_path}") + logger.info(f"Found completed matched file on disk: {found_path}") completed_matched_downloads.append((context_key, context, found_path)) # Don't add to _processed_download_ids yet - wait until thread starts successfully @@ -10107,7 +10125,7 @@ def get_download_status(): if context_key in _download_retry_attempts: retry_count = _download_retry_attempts[context_key]['count'] elapsed = time.time() - _download_retry_attempts[context_key]['first_attempt'] - print(f"File found after {retry_count} retry attempt(s) ({elapsed:.1f}s): {os.path.basename(filename_from_api)}") + logger.warning(f"File found after {retry_count} retry attempt(s) ({elapsed:.1f}s): {os.path.basename(filename_from_api)}") del _download_retry_attempts[context_key] else: # File not found yet - implement retry logic instead of immediate give-up @@ -10119,7 +10137,7 @@ def get_download_status(): 'count': 1, 'first_attempt': time.time() } - print(f"File not found yet: '{os.path.basename(filename_from_api)}' - Will retry (attempt 1/{_download_retry_max})") + logger.warning(f"File not found yet: '{os.path.basename(filename_from_api)}' - Will retry (attempt 1/{_download_retry_max})") else: # Increment retry count _download_retry_attempts[context_key]['count'] += 1 @@ -10128,19 +10146,19 @@ def get_download_status(): if retry_count >= _download_retry_max: # Max retries reached, give up - print(f"CRITICAL: Could not find '{os.path.basename(filename_from_api)}' after {retry_count} attempts over {elapsed:.1f}s. Giving up.") + logger.error(f"CRITICAL: Could not find '{os.path.basename(filename_from_api)}' after {retry_count} attempts over {elapsed:.1f}s. Giving up.") _processed_download_ids.add(context_key) # Clean up retry tracking del _download_retry_attempts[context_key] else: - print(f"File not found yet: '{os.path.basename(filename_from_api)}' - Will retry (attempt {retry_count}/{_download_retry_max}, elapsed: {elapsed:.1f}s)") + logger.warning(f"File not found yet: '{os.path.basename(filename_from_api)}' - Will retry (attempt {retry_count}/{_download_retry_max}, elapsed: {elapsed:.1f}s)") # If we found completed matched downloads, start processing them in background threads if completed_matched_downloads: def process_completed_downloads(): for context_key, context, found_path in completed_matched_downloads: try: - print(f"Starting post-processing thread for: {context_key}") + logger.info(f"Starting post-processing thread for: {context_key}") # Use verification wrapper if context has task tracking IDs, # otherwise call directly (race guard flag still gets set on context) _pp_task_id = context.get('task_id') @@ -10157,16 +10175,16 @@ def get_download_status(): # Only mark as processed AFTER thread starts successfully _processed_download_ids.add(context_key) - print(f"Marked as processed: {context_key}") + logger.info(f"Marked as processed: {context_key}") # DON'T remove context immediately - verification worker needs it # Context will be cleaned up by verification worker after both processors complete - print(f"Keeping context for verification worker: {context_key}") + logger.info(f"Keeping context for verification worker: {context_key}") except Exception as e: - print(f"Error starting post-processing thread for {context_key}: {e}") + logger.error(f"Error starting post-processing thread for {context_key}: {e}") # Don't add to processed set if thread failed to start - print(f"Will retry {context_key} on next check") + logger.warning(f"Will retry {context_key} on next check") # Start a single thread to manage the launching of all processing threads processing_thread = threading.Thread(target=process_completed_downloads) @@ -10212,14 +10230,14 @@ def get_download_status(): # Prevent two contexts from claiming the same physical file _st_norm = os.path.normpath(found_path) if _st_norm in _files_claimed_this_cycle: - print(f"[{source_label}] File already claimed this cycle: {os.path.basename(found_path)} ā deferring") + logger.info(f"[{source_label}] File already claimed this cycle: {os.path.basename(found_path)} ā deferring") continue _files_claimed_this_cycle.add(_st_norm) - print(f"[{source_label}] Found completed matched file on disk: {found_path}") + logger.info(f"[{source_label}] Found completed matched file on disk: {found_path}") # Start post-processing thread def process_streaming_download(_ctx_key=context_key, _ctx=context, _path=found_path, _label=source_label): try: - print(f"[{_label}] Starting post-processing thread for: {_ctx_key}") + logger.info(f"[{_label}] Starting post-processing thread for: {_ctx_key}") # Use verification wrapper if context has task tracking IDs _st_task_id = _ctx.get('task_id') _st_batch_id = _ctx.get('batch_id') @@ -10233,9 +10251,9 @@ def get_download_status(): thread.daemon = True thread.start() _processed_download_ids.add(_ctx_key) - print(f"[{_label}] Marked as processed: {_ctx_key}") + logger.info(f"[{_label}] Marked as processed: {_ctx_key}") except Exception as e: - print(f"[{_label}] Error starting post-processing thread for {_ctx_key}: {e}") + logger.error(f"[{_label}] Error starting post-processing thread for {_ctx_key}: {e}") processing_thread = threading.Thread(target=process_streaming_download) processing_thread.daemon = True @@ -10246,13 +10264,31 @@ def get_download_status(): _processed_download_ids.add(context_key) except Exception as streaming_error: import traceback - print(f"Could not fetch YouTube/Tidal downloads for status: {streaming_error}") + logger.error(f"Could not fetch YouTube/Tidal downloads for status: {streaming_error}") traceback.print_exc() + # Enrich transfers with metadata from download context (artist, album, artwork) + with matched_context_lock: + for transfer in all_transfers: + ctx_key = _make_context_key(transfer.get('username', ''), transfer.get('filename', '')) + ctx = matched_downloads_context.get(ctx_key) + if ctx: + _sp_artist = ctx.get('spotify_artist') or {} + _sp_album = ctx.get('spotify_album') or {} + _sp_track = ctx.get('track_info') or {} + _sp_images = _sp_album.get('images') or [] + transfer['_meta'] = { + 'artist': _sp_artist.get('name', ''), + 'album': _sp_album.get('name', ''), + 'artwork_url': _sp_images[0].get('url', '') if _sp_images and isinstance(_sp_images[0], dict) else '', + 'track_number': _sp_track.get('track_number'), + 'quality': ctx.get('_audio_quality', ''), + } + return jsonify({"transfers": all_transfers}) except Exception as e: - print(f"Error fetching download status: {e}") + logger.error(f"Error fetching download status: {e}") return jsonify({"error": str(e)}), 500 @@ -10282,7 +10318,7 @@ def cancel_download(): else: return jsonify({"success": False, "error": "Failed to cancel download via slskd."}), 500 except Exception as e: - print(f"Error cancelling download: {e}") + logger.error(f"Error cancelling download: {e}") return jsonify({"success": False, "error": str(e)}), 500 @app.route('/api/downloads/cancel-all', methods=['POST']) @@ -10304,7 +10340,7 @@ def cancel_all_downloads(): return jsonify({"success": True, "message": "All downloads cancelled and cleared."}) except Exception as e: - print(f"Error cancelling all downloads: {e}") + logger.error(f"Error cancelling all downloads: {e}") return jsonify({"success": False, "error": str(e)}), 500 @app.route('/api/downloads/clear-finished', methods=['POST']) @@ -10322,7 +10358,7 @@ def clear_finished_downloads(): else: return jsonify({"success": False, "error": "Backend failed to clear downloads."}), 500 except Exception as e: - print(f"Error clearing finished downloads: {e}") + logger.error(f"Error clearing finished downloads: {e}") return jsonify({"success": False, "error": str(e)}), 500 @app.route('/api/downloads/task/{str(e)}
'.encode()) else: error = query_params.get('error', ['Unknown error'])[0] - print(f"Tidal OAuth error: {error}") + logger.error(f"Tidal OAuth error: {error}") add_activity_item("", "Tidal Auth Failed", f"OAuth error: {error}", "Now") self.send_response(400) self.send_header('Content-type', 'text/html') @@ -51187,18 +51127,18 @@ def start_oauth_callback_servers(): _env_val = os.environ.get('SOULSYNC_TIDAL_CALLBACK_PORT') tidal_port = int(_env_val) if _env_val else 8889 if _env_val: - print(f"[OAuth] SOULSYNC_TIDAL_CALLBACK_PORT={_env_val!r} ā binding Tidal callback server on port {tidal_port}") + logger.info(f"[OAuth] SOULSYNC_TIDAL_CALLBACK_PORT={_env_val!r} ā binding Tidal callback server on port {tidal_port}") else: - print(f"[OAuth] SOULSYNC_TIDAL_CALLBACK_PORT not set ā using default port {tidal_port}") + logger.info(f"[OAuth] SOULSYNC_TIDAL_CALLBACK_PORT not set ā using default port {tidal_port}") try: tidal_server = HTTPServer(('0.0.0.0', tidal_port), TidalCallbackHandler) - print(f"Started Tidal OAuth callback server on port {tidal_port}") - print(f"Tidal server listening on all interfaces, port {tidal_port}") + logger.info(f"Started Tidal OAuth callback server on port {tidal_port}") + logger.info(f"Tidal server listening on all interfaces, port {tidal_port}") tidal_server.serve_forever() except Exception as e: - print(f"Failed to start Tidal callback server: {e}") + logger.error(f"Failed to start Tidal callback server: {e}") import traceback - print(f"Full error: {traceback.format_exc()}") + logger.error(f"Full error: {traceback.format_exc()}") # Start both servers in background threads spotify_thread = threading.Thread(target=run_spotify_server, daemon=True) @@ -51207,7 +51147,7 @@ def start_oauth_callback_servers(): spotify_thread.start() tidal_thread.start() - print("OAuth callback servers started") + logger.info("OAuth callback servers started") # ================================================================================================ # MUSICBRAINZ ENRICHMENT - PHASE 5 WEB UI INTEGRATION @@ -51228,11 +51168,11 @@ try: mb_worker.start() if config_manager.get('musicbrainz_enrichment_paused', False): mb_worker.pause() - print("MusicBrainz enrichment worker initialized (paused ā restored from config)") + logger.info("MusicBrainz enrichment worker initialized (paused ā restored from config)") else: - print("MusicBrainz enrichment worker initialized and started") + logger.info("MusicBrainz enrichment worker initialized and started") except Exception as e: - print(f"MusicBrainz worker initialization failed: {e}") + logger.error(f"MusicBrainz worker initialization failed: {e}") mb_worker = None # --- MusicBrainz API Endpoints --- @@ -51305,11 +51245,11 @@ try: audiodb_worker.start() if config_manager.get('audiodb_enrichment_paused', False): audiodb_worker.pause() - print("AudioDB enrichment worker initialized (paused ā restored from config)") + logger.info("AudioDB enrichment worker initialized (paused ā restored from config)") else: - print("AudioDB enrichment worker initialized and started") + logger.info("AudioDB enrichment worker initialized and started") except Exception as e: - print(f"AudioDB worker initialization failed: {e}") + logger.error(f"AudioDB worker initialization failed: {e}") audiodb_worker = None # --- AudioDB API Endpoints --- @@ -51378,11 +51318,11 @@ try: discogs_worker.start() if config_manager.get('discogs_enrichment_paused', False): discogs_worker.pause() - print("Discogs enrichment worker initialized (paused ā restored from config)") + logger.info("Discogs enrichment worker initialized (paused ā restored from config)") else: - print("Discogs enrichment worker initialized and started") + logger.info("Discogs enrichment worker initialized and started") except Exception as e: - print(f"Discogs worker initialization failed: {e}") + logger.error(f"Discogs worker initialization failed: {e}") discogs_worker = None # --- Discogs API Endpoints --- @@ -51440,11 +51380,11 @@ try: deezer_worker.start() if config_manager.get('deezer_enrichment_paused', False): deezer_worker.pause() - print("Deezer enrichment worker initialized (paused ā restored from config)") + logger.info("Deezer enrichment worker initialized (paused ā restored from config)") else: - print("Deezer enrichment worker initialized and started") + logger.info("Deezer enrichment worker initialized and started") except Exception as e: - print(f"Deezer worker initialization failed: {e}") + logger.error(f"Deezer worker initialization failed: {e}") deezer_worker = None # --- Deezer API Endpoints --- @@ -51518,11 +51458,11 @@ try: spotify_enrichment_worker.paused = True # Set BEFORE start() to prevent race condition spotify_enrichment_worker.start() if spotify_enrichment_worker.paused: - print("Spotify enrichment worker initialized (paused ā restored from config)") + logger.info("Spotify enrichment worker initialized (paused ā restored from config)") else: - print("Spotify enrichment worker initialized and started") + logger.info("Spotify enrichment worker initialized and started") except Exception as e: - print(f"Spotify enrichment worker initialization failed: {e}") + logger.error(f"Spotify enrichment worker initialization failed: {e}") spotify_enrichment_worker = None # --- API Rate Monitor Endpoints --- @@ -51617,11 +51557,11 @@ try: itunes_enrichment_worker.start() if config_manager.get('itunes_enrichment_paused', False): itunes_enrichment_worker.pause() - print("iTunes enrichment worker initialized (paused ā restored from config)") + logger.info("iTunes enrichment worker initialized (paused ā restored from config)") else: - print("iTunes enrichment worker initialized and started") + logger.info("iTunes enrichment worker initialized and started") except Exception as e: - print(f"iTunes enrichment worker initialization failed: {e}") + logger.error(f"iTunes enrichment worker initialization failed: {e}") itunes_enrichment_worker = None # --- iTunes API Endpoints --- @@ -51693,11 +51633,11 @@ try: lastfm_worker.start() if config_manager.get('lastfm_enrichment_paused', False): lastfm_worker.pause() - print("Last.fm enrichment worker initialized (paused ā restored from config)") + logger.info("Last.fm enrichment worker initialized (paused ā restored from config)") else: - print("Last.fm enrichment worker initialized and started") + logger.info("Last.fm enrichment worker initialized and started") except Exception as e: - print(f"Last.fm worker initialization failed: {e}") + logger.error(f"Last.fm worker initialization failed: {e}") lastfm_worker = None # --- Last.fm API Endpoints --- @@ -51836,11 +51776,11 @@ try: genius_worker.paused = True genius_worker.start() if genius_worker.paused: - print("Genius enrichment worker initialized (paused ā restored from config)") + logger.info("Genius enrichment worker initialized (paused ā restored from config)") else: - print("Genius enrichment worker initialized and started") + logger.info("Genius enrichment worker initialized and started") except Exception as e: - print(f"Genius worker initialization failed: {e}") + logger.error(f"Genius worker initialization failed: {e}") genius_worker = None # --- Genius API Endpoints --- @@ -51913,11 +51853,11 @@ try: tidal_enrichment_worker.start() if config_manager.get('tidal_enrichment_paused', False): tidal_enrichment_worker.pause() - print("Tidal enrichment worker initialized (paused ā restored from config)") + logger.info("Tidal enrichment worker initialized (paused ā restored from config)") else: - print("Tidal enrichment worker initialized and started") + logger.info("Tidal enrichment worker initialized and started") except Exception as e: - print(f"Tidal worker initialization failed: {e}") + logger.error(f"Tidal worker initialization failed: {e}") tidal_enrichment_worker = None # --- Tidal Enrichment API Endpoints --- @@ -51987,11 +51927,11 @@ try: qobuz_enrichment_worker.start() if config_manager.get('qobuz_enrichment_paused', False): qobuz_enrichment_worker.pause() - print("Qobuz enrichment worker initialized (paused ā restored from config)") + logger.info("Qobuz enrichment worker initialized (paused ā restored from config)") else: - print("Qobuz enrichment worker initialized and started") + logger.info("Qobuz enrichment worker initialized and started") except Exception as e: - print(f"Qobuz worker initialization failed: {e}") + logger.error(f"Qobuz worker initialization failed: {e}") qobuz_enrichment_worker = None # --- Qobuz Enrichment API Endpoints --- @@ -52065,13 +52005,13 @@ try: hydrabase_worker = HydrabaseWorker(get_ws_and_lock=_get_hydrabase_ws_and_lock) hydrabase_worker.start() hydrabase_client = HydrabaseClient(get_ws_and_lock=_get_hydrabase_ws_and_lock) - print("Hydrabase P2P mirror worker and metadata client initialized") + logger.info("Hydrabase P2P mirror worker and metadata client initialized") # Update API blueprint references if hasattr(app, 'soulsync'): app.soulsync['hydrabase_client'] = hydrabase_client app.soulsync['hydrabase_worker'] = hydrabase_worker except Exception as e: - print(f"Hydrabase initialization failed: {e}") + logger.error(f"Hydrabase initialization failed: {e}") hydrabase_worker = None hydrabase_client = None @@ -52088,9 +52028,9 @@ try: _hydrabase_ws = _auto_ws # Don't auto-enable dev mode ā user must explicitly activate dev mode # Auto-connect just establishes the WebSocket for fallback/search tab use - print(f"Hydrabase auto-connected to {_hydra_cfg['url']}") + logger.info(f"Hydrabase auto-connected to {_hydra_cfg['url']}") except Exception as e: - print(f"Hydrabase auto-reconnect failed: {e}") + logger.error(f"Hydrabase auto-reconnect failed: {e}") # --- Hydrabase Worker API Endpoints --- @@ -52162,9 +52102,9 @@ try: soulid_db = MusicDatabase() soulid_worker = SoulIDWorker(database=soulid_db) soulid_worker.start() - print("SoulID worker initialized and started") + logger.info("SoulID worker initialized and started") except Exception as e: - print(f"SoulID worker initialization failed: {e}") + logger.error(f"SoulID worker initialization failed: {e}") soulid_worker = None @app.route('/api/soulid/status', methods=['GET']) @@ -52196,9 +52136,9 @@ try: navidrome_client=navidrome_client, ) listening_stats_worker.start() - print("Listening stats worker initialized and started") + logger.info("Listening stats worker initialized and started") except Exception as e: - print(f"Listening stats worker initialization failed: {e}") + logger.error(f"Listening stats worker initialization failed: {e}") listening_stats_worker = None # --- Stats API Endpoints --- @@ -52489,13 +52429,13 @@ def listening_stats_sync(): import threading def _do_sync(): try: - print("[Stats Sync] Starting manual poll...") + logger.info("[Stats Sync] Starting manual poll...") listening_stats_worker._poll() listening_stats_worker.stats['polls_completed'] += 1 listening_stats_worker.stats['last_poll'] = time.strftime('%Y-%m-%d %H:%M:%S') - print("[Stats Sync] Manual poll completed") + logger.info("[Stats Sync] Manual poll completed") except Exception as e: - print(f"[Stats Sync] Manual poll failed: {e}") + logger.error(f"[Stats Sync] Manual poll failed: {e}") import traceback traceback.print_exc() logger.error(f"Manual stats sync failed: {e}") @@ -52585,9 +52525,9 @@ try: repair_worker._progress_lock_ref = repair_job_progress_lock repair_worker._progress_states_ref = repair_job_progress_states repair_worker.start() - print("Repair worker initialized and started") + logger.info("Repair worker initialized and started") except Exception as e: - print(f"Repair worker initialization failed: {e}") + logger.error(f"Repair worker initialization failed: {e}") repair_worker = None # --- Repair Worker API Endpoints --- @@ -53888,11 +53828,11 @@ try: ) if config_manager.get('auto_import.enabled', False): auto_import_worker.start() - print("Auto-import worker started") + logger.info("Auto-import worker started") else: - print("Auto-import worker initialized (disabled)") + logger.info("Auto-import worker initialized (disabled)") except Exception as _ai_err: - print(f"Auto-import worker init failed: {_ai_err}") + logger.error(f"Auto-import worker init failed: {_ai_err}") @app.route('/api/auto-import/status', methods=['GET']) @@ -54119,13 +54059,13 @@ def _hydrabase_reconnect_loop(): ) _hydrabase_ws = ws _consecutive_failures = 0 - print(f"[Hydrabase] Auto-reconnected to {hydra_cfg['url']}") + logger.info(f"[Hydrabase] Auto-reconnected to {hydra_cfg['url']}") except Exception as e: _consecutive_failures += 1 if _consecutive_failures <= 3: - print(f"[Hydrabase] Reconnect attempt failed ({_consecutive_failures}): {e}") + logger.error(f"[Hydrabase] Reconnect attempt failed ({_consecutive_failures}): {e}") elif _consecutive_failures == 4: - print(f"[Hydrabase] Reconnect failing repeatedly ā suppressing further logs until success") + logger.error(f"[Hydrabase] Reconnect failing repeatedly ā suppressing further logs until success") except Exception: pass # Don't crash the monitor loop @@ -54470,10 +54410,10 @@ def _emit_live_log_loop(): _last_pos = {} # {source: file_position} _active_source = 'app' log_map = { - 'app': os.path.join('logs', 'app.log'), - 'post_processing': os.path.join('logs', 'post_processing.log'), - 'acoustid': os.path.join('logs', 'acoustid.log'), - 'source_reuse': os.path.join('logs', 'source_reuse.log'), + 'app': Path(_log_path), + 'acoustid': _log_dir / 'acoustid.log', + 'post_processing': _log_dir / 'post_processing.log', + 'source_reuse': _log_dir / 'source_reuse.log', } while not globals().get('IS_SHUTTING_DOWN', False): socketio.sleep(0.5) @@ -54734,36 +54674,36 @@ def start_runtime_services(): if _runtime_started: return - print("Starting SoulSync runtime services...") + logger.info("Starting SoulSync runtime services...") # Dump SOULSYNC_* env vars for diagnostics (helps debug Docker/Unraid env issues) _soulsync_env = {k: v for k, v in os.environ.items() if k.startswith('SOULSYNC_')} if _soulsync_env: - print(f"[Startup] SOULSYNC environment variables: {_soulsync_env}") + logger.info(f"[Startup] SOULSYNC environment variables: {_soulsync_env}") else: - print("[Startup] No SOULSYNC_* environment variables detected") + logger.warning("[Startup] No SOULSYNC_* environment variables detected") # Start OAuth callback servers - print("Starting OAuth callback servers...") + logger.info("Starting OAuth callback servers...") start_oauth_callback_servers() # Startup diagnostics: Check and recover stuck flags - print("Running startup diagnostics...") + logger.info("Running startup diagnostics...") stuck_flags_recovered = check_and_recover_stuck_flags() if stuck_flags_recovered: - print("Recovered stuck flags from previous session") + logger.warning("Recovered stuck flags from previous session") else: - print("No stuck flags detected - system healthy") + logger.warning("No stuck flags detected - system healthy") # Start simple background monitor when server starts - print("Starting simple background monitor...") + logger.info("Starting simple background monitor...") start_simple_background_monitor() - print("Simple background monitor started (includes automatic search cleanup)") + logger.info("Simple background monitor started (includes automatic search cleanup)") # Wishlist/watchlist timers are now managed by AutomationEngine system automations # Pre-build import suggestions cache in background - print("Pre-building import suggestions cache...") + logger.info("Pre-building import suggestions cache...") start_import_suggestions_cache() # Initialize app start time for uptime tracking @@ -54773,26 +54713,26 @@ def start_runtime_services(): _register_automation_handlers() if automation_engine: try: - print("Starting automation engine...") + logger.info("Starting automation engine...") automation_engine.start() - print("Automation engine started") + logger.info("Automation engine started") try: automation_engine.emit('app_started', {}) except Exception: pass except AttributeError as e: - print(f"Automation engine failed to start: {e}") - print(" If using Docker, check that your volume mount is /app/data (not /app/database)") + logger.error(f"Automation engine failed to start: {e}") + logger.info(" If using Docker, check that your volume mount is /app/data (not /app/database)") logger.error(f"Automation engine start error (possible stale Docker volume): {e}") except Exception as e: - print(f"Automation engine failed to start: {e}") + logger.error(f"Automation engine failed to start: {e}") logger.error(f"Automation engine start error: {e}") # Add startup activity add_activity_item("", "System Started", "SoulSync Web UI Server initialized", "Now") # Start WebSocket background emitters - print("Starting WebSocket background emitters...") + logger.info("Starting WebSocket background emitters...") # Phase 1: Global pollers socketio.start_background_task(_emit_service_status_loop) socketio.start_background_task(_emit_watchlist_count_loop) @@ -54820,7 +54760,7 @@ def start_runtime_services(): socketio.start_background_task(_emit_rate_monitor_loop) # Live log tail ā streams new log lines to the log viewer socketio.start_background_task(_emit_live_log_loop) - print("WebSocket emitters started (Phase 1-7: global/dashboard/enrichment/tools/sync/automations/repair + rate monitor + live logs)") + logger.info("WebSocket emitters started (Phase 1-7: global/dashboard/enrichment/tools/sync/automations/repair + rate monitor + live logs)") _runtime_started = True @@ -54828,8 +54768,8 @@ def start_runtime_services(): # Direct execution: python web_server.py (dev/Windows fallback) # Production should use: gunicorn -c gunicorn.conf.py wsgi:application if _DIRECT_RUN: - print("Starting SoulSync Web UI Server...") - print("Open your browser and navigate to http://127.0.0.1:8008") - print("Tip: For production, use gunicorn -c gunicorn.conf.py wsgi:application") + logger.info("Starting SoulSync Web UI Server...") + logger.info("Open your browser and navigate to http://127.0.0.1:8008") + logger.info("Tip: For production, use gunicorn -c gunicorn.conf.py wsgi:application") start_runtime_services() socketio.run(app, host='0.0.0.0', port=8008, debug=False, allow_unsafe_werkzeug=True) diff --git a/webui/index.html b/webui/index.html index e8d14fc7..6961bf86 100644 --- a/webui/index.html +++ b/webui/index.html @@ -5098,28 +5098,28 @@ Variables: $albumartist, $artist, $artistletter, $album, $albumtype, - $title, $track, $disc (01), $discnum (1), $year, $quality (filename only) + $title, $track, $disc (01), $discnum (1), $year, $quality (filename only). Use ${var} to append text: ${albumtype}s ā Albums