diff --git a/allstarr/Controllers/JellyfinController.cs b/allstarr/Controllers/JellyfinController.cs index b58074a..c156ac3 100644 --- a/allstarr/Controllers/JellyfinController.cs +++ b/allstarr/Controllers/JellyfinController.cs @@ -1875,8 +1875,16 @@ public class JellyfinController : ControllerBase var sessionCreated = await _sessionManager.EnsureSessionAsync(deviceId, client ?? "Unknown", device ?? "Unknown", version ?? "1.0", Request.Headers); if (sessionCreated) { - _logger.LogInformation("✓ Session ensured for device {DeviceId} after playback start", deviceId); + _logger.LogWarning("✓ SESSION: Session ensured for device {DeviceId} after playback start", deviceId); } + else + { + _logger.LogWarning("⚠️ SESSION: Failed to ensure session for device {DeviceId}", deviceId); + } + } + else + { + _logger.LogWarning("⚠️ SESSION: No device ID found in headers for playback start"); } } else diff --git a/allstarr/Middleware/WebSocketProxyMiddleware.cs b/allstarr/Middleware/WebSocketProxyMiddleware.cs index d6a697a..cc75b78 100644 --- a/allstarr/Middleware/WebSocketProxyMiddleware.cs +++ b/allstarr/Middleware/WebSocketProxyMiddleware.cs @@ -23,7 +23,7 @@ public class WebSocketProxyMiddleware _settings = settings.Value; _logger = logger; - _logger.LogInformation("🔧 WebSocketProxyMiddleware initialized - Jellyfin URL: {Url}", _settings.Url); + _logger.LogWarning("🔧 WEBSOCKET: WebSocketProxyMiddleware initialized - Jellyfin URL: {Url}", _settings.Url); } public async Task InvokeAsync(HttpContext context) @@ -38,7 +38,7 @@ public class WebSocketProxyMiddleware isWebSocket || context.Request.Headers.ContainsKey("Upgrade")) { - _logger.LogInformation("🔍 Potential WebSocket request: Path={Path}, IsWs={IsWs}, Method={Method}, Upgrade={Upgrade}, Connection={Connection}", + _logger.LogWarning("🔍 WEBSOCKET: Potential WebSocket request: Path={Path}, IsWs={IsWs}, Method={Method}, Upgrade={Upgrade}, Connection={Connection}", path, isWebSocket, context.Request.Method, @@ -50,7 +50,7 @@ public class WebSocketProxyMiddleware if (context.Request.Path.StartsWithSegments("/socket", StringComparison.OrdinalIgnoreCase) && context.WebSockets.IsWebSocketRequest) { - _logger.LogInformation("🔌 WebSocket connection request received from {RemoteIp}", + _logger.LogWarning("🔌 WEBSOCKET: WebSocket connection request received from {RemoteIp}", context.Connection.RemoteIpAddress); await HandleWebSocketProxyAsync(context); @@ -70,7 +70,7 @@ public class WebSocketProxyMiddleware { // Accept the WebSocket connection from the client clientWebSocket = await context.WebSockets.AcceptWebSocketAsync(); - _logger.LogInformation("✓ Client WebSocket accepted"); + _logger.LogWarning("✓ WEBSOCKET: Client WebSocket accepted"); // Build Jellyfin WebSocket URL var jellyfinUrl = _settings.Url?.TrimEnd('/') ?? ""; @@ -84,7 +84,7 @@ public class WebSocketProxyMiddleware jellyfinWsUrl += context.Request.QueryString.Value; } - _logger.LogInformation("Connecting to Jellyfin WebSocket: {Url}", jellyfinWsUrl); + _logger.LogWarning("🔗 WEBSOCKET: Connecting to Jellyfin WebSocket: {Url}", jellyfinWsUrl); // Connect to Jellyfin WebSocket serverWebSocket = new ClientWebSocket(); @@ -93,19 +93,19 @@ public class WebSocketProxyMiddleware if (context.Request.Headers.TryGetValue("Authorization", out var authHeader)) { serverWebSocket.Options.SetRequestHeader("Authorization", authHeader.ToString()); - _logger.LogDebug("Forwarded Authorization header"); + _logger.LogWarning("🔑 WEBSOCKET: Forwarded Authorization header"); } else if (context.Request.Headers.TryGetValue("X-Emby-Authorization", out var embyAuthHeader)) { serverWebSocket.Options.SetRequestHeader("X-Emby-Authorization", embyAuthHeader.ToString()); - _logger.LogDebug("Forwarded X-Emby-Authorization header"); + _logger.LogWarning("🔑 WEBSOCKET: Forwarded X-Emby-Authorization header"); } // Set user agent serverWebSocket.Options.SetRequestHeader("User-Agent", "Allstarr/1.0"); await serverWebSocket.ConnectAsync(new Uri(jellyfinWsUrl), context.RequestAborted); - _logger.LogInformation("✓ Connected to Jellyfin WebSocket"); + _logger.LogWarning("✓ WEBSOCKET: Connected to Jellyfin WebSocket"); // Start bidirectional proxying var clientToServer = ProxyMessagesAsync(clientWebSocket, serverWebSocket, "Client→Server", context.RequestAborted); @@ -114,15 +114,15 @@ public class WebSocketProxyMiddleware // Wait for either direction to complete await Task.WhenAny(clientToServer, serverToClient); - _logger.LogInformation("WebSocket proxy connection closed"); + _logger.LogWarning("🔌 WEBSOCKET: WebSocket proxy connection closed"); } catch (WebSocketException wsEx) { - _logger.LogWarning(wsEx, "WebSocket error: {Message}", wsEx.Message); + _logger.LogWarning(wsEx, "⚠️ WEBSOCKET: WebSocket error: {Message}", wsEx.Message); } catch (Exception ex) { - _logger.LogError(ex, "Error in WebSocket proxy"); + _logger.LogError(ex, "❌ WEBSOCKET: Error in WebSocket proxy"); } finally { @@ -154,7 +154,7 @@ public class WebSocketProxyMiddleware clientWebSocket?.Dispose(); serverWebSocket?.Dispose(); - _logger.LogInformation("WebSocket connections cleaned up"); + _logger.LogWarning("🧹 WEBSOCKET: WebSocket connections cleaned up"); } } @@ -175,7 +175,7 @@ public class WebSocketProxyMiddleware if (result.MessageType == WebSocketMessageType.Close) { - _logger.LogInformation("{Direction}: Close message received", direction); + _logger.LogWarning("🔌 WEBSOCKET {Direction}: Close message received", direction); await destination.CloseAsync( result.CloseStatus ?? WebSocketCloseStatus.NormalClosure, result.CloseStatusDescription, @@ -215,15 +215,15 @@ public class WebSocketProxyMiddleware } catch (OperationCanceledException) { - _logger.LogInformation("{Direction}: Operation cancelled", direction); + _logger.LogWarning("⚠️ WEBSOCKET {Direction}: Operation cancelled", direction); } catch (WebSocketException wsEx) when (wsEx.WebSocketErrorCode == WebSocketError.ConnectionClosedPrematurely) { - _logger.LogInformation("{Direction}: Connection closed prematurely", direction); + _logger.LogWarning("⚠️ WEBSOCKET {Direction}: Connection closed prematurely", direction); } catch (Exception ex) { - _logger.LogWarning(ex, "{Direction}: Error proxying messages", direction); + _logger.LogWarning(ex, "⚠️ WEBSOCKET {Direction}: Error proxying messages", direction); } } } diff --git a/allstarr/Services/Jellyfin/JellyfinProxyService.cs b/allstarr/Services/Jellyfin/JellyfinProxyService.cs index dd65c58..1ec9749 100644 --- a/allstarr/Services/Jellyfin/JellyfinProxyService.cs +++ b/allstarr/Services/Jellyfin/JellyfinProxyService.cs @@ -394,11 +394,17 @@ public class JellyfinProxyService if (!response.IsSuccessStatusCode) { var errorContent = await response.Content.ReadAsStringAsync(); - _logger.LogWarning("Jellyfin POST request failed: {StatusCode} for {Url}. Response: {Response}", + _logger.LogWarning("❌ SESSION: Jellyfin POST request failed: {StatusCode} for {Url}. Response: {Response}", response.StatusCode, url, errorContent); return (null, statusCode); } + // Log successful session-related responses + if (endpoint.Contains("Sessions", StringComparison.OrdinalIgnoreCase)) + { + _logger.LogWarning("✓ SESSION: Jellyfin responded {StatusCode} for {Endpoint}", statusCode, endpoint); + } + // Handle 204 No Content responses (e.g., /sessions/playing, /sessions/playing/progress) if (response.StatusCode == System.Net.HttpStatusCode.NoContent) { @@ -413,6 +419,13 @@ public class JellyfinProxyService return (null, statusCode); } + // Log response content for session endpoints + if (endpoint.Contains("Sessions", StringComparison.OrdinalIgnoreCase) && !string.IsNullOrWhiteSpace(responseContent)) + { + var preview = responseContent.Length > 200 ? responseContent[..200] + "..." : responseContent; + _logger.LogWarning("📥 SESSION: Jellyfin response body: {Body}", preview); + } + return (JsonDocument.Parse(responseContent), statusCode); } diff --git a/allstarr/Services/Jellyfin/JellyfinSessionManager.cs b/allstarr/Services/Jellyfin/JellyfinSessionManager.cs index 3388d72..05f038b 100644 --- a/allstarr/Services/Jellyfin/JellyfinSessionManager.cs +++ b/allstarr/Services/Jellyfin/JellyfinSessionManager.cs @@ -22,8 +22,10 @@ public class JellyfinSessionManager _proxyService = proxyService; _logger = logger; - // Keep sessions alive every 30 seconds - _keepAliveTimer = new Timer(KeepSessionsAlive, null, TimeSpan.FromSeconds(30), TimeSpan.FromSeconds(30)); + // Keep sessions alive every 10 seconds (Jellyfin considers sessions stale after ~15 seconds of inactivity) + _keepAliveTimer = new Timer(KeepSessionsAlive, null, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(10)); + + _logger.LogWarning("🔧 SESSION: JellyfinSessionManager initialized with 10-second keep-alive"); } /// @@ -33,7 +35,7 @@ public class JellyfinSessionManager { if (string.IsNullOrEmpty(deviceId)) { - _logger.LogWarning("Cannot create session - no device ID"); + _logger.LogWarning("⚠️ SESSION: Cannot create session - no device ID"); return false; } @@ -41,21 +43,21 @@ public class JellyfinSessionManager if (_sessions.TryGetValue(deviceId, out var existingSession)) { existingSession.LastActivity = DateTime.UtcNow; - _logger.LogDebug("Session already exists for device {DeviceId}", deviceId); + _logger.LogWarning("✓ SESSION: Session already exists for device {DeviceId}", deviceId); // Refresh capabilities to keep session alive await PostCapabilitiesAsync(headers); return true; } - _logger.LogInformation("🔧 Creating new session for device: {DeviceId} ({Client} on {Device})", deviceId, client, device); + _logger.LogWarning("🔧 SESSION: Creating new session for device: {DeviceId} ({Client} on {Device})", deviceId, client, device); try { // Post session capabilities to Jellyfin - this creates the session await PostCapabilitiesAsync(headers); - _logger.LogInformation("✓ Session created for {DeviceId}", deviceId); + _logger.LogWarning("✓ SESSION: Session created for {DeviceId}", deviceId); // Track this session _sessions[deviceId] = new SessionInfo @@ -72,7 +74,7 @@ public class JellyfinSessionManager } catch (Exception ex) { - _logger.LogError(ex, "Error creating session for {DeviceId}", deviceId); + _logger.LogError(ex, "❌ SESSION: Error creating session for {DeviceId}", deviceId); return false; } } @@ -99,9 +101,13 @@ public class JellyfinSessionManager var json = JsonSerializer.Serialize(capabilities); var (result, statusCode) = await _proxyService.PostJsonAsync("Sessions/Capabilities/Full", json, headers); - if (statusCode != 204 && statusCode != 200) + if (statusCode == 204 || statusCode == 200) { - _logger.LogWarning("Failed to post capabilities - status {StatusCode}", statusCode); + _logger.LogWarning("✓ SESSION: Posted capabilities successfully ({StatusCode})", statusCode); + } + else + { + _logger.LogWarning("⚠️ SESSION: Failed to post capabilities - status {StatusCode}", statusCode); } } @@ -113,6 +119,11 @@ public class JellyfinSessionManager if (_sessions.TryGetValue(deviceId, out var session)) { session.LastActivity = DateTime.UtcNow; + _logger.LogWarning("🔄 SESSION: Updated activity for {DeviceId}", deviceId); + } + else + { + _logger.LogWarning("⚠️ SESSION: Cannot update activity - device {DeviceId} not found", deviceId); } } @@ -123,7 +134,7 @@ public class JellyfinSessionManager { if (_sessions.TryRemove(deviceId, out var session)) { - _logger.LogInformation("Removing session for device {DeviceId}", deviceId); + _logger.LogWarning("🗑️ SESSION: Removing session for device {DeviceId}", deviceId); try { @@ -133,7 +144,7 @@ public class JellyfinSessionManager } catch (Exception ex) { - _logger.LogDebug(ex, "Error removing session for {DeviceId}", deviceId); + _logger.LogWarning(ex, "⚠️ SESSION: Error removing session for {DeviceId}", deviceId); } } } @@ -151,7 +162,7 @@ public class JellyfinSessionManager return; } - _logger.LogDebug("Keeping {Count} sessions alive", activeSessions.Count); + _logger.LogWarning("💓 SESSION: Keeping {Count} sessions alive", activeSessions.Count); foreach (var session in activeSessions) { @@ -159,11 +170,11 @@ public class JellyfinSessionManager { // Post capabilities again to keep session alive await PostCapabilitiesAsync(session.Headers); - _logger.LogDebug("✓ Kept session alive for {DeviceId}", session.DeviceId); + _logger.LogWarning("✓ SESSION: Kept session alive for {DeviceId}", session.DeviceId); } catch (Exception ex) { - _logger.LogDebug(ex, "Error keeping session alive for {DeviceId}", session.DeviceId); + _logger.LogWarning(ex, "⚠️ SESSION: Error keeping session alive for {DeviceId}", session.DeviceId); } } @@ -171,7 +182,7 @@ public class JellyfinSessionManager var staleSessions = _sessions.Where(kvp => now - kvp.Value.LastActivity > TimeSpan.FromMinutes(10)).ToList(); foreach (var stale in staleSessions) { - _logger.LogInformation("Removing stale session for {DeviceId}", stale.Key); + _logger.LogWarning("🧹 SESSION: Removing stale session for {DeviceId}", stale.Key); _sessions.TryRemove(stale.Key, out _); } }