diff --git a/app/__init__.py b/app/__init__.py index ce12c86..61cccbb 100644 --- a/app/__init__.py +++ b/app/__init__.py @@ -87,8 +87,14 @@ def create_app(): StreamProcessingService.initialize() + # Initialize music player service + from app.services.music_player_service import music_player_service + + music_player_service.app = app # Store app instance for Flask context + music_player_service.start_vlc_instance() + # Register blueprints - from app.routes import admin, admin_sounds, auth, main, soundboard, stream + from app.routes import admin, admin_sounds, auth, main, player, soundboard, stream app.register_blueprint(main.bp, url_prefix="/api") app.register_blueprint(auth.bp, url_prefix="/api/auth") @@ -96,12 +102,14 @@ def create_app(): app.register_blueprint(admin_sounds.bp, url_prefix="/api/admin/sounds") app.register_blueprint(soundboard.bp, url_prefix="/api/soundboard") app.register_blueprint(stream.bp, url_prefix="/api/stream") + app.register_blueprint(player.bp, url_prefix="/api/player") - # Shutdown scheduler when app is torn down + # Shutdown services when app is torn down @app.teardown_appcontext - def shutdown_scheduler(exception): - """Stop scheduler when app context is torn down.""" + def shutdown_services(exception): + """Stop services when app context is torn down.""" if exception: scheduler_service.stop() + music_player_service.stop_vlc_instance() return app diff --git a/app/routes/player.py b/app/routes/player.py new file mode 100644 index 0000000..4329ea1 --- /dev/null +++ b/app/routes/player.py @@ -0,0 +1,244 @@ +"""Music player API routes.""" + +from flask import Blueprint, jsonify, request + +from app.services.decorators import require_auth +from app.services.error_handling_service import ErrorHandlingService +from app.services.music_player_service import music_player_service + +bp = Blueprint("player", __name__) + + +@bp.route("/state", methods=["GET"]) +@require_auth +def get_player_state(): + """Get current player state.""" + try: + state = music_player_service.get_player_state() + return jsonify(state), 200 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/play", methods=["POST"]) +@require_auth +def play(): + """Start playback.""" + try: + success = music_player_service.play() + if success: + return jsonify({"message": "Playback started"}), 200 + return jsonify({"error": "Failed to start playback"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/pause", methods=["POST"]) +@require_auth +def pause(): + """Pause playback.""" + try: + success = music_player_service.pause() + if success: + return jsonify({"message": "Playback paused"}), 200 + return jsonify({"error": "Failed to pause playback"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/stop", methods=["POST"]) +@require_auth +def stop(): + """Stop playback.""" + try: + success = music_player_service.stop() + if success: + return jsonify({"message": "Playback stopped"}), 200 + return jsonify({"error": "Failed to stop playback"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/next", methods=["POST"]) +@require_auth +def next_track(): + """Skip to next track.""" + try: + success = music_player_service.next_track() + if success: + return jsonify({"message": "Skipped to next track"}), 200 + return jsonify({"error": "Failed to skip to next track"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/previous", methods=["POST"]) +@require_auth +def previous_track(): + """Skip to previous track.""" + try: + success = music_player_service.previous_track() + if success: + return jsonify({"message": "Skipped to previous track"}), 200 + return jsonify({"error": "Failed to skip to previous track"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/seek", methods=["POST"]) +@require_auth +def seek(): + """Seek to position.""" + try: + data = request.get_json() + if not data or "position" not in data: + return jsonify({"error": "Position required"}), 400 + + position = float(data["position"]) + if not 0.0 <= position <= 1.0: + return jsonify({"error": "Position must be between 0.0 and 1.0"}), 400 + + success = music_player_service.seek(position) + if success: + return jsonify({"message": "Seek successful"}), 200 + return jsonify({"error": "Failed to seek"}), 400 + except (ValueError, TypeError): + return jsonify({"error": "Invalid position value"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/volume", methods=["POST"]) +@require_auth +def set_volume(): + """Set volume.""" + try: + data = request.get_json() + if not data or "volume" not in data: + return jsonify({"error": "Volume required"}), 400 + + volume = int(data["volume"]) + if not 0 <= volume <= 100: + return jsonify({"error": "Volume must be between 0 and 100"}), 400 + + success = music_player_service.set_volume(volume) + if success: + return jsonify({"message": "Volume set successfully"}), 200 + return jsonify({"error": "Failed to set volume"}), 400 + except (ValueError, TypeError): + return jsonify({"error": "Invalid volume value"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/mode", methods=["POST"]) +@require_auth +def set_play_mode(): + """Set play mode.""" + try: + data = request.get_json() + if not data or "mode" not in data: + return jsonify({"error": "Mode required"}), 400 + + mode = data["mode"] + valid_modes = ["continuous", "loop-playlist", "loop-one", "random"] + if mode not in valid_modes: + return jsonify({"error": f"Mode must be one of: {', '.join(valid_modes)}"}), 400 + + success = music_player_service.set_play_mode(mode) + if success: + return jsonify({"message": "Play mode set successfully"}), 200 + return jsonify({"error": "Failed to set play mode"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/playlist", methods=["POST"]) +@require_auth +def load_playlist(): + """Load a playlist into the player.""" + try: + data = request.get_json() + if not data or "playlist_id" not in data: + return jsonify({"error": "Playlist ID required"}), 400 + + playlist_id = int(data["playlist_id"]) + success = music_player_service.load_playlist(playlist_id) + if success: + return jsonify({"message": "Playlist loaded successfully"}), 200 + return jsonify({"error": "Failed to load playlist"}), 400 + except (ValueError, TypeError): + return jsonify({"error": "Invalid playlist ID"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/play-track", methods=["POST"]) +@require_auth +def play_track(): + """Play track at specific index.""" + try: + data = request.get_json() + if not data or "index" not in data: + return jsonify({"error": "Track index required"}), 400 + + index = int(data["index"]) + success = music_player_service.play_track_at_index(index) + if success: + return jsonify({"message": "Track playing"}), 200 + return jsonify({"error": "Failed to play track"}), 400 + except (ValueError, TypeError): + return jsonify({"error": "Invalid track index"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/start-instance", methods=["POST"]) +@require_auth +def start_vlc_instance(): + """Start the VLC player instance.""" + try: + success = music_player_service.start_vlc_instance() + if success: + return jsonify({"message": "VLC instance started successfully"}), 200 + return jsonify({"error": "Failed to start VLC instance"}), 500 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/stop-instance", methods=["POST"]) +@require_auth +def stop_vlc_instance(): + """Stop the VLC player instance.""" + try: + success = music_player_service.stop_vlc_instance() + if success: + return jsonify({"message": "VLC instance stopped successfully"}), 200 + return jsonify({"error": "Failed to stop VLC instance"}), 500 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/load-main-playlist", methods=["POST"]) +@require_auth +def load_main_playlist(): + """Load the main playlist into the player.""" + try: + success = music_player_service.load_main_playlist() + if success: + return jsonify({"message": "Main playlist loaded successfully"}), 200 + return jsonify({"error": "Failed to load main playlist"}), 400 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) + + +@bp.route("/test-emit", methods=["POST"]) +@require_auth +def test_emit(): + """Test SocketIO emission manually.""" + try: + # Force emit player state + music_player_service._emit_player_state() + return jsonify({"message": "Test emission sent"}), 200 + except Exception as e: + return ErrorHandlingService.handle_generic_error(e) \ No newline at end of file diff --git a/app/services/music_player_service.py b/app/services/music_player_service.py new file mode 100644 index 0000000..9476716 --- /dev/null +++ b/app/services/music_player_service.py @@ -0,0 +1,614 @@ +"""Music player service using VLC Python bindings with playlist management and real-time sync.""" + +import os +import threading +import time +from typing import Any, Optional + +import vlc +from flask import current_app + +from app.models.playlist import Playlist +from app.models.sound import Sound +from app.services.logging_service import LoggingService +from app.services.socketio_service import socketio_service + +logger = LoggingService.get_logger(__name__) + + +class MusicPlayerService: + """Service for managing a VLC music player with playlist support.""" + + def __init__(self): + """Initialize the music player service.""" + self.instance: Optional[vlc.Instance] = None + self.player: Optional[vlc.MediaPlayer] = None + self.app = None # Store Flask app instance for context + + self.current_playlist_id: Optional[int] = None + self.current_track_index = 0 + self.playlist_files: list[str] = ( + [] + ) # Store file paths for manual playlist management + self.volume = 80 + self.play_mode = ( + "continuous" # continuous, loop-playlist, loop-one, random + ) + self.is_playing = False + self.current_time = 0 + self.duration = 0 + self.last_sync_time = 0 + self.sync_interval = 1.0 # seconds + self.lock = threading.Lock() + self._sync_thread = None + self._stop_sync = False + + def start_vlc_instance(self) -> bool: + """Start a VLC instance with Python bindings.""" + try: + # Create VLC instance with audio output enabled + vlc_args = [ + "--intf=dummy", # No interface + "--no-video", # Audio only + ] + + self.instance = vlc.Instance(vlc_args) + if not self.instance: + logger.error("Failed to create VLC instance") + return False + + # Create media player + self.player = self.instance.media_player_new() + if not self.player: + logger.error("Failed to create VLC media player") + return False + + # Set initial volume + self.player.audio_set_volume(self.volume) + + logger.info("VLC music player started successfully") + self._start_sync_thread() + return True + + except Exception as e: + logger.error(f"Error starting VLC instance: {e}") + return False + + def stop_vlc_instance(self) -> bool: + """Stop the VLC instance.""" + try: + self._stop_sync = True + if self._sync_thread: + self._sync_thread.join(timeout=2) + + if self.player: + self.player.stop() + + # Release VLC objects + self.player = None + self.instance = None + + logger.info("VLC music player stopped") + return True + + except Exception as e: + logger.error(f"Error stopping VLC instance: {e}") + return False + + def load_playlist(self, playlist_id: int) -> bool: + """Load a playlist into VLC.""" + try: + if not self.instance or not self.player: + logger.error("VLC not initialized") + return False + + with self.lock: + # Ensure we have Flask app context for database queries + if current_app: + with current_app.app_context(): + playlist = Playlist.query.get(playlist_id) + if not playlist: + return False + + return self._load_playlist_with_context(playlist) + else: + # Fallback for when no Flask context is available + logger.warning( + "No Flask context available for loading playlist" + ) + return False + except Exception as e: + logger.error(f"Error loading playlist {playlist_id}: {e}") + return False + + def _load_playlist_with_context(self, playlist) -> bool: + """Load playlist with database context already established.""" + try: + # Clear current playlist + self.playlist_files = [] + + # Add tracks to our internal playlist + for playlist_sound in sorted( + playlist.playlist_sounds, key=lambda x: x.order + ): + sound = playlist_sound.sound + if sound: + file_path = self._get_sound_file_path(sound) + if file_path and os.path.exists(file_path): + self.playlist_files.append(file_path) + + self.current_playlist_id = playlist.id + self.current_track_index = 0 + + # Load first track if available + if self.playlist_files: + self._load_track_at_index(0) + + # Emit playlist loaded event + self._emit_player_state() + + logger.info( + f"Loaded playlist '{playlist.name}' with {len(self.playlist_files)} tracks" + ) + return True + + except Exception as e: + logger.error(f"Error in _load_playlist_with_context: {e}") + return False + + def _load_track_at_index(self, index: int) -> bool: + """Load a specific track by index.""" + try: + if 0 <= index < len(self.playlist_files): + file_path = self.playlist_files[index] + media = self.instance.media_new(file_path) + if media: + self.player.set_media(media) + self.current_track_index = index + return True + return False + except Exception as e: + logger.error(f"Error loading track at index {index}: {e}") + return False + + def _get_sound_file_path(self, sound: Sound) -> Optional[str]: + """Get the file path for a sound, preferring normalized version.""" + try: + if sound.type == "STR": + # Stream sounds + base_path = "sounds/stream" + elif sound.type == "SAY": + # Say sounds + base_path = "sounds/say" + else: + # Soundboard sounds + base_path = "sounds/soundboard" + + # Check for normalized version first + if sound.is_normalized and sound.normalized_filename: + normalized_path = os.path.join( + "sounds/normalized", + sound.type.lower(), + sound.normalized_filename, + ) + if os.path.exists(normalized_path): + return os.path.abspath(normalized_path) + + # Fall back to original file + original_path = os.path.join(base_path, sound.filename) + if os.path.exists(original_path): + return os.path.abspath(original_path) + + return None + + except Exception as e: + logger.error(f"Error getting file path for sound {sound.id}: {e}") + return None + + def play(self) -> bool: + """Start playback.""" + try: + if not self.player: + return False + + result = self.player.play() + if result == 0: # Success + self.is_playing = True + self._emit_player_state() + return True + return False + except Exception as e: + logger.error(f"Error starting playback: {e}") + return False + + def pause(self) -> bool: + """Pause playback.""" + try: + if not self.player: + return False + + self.player.pause() + self.is_playing = False + self._emit_player_state() + return True + except Exception as e: + logger.error(f"Error pausing playback: {e}") + return False + + def stop(self) -> bool: + """Stop playback.""" + try: + if not self.player: + return False + + self.player.stop() + self.is_playing = False + self.current_time = 0 + self._emit_player_state() + return True + except Exception as e: + logger.error(f"Error stopping playback: {e}") + return False + + def next_track(self) -> bool: + """Skip to next track.""" + try: + if not self.playlist_files: + return False + + next_index = self.current_track_index + 1 + + # Handle different play modes + if self.play_mode == "loop-playlist" and next_index >= len( + self.playlist_files + ): + next_index = 0 + elif self.play_mode == "random": + import random + + next_index = random.randint(0, len(self.playlist_files) - 1) + elif next_index >= len(self.playlist_files): + # End of playlist in continuous mode + self.stop() + return True + + if self._load_track_at_index(next_index): + if self.is_playing: + self.play() + self._emit_player_state() + return True + return False + except Exception as e: + logger.error(f"Error skipping to next track: {e}") + return False + + def previous_track(self) -> bool: + """Skip to previous track.""" + try: + if not self.playlist_files: + return False + + prev_index = self.current_track_index - 1 + + # Handle different play modes + if self.play_mode == "loop-playlist" and prev_index < 0: + prev_index = len(self.playlist_files) - 1 + elif self.play_mode == "random": + import random + + prev_index = random.randint(0, len(self.playlist_files) - 1) + elif prev_index < 0: + prev_index = 0 + + if self._load_track_at_index(prev_index): + if self.is_playing: + self.play() + self._emit_player_state() + return True + return False + except Exception as e: + logger.error(f"Error skipping to previous track: {e}") + return False + + def seek(self, position: float) -> bool: + """Seek to position (0.0 to 1.0).""" + try: + if not self.player: + return False + + # Set position as percentage + self.player.set_position(position) + self.current_time = position * self.duration + self._emit_player_state() + return True + except Exception as e: + logger.error(f"Error seeking: {e}") + return False + + def set_volume(self, volume: int) -> bool: + """Set volume (0-100).""" + try: + if not self.player: + return False + + volume = max(0, min(100, volume)) + result = self.player.audio_set_volume(volume) + if result == 0: # Success + self.volume = volume + self._emit_player_state() + return True + return False + except Exception as e: + logger.error(f"Error setting volume: {e}") + return False + + def set_play_mode(self, mode: str) -> bool: + """Set play mode.""" + try: + if mode in ["continuous", "loop-playlist", "loop-one", "random"]: + self.play_mode = mode + self._emit_player_state() + return True + return False + except Exception as e: + logger.error(f"Error setting play mode: {e}") + return False + + def play_track_at_index(self, index: int) -> bool: + """Play track at specific playlist index.""" + try: + if self._load_track_at_index(index): + result = self.play() + self._emit_player_state() + return result + return False + except Exception as e: + logger.error(f"Error playing track at index {index}: {e}") + return False + + def _get_playlist_length(self) -> int: + """Get current playlist length.""" + return len(self.playlist_files) + + def get_current_track(self) -> Optional[dict]: + """Get current track information.""" + try: + if not self.current_playlist_id: + return None + + # Ensure we have Flask app context + if current_app: + with current_app.app_context(): + playlist = Playlist.query.get(self.current_playlist_id) + if playlist and 0 <= self.current_track_index < len( + playlist.playlist_sounds + ): + playlist_sounds = sorted( + playlist.playlist_sounds, key=lambda x: x.order + ) + current_playlist_sound = playlist_sounds[ + self.current_track_index + ] + sound = current_playlist_sound.sound + + if sound: + return { + "id": sound.id, + "title": sound.name, + "artist": None, # Could be extracted from metadata + "duration": sound.duration or 0, + "thumbnail": ( + f"/api/sounds/{sound.type.lower()}/thumbnails/{sound.thumbnail}" + if sound.thumbnail + else None + ), + "type": sound.type, + } + return None + except Exception as e: + logger.error(f"Error getting current track: {e}") + return None + + def get_playlist_tracks(self) -> list[dict]: + """Get all tracks in current playlist.""" + try: + tracks = [] + if not self.current_playlist_id: + return tracks + + # Ensure we have Flask app context + if current_app: + with current_app.app_context(): + playlist = Playlist.query.get(self.current_playlist_id) + if playlist: + for playlist_sound in sorted( + playlist.playlist_sounds, key=lambda x: x.order + ): + sound = playlist_sound.sound + if sound: + tracks.append( + { + "id": sound.id, + "title": sound.name, + "artist": None, + "duration": sound.duration or 0, + "thumbnail": ( + f"/api/sounds/{sound.type.lower()}/thumbnails/{sound.thumbnail}" + if sound.thumbnail + else None + ), + "type": sound.type, + } + ) + return tracks + except Exception as e: + logger.error(f"Error getting playlist tracks: {e}") + return [] + + def get_player_state(self) -> dict[str, Any]: + """Get complete player state.""" + return { + "is_playing": self.is_playing, + "current_time": self.current_time, + "duration": self.duration, + "volume": self.volume, + "play_mode": self.play_mode, + "current_track": self.get_current_track(), + "current_track_index": self.current_track_index, + "playlist": self.get_playlist_tracks(), + "playlist_id": self.current_playlist_id, + } + + def _start_sync_thread(self): + """Start background thread to sync with VLC state.""" + self._stop_sync = False + self._sync_thread = threading.Thread( + target=self._sync_loop, daemon=True + ) + self._sync_thread.start() + + def _sync_loop(self): + """Background loop to sync player state with VLC.""" + while not self._stop_sync: + try: + current_time = time.time() + if current_time - self.last_sync_time >= self.sync_interval: + self._sync_with_vlc() + self.last_sync_time = current_time + + time.sleep(0.1) # Small sleep to prevent busy waiting + + except Exception as e: + logger.debug(f"Error in sync loop: {e}") + time.sleep(1) # Longer sleep on error + + def _sync_with_vlc(self): + """Sync internal state with VLC.""" + try: + if not self.player: + return + + # Update playback state + old_playing = self.is_playing + old_time = self.current_time + + # Get current state from VLC + state = self.player.get_state() + self.is_playing = state == vlc.State.Playing + + # Get time and duration (in milliseconds) + self.current_time = self.player.get_time() + self.duration = self.player.get_length() + + # Get volume + self.volume = self.player.audio_get_volume() + + # Check if track ended and handle auto-advance + if state == vlc.State.Ended and self.play_mode in [ + "continuous", + "loop-playlist", + "random", + ]: + self.next_track() + elif state == vlc.State.Ended and self.play_mode == "loop-one": + # Restart the same track + self.player.set_position(0) + self.play() + + # Emit updates if state changed significantly or periodically + state_changed = ( + old_playing != self.is_playing + or abs(old_time - self.current_time) + > 1000 # More than 1 second difference + ) + + # Always emit if playing to keep frontend updated + if state_changed or self.is_playing: + self._emit_player_state() + + except Exception as e: + logger.debug(f"Error syncing with VLC: {e}") + + def _emit_player_state(self): + """Emit current player state via SocketIO.""" + try: + # Update state from VLC before emitting + self._sync_vlc_state_only() + + # Try to use Flask context for database queries + app_to_use = self.app or current_app + + if app_to_use: + with app_to_use.app_context(): + state = self.get_player_state() + socketio_service.emit_to_all("player_state_update", state) + logger.info(f"Emitted player state: playing={state['is_playing']}, time={state['current_time']}, track={state.get('current_track', {}).get('title', 'None')}") + else: + # Fallback when no Flask context - emit basic state without database queries + basic_state = { + "is_playing": self.is_playing, + "current_time": self.current_time, + "duration": self.duration, + "volume": self.volume, + "play_mode": self.play_mode, + "current_track": None, + "current_track_index": self.current_track_index, + "playlist": [], + "playlist_id": self.current_playlist_id, + } + socketio_service.emit_to_all("player_state_update", basic_state) + logger.info(f"Emitted basic player state: playing={basic_state['is_playing']}, time={basic_state['current_time']}") + except Exception as e: + logger.debug(f"Error emitting player state: {e}") + + def _sync_vlc_state_only(self): + """Sync only the VLC state without auto-advance logic.""" + try: + if not self.player: + return + + # Get current state from VLC + state = self.player.get_state() + self.is_playing = state == vlc.State.Playing + + # Get time and duration (in milliseconds) + self.current_time = self.player.get_time() + self.duration = self.player.get_length() + + # Get volume + self.volume = self.player.audio_get_volume() + + except Exception as e: + logger.debug(f"Error syncing VLC state: {e}") + + def load_main_playlist(self) -> bool: + """Load main playlist if available (to be called from within Flask context).""" + try: + logger.info("Attempting to load main playlist...") + main_playlist = Playlist.query.filter_by(name="Main").first() + if main_playlist: + logger.info( + f"Found main playlist with {len(main_playlist.playlist_sounds)} tracks" + ) + result = self.load_playlist(main_playlist.id) + logger.info(f"Load playlist result: {result}") + if result: + logger.info( + f"Successfully loaded main playlist with {len(main_playlist.playlist_sounds)} tracks" + ) + return True + else: + logger.warning("Failed to load main playlist") + return False + else: + logger.warning( + "Main playlist not found, player ready without playlist" + ) + return False + except Exception as e: + logger.error(f"Error loading main playlist: {e}") + return False + + +# Global music player service instance +music_player_service = MusicPlayerService() diff --git a/app/services/socketio_service.py b/app/services/socketio_service.py index 0517ef2..8970c39 100644 --- a/app/services/socketio_service.py +++ b/app/services/socketio_service.py @@ -9,6 +9,12 @@ from app import socketio logger = logging.getLogger(__name__) +# Add debug print to ensure this module is loaded +print(f"๐Ÿ”ง SocketIO Service: Module loaded, logger level: {logger.level}") +print(f"๐Ÿ”ง SocketIO Service: Effective logger level: {logger.getEffectiveLevel()}") +print(f"๐Ÿ”ง SocketIO Service: Parent logger handlers: {logger.parent.handlers}") +print(f"๐Ÿ”ง SocketIO Service: Logger handlers: {logger.handlers}") + class SocketIOService: """Service for managing SocketIO connections and user rooms.""" @@ -25,6 +31,15 @@ class SocketIOService: socketio.emit(event, data, room=room) logger.debug(f"Emitted {event} to user {user_id} in room {room}") + @staticmethod + def emit_to_all(event: str, data: dict) -> None: + """Emit an event to all connected clients.""" + try: + socketio.emit(event, data) + logger.info(f"Successfully emitted {event} to all clients with data keys: {list(data.keys())}") + except Exception as e: + logger.error(f"Failed to emit {event}: {e}") + @staticmethod def emit_credits_changed(user_id: int, new_credits: int) -> None: """Emit credits_changed event to a user.""" @@ -43,7 +58,10 @@ class SocketIOService: # Check if we have the access_token cookie access_token = request.cookies.get("access_token_cookie") + logger.debug(f"Access token from cookies: {access_token[:20] if access_token else None}...") + if not access_token: + logger.debug("No access token found in cookies") return None # Decode the JWT token manually @@ -51,9 +69,13 @@ class SocketIOService: try: decoded_token = decode_token(access_token) current_user_id = decoded_token["sub"] + logger.debug(f"Decoded user ID: {current_user_id}") + if not current_user_id: + logger.debug("No user ID in token") return None - except Exception: + except Exception as e: + logger.debug(f"Token decode error: {e}") return None # Query database for user data @@ -61,8 +83,10 @@ class SocketIOService: user = User.query.get(int(current_user_id)) if not user or not user.is_active: + logger.debug(f"User not found or inactive: {current_user_id}") return None + logger.debug(f"Successfully found user: {user.email}") return { "id": str(user.id), "email": user.email, @@ -70,29 +94,41 @@ class SocketIOService: "role": user.role, "credits": user.credits, } - except Exception: + except Exception as e: + logger.debug(f"Exception in get_user_from_socketio: {e}") return None @socketio.on("connect") -def handle_connect(auth=None) -> bool: +def handle_connect(auth=None): """Handle client connection.""" + print(f"๐Ÿ”Œ CONNECT EVENT HANDLER CALLED: {request.sid}") try: - logger.info(f"SocketIO connection from {request.remote_addr}") - return True + logger.info(f"SocketIO connection established from {request.remote_addr}") + logger.info(f"Session ID: {request.sid}") + logger.info(f"Cookies: {request.cookies}") + print(f"๐Ÿ”Œ CONNECT SUCCESS: {request.sid}") except Exception: logger.exception("Error handling SocketIO connection") + print(f"๐Ÿ”Œ CONNECT ERROR: {request.sid}") disconnect() - return False @socketio.on("authenticate") def handle_authenticate(data): """Handle authentication after connection.""" + print(f"๐Ÿ” AUTHENTICATE EVENT HANDLER CALLED: {request.sid}") + logger.info(f"๐Ÿ” SOCKETIO EVENT: authenticate received from {request.sid}") + logger.info(f"๐Ÿ” Auth data: {data}") + logger.info(f"๐Ÿ” Request cookies: {dict(request.cookies)}") + try: user = SocketIOService.get_user_from_socketio() + logger.info(f"๐Ÿ” User lookup result: {user}") + if not user: + logger.warning("๐Ÿ” Authentication failed - no user found") emit("auth_error", {"error": "Authentication failed"}) disconnect() return @@ -103,21 +139,30 @@ def handle_authenticate(data): # Join user-specific room join_room(user_room) - logger.info(f"User {user_id} authenticated and joined room {user_room}") + logger.info(f"๐Ÿ” User {user_id} authenticated and joined room {user_room}") # Send current credits on authentication emit("auth_success", {"user": user}) emit("credits_changed", {"credits": user["credits"]}) except Exception: - logger.exception("Error handling SocketIO authentication") + logger.exception("๐Ÿ” Error handling SocketIO authentication") emit("auth_error", {"error": "Authentication failed"}) disconnect() +@socketio.on("test_event") +def handle_test_event(data): + """Test handler to verify SocketIO events are working.""" + print(f"๐Ÿงช TEST EVENT HANDLER CALLED: {request.sid}") + logger.info(f"๐Ÿงช TEST EVENT received: {data}") + emit("test_response", {"message": "Test event received successfully"}) + + @socketio.on("disconnect") -def handle_disconnect() -> None: +def handle_disconnect(): """Handle client disconnection.""" + print(f"๐Ÿ”Œ DISCONNECT EVENT HANDLER CALLED: {request.sid}") try: user = SocketIOService.get_user_from_socketio() if user: @@ -132,3 +177,20 @@ def handle_disconnect() -> None: # Export the service instance socketio_service = SocketIOService() + +# Debug: Print registered event handlers +try: + print(f"๐Ÿ”ง SocketIO Service: Registered event handlers: {list(socketio.server.handlers.keys())}") + print(f"๐Ÿ”ง SocketIO Service: Namespace handlers: {socketio.server.handlers.get('/', {})}") +except Exception as e: + print(f"๐Ÿ”ง SocketIO Service: Error accessing handlers: {e}") + print(f"๐Ÿ”ง SocketIO Service: SocketIO server: {socketio.server}") + print(f"๐Ÿ”ง SocketIO Service: SocketIO instance: {socketio}") + +# Test manual event registration +@socketio.on("manual_test") +def handle_manual_test(data): + """Manual test handler.""" + print(f"๐Ÿงช MANUAL TEST EVENT: {data}") + +print("๐Ÿ”ง SocketIO Service: Manual test handler registered") diff --git a/backend.log b/backend.log new file mode 100644 index 0000000..51f4ec6 --- /dev/null +++ b/backend.log @@ -0,0 +1,82 @@ +19:40:31 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:31 - app.services.scheduler_service - INFO - Daily credit refill job scheduled for 00:00 UTC +19:40:31 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:31 - app.services.scheduler_service - INFO - Sound scanning job scheduled every 5 minutes +19:40:31 - apscheduler.scheduler - INFO - Added job "Daily Credit Refill" to job store "default" +19:40:31 - apscheduler.scheduler - INFO - Added job "Sound Directory Scan" to job store "default" +19:40:31 - apscheduler.scheduler - INFO - Scheduler started +19:40:31 - app.services.scheduler_service - INFO - Scheduler started successfully +19:40:31 - app.services.stream_processing_service - INFO - StreamProcessingService initialized with 2 workers +19:40:31 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:31 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:31 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:31 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:31 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:31 - werkzeug - WARNING - Werkzeug appears to be used in a production deployment. Consider switching to a production web server instead. +๐Ÿ”ง SocketIO Service: Module loaded, logger level: 10 +๐Ÿ”ง SocketIO Service: Effective logger level: 10 +๐Ÿ”ง SocketIO Service: Parent logger handlers: [ (NOTSET)>] +๐Ÿ”ง SocketIO Service: Logger handlers: [] +๐Ÿ”ง SocketIO Service: Registered event handlers: ['/'] + * Serving Flask app 'app' + * Debug mode: on +19:40:31 - werkzeug - INFO - WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead. + * Running on all addresses (0.0.0.0) + * Running on http://127.0.0.1:5000 + * Running on http://10.8.0.2:5000 +19:40:31 - werkzeug - INFO - Press CTRL+C to quit +19:40:31 - werkzeug - INFO - * Restarting with stat +19:40:32 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:32 - app.services.scheduler_service - INFO - Daily credit refill job scheduled for 00:00 UTC +19:40:32 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:32 - app.services.scheduler_service - INFO - Sound scanning job scheduled every 5 minutes +19:40:32 - apscheduler.scheduler - INFO - Added job "Daily Credit Refill" to job store "default" +19:40:32 - apscheduler.scheduler - INFO - Added job "Sound Directory Scan" to job store "default" +19:40:32 - apscheduler.scheduler - INFO - Scheduler started +19:40:32 - app.services.scheduler_service - INFO - Scheduler started successfully +19:40:32 - app.services.stream_processing_service - INFO - StreamProcessingService initialized with 2 workers +19:40:32 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:32 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:32 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:32 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:32 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:32 - werkzeug - WARNING - Werkzeug appears to be used in a production deployment. Consider switching to a production web server instead. +19:40:32 - werkzeug - WARNING - * Debugger is active! +19:40:32 - werkzeug - INFO - * Debugger PIN: 138-440-685 +19:40:32 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:32] "GET /socket.io/?EIO=4&transport=polling&t=e00ab8wz HTTP/1.1" 200 - +19:40:32 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:32] "POST /socket.io/?EIO=4&transport=polling&t=e00dbx25&sid=3ANQFsbixyerJ988AAAA HTTP/1.1" 200 - +19:40:32 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:32] "GET /socket.io/?EIO=4&transport=polling&t=e00dc4kv&sid=3ANQFsbixyerJ988AAAA HTTP/1.1" 200 - +19:40:32 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:32] "POST /socket.io/?EIO=4&transport=polling&t=e00dltvr&sid=3ANQFsbixyerJ988AAAA HTTP/1.1" 200 - +19:40:32 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:32] "POST /socket.io/?EIO=4&transport=polling&t=e00dryur&sid=3ANQFsbixyerJ988AAAA HTTP/1.1" 200 - +19:40:49 - werkzeug - INFO - * Detected change in '/home/jschoisy/Dev/perso/sdb-claude/backend/app/services/socketio_service.py', reloading +๐Ÿ”ง SocketIO Service: Module loaded, logger level: 10 +๐Ÿ”ง SocketIO Service: Effective logger level: 10 +๐Ÿ”ง SocketIO Service: Parent logger handlers: [ (NOTSET)>] +๐Ÿ”ง SocketIO Service: Logger handlers: [] +๐Ÿ”ง SocketIO Service: Registered event handlers: ['/'] +19:40:49 - werkzeug - INFO - * Restarting with stat +19:40:49 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:49 - app.services.scheduler_service - INFO - Daily credit refill job scheduled for 00:00 UTC +19:40:49 - apscheduler.scheduler - INFO - Adding job tentatively -- it will be properly scheduled when the scheduler starts +19:40:49 - app.services.scheduler_service - INFO - Sound scanning job scheduled every 5 minutes +19:40:49 - apscheduler.scheduler - INFO - Added job "Daily Credit Refill" to job store "default" +19:40:49 - apscheduler.scheduler - INFO - Added job "Sound Directory Scan" to job store "default" +19:40:49 - apscheduler.scheduler - INFO - Scheduler started +19:40:49 - app.services.scheduler_service - INFO - Scheduler started successfully +19:40:50 - app.services.stream_processing_service - INFO - StreamProcessingService initialized with 2 workers +19:40:50 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:50 - app.services.scheduler_service - WARNING - Scheduler is already running +19:40:50 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:50 - werkzeug - WARNING - Werkzeug appears to be used in a production deployment. Consider switching to a production web server instead. +19:40:50 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:50 - app.services.music_player_service - INFO - VLC music player started successfully +19:40:50 - werkzeug - WARNING - * Debugger is active! +19:40:50 - werkzeug - INFO - * Debugger PIN: 220-239-682 +Invalid session 3ANQFsbixyerJ988AAAA (further occurrences of this error will be logged with level INFO) +19:40:50 - engineio.server - ERROR - Invalid session 3ANQFsbixyerJ988AAAA (further occurrences of this error will be logged with level INFO) +19:40:50 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:50] "POST /socket.io/?EIO=4&transport=polling&t=e0do0065&sid=3ANQFsbixyerJ988AAAA HTTP/1.1" 400 - +19:40:51 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:51] "GET /socket.io/?EIO=4&transport=polling&t=e0esh2w2 HTTP/1.1" 200 - +19:40:51 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:51] "POST /socket.io/?EIO=4&transport=polling&t=e0esr2m9&sid=C18CrSifHGP8BpkeAAAE HTTP/1.1" 200 - +19:40:51 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:51] "GET /socket.io/?EIO=4&transport=polling&t=e0ess9wp&sid=C18CrSifHGP8BpkeAAAE HTTP/1.1" 200 - +19:40:51 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:51] "POST /socket.io/?EIO=4&transport=polling&t=e0et0qa7&sid=C18CrSifHGP8BpkeAAAE HTTP/1.1" 200 - +19:40:51 - werkzeug - INFO - 127.0.0.1 - - [07/Jul/2025 19:40:51] "POST /socket.io/?EIO=4&transport=polling&t=e0et3xhl&sid=C18CrSifHGP8BpkeAAAE HTTP/1.1" 200 - diff --git a/main.py b/main.py index 945692d..cbab741 100644 --- a/main.py +++ b/main.py @@ -1,3 +1,4 @@ +import logging from dotenv import load_dotenv from app import create_app, socketio @@ -5,11 +6,24 @@ from app import create_app, socketio # Load environment variables from .env file load_dotenv() +# Configure logging to show all INFO and DEBUG messages +logging.basicConfig( + level=logging.INFO, + format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', + datefmt='%H:%M:%S' +) + +# Set specific loggers to DEBUG for detailed SocketIO and music player logs +logging.getLogger('app.services.socketio_service').setLevel(logging.DEBUG) +logging.getLogger('app.services.music_player_service').setLevel(logging.INFO) + def main() -> None: """Run the Flask application with SocketIO.""" app = create_app() - socketio.run(app, debug=True, host="0.0.0.0", port=5000) + socketio.run( + app, debug=True, host="0.0.0.0", port=5000, allow_unsafe_werkzeug=True + ) if __name__ == "__main__": diff --git a/pyproject.toml b/pyproject.toml index ae97fa4..5f52b2f 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -17,6 +17,7 @@ dependencies = [ "flask-sqlalchemy==3.1.1", "pydub==0.25.1", "python-dotenv==1.1.1", + "python-vlc>=3.0.21203", "requests==2.32.4", "werkzeug==3.1.3", "yt-dlp>=2025.6.30", diff --git a/uv.lock b/uv.lock index 7bf1887..5544af3 100644 --- a/uv.lock +++ b/uv.lock @@ -582,6 +582,15 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/3c/32/b4fb8585d1be0f68bde7e110dffbcf354915f77ad8c778563f0ad9655c02/python_socketio-5.13.0-py3-none-any.whl", hash = "sha256:51f68d6499f2df8524668c24bcec13ba1414117cfb3a90115c559b601ab10caf", size = 77800 }, ] +[[package]] +name = "python-vlc" +version = "3.0.21203" +source = { registry = "https://pypi.org/simple" } +sdist = { url = "https://files.pythonhosted.org/packages/4b/5b/f9ce6f0c9877b6fe5eafbade55e0dcb6b2b30f1c2c95837aef40e390d63b/python_vlc-3.0.21203.tar.gz", hash = "sha256:52d0544b276b11e58b6c0b748c3e0518f94f74b1b4cd328c83a59eacabead1ec", size = 162211 } +wheels = [ + { url = "https://files.pythonhosted.org/packages/5b/ee/7d76eb3b50ccb1397621f32ede0fb4d17aa55a9aa2251bc34e6b9929fdce/python_vlc-3.0.21203-py3-none-any.whl", hash = "sha256:1613451a31b692ec276296ceeae0c0ba82bfc2d094dabf9aceb70f58944a6320", size = 87651 }, +] + [[package]] name = "requests" version = "2.32.4" @@ -638,6 +647,7 @@ dependencies = [ { name = "flask-sqlalchemy" }, { name = "pydub" }, { name = "python-dotenv" }, + { name = "python-vlc" }, { name = "requests" }, { name = "werkzeug" }, { name = "yt-dlp" }, @@ -663,6 +673,7 @@ requires-dist = [ { name = "flask-sqlalchemy", specifier = "==3.1.1" }, { name = "pydub", specifier = "==0.25.1" }, { name = "python-dotenv", specifier = "==1.1.1" }, + { name = "python-vlc", specifier = ">=3.0.21203" }, { name = "requests", specifier = "==2.32.4" }, { name = "werkzeug", specifier = "==3.1.3" }, { name = "yt-dlp", specifier = ">=2025.6.30" },