diff --git a/src/Empostor.Api/Languages/LanguageService.cs b/src/Empostor.Api/Languages/LanguageService.cs index 9e1681b..9c70e57 100644 --- a/src/Empostor.Api/Languages/LanguageService.cs +++ b/src/Empostor.Api/Languages/LanguageService.cs @@ -59,7 +59,7 @@ public sealed class LanguageService { _tables.Clear(); LoadAll(); - _logger.LogInformation("[Language] Reloaded all language files."); + _logger.LogInformation("LanguageReloaded all language files."); } /// @@ -84,7 +84,7 @@ public sealed class LanguageService } } - _logger.LogDebug("[Language] Plugin added {Count} keys for {Lang}", table.Count, langCode); + _logger.LogDebug("LanguagePlugin added {Count} keys for {Lang}", table.Count, langCode); } } @@ -111,15 +111,15 @@ public sealed class LanguageService var table = JsonSerializer.Deserialize>(json) ?? new Dictionary(); _tables[code] = table; - _logger.LogDebug("[Language] Loaded {Code} ({Count} keys)", code, table.Count); + _logger.LogDebug("LanguageLoaded {Code} ({Count} keys)", code, table.Count); } catch (Exception ex) { - _logger.LogWarning(ex, "[Language] Failed to load {File}", file); + _logger.LogWarning(ex, "LanguageFailed to load {File}", file); } } - _logger.LogInformation("[Language] Loaded {Count} language file(s).", _tables.Count); + _logger.LogInformation("LanguageLoaded {Count} language file(s).", _tables.Count); } private void EnsureDefaults() diff --git a/src/Empostor.Server/Http/AdminController.cs b/src/Empostor.Server/Http/AdminController.cs index b09f652..c40bf7f 100644 --- a/src/Empostor.Server/Http/AdminController.cs +++ b/src/Empostor.Server/Http/AdminController.cs @@ -80,7 +80,7 @@ namespace Empostor.Server.Http || _config.Password == "admin123") { _logger.LogWarning( - "[Admin] SECURITY: Default or empty admin password detected! Set a strong password in config.json -> Admin.Password to protect the admin panel."); + "AdminSECURITY: Default or empty admin password detected! Set a strong password in config.json -> Admin.Password to protect the admin panel."); } } @@ -117,7 +117,7 @@ namespace Empostor.Server.Http && DateTime.UtcNow - entry.FirstAttempt < LoginLockoutDuration) { var remaining = (int)(LoginLockoutDuration - (DateTime.UtcNow - entry.FirstAttempt)).TotalMinutes; - _logger.LogWarning("[Admin] Rate-limited login attempt from {Ip} (locked out for ~{Min}m more)", ip, Math.Max(1, remaining)); + _logger.LogWarning("AdminRate-limited login attempt from {Ip} (locked out for ~{Min}m more)", ip, Math.Max(1, remaining)); return Content(LoginHtml.Replace("", $"

Too many failed attempts. Try again in {Math.Max(1, remaining)} minute(s).

"), "text/html; charset=utf-8"); @@ -138,7 +138,7 @@ namespace Empostor.Server.Http _ => (1, DateTime.UtcNow), (_, e) => (e.Count + 1, e.FirstAttempt)); - _logger.LogWarning("[Admin] Failed login from {Ip} (attempt {Count})", ip, + _logger.LogWarning("AdminFailed login from {Ip} (attempt {Count})", ip, _loginFailures.TryGetValue(ip, out var updated) ? updated.Count : 1); return Content(LoginHtml.Replace("", "

Incorrect password.

"), @@ -291,7 +291,7 @@ namespace Empostor.Server.Http return BadRequest(Err("No host character")); } - await host.SendChatAsync($"[Admin] {req.Message}"); + await host.SendChatAsync($"Admin{req.Message}"); return Ok(new { ok = true }); } diff --git a/src/Empostor.Server/Http/HelloController.cs b/src/Empostor.Server/Http/HelloController.cs index bbd32d3..553efd7 100644 --- a/src/Empostor.Server/Http/HelloController.cs +++ b/src/Empostor.Server/Http/HelloController.cs @@ -25,7 +25,7 @@ public sealed class HelloController : ControllerBase { if (!System.IO.File.Exists(IndexFile)) { - _logger.LogWarning("[HelloController] Pages/index.html not found, serving fallback."); + _logger.LogWarning("HelloControllerPages/index.html not found, serving fallback."); return Content(FallbackHtml(), "text/html; charset=utf-8"); } @@ -52,13 +52,13 @@ public sealed class HelloController : ControllerBase if (!Directory.Exists(PagesDir)) { Directory.CreateDirectory(PagesDir); - _logger.LogInformation("[HelloController] Created Pages/ directory at {Path}", PagesDir); + _logger.LogInformation("HelloControllerCreated Pages/ directory at {Path}", PagesDir); } if (!System.IO.File.Exists(IndexFile)) { System.IO.File.WriteAllText(IndexFile, DefaultIndexHtml()); - _logger.LogInformation("[HelloController] Written default Pages/index.html"); + _logger.LogInformation("HelloControllerWritten default Pages/index.html"); } } } diff --git a/src/Empostor.Server/Http/MarketplaceController.cs b/src/Empostor.Server/Http/MarketplaceController.cs index 379c7d6..ddbfa0a 100644 --- a/src/Empostor.Server/Http/MarketplaceController.cs +++ b/src/Empostor.Server/Http/MarketplaceController.cs @@ -96,7 +96,7 @@ namespace Empostor.Server.Http } catch (Exception ex) { - _logger.LogWarning(ex, "[Marketplace] Failed to fetch {Url}", url); + _logger.LogWarning(ex, "MarketplaceFailed to fetch {Url}", url); return StatusCode(502, new { error = "Failed to fetch marketplace: " + ex.Message }); } } @@ -148,12 +148,12 @@ namespace Empostor.Server.Http var bytes = await client.GetByteArrayAsync(req.DownloadUrl); await System.IO.File.WriteAllBytesAsync(Path.Combine(PluginsDir, fileName), bytes); - _logger.LogInformation("[Marketplace] Installed {File} from {Url}", fileName, req.DownloadUrl); + _logger.LogInformation("MarketplaceInstalled {File} from {Url}", fileName, req.DownloadUrl); return Ok(new { installed = fileName, restartRequired = true }); } catch (Exception ex) { - _logger.LogWarning(ex, "[Marketplace] Install failed: {Url}", req.DownloadUrl); + _logger.LogWarning(ex, "MarketplaceInstall failed: {Url}", req.DownloadUrl); return StatusCode(500, new { error = ex.Message }); } } @@ -184,7 +184,7 @@ namespace Empostor.Server.Http } catch (Exception ex) { - _logger.LogWarning(ex, "[Update] GitHub check failed"); + _logger.LogWarning(ex, "UpdateGitHub check failed"); return StatusCode(502, new { error = ex.Message }); } } diff --git a/src/Empostor.Server/Http/PrivacyController.cs b/src/Empostor.Server/Http/PrivacyController.cs index 715109d..b005505 100644 --- a/src/Empostor.Server/Http/PrivacyController.cs +++ b/src/Empostor.Server/Http/PrivacyController.cs @@ -54,7 +54,7 @@ public sealed class PrivacyController : ControllerBase return Unauthorized(new { error = "Invalid token." }); System.IO.File.WriteAllText(PrivacyFile, content); - _logger.LogInformation("[PrivacyController] Privacy policy updated."); + _logger.LogInformation("PrivacyControllerPrivacy policy updated."); return Ok(new { success = true }); } catch (Exception ex) @@ -78,7 +78,7 @@ public sealed class PrivacyController : ControllerBase if (!System.IO.File.Exists(PrivacyFile)) { System.IO.File.WriteAllText(PrivacyFile, DefaultPrivacyHtml()); - _logger.LogInformation("[PrivacyController] Written default Pages/privacy.html"); + _logger.LogInformation("PrivacyControllerWritten default Pages/privacy.html"); } } } diff --git a/src/Empostor.Server/Http/TokenController.cs b/src/Empostor.Server/Http/TokenController.cs index d8ac78b..e677860 100644 --- a/src/Empostor.Server/Http/TokenController.cs +++ b/src/Empostor.Server/Http/TokenController.cs @@ -65,7 +65,7 @@ public sealed class TokenController : ControllerBase { if (string.IsNullOrEmpty(authorization) || !authorization.StartsWith("Bearer ")) { - _logger.LogWarning("[TokenController] Missing or invalid Authorization header"); + _logger.LogWarning("TokenController missing or invalid Authorization header"); return Unauthorized(new { error = "Missing or invalid authorization" }); } @@ -73,7 +73,7 @@ public sealed class TokenController : ControllerBase var productUserId = ExtractProductUserIdFromJwt(eosToken); if (string.IsNullOrEmpty(productUserId)) { - _logger.LogWarning("[TokenController] Could not extract PUID from token"); + _logger.LogWarning("TokenController could not extract PUID from token"); return Unauthorized(new { error = "Invalid token content" }); } @@ -101,6 +101,10 @@ public sealed class TokenController : ControllerBase FriendCodeConfirmed = _nikoFriendCodeConfirmed, }; + // Extract name from friend code (e.g., "ufolud" from "ufolud#1234") + var playerName = friendCode?.Split('#')[0] ?? productUserId[..Math.Min(8, productUserId.Length)]; + authInfo.Name = playerName; + if (deltaPort > 0) { // Port allocated — store by port and start delta listener for UDP matching @@ -108,8 +112,8 @@ public sealed class TokenController : ControllerBase _ = _deltaListenerManager.StartDeltaListenerAsync(deltaPort); _logger.LogInformation( - "[TokenController] Authenticated: PUID={Puid} FriendCode={FC} DeltaPort={Port} IP={Ip}", - productUserId, friendCode, deltaPort, clientIp); + "TokenUser {Name} {Puid} {FriendCode} {Ip} {Port} added.", + playerName, productUserId, friendCode, clientIp, deltaPort); } else { @@ -120,8 +124,8 @@ public sealed class TokenController : ControllerBase } _logger.LogInformation( - "[TokenController] Authenticated: PUID={Puid} FriendCode={FC} Port=0 (IP fallback) IP={Ip}", - productUserId, friendCode, clientIp); + "TokenUser {Name} {Puid} {FriendCode} {Ip} {Port} added.", + playerName, productUserId, friendCode, clientIp, 0); } var response = new TokenResponse @@ -139,7 +143,7 @@ public sealed class TokenController : ControllerBase } catch (Exception ex) { - _logger.LogError(ex, "[TokenController] Unexpected error"); + _logger.LogError(ex, "TokenController unexpected error"); return StatusCode(500, new { error = "Internal server error" }); } } @@ -189,13 +193,13 @@ public sealed class TokenController : ControllerBase if (cached != null) { _logger.LogInformation( - "[TokenController] FriendCode found in cache: PUID={Puid} FC={FC}", + "TokenControllerFriendCode found in cache: PUID={Puid} FC={FC}", productUserId, cached); return cached; } var mode = _authApiConfig.Mode; - _logger.LogDebug("[TokenController] AuthApi mode: {Mode}", mode); + _logger.LogDebug("TokenControllerAuthApi mode: {Mode}", mode); string? friendCode = null; @@ -221,7 +225,7 @@ public sealed class TokenController : ControllerBase if (nikoKeyIsCustom) { - _logger.LogDebug("[TokenController] Both mode: trying Niko first (custom key)"); + _logger.LogDebug("TokenController Both mode: trying Niko first (custom key)"); friendCode = await FetchFromNikoAsync(eosToken, productUserId); if (string.IsNullOrEmpty(friendCode)) { @@ -230,7 +234,7 @@ public sealed class TokenController : ControllerBase } else { - _logger.LogDebug("[TokenController] Both mode: trying Ume first (default Niko key)"); + _logger.LogDebug("TokenController Both mode: trying Ume first (default Niko key)"); friendCode = await FetchFromUmeAsync(eosToken, productUserId); if (string.IsNullOrEmpty(friendCode)) { @@ -253,7 +257,7 @@ public sealed class TokenController : ControllerBase { friendCode = GenerateFallbackFriendCode(productUserId); _logger.LogWarning( - "[TokenController] FriendCode fetch failed for PUID={Puid}, using fallback: {FC}", + "TokenController FriendCode fetch failed for PUID={Puid}, using fallback: {FC}", productUserId, friendCode); } else @@ -333,13 +337,13 @@ public sealed class TokenController : ControllerBase if (!response.IsSuccessStatusCode) { _logger.LogWarning( - "[TokenController] Innersloth API returned {Status} for PUID={Puid}", + "TokenControllerInnersloth API returned {Status} for PUID={Puid}", response.StatusCode, productUserId); return null; } var json = await response.Content.ReadAsStringAsync(); - _logger.LogInformation("[TokenController] Innersloth raw response: {Json}", json); + _logger.LogInformation("TokenControllerInnersloth raw response: {Json}", json); using var doc = JsonDocument.Parse(json); var root = doc.RootElement; var attrs = root.TryGetProperty("data", out var data) @@ -351,18 +355,18 @@ public sealed class TokenController : ControllerBase { var fc = $"{username}#{discriminator}"; _logger.LogInformation( - "[TokenController] FriendCode fetched from Innersloth: PUID={Puid} FC={FC}", + "TokenControllerFriendCode fetched from Innersloth: PUID={Puid} FC={FC}", productUserId, fc); return fc; } _logger.LogWarning( - "[TokenController] Missing username/discriminator in Innersloth response for PUID={Puid}", + "TokenControllerMissing username/discriminator in Innersloth response for PUID={Puid}", productUserId); } catch (Exception ex) { - _logger.LogError(ex, "[TokenController] Exception calling Innersloth API for PUID={Puid}", productUserId); + _logger.LogError(ex, "TokenControllerException calling Innersloth API for PUID={Puid}", productUserId); } return null; @@ -372,7 +376,7 @@ public sealed class TokenController : ControllerBase { if (string.IsNullOrEmpty(_authApiConfig.NikoApiKey)) { - _logger.LogWarning("[TokenController] NikoApiKey is empty, skipping Niko API"); + _logger.LogWarning("TokenControllerNikoApiKey is empty, skipping Niko API"); return null; } @@ -400,7 +404,7 @@ public sealed class TokenController : ControllerBase if (!putResp.IsSuccessStatusCode) { _logger.LogWarning( - "[TokenController] Niko PUT returned {Status} for PUID={Puid}", + "TokenControllerNiko PUT returned {Status} for PUID={Puid}", putResp.StatusCode, productUserId); return null; } @@ -410,14 +414,14 @@ public sealed class TokenController : ControllerBase if (createResult == null || string.IsNullOrEmpty(createResult.VerifyCode)) { _logger.LogWarning( - "[TokenController] Niko PUT response missing VerifyCode for PUID={Puid}", productUserId); + "TokenControllerNiko PUT response missing VerifyCode for PUID={Puid}", productUserId); return null; } var verifyCode = createResult.VerifyCode; _nikoVerifyCode = verifyCode; _logger.LogInformation( - "[TokenController] Niko verify request created: Code={Code} for PUID={Puid}", + "TokenControllerNiko verify request created: Code={Code} for PUID={Puid}", verifyCode, productUserId); // Proxy EOS token to Niko to trigger HTTP auth @@ -454,14 +458,14 @@ public sealed class TokenController : ControllerBase && !string.Equals(result.Puid, productUserId, StringComparison.OrdinalIgnoreCase)) { _logger.LogWarning( - "[TokenController] Niko PUID mismatch: expected={Expected} got={Got}", + "TokenControllerNiko PUID mismatch: expected={Expected} got={Got}", productUserId, result.Puid); return null; } _nikoFriendCodeConfirmed = true; _logger.LogInformation( - "[TokenController] FriendCode fetched from Niko: PUID={Puid} FC={FC} Status={Status}", + "TokenControllerFriendCode fetched from Niko: PUID={Puid} FC={FC} Status={Status}", productUserId, result.FriendCode, result.VerifyStatus); _ = DeleteNikoVerificationAsync(client, apiUrl, verifyCode); @@ -470,17 +474,17 @@ public sealed class TokenController : ControllerBase } _logger.LogDebug( - "[TokenController] Niko poll {Attempt}: Status={Status} for PUID={Puid}", + "TokenControllerNiko poll {Attempt}: Status={Status} for PUID={Puid}", i + 1, result.VerifyStatus ?? "null", productUserId); } _logger.LogInformation( - "[TokenController] Niko friend code not yet available for PUID={Puid}, VerifyCode={Code} deferred to handshake", + "TokenControllerNiko friend code not yet available for PUID={Puid}, VerifyCode={Code} deferred to handshake", productUserId, verifyCode); } catch (Exception ex) { - _logger.LogError(ex, "[TokenController] Exception calling Niko API for PUID={Puid}", productUserId); + _logger.LogError(ex, "TokenControllerException calling Niko API for PUID={Puid}", productUserId); } return null; @@ -500,13 +504,13 @@ public sealed class TokenController : ControllerBase var resp = await client.SendAsync(req); _logger.LogDebug( - "[TokenController] Niko proxy auth returned {Status} for PUID={Puid}", + "TokenControllerNiko proxy auth returned {Status} for PUID={Puid}", resp.StatusCode, productUserId); } catch (Exception ex) { _logger.LogWarning(ex, - "[TokenController] Failed to proxy EOS token to Niko for PUID={Puid}", productUserId); + "TokenControllerFailed to proxy EOS token to Niko for PUID={Puid}", productUserId); } } @@ -537,7 +541,7 @@ public sealed class TokenController : ControllerBase if (string.IsNullOrEmpty(_authApiConfig.RelayApiBaseUrl) || string.IsNullOrEmpty(_authApiConfig.RelayApiKey)) { - _logger.LogWarning("[TokenController] RelayApi config incomplete, skipping relay"); + _logger.LogWarning("TokenControllerRelayApi config incomplete, skipping relay"); return null; } @@ -563,7 +567,7 @@ public sealed class TokenController : ControllerBase if (!resp.IsSuccessStatusCode) { _logger.LogWarning( - "[TokenController] Relay returned {Status} for PUID={Puid}", + "TokenControllerRelay returned {Status} for PUID={Puid}", resp.StatusCode, productUserId); return null; } @@ -573,7 +577,7 @@ public sealed class TokenController : ControllerBase if (result == null || string.IsNullOrEmpty(result.FriendCode)) { _logger.LogWarning( - "[TokenController] Relay response missing FriendCode for PUID={Puid}", + "TokenControllerRelay response missing FriendCode for PUID={Puid}", productUserId); return null; } @@ -582,19 +586,19 @@ public sealed class TokenController : ControllerBase || !string.Equals(result.ProductUserId, productUserId, StringComparison.OrdinalIgnoreCase)) { _logger.LogWarning( - "[TokenController] Relay PUID mismatch: expected={Expected} got={Got}", + "TokenControllerRelay PUID mismatch: expected={Expected} got={Got}", productUserId, result.ProductUserId); return null; } _logger.LogInformation( - "[TokenController] FriendCode from Relay: PUID={Puid} FC={FC}", + "TokenControllerFriendCode from Relay: PUID={Puid} FC={FC}", productUserId, result.FriendCode); return result.FriendCode; } catch (Exception ex) { - _logger.LogError(ex, "[TokenController] Exception calling Relay for PUID={Puid}", productUserId); + _logger.LogError(ex, "TokenControllerException calling Relay for PUID={Puid}", productUserId); } return null; @@ -605,7 +609,7 @@ public sealed class TokenController : ControllerBase if (string.IsNullOrEmpty(_authApiConfig.UmeApiBaseUrl) || string.IsNullOrEmpty(_authApiConfig.UmeApiKey)) { - _logger.LogWarning("[TokenController] UmeApi config incomplete, skipping Ume"); + _logger.LogWarning("TokenControllerUmeApi config incomplete, skipping Ume"); return null; } @@ -629,13 +633,13 @@ public sealed class TokenController : ControllerBase if (!resp.IsSuccessStatusCode) { _logger.LogWarning( - "[TokenController] Ume returned {Status} for PUID={Puid}", + "TokenControllerUme returned {Status} for PUID={Puid}", resp.StatusCode, productUserId); return null; } var json = await resp.Content.ReadAsStringAsync(); - _logger.LogInformation("[TokenController] Ume raw response: {Json}", json); + _logger.LogInformation("TokenControllerUme raw response: {Json}", json); using var doc = JsonDocument.Parse(json); var root = doc.RootElement; @@ -643,7 +647,7 @@ public sealed class TokenController : ControllerBase if (status != "Verified") { _logger.LogWarning( - "[TokenController] Ume VerifyStatus={Status} for PUID={Puid}", + "TokenControllerUme VerifyStatus={Status} for PUID={Puid}", status, productUserId); return null; } @@ -652,7 +656,7 @@ public sealed class TokenController : ControllerBase if (string.IsNullOrEmpty(friendCode)) { _logger.LogWarning( - "[TokenController] Ume response missing FriendCode for PUID={Puid}", + "TokenControllerUme response missing FriendCode for PUID={Puid}", productUserId); return null; } @@ -662,19 +666,19 @@ public sealed class TokenController : ControllerBase || !string.Equals(returnedPuid, productUserId, StringComparison.OrdinalIgnoreCase)) { _logger.LogWarning( - "[TokenController] Ume PUID mismatch: expected={Expected} got={Got}", + "TokenControllerUme PUID mismatch: expected={Expected} got={Got}", productUserId, returnedPuid); return null; } _logger.LogInformation( - "[TokenController] FriendCode from Ume: PUID={Puid} FC={FC}", + "TokenControllerFriendCode from Ume: PUID={Puid} FC={FC}", productUserId, friendCode); return friendCode; } catch (Exception ex) { - _logger.LogError(ex, "[TokenController] Exception calling Ume for PUID={Puid}", productUserId); + _logger.LogError(ex, "TokenControllerException calling Ume for PUID={Puid}", productUserId); } return null; diff --git a/src/Empostor.Server/Net/Client.cs b/src/Empostor.Server/Net/Client.cs index 4e33362..23e5379 100644 --- a/src/Empostor.Server/Net/Client.cs +++ b/src/Empostor.Server/Net/Client.cs @@ -65,7 +65,7 @@ namespace Empostor.Server.Net bool LogUnknownCategory(CheatCategory category) { - _logger.LogWarning("Unknown cheat category {Category} was used when reporting", category); + _logger.LogWarning("Client [{Id}] unknown cheat category {Category} when reporting", Id, category); return true; } @@ -91,7 +91,7 @@ namespace Empostor.Server.Net var supportCode = Random.Shared.Next(0, 999_999).ToString("000-000"); - _logger.LogWarning("Client {Name} ({Id}) was caught cheating: [{SupportCode}] [{Context}-{Category}] {Message}", Name, Id, supportCode, context.Name, category, message); + _logger.LogWarning("Client [{Id}]{Name} was caught cheating: [{SupportCode}] [{Context}-{Category}] {Message}", Id, Name, supportCode, context.Name, category, message); if (Player is { } player) { @@ -118,7 +118,7 @@ namespace Empostor.Server.Net { var flag = reader.Tag; - _logger.LogTrace("[{0}] Server got {1}.", Id, MessageFlags.FlagToString(flag)); + _logger.LogTrace("Client [{Id}] received {Flag}", Id, MessageFlags.FlagToString(flag)); switch (flag) { @@ -278,13 +278,13 @@ namespace Empostor.Server.Net if (packed.Tag != MessageFlags.GameDataTo) { - _logger.LogWarning("PackedGameDataTo contained non-GameDataTo flag {0}.", packed.Tag); + _logger.LogWarning("Client [{Id}] PackedGameDataTo contained non-GameDataTo flag {Flag}", Id, packed.Tag); return; } if (packed.ReadInt32() != Player!.Game.Code) { - _logger.LogWarning("PackedGameDataTo contained GameDataTo for the wrong game."); + _logger.LogWarning("Client [{Id}] PackedGameDataTo contained GameDataTo for wrong game", Id); return; } @@ -390,7 +390,7 @@ namespace Empostor.Server.Net break; } - _logger.LogWarning("Server received unknown flag {0}.", flag); + _logger.LogWarning("Client [{Id}] sent unknown flag {Flag}", Id, flag); break; } @@ -402,7 +402,8 @@ namespace Empostor.Server.Net reader.Position < reader.Length) { _logger.LogWarning( - "Server did not consume all bytes from {0} ({1} < {2}).", + "Client [{Id}] unconsumed bytes for flag {Flag} ({Pos} < {Len})", + Id, flag, reader.Position, reader.Length); @@ -423,10 +424,14 @@ namespace Empostor.Server.Net } catch (Exception ex) { - _logger.LogError(ex, "Exception caught in client disconnection."); + _logger.LogError(ex, "Exception caught in client [{Id}] disconnection.", Id); } - _logger.LogInformation("Client {0} disconnecting, reason: {1}", Id, reason); + var platform = PlatformSpecificData?.Platform.ToString().ToLowerInvariant() ?? "unknown"; + var hashPuid = ProductUserId?.Length >= 9 ? ProductUserId[..9] : ProductUserId ?? "0"; + var fc = FriendCode ?? "unknown"; + _logger.LogInformation("Client {Id} {Name} {FriendCode} {HashPuid} {Platform} disconnecting, reason: {Reason}", + Id, Name, fc, hashPuid, platform, reason); _clientManager.Remove(this); await _gameManager.OnClientDisconnectAsync(this); } @@ -454,7 +459,7 @@ namespace Empostor.Server.Net return true; } - _logger.LogWarning("[{0}] Client sent packet only allowed by the host ({1}).", Id, game.HostId); + _logger.LogWarning("Client [{Id}] sent packet only allowed by the host ({HostId})", Id, game.HostId); return false; } @@ -480,7 +485,7 @@ namespace Empostor.Server.Net return true; } - _logger.LogWarning("[{0}] Client sent PackedGameDataTo only allowed by the host ({1}).", Id, game.HostId); + _logger.LogWarning("Client [{Id}] sent PackedGameDataTo only allowed by the host ({HostId})", Id, game.HostId); return false; } diff --git a/src/Empostor.Server/Net/Manager/ClientManager.cs b/src/Empostor.Server/Net/Manager/ClientManager.cs index 4558032..6b46ec6 100644 --- a/src/Empostor.Server/Net/Manager/ClientManager.cs +++ b/src/Empostor.Server/Net/Manager/ClientManager.cs @@ -59,23 +59,24 @@ namespace Empostor.Server.Net.Manager _authApiConfig = authApiConfig.Value; _portPool = portPool; + if (_compatibilityConfig.AllowFutureGameVersions) + { + _logger.LogWarning("AllowFutureGameVersions, which allows future Among Us versions to connect that were unknown at the time this Impostor was built"); + } + + if (_compatibilityConfig.AllowHostAuthority) + { + _logger.LogWarning("AllowHostAuthority, which allows game hosts to control more game features, but it uses less well tested code on the client, which causes some bugs"); + } + + if (_compatibilityConfig.AllowVersionMixing) + { + _logger.LogWarning("AllowVersionMixing, which allows players to join games created on different game versions that they may not be 100% compatible with"); + } + if (_compatibilityConfig.AllowFutureGameVersions || _compatibilityConfig.AllowHostAuthority || _compatibilityConfig.AllowVersionMixing) { - _logger.LogWarning("One or more compatibility options were enabled, please mention these when seeking support:"); - if (_compatibilityConfig.AllowFutureGameVersions) - { - _logger.LogWarning("AllowFutureGameVersions"); - } - - if (_compatibilityConfig.AllowHostAuthority) - { - _logger.LogWarning("AllowHostAuthority"); - } - - if (_compatibilityConfig.AllowVersionMixing) - { - _logger.LogWarning("AllowVersionMixing"); - } + _logger.LogWarning("One or more compatibility options were enabled, please mention these when seeking support"); } } @@ -97,11 +98,13 @@ namespace Empostor.Server.Net.Manager PlatformSpecificData? platformSpecificData, int deltaPort = 0) { + var id = NextId(); + var versionCompare = _compatibilityManager.CanConnectToServer(clientVersion); if (versionCompare == ICompatibilityManager.VersionCompareResult.ServerTooOld && _compatibilityConfig.AllowFutureGameVersions && platformSpecificData != null) { - _logger.LogWarning("Client connected using future version: {v}", clientVersion); + _logger.LogWarning("Client [{Id}]{Name} connected using future version {Version}", id, name, clientVersion); } else if (versionCompare != ICompatibilityManager.VersionCompareResult.Compatible || platformSpecificData == null) @@ -126,7 +129,7 @@ namespace Empostor.Server.Net.Manager return; } - _logger.LogInformation("Player {Name} connected with host authority.", name); + _logger.LogInformation("Client [{Id}]{Name} connected with host authority", id, name); } if (name.Length > 10) { await connection.CustomDisconnectAsync(DisconnectReason.Custom, DisconnectMessages.UsernameLength); return; } @@ -158,28 +161,25 @@ namespace Empostor.Server.Net.Manager friendCode = nikoResult.Value.FriendCode; authInfo.FriendCode = friendCode; authInfo.FriendCodeConfirmed = true; - _logger.LogInformation( - "[Auth] {Name}: Niko PUID matched via port={Port} → FriendCode={FC} PUID={Puid}", - name, deltaPort, friendCode, authInfo.ProductUserId); } else { _logger.LogWarning( - "[Auth] {Name}: Niko PUID mismatch (expected={Expected}, got={Got}) — keeping existing FC", + "Niko PUID mismatch for {Name}: expected {Expected} got {Got}", name, authInfo.ProductUserId, nikoResult.Value.Puid); } } } _logger.LogInformation( - "[Auth] {Name}: matched via port={Port} → FriendCode={FC} PUID={Puid}", - name, deltaPort, friendCode, authInfo.ProductUserId); + "Client [{Id}]{Name} from port {Port} is authorized as {FriendCode} {HashPuid}", + id, name, deltaPort, friendCode ?? "unknown", HashPuid(authInfo.ProductUserId)); } else { _logger.LogWarning( - "[Auth] {Name}: port={Port} has no auth info (expired or unknown), falling back to IP", - name, deltaPort); + "Client [{Id}]{Name} port {Port} has no auth info, falling back to IP", + id, name, deltaPort); } } @@ -191,14 +191,14 @@ namespace Empostor.Server.Net.Manager { friendCode = authInfo.FriendCode; _logger.LogInformation( - "[Auth] {Name}: matched via IP={Ip} → FriendCode={FC}", - name, NormalizeIp(clientIp), friendCode); + "Client [{Id}]{Name} from {Ip} is authorized as {FriendCode} {HashPuid}", + id, name, NormalizeIp(clientIp), friendCode ?? "unknown", HashPuid(authInfo.ProductUserId)); } else { _logger.LogWarning( - "[Auth] {Name}: no auth info found (deltaPort={DP}, IP={Ip}) — FriendCode will be null", - name, deltaPort, NormalizeIp(clientIp)); + "Client [{Id}]{Name}: no auth info found (port={Port}, ip={Ip})", + id, name, deltaPort, NormalizeIp(clientIp)); } } @@ -207,16 +207,15 @@ namespace Empostor.Server.Net.Manager client.ProductUserId = authInfo?.ProductUserId; client.DeltaPort = deltaPort; - var id = NextId(); client.Id = id; - _logger.LogTrace("Client connected: Id={Id} Name={Name} FriendCode={FC} DeltaPort={DP}", id, name, client.FriendCode ?? "(none)", deltaPort); + _logger.LogDebug("Client [{Id}]{Name} connected with FriendCode={FC} DeltaPort={DP}", id, name, client.FriendCode ?? "(none)", deltaPort); _clients.TryAdd(id, client); await _eventManager.CallAsync(new ClientConnectedEvent(connection, client)); } public void Remove(IClient client) { - _logger.LogTrace("Client {Id} disconnected.", client.Id); + _logger.LogDebug("Client [{Id}] removed from client manager", client.Id); _clients.TryRemove(client.Id, out _); if (client is ClientBase cb && cb.DeltaPort > 0) @@ -261,12 +260,12 @@ namespace Empostor.Server.Net.Manager if (string.IsNullOrEmpty(friendCode) || (status != "HttpPending" && status != "Verified")) { - _logger.LogDebug("[Auth] Niko GET status={Status} for VerifyCode={Code}", status, verifyCode); + _logger.LogDebug("Niko GET status={Status} for VerifyCode={Code}", status, verifyCode); return null; } _logger.LogInformation( - "[Auth] Niko GET success: FC={FC} PUID={Puid} Status={Status}", + "Niko GET success: FC={FC} PUID={Puid} Status={Status}", friendCode, puid, status); _ = DeleteNikoVerifyAsync(apiUrl, verifyCode); @@ -275,7 +274,7 @@ namespace Empostor.Server.Net.Manager } catch (Exception ex) { - _logger.LogWarning(ex, "[Auth] Niko GET failed for VerifyCode={Code}", verifyCode); + _logger.LogWarning(ex, "Niko GET failed for VerifyCode={Code}", verifyCode); return null; } } @@ -308,5 +307,16 @@ namespace Empostor.Server.Net.Manager return addr.IsIPv4MappedToIPv6 ? addr.MapToIPv4().ToString() : addr.ToString(); } + + private static string HashPuid(string puid) + { + if (string.IsNullOrEmpty(puid) || puid.Length < 9) + { + return puid ?? "0"; + } + + // Use first 9 characters of the PUID as the short hash + return puid[..9]; + } } } diff --git a/src/Empostor.Server/Net/Manager/GameManager.cs b/src/Empostor.Server/Net/Manager/GameManager.cs index 31d2fcc..90420e1 100644 --- a/src/Empostor.Server/Net/Manager/GameManager.cs +++ b/src/Empostor.Server/Net/Manager/GameManager.cs @@ -77,7 +77,7 @@ namespace Empostor.Server.Net.Manager return; } - _logger.LogDebug("Remove game with code {0} ({1}).", GameCodeParser.IntToGameName(gameCode), gameCode); + _logger.LogInformation("Remove game with code {CodeName} ({Code}).", GameCodeParser.IntToGameName(gameCode), gameCode); await _eventManager.CallAsync(new GameDestroyedEvent(game)); } diff --git a/src/Empostor.Server/Net/Matchmaker.cs b/src/Empostor.Server/Net/Matchmaker.cs index 40c4800..3916a46 100644 --- a/src/Empostor.Server/Net/Matchmaker.cs +++ b/src/Empostor.Server/Net/Matchmaker.cs @@ -79,7 +79,7 @@ namespace Empostor.Server.Net }; await _mainListener.StartAsync(); - _logger.LogInformation("[Matchmaker] UDP listener started on {EP}", ipEndPoint); + _logger.LogInformation("Matchmaker UDP listener started on {EP}", ipEndPoint); } /// @@ -89,13 +89,13 @@ namespace Empostor.Server.Net { if (_mainEndPoint == null) { - _logger.LogError("[Matchmaker] Cannot start delta listener: main endpoint not initialized"); + _logger.LogError("Matchmaker cannot start delta listener: main endpoint not initialized"); return; } if (_deltaListeners.ContainsKey(port)) { - _logger.LogDebug("[Matchmaker] Delta listener for port {Port} already running", port); + _logger.LogDebug("Matchmaker delta listener for port {Port} already running", port); return; } @@ -120,11 +120,11 @@ namespace Empostor.Server.Net // Open firewall for this port await _firewall.OpenPortAsync((ushort)port); - _logger.LogInformation("[Matchmaker] Delta UDP listener started on port {Port}", port); + _logger.LogInformation("Matchmaker delta UDP listener started on port {Port}", port); } catch (SocketException ex) { - _logger.LogError(ex, "[Matchmaker] Failed to start delta listener on port {Port} (may be in use)", port); + _logger.LogError(ex, "Matchmaker failed to start delta listener on port {Port} (may be in use)", port); // Return the port — it's unusable _portPool.ReturnPort(port); } @@ -140,11 +140,11 @@ namespace Empostor.Server.Net } catch (Exception ex) { - _logger.LogWarning(ex, "[Matchmaker] Error disposing delta listener on port {Port}", port); + _logger.LogWarning(ex, "Matchmaker error disposing delta listener on port {Port}", port); } await _firewall.ClosePortAsync((ushort)port); - _logger.LogInformation("[Matchmaker] Delta UDP listener stopped on port {Port}", port); + _logger.LogInformation("Matchmaker delta UDP listener stopped on port {Port}", port); } } @@ -160,11 +160,11 @@ namespace Empostor.Server.Net try { await listener.DisposeAsync(); - _logger.LogDebug("[Matchmaker] Stopped delta listener on port {Port}", port); + _logger.LogDebug("Matchmaker stopped delta listener on port {Port}", port); } catch (Exception ex) { - _logger.LogWarning(ex, "[Matchmaker] Error stopping delta listener on port {Port}", port); + _logger.LogWarning(ex, "Matchmaker error stopping delta listener on port {Port}", port); } } diff --git a/src/Empostor.Server/Net/MatchmakerService.cs b/src/Empostor.Server/Net/MatchmakerService.cs index a79d2ed..1772c59 100644 --- a/src/Empostor.Server/Net/MatchmakerService.cs +++ b/src/Empostor.Server/Net/MatchmakerService.cs @@ -38,7 +38,7 @@ namespace Empostor.Server.Net await _matchmaker.StartAsync(endpoint); _logger.LogInformation( - "Matchmaker is listening on {0}:{1}, the public server ip is {2}:{3}.", + "Matchmaker is listening on {Address}:{Port}, the public server ip is {PublicIp}:{PublicPort}.", endpoint.Address, endpoint.Port, _serverConfig.ResolvePublicIp(), @@ -47,16 +47,12 @@ namespace Empostor.Server.Net if (_portPool.IsEnabled) { _logger.LogInformation( - "Delta port pool enabled: range {Start}-{End}, firewall UFW={Ufw} Firewalld={Fwd}", - _serverConfig.DeltaPortStart, - _serverConfig.DeltaPortEnd, - _serverConfig.UseUfw, - _serverConfig.UseFirewalld); + "Delta Matchmaker is enabled."); } else { _logger.LogInformation( - "Delta port pool disabled (DeltaPortStart={Start}, DeltaPortEnd={End}). Using IP-based matching.", + "Delta Matchmaker is disabled (DeltaPortStart={Start}, DeltaPortEnd={End}). Using IP-based matching.", _serverConfig.DeltaPortStart, _serverConfig.DeltaPortEnd); } diff --git a/src/Empostor.Server/Net/PortPoolService.cs b/src/Empostor.Server/Net/PortPoolService.cs index 9fcb85e..2a6dc0f 100644 --- a/src/Empostor.Server/Net/PortPoolService.cs +++ b/src/Empostor.Server/Net/PortPoolService.cs @@ -60,17 +60,17 @@ public sealed class PortPoolService : IDisposable if (skipped > 0) { _logger.LogWarning( - "[PortPool] Skipped {Count} port(s) overlapping with main listen port {ListenPort}", + "PortPool skipped {Count} port(s) overlapping with main listen port {ListenPort}", skipped, _listenPort); } _logger.LogInformation( - "[PortPool] Initialized with {Count} ports ({Start}-{End})", + "PortPool initialized with {Count} ports ({Start}-{End})", _availablePorts.Count, _deltaPortStart, _deltaPortEnd); } else { - _logger.LogInformation("[PortPool] Disabled (DeltaPortStart={Start}, DeltaPortEnd={End})", + _logger.LogInformation("PortPool disabled (DeltaPortStart={Start}, DeltaPortEnd={End})", _deltaPortStart, _deltaPortEnd); } } @@ -87,7 +87,7 @@ public sealed class PortPoolService : IDisposable if (!_availablePorts.TryTake(out var port)) { - _logger.LogWarning("[PortPool] Pool exhausted for PUID={Puid}", puid); + _logger.LogWarning("PortPool exhausted for PUID={Puid}", puid); return 0; } @@ -105,7 +105,7 @@ public sealed class PortPoolService : IDisposable _timeouts[port] = cts; _ = TimeoutAsync(port, cts.Token); - _logger.LogDebug("[PortPool] Allocated port {Port} to PUID={Puid}", port, puid); + _logger.LogDebug("PortPool allocated port {Port} to PUID={Puid}", port, puid); return port; } @@ -125,7 +125,7 @@ public sealed class PortPoolService : IDisposable _activeLeases.TryRemove(port, out _); _availablePorts.Add(port); - _logger.LogInformation("[PortPool] Returned port {Port} to pool", port); + _logger.LogInformation("PortPool returned port {Port} to pool", port); OnPortReturned?.Invoke(port); } @@ -145,7 +145,7 @@ public sealed class PortPoolService : IDisposable { cts.Cancel(); cts.Dispose(); - _logger.LogDebug("[PortPool] Port {Port} confirmed (timeout cancelled)", port); + _logger.LogDebug("PortPool port {Port} confirmed (timeout cancelled)", port); } } @@ -161,7 +161,7 @@ public sealed class PortPoolService : IDisposable await Task.Delay(TimeSpan.FromMinutes(5), ct); // Timer fired — no connection came in - _logger.LogWarning("[PortPool] Port {Port} lease expired (no connection), returning to pool", port); + _logger.LogWarning("PortPool port {Port} lease expired (no connection), returning to pool", port); ReturnPort(port); } catch (OperationCanceledException) diff --git a/src/Empostor.Server/Net/State/ClientPlayer.cs b/src/Empostor.Server/Net/State/ClientPlayer.cs index 4e7383d..72fde4c 100644 --- a/src/Empostor.Server/Net/State/ClientPlayer.cs +++ b/src/Empostor.Server/Net/State/ClientPlayer.cs @@ -75,13 +75,13 @@ namespace Empostor.Server.Net.State { if (Character == null) { - _logger.LogInformation("{0} - Player {1} spawn timed out, kicking.", Game.Code, Client.Id); + _logger.LogInformation("{Code} - Player {Id} spawn timed out, kicking.", Game.Code, Client.Id); await KickAsync(); } } catch (Exception e) { - _logger.LogError(e, "Exception caught while kicking player for spawn timeout."); + _logger.LogError(e, "{Code} - Exception while kicking player {Id} for spawn timeout", Game.Code, Client.Id); } finally { diff --git a/src/Empostor.Server/Net/State/Game.Data.cs b/src/Empostor.Server/Net/State/Game.Data.cs index 2cc340e..04a8122 100644 --- a/src/Empostor.Server/Net/State/Game.Data.cs +++ b/src/Empostor.Server/Net/State/Game.Data.cs @@ -87,7 +87,7 @@ namespace Empostor.Server.Net.State var targetId = parent.ReadPackedInt32(); if (!TryGetPlayer(targetId, out target)) { - _logger.LogWarning("Player {0} tried to send GameData to unknown player {1}.", sender.Client.Id, targetId); + _logger.LogWarning("{Code} - Player {Id} sent GameData to unknown player {Target}", Code, sender.Client.Id, targetId); return false; } @@ -110,7 +110,7 @@ namespace Empostor.Server.Net.State } else { - _logger.LogWarning("Received DataFlag for unregistered NetId {0}.", netId); + _logger.LogWarning("{Code} - Received DataFlag for unregistered NetId {NetId}", Code, netId); } break; @@ -129,7 +129,7 @@ namespace Empostor.Server.Net.State } else { - _logger.LogWarning("Received RpcFlag for unregistered NetId {0}.", netId); + _logger.LogWarning("{Code} - Received RpcFlag for unregistered NetId {NetId}", Code, netId); } break; @@ -315,7 +315,7 @@ namespace Empostor.Server.Net.State default: { - _logger.LogWarning("Bad GameData tag {0}", reader.Tag); + _logger.LogWarning("{Code} - Bad GameData tag {Tag}", Code, reader.Tag); break; } } @@ -513,7 +513,7 @@ namespace Empostor.Server.Net.State if (!AddNetObject(playerInfo)) { - _logger.LogError("Couldn't spawn PlayerInfo for {Name} ({ClientId})", sender.Client.Name, sender.Client.Id); + _logger.LogError("{Code} - Could not spawn PlayerInfo for {Name} ({ClientId})", Code, sender.Client.Name, sender.Client.Id); playerInfo.NetId = uint.MaxValue; return; } diff --git a/src/Empostor.Server/Net/State/Game.Incoming.cs b/src/Empostor.Server/Net/State/Game.Incoming.cs index 2e2986f..0573923 100644 --- a/src/Empostor.Server/Net/State/Game.Incoming.cs +++ b/src/Empostor.Server/Net/State/Game.Incoming.cs @@ -57,7 +57,7 @@ namespace Empostor.Server.Net.State public async ValueTask HandleRemovePlayer(int playerId, DisconnectReason reason) { - await PlayerRemove(playerId); + await PlayerRemove(playerId, reason: reason.ToString()); if (GameState == GameStates.Destroyed) { return; @@ -70,14 +70,14 @@ namespace Empostor.Server.Net.State public async ValueTask HandleKickPlayer(int playerId, bool isBan) { - _logger.LogInformation("{0} - Player {1} has left.", Code, playerId); + _logger.LogInformation("{Code} - Kicking player {PlayerId} (Ban={IsBan})", Code, playerId, isBan); using (var kickMsg = MessageWriter.Get(MessageType.Reliable)) { WriteKickPlayerMessage(kickMsg, false, playerId, isBan); await SendToAllAsync(kickMsg); } - await PlayerRemove(playerId, isBan); + await PlayerRemove(playerId, reason: isBan ? "Ban" : "Kicked", isBan: isBan); if (GameState == GameStates.Destroyed) { return; @@ -118,7 +118,18 @@ namespace Empostor.Server.Net.State private async ValueTask HandleJoinGameNew(ClientPlayer sender, bool isNew) { - _logger.LogInformation("{0} - Player {1} ({2}) is joining.", Code, sender.Client.Name, sender.Client.Id); + var client = sender.Client; + var clientIp = client.Connection.EndPoint?.Address; + var ipStr = clientIp?.IsIPv4MappedToIPv6 == true ? clientIp.MapToIPv4().ToString() : clientIp?.ToString() ?? "?"; + var remotePort = (client.Connection.EndPoint as System.Net.IPEndPoint)?.Port ?? 0; + var authority = client.GameVersion.HasDisableServerAuthorityFlag ? "true" : "false"; + var version = client.GameVersion.ToString(); + var hashPuid = client.ProductUserId?.Length >= 9 ? client.ProductUserId[..9] : client.ProductUserId ?? "0"; + var deltaPort = client.DeltaPort; + + _logger.LogInformation("{Code} - Player {Name} ({HashPuid}) ({Id}) is joining from ({Ip}:{RemotePort}) with v{Version}, Authority:{Authority}, port: {DeltaPort}", + Code, sender.Client.Name, hashPuid, sender.Client.Id, ipStr, remotePort, version, authority, deltaPort); + if (isNew) { await PlayerAdd(sender); @@ -206,7 +217,10 @@ namespace Empostor.Server.Net.State private async ValueTask HandleJoinGameNext(ClientPlayer sender, bool isNew) { - _logger.LogInformation("{0} - Player {1} ({2}) is rejoining.", Code, sender.Client.Name, sender.Client.Id); + var authority = sender.Client.GameVersion.HasDisableServerAuthorityFlag ? "true" : "false"; + _logger.LogInformation("{Code} - Player {Name} ({Id}) is rejoining. Player Authority : {Authority}, port: {DeltaPort}", + Code, sender.Client.Name, sender.Client.Id, authority, sender.Client.DeltaPort); + if (isNew) { await PlayerAdd(sender); @@ -214,6 +228,7 @@ namespace Empostor.Server.Net.State if (sender.Client.Id == HostId) { + _logger.LogInformation("{Code} - Host {Name} ({Id}) is rejoining.", Code, sender.Client.Name, sender.Client.Id); GameState = GameStates.NotStarted; await HandleJoinGameNew(sender, false); await CheckLimboPlayers(); diff --git a/src/Empostor.Server/Net/State/Game.State.cs b/src/Empostor.Server/Net/State/Game.State.cs index b09b3bf..6452f5b 100644 --- a/src/Empostor.Server/Net/State/Game.State.cs +++ b/src/Empostor.Server/Net/State/Game.State.cs @@ -26,14 +26,16 @@ namespace Empostor.Server.Net.State await _eventManager.CallAsync(new GamePlayerJoinedEvent(this, player)); } - private async ValueTask PlayerRemove(int playerId, bool isBan = false) + private async ValueTask PlayerRemove(int playerId, string reason = "", bool isBan = false) { if (!_players.TryRemove(playerId, out var player)) { return false; } - _logger.LogInformation("{0} - Player {1} ({2}) has left.", Code, player.Client.Name, playerId); + _logger.LogInformation("{Code} - Player {Name} ({Id}) has left for \"{Reason}\" hashpuid : {HashPuid}", + Code, player.Client.Name, playerId, reason, + player.Client.ProductUserId?.Length >= 9 ? player.Client.ProductUserId[..9] : player.Client.ProductUserId ?? "0"); if (GameState == GameStates.Starting || GameState == GameStates.Started || GameState == GameStates.NotStarted) { if (player.Character?.PlayerInfo != null) @@ -69,7 +71,7 @@ namespace Empostor.Server.Net.State await Task.Delay(_timeoutConfig.ConnectionTimeout); if (player.Client.Connection.IsConnected && player.Client.Connection is HazelConnection hazel) { - _logger.LogInformation("{0} - Player {1} ({2}) kept connection open after leaving, disposing.", Code, player.Client.Name, playerId); + _logger.LogInformation("{Code} - Player {Name} ({Id}) kept connection open after leaving, disposing.", Code, player.Client.Name, playerId); await player.Client.DisconnectAsync(isBan ? DisconnectReason.Banned : DisconnectReason.Kicked); } }); @@ -101,7 +103,7 @@ namespace Empostor.Server.Net.State } HostId = host.Client.Id; - _logger.LogInformation("{0} - Assigned {1} ({2}) as new host.", Code, host.Client.Name, host.Client.Id); + _logger.LogInformation("{Code} - Assigned {Name} ({Id}) as new host.", Code, host.Client.Name, host.Client.Id); if (GameState == GameStates.Ended && host.Limbo == LimboStates.WaitingForHost) { GameState = GameStates.NotStarted; diff --git a/src/Empostor.Server/Program.cs b/src/Empostor.Server/Program.cs index 307b6b5..959aefe 100644 --- a/src/Empostor.Server/Program.cs +++ b/src/Empostor.Server/Program.cs @@ -53,10 +53,12 @@ namespace Empostor.Server { private static int Main(string[] args) { - Log.Logger = new LoggerConfiguration().WriteTo.Console().CreateBootstrapLogger(); + Log.Logger = new LoggerConfiguration() + .WriteTo.Console(outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] {Message:lj}{NewLine}{Exception}") + .CreateBootstrapLogger(); try { - Log.Information("Starting Empostor v{0}", DotnetUtils.Version); + Log.Information("Empostor v{Version} starting", DotnetUtils.Version); CreateHostBuilder(args).Build().Run(); return 0; } @@ -246,7 +248,7 @@ namespace Empostor.Server #endif .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning) .Enrich.FromLogContext() - .WriteTo.Console() + .WriteTo.Console(outputTemplate: "{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] {Message:lj}{NewLine}{Exception}") .WriteTo.File( "Log/empostor-.log", rollingInterval: RollingInterval.Day, diff --git a/src/Empostor.Server/Service/Admin/Ban/BanEnforcementListener.cs b/src/Empostor.Server/Service/Admin/Ban/BanEnforcementListener.cs index ef90d91..10b96b2 100644 --- a/src/Empostor.Server/Service/Admin/Ban/BanEnforcementListener.cs +++ b/src/Empostor.Server/Service/Admin/Ban/BanEnforcementListener.cs @@ -25,7 +25,7 @@ public sealed class BanEnforcementListener : IEventListener // IP 封禁检查 if (ip != null && _bans.IsIpBanned(ip)) { - _logger.LogWarning("[Ban] Rejecting banned IP {Ip} ({Name})", ip, client.Name); + _logger.LogWarning("BanRejecting banned IP {Ip} ({Name})", ip, client.Name); await client.DisconnectAsync(DisconnectReason.Banned, "You are banned from this server."); return; } @@ -33,7 +33,7 @@ public sealed class BanEnforcementListener : IEventListener // FriendCode 封禁检查 if (_bans.IsFriendCodeBanned(client.FriendCode)) { - _logger.LogWarning("[Ban] Rejecting banned FriendCode {FC} ({Name})", client.FriendCode, client.Name); + _logger.LogWarning("BanRejecting banned FriendCode {FC} ({Name})", client.FriendCode, client.Name); await client.DisconnectAsync(DisconnectReason.Banned, "You are banned from this server."); } } diff --git a/src/Empostor.Server/Service/Admin/Ban/BanStore.cs b/src/Empostor.Server/Service/Admin/Ban/BanStore.cs index e81598a..7ff3bcb 100644 --- a/src/Empostor.Server/Service/Admin/Ban/BanStore.cs +++ b/src/Empostor.Server/Service/Admin/Ban/BanStore.cs @@ -96,7 +96,7 @@ namespace Empostor.Server.Service.Admin.Ban var data = new BanData { Ips = new(_ips), FriendCodes = new(_friendCodes) }; await File.WriteAllTextAsync(BanFile, JsonSerializer.Serialize(data, JsonOpts)); } - catch (Exception ex) { _logger.LogWarning(ex, "[BanStore] Failed to save bans.json"); } + catch (Exception ex) { _logger.LogWarning(ex, "BanStoreFailed to save bans.json"); } finally { _saveLock.Release(); } }); } @@ -115,10 +115,10 @@ namespace Empostor.Server.Service.Admin.Ban { _ips = new(data.Ips ?? new()); _friendCodes = new(data.FriendCodes ?? new()); - _logger.LogInformation("[BanStore] Loaded {I} IP bans + {F} FC bans", _ips.Count, _friendCodes.Count); + _logger.LogInformation("BanStoreLoaded {I} IP bans + {F} FC bans", _ips.Count, _friendCodes.Count); } } - catch (Exception ex) { _logger.LogWarning(ex, "[BanStore] Failed to load bans.json"); } + catch (Exception ex) { _logger.LogWarning(ex, "BanStoreFailed to load bans.json"); } } private static string Normalize(IPAddress ip) diff --git a/src/Empostor.Server/Service/Admin/Reactor/ReactorHandshakeListener.cs b/src/Empostor.Server/Service/Admin/Reactor/ReactorHandshakeListener.cs index ab43767..1a397e1 100644 --- a/src/Empostor.Server/Service/Admin/Reactor/ReactorHandshakeListener.cs +++ b/src/Empostor.Server/Service/Admin/Reactor/ReactorHandshakeListener.cs @@ -41,7 +41,7 @@ namespace Empostor.Server.Service.Admin.Reactor { if (reader.Position < reader.Length) { - _logger.LogTrace("[ReactorMods] No Reactor header found for {Name}", e.Connection.Client?.Name ?? "unknown"); + _logger.LogTrace("ReactorModsNo Reactor header found for {Name}", e.Connection.Client?.Name ?? "unknown"); } return; @@ -60,7 +60,7 @@ namespace Empostor.Server.Service.Admin.Reactor if (mods.Length > 0) { _logger.LogInformation( - "[ReactorMods] {Name} has {Count} mod(s) (protocol v{Proto}): {Mods}", + "ReactorMods{Name} has {Count} mod(s) (protocol v{Proto}): {Mods}", e.Connection.Client?.Name ?? "unknown", mods.Length, protocolVersion, diff --git a/src/Empostor.Server/Service/Admin/Report/ReportStore.cs b/src/Empostor.Server/Service/Admin/Report/ReportStore.cs index 5bb1cbb..2ded824 100644 --- a/src/Empostor.Server/Service/Admin/Report/ReportStore.cs +++ b/src/Empostor.Server/Service/Admin/Report/ReportStore.cs @@ -72,7 +72,7 @@ namespace Empostor.Server.Service.Admin.Report } catch (Exception ex) { - _logger.LogWarning(ex, "[Report] Failed to save reports"); + _logger.LogWarning(ex, "ReportFailed to save reports"); } finally { @@ -98,12 +98,12 @@ namespace Empostor.Server.Service.Admin.Report _reports.AddRange(list.Take(Max)); } - _logger.LogInformation("[Report] Loaded {Count} report(s)", _reports.Count); + _logger.LogInformation("ReportLoaded {Count} report(s)", _reports.Count); } } catch (Exception ex) { - _logger.LogWarning(ex, "[Report] Failed to load reports file"); + _logger.LogWarning(ex, "ReportFailed to load reports file"); } } diff --git a/src/Empostor.Server/Service/Api/DiscordWebhookListener.cs b/src/Empostor.Server/Service/Api/DiscordWebhookListener.cs index 2cd59ed..2cdabb4 100644 --- a/src/Empostor.Server/Service/Api/DiscordWebhookListener.cs +++ b/src/Empostor.Server/Service/Api/DiscordWebhookListener.cs @@ -158,12 +158,12 @@ internal sealed class DiscordWebhookListener : IEventListener var resp = await client.PostAsync(url, new StringContent(json, Encoding.UTF8, "application/json")); if (!resp.IsSuccessStatusCode) { - _logger.LogWarning("[Discord] Webhook returned {Status}", (int)resp.StatusCode); + _logger.LogWarning("DiscordWebhook returned {Status}", (int)resp.StatusCode); } } catch (Exception ex) { - _logger.LogWarning(ex, "[Discord] Failed to send webhook"); + _logger.LogWarning(ex, "DiscordFailed to send webhook"); } } } diff --git a/src/Empostor.Server/Service/Api/DiscordWebhookStore.cs b/src/Empostor.Server/Service/Api/DiscordWebhookStore.cs index 1e763d8..00798e1 100644 --- a/src/Empostor.Server/Service/Api/DiscordWebhookStore.cs +++ b/src/Empostor.Server/Service/Api/DiscordWebhookStore.cs @@ -36,13 +36,13 @@ public sealed class DiscordWebhookStore NotifyOnReport = saved.NotifyOnReport; NotifyOnPlayerJoin = saved.NotifyOnPlayerJoin; NotifyOnGameEnded = saved.NotifyOnGameEnded; - _logger.LogInformation("[DiscordWebhook] Loaded from {File}", ConfigFile); + _logger.LogInformation("DiscordWebhookLoaded from {File}", ConfigFile); return; } } catch (Exception ex) { - _logger.LogWarning(ex, "[DiscordWebhook] Failed to load {File}, using defaults", ConfigFile); + _logger.LogWarning(ex, "DiscordWebhookFailed to load {File}, using defaults", ConfigFile); } } @@ -93,11 +93,11 @@ public sealed class DiscordWebhookStore { var json = JsonSerializer.Serialize(Snapshot, JsonOpts); await File.WriteAllTextAsync(ConfigFile, json); - _logger.LogInformation("[DiscordWebhook] Saved to {File}", ConfigFile); + _logger.LogInformation("DiscordWebhookSaved to {File}", ConfigFile); } catch (Exception ex) { - _logger.LogWarning(ex, "[DiscordWebhook] Failed to save {File}", ConfigFile); + _logger.LogWarning(ex, "DiscordWebhookFailed to save {File}", ConfigFile); } finally { diff --git a/src/Empostor.Server/Service/Auth/AuthCacheService.cs b/src/Empostor.Server/Service/Auth/AuthCacheService.cs index d607fd6..2939836 100644 --- a/src/Empostor.Server/Service/Auth/AuthCacheService.cs +++ b/src/Empostor.Server/Service/Auth/AuthCacheService.cs @@ -63,7 +63,7 @@ public sealed class AuthCacheService : IDisposable } } - _logger.LogDebug("[Auth] Stored PUID={Puid} FC={FC}", productUserId, friendCode ?? "(none)"); + _logger.LogDebug("AuthCache stored PUID={Puid} FC={FC}", productUserId, friendCode ?? "(none)"); } public UserAuthInfo? FindByToken(string? matchmakerToken) @@ -185,6 +185,10 @@ public sealed class AuthCacheService : IDisposable _ipToPort.TryRemove(info.ClientIp, out _); } + _logger.LogInformation( + "TokenUser {Name} {FriendCode} removed for inactivity timer. Port: {Port}", + info.Name, info.FriendCode, port); + OnPortExpired?.Invoke(port); } } @@ -193,15 +197,22 @@ public sealed class AuthCacheService : IDisposable var expiredIps = _byIpDirect.Where(kv => Expired(kv.Value)).Select(kv => kv.Key).ToList(); foreach (var ip in expiredIps) { - _byIpDirect.TryRemove(ip, out _); - _ipToPort.TryRemove(ip, out _); + if (_byIpDirect.TryRemove(ip, out var info)) + { + var port = _ipToPort.TryGetValue(ip, out var p) ? p : 0; + _ipToPort.TryRemove(ip, out _); + + _logger.LogInformation( + "TokenUser {Name} {FriendCode} removed for inactivity timer. Port: {Port}", + info.Name, info.FriendCode, port); + } } var totalExpired = expired.Count + expiredPorts.Count + expiredIps.Count; if (totalExpired > 0) { - _logger.LogDebug("[Auth] Cleaned {Count} expired entries (token={T}, port={P}, ip={I})", - totalExpired, expired.Count, expiredPorts.Count, expiredIps.Count); + _logger.LogDebug("AuthCache cleaned {Count} expired entries", + totalExpired); } } @@ -222,6 +233,8 @@ public sealed class UserAuthInfo public string FriendCode { get; set; } = string.Empty; + public string Name { get; set; } = string.Empty; + public string? ClientIp { get; set; } public DateTime CreatedAt { get; set; } = DateTime.UtcNow; diff --git a/src/Empostor.Server/Service/Firewall/FirewalldFirewallService.cs b/src/Empostor.Server/Service/Firewall/FirewalldFirewallService.cs index 9d876c0..3fc8c0c 100644 --- a/src/Empostor.Server/Service/Firewall/FirewalldFirewallService.cs +++ b/src/Empostor.Server/Service/Firewall/FirewalldFirewallService.cs @@ -54,17 +54,17 @@ public sealed class FirewalldFirewallService : IFirewallService if (process.ExitCode != 0) { var stderr = await process.StandardError.ReadToEndAsync(ct); - _logger.LogWarning("[Firewall] firewall-cmd {Args} failed (exit={Code}): {Error}", + _logger.LogWarning("Firewallfirewall-cmd {Args} failed (exit={Code}): {Error}", arguments, process.ExitCode, stderr.Trim()); } else { - _logger.LogInformation("[Firewall] firewall-cmd {Args} succeeded", arguments); + _logger.LogInformation("Firewallfirewall-cmd {Args} succeeded", arguments); } } catch (Exception ex) { - _logger.LogWarning(ex, "[Firewall] Failed to run firewall-cmd {Args}", arguments); + _logger.LogWarning(ex, "FirewallFailed to run firewall-cmd {Args}", arguments); } } } diff --git a/src/Empostor.Server/Service/Firewall/NoopFirewallService.cs b/src/Empostor.Server/Service/Firewall/NoopFirewallService.cs index 5c5866b..c115196 100644 --- a/src/Empostor.Server/Service/Firewall/NoopFirewallService.cs +++ b/src/Empostor.Server/Service/Firewall/NoopFirewallService.cs @@ -18,13 +18,13 @@ public sealed class NoopFirewallService : IFirewallService public ValueTask OpenPortAsync(ushort port, CancellationToken ct = default) { - _logger.LogDebug("[Firewall] Noop: would open port {Port}/udp", port); + _logger.LogDebug("FirewallNoop: would open port {Port}/udp", port); return ValueTask.CompletedTask; } public ValueTask ClosePortAsync(ushort port, CancellationToken ct = default) { - _logger.LogDebug("[Firewall] Noop: would close port {Port}/udp", port); + _logger.LogDebug("FirewallNoop: would close port {Port}/udp", port); return ValueTask.CompletedTask; } } diff --git a/src/Empostor.Server/Service/Firewall/UfwFirewallService.cs b/src/Empostor.Server/Service/Firewall/UfwFirewallService.cs index a3f114e..e4c809a 100644 --- a/src/Empostor.Server/Service/Firewall/UfwFirewallService.cs +++ b/src/Empostor.Server/Service/Firewall/UfwFirewallService.cs @@ -52,17 +52,17 @@ public sealed class UfwFirewallService : IFirewallService if (process.ExitCode != 0) { var stderr = await process.StandardError.ReadToEndAsync(ct); - _logger.LogWarning("[Firewall] ufw {Args} failed (exit={Code}): {Error}", + _logger.LogWarning("Firewallufw {Args} failed (exit={Code}): {Error}", arguments, process.ExitCode, stderr.Trim()); } else { - _logger.LogInformation("[Firewall] ufw {Args} succeeded", arguments); + _logger.LogInformation("Firewallufw {Args} succeeded", arguments); } } catch (Exception ex) { - _logger.LogWarning(ex, "[Firewall] Failed to run ufw {Args}", arguments); + _logger.LogWarning(ex, "FirewallFailed to run ufw {Args}", arguments); } } } diff --git a/src/Empostor.Server/Service/Stat/PlayerLogStore.cs b/src/Empostor.Server/Service/Stat/PlayerLogStore.cs index 2aa77ff..6f63792 100644 --- a/src/Empostor.Server/Service/Stat/PlayerLogStore.cs +++ b/src/Empostor.Server/Service/Stat/PlayerLogStore.cs @@ -109,7 +109,7 @@ public sealed class PlayerLogStore : IDisposable } catch (Exception ex) { - _logger.LogWarning(ex, "[PlayerLog] Failed to save logs"); + _logger.LogWarning(ex, "PlayerLogFailed to save logs"); } finally { @@ -142,12 +142,12 @@ public sealed class PlayerLogStore : IDisposable Interlocked.Decrement(ref _count); } - _logger.LogInformation("[PlayerLog] Loaded {Count} log(s)", _count); + _logger.LogInformation("PlayerLogLoaded {Count} log(s)", _count); } } catch (Exception ex) { - _logger.LogWarning(ex, "[PlayerLog] Failed to load logs file"); + _logger.LogWarning(ex, "PlayerLogFailed to load logs file"); } } diff --git a/src/Empostor.Server/Service/Stat/PlayerStatsStore.cs b/src/Empostor.Server/Service/Stat/PlayerStatsStore.cs index da10979..6a68934 100644 --- a/src/Empostor.Server/Service/Stat/PlayerStatsStore.cs +++ b/src/Empostor.Server/Service/Stat/PlayerStatsStore.cs @@ -152,7 +152,7 @@ public sealed class PlayerStatsStore : IDisposable var list = _stats.Values.ToList(); await File.WriteAllTextAsync(StatsFile, JsonSerializer.Serialize(list, JsonOpts)); } - catch (Exception ex) { _logger.LogWarning(ex, "[PlayerStats] Failed to save stats"); } + catch (Exception ex) { _logger.LogWarning(ex, "PlayerStatsFailed to save stats"); } finally { _saveLock.Release(); } }); } @@ -161,7 +161,7 @@ public sealed class PlayerStatsStore : IDisposable { if (!File.Exists(StatsFile)) { - _logger.LogDebug("[PlayerStats] No stats file found, starting fresh"); + _logger.LogDebug("PlayerStatsNo stats file found, starting fresh"); return; } @@ -172,10 +172,10 @@ public sealed class PlayerStatsStore : IDisposable { _stats = new ConcurrentDictionary( list.ToDictionary(e => e.FriendCode, StringComparer.OrdinalIgnoreCase)); - _logger.LogInformation("[PlayerStats] Loaded {Count} player stats", _stats.Count); + _logger.LogInformation("PlayerStatsLoaded {Count} player stats", _stats.Count); } } - catch (Exception ex) { _logger.LogWarning(ex, "[PlayerStats] Failed to load stats file"); } + catch (Exception ex) { _logger.LogWarning(ex, "PlayerStatsFailed to load stats file"); } } private static string Normalize(string friendCode) diff --git a/src/NextFast.Hazel-New/Next.Hazel/UPnP/ILogger.cs b/src/NextFast.Hazel-New/Next.Hazel/UPnP/ILogger.cs index 3a622d6..cf49eac 100644 --- a/src/NextFast.Hazel-New/Next.Hazel/UPnP/ILogger.cs +++ b/src/NextFast.Hazel-New/Next.Hazel/UPnP/ILogger.cs @@ -37,16 +37,16 @@ public class ConsoleLogger : ILogger public void WriteVerbose(string msg) { - if (verbose) Console.WriteLine($"{DateTime.Now} [VERBOSE] {msg}"); + if (verbose) Console.WriteLine($"{DateTimeOffset.Now:yyyy-MM-dd HH:mm:ss.fff zzz} [VRB] {msg}"); } public void WriteError(string msg) { - Console.WriteLine($"{DateTime.Now} [ERROR] {msg}"); + Console.WriteLine($"{DateTimeOffset.Now:yyyy-MM-dd HH:mm:ss.fff zzz} [ERR] {msg}"); } public void WriteInfo(string msg) { - Console.WriteLine($"{DateTime.Now} [INFO] {msg}"); + Console.WriteLine($"{DateTimeOffset.Now:yyyy-MM-dd HH:mm:ss.fff zzz} [INF] {msg}"); } } \ No newline at end of file