feat: Implement Music Player Service with VLC integration

- Added MusicPlayerService for managing VLC music playback with playlist support.
- Implemented methods for loading playlists, controlling playback (play, pause, stop, next, previous), and managing volume and play modes.
- Integrated real-time synchronization with VLC state using a background thread.
- Added SocketIO event emissions for player state updates.
- Enhanced logging for better debugging and tracking of player state changes.

fix: Improve SocketIO service logging and event handling

- Added detailed logging for SocketIO events and user authentication.
- Implemented a test event handler to verify SocketIO functionality.
- Enhanced error handling and logging for better traceability.

chore: Update dependencies and logging configuration

- Added python-vlc dependency for VLC integration.
- Configured logging to show INFO and DEBUG messages for better visibility during development.
- Updated main application entry point to allow unsafe Werkzeug for debugging purposes.
This commit is contained in:
JSC
2025-07-07 20:51:53 +02:00
parent c44b055f83
commit e7d958eb39
8 changed files with 1050 additions and 14 deletions

View File

@@ -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

244
app/routes/player.py Normal file
View File

@@ -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)

View File

@@ -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()

View File

@@ -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")

82
backend.log Normal file
View File

@@ -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: [<StreamHandler <stderr> (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: [<StreamHandler <stderr> (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 -

16
main.py
View File

@@ -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__":

View File

@@ -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",

11
uv.lock generated
View File

@@ -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" },