Fix logging levels - use appropriate debug/info/warn/error levels

This commit is contained in:
2026-02-03 14:12:39 -05:00
parent 494b4bbbc2
commit f5ce355747
2 changed files with 36 additions and 36 deletions

View File

@@ -23,7 +23,7 @@ public class WebSocketProxyMiddleware
_settings = settings.Value; _settings = settings.Value;
_logger = logger; _logger = logger;
_logger.LogWarning("🔧 WEBSOCKET: WebSocketProxyMiddleware initialized - Jellyfin URL: {Url}", _settings.Url); _logger.LogDebug("🔧 WEBSOCKET: WebSocketProxyMiddleware initialized - Jellyfin URL: {Url}", _settings.Url);
} }
public async Task InvokeAsync(HttpContext context) public async Task InvokeAsync(HttpContext context)
@@ -38,7 +38,7 @@ public class WebSocketProxyMiddleware
isWebSocket || isWebSocket ||
context.Request.Headers.ContainsKey("Upgrade")) context.Request.Headers.ContainsKey("Upgrade"))
{ {
_logger.LogWarning("🔍 WEBSOCKET: Potential WebSocket request: Path={Path}, IsWs={IsWs}, Method={Method}, Upgrade={Upgrade}, Connection={Connection}", _logger.LogDebug("🔍 WEBSOCKET: Potential WebSocket request: Path={Path}, IsWs={IsWs}, Method={Method}, Upgrade={Upgrade}, Connection={Connection}",
path, path,
isWebSocket, isWebSocket,
context.Request.Method, context.Request.Method,
@@ -50,7 +50,7 @@ public class WebSocketProxyMiddleware
if (context.Request.Path.StartsWithSegments("/socket", StringComparison.OrdinalIgnoreCase) && if (context.Request.Path.StartsWithSegments("/socket", StringComparison.OrdinalIgnoreCase) &&
context.WebSockets.IsWebSocketRequest) context.WebSockets.IsWebSocketRequest)
{ {
_logger.LogWarning("🔌 WEBSOCKET: WebSocket connection request received from {RemoteIp}", _logger.LogInformation("🔌 WEBSOCKET: WebSocket connection request received from {RemoteIp}",
context.Connection.RemoteIpAddress); context.Connection.RemoteIpAddress);
await HandleWebSocketProxyAsync(context); await HandleWebSocketProxyAsync(context);
@@ -70,7 +70,7 @@ public class WebSocketProxyMiddleware
{ {
// Accept the WebSocket connection from the client // Accept the WebSocket connection from the client
clientWebSocket = await context.WebSockets.AcceptWebSocketAsync(); clientWebSocket = await context.WebSockets.AcceptWebSocketAsync();
_logger.LogWarning("✓ WEBSOCKET: Client WebSocket accepted"); _logger.LogDebug("✓ WEBSOCKET: Client WebSocket accepted");
// Build Jellyfin WebSocket URL // Build Jellyfin WebSocket URL
var jellyfinUrl = _settings.Url?.TrimEnd('/') ?? ""; var jellyfinUrl = _settings.Url?.TrimEnd('/') ?? "";
@@ -84,7 +84,7 @@ public class WebSocketProxyMiddleware
jellyfinWsUrl += context.Request.QueryString.Value; jellyfinWsUrl += context.Request.QueryString.Value;
} }
_logger.LogWarning("🔗 WEBSOCKET: Connecting to Jellyfin WebSocket: {Url}", jellyfinWsUrl); _logger.LogDebug("🔗 WEBSOCKET: Connecting to Jellyfin WebSocket: {Url}", jellyfinWsUrl);
// Connect to Jellyfin WebSocket // Connect to Jellyfin WebSocket
serverWebSocket = new ClientWebSocket(); serverWebSocket = new ClientWebSocket();
@@ -94,7 +94,7 @@ public class WebSocketProxyMiddleware
if (context.Request.Headers.TryGetValue("X-Emby-Authorization", out var embyAuthHeader)) if (context.Request.Headers.TryGetValue("X-Emby-Authorization", out var embyAuthHeader))
{ {
serverWebSocket.Options.SetRequestHeader("X-Emby-Authorization", embyAuthHeader.ToString()); serverWebSocket.Options.SetRequestHeader("X-Emby-Authorization", embyAuthHeader.ToString());
_logger.LogWarning("🔑 WEBSOCKET: Forwarded X-Emby-Authorization header"); _logger.LogDebug("🔑 WEBSOCKET: Forwarded X-Emby-Authorization header");
} }
else if (context.Request.Headers.TryGetValue("Authorization", out var authHeader)) else if (context.Request.Headers.TryGetValue("Authorization", out var authHeader))
{ {
@@ -103,12 +103,12 @@ public class WebSocketProxyMiddleware
if (authValue.Contains("MediaBrowser", StringComparison.OrdinalIgnoreCase)) if (authValue.Contains("MediaBrowser", StringComparison.OrdinalIgnoreCase))
{ {
serverWebSocket.Options.SetRequestHeader("X-Emby-Authorization", authValue); serverWebSocket.Options.SetRequestHeader("X-Emby-Authorization", authValue);
_logger.LogWarning("🔑 WEBSOCKET: Converted Authorization to X-Emby-Authorization header"); _logger.LogDebug("🔑 WEBSOCKET: Converted Authorization to X-Emby-Authorization header");
} }
else else
{ {
serverWebSocket.Options.SetRequestHeader("Authorization", authValue); serverWebSocket.Options.SetRequestHeader("Authorization", authValue);
_logger.LogWarning("🔑 WEBSOCKET: Forwarded Authorization header"); _logger.LogDebug("🔑 WEBSOCKET: Forwarded Authorization header");
} }
} }
@@ -116,7 +116,7 @@ public class WebSocketProxyMiddleware
serverWebSocket.Options.SetRequestHeader("User-Agent", "Allstarr/1.0"); serverWebSocket.Options.SetRequestHeader("User-Agent", "Allstarr/1.0");
await serverWebSocket.ConnectAsync(new Uri(jellyfinWsUrl), context.RequestAborted); await serverWebSocket.ConnectAsync(new Uri(jellyfinWsUrl), context.RequestAborted);
_logger.LogWarning("✓ WEBSOCKET: Connected to Jellyfin WebSocket"); _logger.LogInformation("✓ WEBSOCKET: Connected to Jellyfin WebSocket");
// Start bidirectional proxying // Start bidirectional proxying
var clientToServer = ProxyMessagesAsync(clientWebSocket, serverWebSocket, "Client→Server", context.RequestAborted); var clientToServer = ProxyMessagesAsync(clientWebSocket, serverWebSocket, "Client→Server", context.RequestAborted);
@@ -125,7 +125,7 @@ public class WebSocketProxyMiddleware
// Wait for either direction to complete // Wait for either direction to complete
await Task.WhenAny(clientToServer, serverToClient); await Task.WhenAny(clientToServer, serverToClient);
_logger.LogWarning("🔌 WEBSOCKET: WebSocket proxy connection closed"); _logger.LogDebug("🔌 WEBSOCKET: WebSocket proxy connection closed");
} }
catch (WebSocketException wsEx) catch (WebSocketException wsEx)
{ {
@@ -165,7 +165,7 @@ public class WebSocketProxyMiddleware
clientWebSocket?.Dispose(); clientWebSocket?.Dispose();
serverWebSocket?.Dispose(); serverWebSocket?.Dispose();
_logger.LogWarning("🧹 WEBSOCKET: WebSocket connections cleaned up"); _logger.LogDebug("🧹 WEBSOCKET: WebSocket connections cleaned up");
} }
} }
@@ -186,7 +186,7 @@ public class WebSocketProxyMiddleware
if (result.MessageType == WebSocketMessageType.Close) if (result.MessageType == WebSocketMessageType.Close)
{ {
_logger.LogWarning("🔌 WEBSOCKET {Direction}: Close message received", direction); _logger.LogDebug("🔌 WEBSOCKET {Direction}: Close message received", direction);
await destination.CloseAsync( await destination.CloseAsync(
result.CloseStatus ?? WebSocketCloseStatus.NormalClosure, result.CloseStatus ?? WebSocketCloseStatus.NormalClosure,
result.CloseStatusDescription, result.CloseStatusDescription,
@@ -226,11 +226,11 @@ public class WebSocketProxyMiddleware
} }
catch (OperationCanceledException) catch (OperationCanceledException)
{ {
_logger.LogWarning("⚠️ WEBSOCKET {Direction}: Operation cancelled", direction); _logger.LogDebug("⚠️ WEBSOCKET {Direction}: Operation cancelled", direction);
} }
catch (WebSocketException wsEx) when (wsEx.WebSocketErrorCode == WebSocketError.ConnectionClosedPrematurely) catch (WebSocketException wsEx) when (wsEx.WebSocketErrorCode == WebSocketError.ConnectionClosedPrematurely)
{ {
_logger.LogWarning("⚠️ WEBSOCKET {Direction}: Connection closed prematurely", direction); _logger.LogDebug("⚠️ WEBSOCKET {Direction}: Connection closed prematurely", direction);
} }
catch (Exception ex) catch (Exception ex)
{ {

View File

@@ -33,7 +33,7 @@ public class JellyfinSessionManager : IDisposable
// Keep sessions alive every 10 seconds (Jellyfin considers sessions stale after ~15 seconds of inactivity) // 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)); _keepAliveTimer = new Timer(KeepSessionsAlive, null, TimeSpan.FromSeconds(10), TimeSpan.FromSeconds(10));
_logger.LogWarning("🔧 SESSION: JellyfinSessionManager initialized with 10-second keep-alive and WebSocket support"); _logger.LogDebug("🔧 SESSION: JellyfinSessionManager initialized with 10-second keep-alive and WebSocket support");
} }
/// <summary> /// <summary>
@@ -51,17 +51,17 @@ public class JellyfinSessionManager : IDisposable
if (_sessions.TryGetValue(deviceId, out var existingSession)) if (_sessions.TryGetValue(deviceId, out var existingSession))
{ {
existingSession.LastActivity = DateTime.UtcNow; existingSession.LastActivity = DateTime.UtcNow;
_logger.LogWarning("✓ SESSION: Session already exists for device {DeviceId}", deviceId); _logger.LogDebug("✓ SESSION: Session already exists for device {DeviceId}", deviceId);
// Refresh capabilities to keep session alive // Refresh capabilities to keep session alive
await PostCapabilitiesAsync(headers); await PostCapabilitiesAsync(headers);
return true; return true;
} }
_logger.LogWarning("🔧 SESSION: Creating new session for device: {DeviceId} ({Client} on {Device})", deviceId, client, device); _logger.LogInformation("🔧 SESSION: Creating new session for device: {DeviceId} ({Client} on {Device})", deviceId, client, device);
// Log the headers we received for debugging // Log the headers we received for debugging
_logger.LogWarning("🔍 SESSION: Headers received for session creation: {Headers}", _logger.LogDebug("🔍 SESSION: Headers received for session creation: {Headers}",
string.Join(", ", headers.Select(h => $"{h.Key}={h.Value.ToString().Substring(0, Math.Min(30, h.Value.ToString().Length))}..."))); string.Join(", ", headers.Select(h => $"{h.Key}={h.Value.ToString().Substring(0, Math.Min(30, h.Value.ToString().Length))}...")));
try try
@@ -69,7 +69,7 @@ public class JellyfinSessionManager : IDisposable
// Post session capabilities to Jellyfin - this creates the session // Post session capabilities to Jellyfin - this creates the session
await PostCapabilitiesAsync(headers); await PostCapabilitiesAsync(headers);
_logger.LogWarning("✓ SESSION: Session created for {DeviceId}", deviceId); _logger.LogInformation("✓ SESSION: Session created for {DeviceId}", deviceId);
// Track this session // Track this session
_sessions[deviceId] = new SessionInfo _sessions[deviceId] = new SessionInfo
@@ -135,11 +135,11 @@ public class JellyfinSessionManager : IDisposable
if (_sessions.TryGetValue(deviceId, out var session)) if (_sessions.TryGetValue(deviceId, out var session))
{ {
session.LastActivity = DateTime.UtcNow; session.LastActivity = DateTime.UtcNow;
_logger.LogWarning("🔄 SESSION: Updated activity for {DeviceId}", deviceId); _logger.LogDebug("🔄 SESSION: Updated activity for {DeviceId}", deviceId);
} }
else else
{ {
_logger.LogWarning("⚠️ SESSION: Cannot update activity - device {DeviceId} not found", deviceId); _logger.LogDebug("⚠️ SESSION: Cannot update activity - device {DeviceId} not found", deviceId);
} }
} }
@@ -150,7 +150,7 @@ public class JellyfinSessionManager : IDisposable
{ {
if (_sessions.TryRemove(deviceId, out var session)) if (_sessions.TryRemove(deviceId, out var session))
{ {
_logger.LogWarning("🗑️ SESSION: Removing session for device {DeviceId}", deviceId); _logger.LogInformation("🗑️ SESSION: Removing session for device {DeviceId}", deviceId);
// Close WebSocket if it exists // Close WebSocket if it exists
if (session.WebSocket != null && session.WebSocket.State == WebSocketState.Open) if (session.WebSocket != null && session.WebSocket.State == WebSocketState.Open)
@@ -158,7 +158,7 @@ public class JellyfinSessionManager : IDisposable
try try
{ {
await session.WebSocket.CloseAsync(WebSocketCloseStatus.NormalClosure, "Session ended", CancellationToken.None); await session.WebSocket.CloseAsync(WebSocketCloseStatus.NormalClosure, "Session ended", CancellationToken.None);
_logger.LogWarning("🔌 WEBSOCKET: Closed WebSocket for device {DeviceId}", deviceId); _logger.LogDebug("🔌 WEBSOCKET: Closed WebSocket for device {DeviceId}", deviceId);
} }
catch (Exception ex) catch (Exception ex)
{ {
@@ -178,7 +178,7 @@ public class JellyfinSessionManager : IDisposable
} }
catch (Exception ex) catch (Exception ex)
{ {
_logger.LogWarning(ex, "⚠️ SESSION: Error removing session for {DeviceId}", deviceId); _logger.LogWarning("⚠️ SESSION: Error removing session for {DeviceId}: {Message}", deviceId, ex.Message);
} }
} }
} }
@@ -191,7 +191,7 @@ public class JellyfinSessionManager : IDisposable
{ {
if (!_sessions.TryGetValue(deviceId, out var session)) if (!_sessions.TryGetValue(deviceId, out var session))
{ {
_logger.LogWarning("⚠️ WEBSOCKET: Cannot create WebSocket - session {DeviceId} not found", deviceId); _logger.LogDebug("⚠️ WEBSOCKET: Cannot create WebSocket - session {DeviceId} not found", deviceId);
return; return;
} }
@@ -213,7 +213,7 @@ public class JellyfinSessionManager : IDisposable
session.WebSocket = webSocket; session.WebSocket = webSocket;
// Log available headers for debugging // Log available headers for debugging
_logger.LogWarning("🔍 WEBSOCKET: Available headers for {DeviceId}: {Headers}", _logger.LogDebug("🔍 WEBSOCKET: Available headers for {DeviceId}: {Headers}",
deviceId, string.Join(", ", headers.Keys)); deviceId, string.Join(", ", headers.Keys));
// Forward authentication headers from the CLIENT - this is critical for session to appear under the right user // Forward authentication headers from the CLIENT - this is critical for session to appear under the right user
@@ -221,7 +221,7 @@ public class JellyfinSessionManager : IDisposable
if (headers.TryGetValue("X-Emby-Authorization", out var embyAuth)) if (headers.TryGetValue("X-Emby-Authorization", out var embyAuth))
{ {
webSocket.Options.SetRequestHeader("X-Emby-Authorization", embyAuth.ToString()); webSocket.Options.SetRequestHeader("X-Emby-Authorization", embyAuth.ToString());
_logger.LogWarning("🔑 WEBSOCKET: Using X-Emby-Authorization for {DeviceId}: {Auth}", _logger.LogDebug("🔑 WEBSOCKET: Using X-Emby-Authorization for {DeviceId}: {Auth}",
deviceId, embyAuth.ToString().Length > 50 ? embyAuth.ToString()[..50] + "..." : embyAuth.ToString()); deviceId, embyAuth.ToString().Length > 50 ? embyAuth.ToString()[..50] + "..." : embyAuth.ToString());
authFound = true; authFound = true;
} }
@@ -231,14 +231,14 @@ public class JellyfinSessionManager : IDisposable
if (authValue.Contains("MediaBrowser", StringComparison.OrdinalIgnoreCase)) if (authValue.Contains("MediaBrowser", StringComparison.OrdinalIgnoreCase))
{ {
webSocket.Options.SetRequestHeader("X-Emby-Authorization", authValue); webSocket.Options.SetRequestHeader("X-Emby-Authorization", authValue);
_logger.LogWarning("🔑 WEBSOCKET: Converted Authorization to X-Emby-Authorization for {DeviceId}: {Auth}", _logger.LogDebug("🔑 WEBSOCKET: Converted Authorization to X-Emby-Authorization for {DeviceId}: {Auth}",
deviceId, authValue.Length > 50 ? authValue[..50] + "..." : authValue); deviceId, authValue.Length > 50 ? authValue[..50] + "..." : authValue);
authFound = true; authFound = true;
} }
else else
{ {
webSocket.Options.SetRequestHeader("Authorization", authValue); webSocket.Options.SetRequestHeader("Authorization", authValue);
_logger.LogWarning("🔑 WEBSOCKET: Using Authorization for {DeviceId}: {Auth}", _logger.LogDebug("🔑 WEBSOCKET: Using Authorization for {DeviceId}: {Auth}",
deviceId, authValue.Length > 50 ? authValue[..50] + "..." : authValue); deviceId, authValue.Length > 50 ? authValue[..50] + "..." : authValue);
authFound = true; authFound = true;
} }
@@ -258,14 +258,14 @@ public class JellyfinSessionManager : IDisposable
} }
} }
_logger.LogWarning("🔗 WEBSOCKET: Connecting to Jellyfin for device {DeviceId}: {Url}", deviceId, jellyfinWsUrl); _logger.LogDebug("🔗 WEBSOCKET: Connecting to Jellyfin for device {DeviceId}: {Url}", deviceId, jellyfinWsUrl);
// Set user agent // Set user agent
webSocket.Options.SetRequestHeader("User-Agent", $"Allstarr-Proxy/{session.Client}"); webSocket.Options.SetRequestHeader("User-Agent", $"Allstarr-Proxy/{session.Client}");
// Connect to Jellyfin // Connect to Jellyfin
await webSocket.ConnectAsync(new Uri(jellyfinWsUrl), CancellationToken.None); await webSocket.ConnectAsync(new Uri(jellyfinWsUrl), CancellationToken.None);
_logger.LogWarning("✓ WEBSOCKET: Connected to Jellyfin for device {DeviceId}", deviceId); _logger.LogInformation("✓ WEBSOCKET: Connected to Jellyfin for device {DeviceId}", deviceId);
// CRITICAL: Send ForceKeepAlive message to initialize session in Jellyfin // CRITICAL: Send ForceKeepAlive message to initialize session in Jellyfin
// This tells Jellyfin to create/show the session in the dashboard // This tells Jellyfin to create/show the session in the dashboard
@@ -273,13 +273,13 @@ public class JellyfinSessionManager : IDisposable
var forceKeepAliveMessage = "{\"MessageType\":\"ForceKeepAlive\",\"Data\":100}"; var forceKeepAliveMessage = "{\"MessageType\":\"ForceKeepAlive\",\"Data\":100}";
var messageBytes = Encoding.UTF8.GetBytes(forceKeepAliveMessage); var messageBytes = Encoding.UTF8.GetBytes(forceKeepAliveMessage);
await webSocket.SendAsync(new ArraySegment<byte>(messageBytes), WebSocketMessageType.Text, true, CancellationToken.None); await webSocket.SendAsync(new ArraySegment<byte>(messageBytes), WebSocketMessageType.Text, true, CancellationToken.None);
_logger.LogWarning("📤 WEBSOCKET: Sent ForceKeepAlive to initialize session for {DeviceId}", deviceId); _logger.LogDebug("📤 WEBSOCKET: Sent ForceKeepAlive to initialize session for {DeviceId}", deviceId);
// Also send SessionsStart to subscribe to session updates // Also send SessionsStart to subscribe to session updates
var sessionsStartMessage = "{\"MessageType\":\"SessionsStart\",\"Data\":\"0,1500\"}"; var sessionsStartMessage = "{\"MessageType\":\"SessionsStart\",\"Data\":\"0,1500\"}";
messageBytes = Encoding.UTF8.GetBytes(sessionsStartMessage); messageBytes = Encoding.UTF8.GetBytes(sessionsStartMessage);
await webSocket.SendAsync(new ArraySegment<byte>(messageBytes), WebSocketMessageType.Text, true, CancellationToken.None); await webSocket.SendAsync(new ArraySegment<byte>(messageBytes), WebSocketMessageType.Text, true, CancellationToken.None);
_logger.LogWarning("📤 WEBSOCKET: Sent SessionsStart for {DeviceId}", deviceId); _logger.LogDebug("📤 WEBSOCKET: Sent SessionsStart for {DeviceId}", deviceId);
// Keep the WebSocket alive by reading messages and sending periodic keep-alive // Keep the WebSocket alive by reading messages and sending periodic keep-alive
var buffer = new byte[1024 * 4]; var buffer = new byte[1024 * 4];
@@ -300,7 +300,7 @@ public class JellyfinSessionManager : IDisposable
if (result.MessageType == WebSocketMessageType.Close) if (result.MessageType == WebSocketMessageType.Close)
{ {
_logger.LogWarning("🔌 WEBSOCKET: Jellyfin closed WebSocket for device {DeviceId}", deviceId); _logger.LogDebug("🔌 WEBSOCKET: Jellyfin closed WebSocket for device {DeviceId}", deviceId);
break; break;
} }
@@ -338,7 +338,7 @@ public class JellyfinSessionManager : IDisposable
var keepAliveMsg = "{\"MessageType\":\"KeepAlive\"}"; var keepAliveMsg = "{\"MessageType\":\"KeepAlive\"}";
var keepAliveBytes = Encoding.UTF8.GetBytes(keepAliveMsg); var keepAliveBytes = Encoding.UTF8.GetBytes(keepAliveMsg);
await webSocket.SendAsync(new ArraySegment<byte>(keepAliveBytes), WebSocketMessageType.Text, true, CancellationToken.None); await webSocket.SendAsync(new ArraySegment<byte>(keepAliveBytes), WebSocketMessageType.Text, true, CancellationToken.None);
_logger.LogWarning("💓 WEBSOCKET: Sent KeepAlive for {DeviceId}", deviceId); _logger.LogDebug("💓 WEBSOCKET: Sent KeepAlive for {DeviceId}", deviceId);
lastKeepAlive = DateTime.UtcNow; lastKeepAlive = DateTime.UtcNow;
} }
} }
@@ -366,7 +366,7 @@ public class JellyfinSessionManager : IDisposable
catch { } catch { }
} }
webSocket.Dispose(); webSocket.Dispose();
_logger.LogWarning("🧹 WEBSOCKET: Cleaned up WebSocket for device {DeviceId}", deviceId); _logger.LogDebug("🧹 WEBSOCKET: Cleaned up WebSocket for device {DeviceId}", deviceId);
} }
// Clear WebSocket reference from session // Clear WebSocket reference from session