From 98d13ebbbb5ce021a961bc624d86a366c838130c Mon Sep 17 00:00:00 2001
From: flashwave <me@flash.moe>
Date: Mon, 28 Apr 2025 12:29:11 +0000
Subject: [PATCH] Improved logging system.
---
.gitignore | 1 +
SharpChat.Flashii/FlashiiClient.cs | 22 ++++++-
SharpChat.Flashii/SharpChat.Flashii.csproj | 4 ++
SharpChat.MariaDB/MariaDBMessageStorage.cs | 12 ++--
SharpChat.MariaDB/MariaDBMigrations.cs | 6 +-
SharpChat.MariaDB/MariaDBStorage.cs | 9 ++-
SharpChat.MariaDB/SharpChat.MariaDB.csproj | 1 +
SharpChat.SQLite/SQLiteConnection.cs | 1 -
SharpChat.SQLite/SQLiteMessageStorage.cs | 12 ++--
SharpChat.SQLite/SQLiteMigrations.cs | 6 +-
SharpChat.SQLite/SQLiteStorage.cs | 9 ++-
SharpChat.SQLite/SharpChat.SQLite.csproj | 1 +
.../C2SPacketHandlers/AuthC2SPacketHandler.cs | 7 +-
.../SendMessageC2SPacketHandler.cs | 4 --
.../ShutdownRestartClientCommand.cs | 3 +-
SharpChat/Connection.cs | 44 +++----------
SharpChat/Context.cs | 17 +++--
SharpChat/Program.cs | 65 +++++++++++++++----
SharpChat/SharpChat.csproj | 1 +
SharpChat/SharpChatWebSocketServer.cs | 28 ++++----
SharpChat/SockChatServer.cs | 53 ++++++++++++---
SharpChatCommon/Configuration/CachedValue.cs | 1 -
SharpChatCommon/Logger.cs | 33 ----------
SharpChatCommon/SharpChatCommon.csproj | 4 ++
24 files changed, 202 insertions(+), 142 deletions(-)
delete mode 100644 SharpChatCommon/Logger.cs
diff --git a/.gitignore b/.gitignore
index 215570f..8b2dbd5 100644
--- a/.gitignore
+++ b/.gitignore
@@ -12,6 +12,7 @@ sharpchat.db
sharpchat.db-wal
sharpchat.db-shm
SharpChat/version.txt
+logs/
# User-specific files
*.suo
diff --git a/SharpChat.Flashii/FlashiiClient.cs b/SharpChat.Flashii/FlashiiClient.cs
index c4675c2..ffac01b 100644
--- a/SharpChat.Flashii/FlashiiClient.cs
+++ b/SharpChat.Flashii/FlashiiClient.cs
@@ -1,3 +1,4 @@
+using Microsoft.Extensions.Logging;
using SharpChat.Auth;
using SharpChat.Bans;
using SharpChat.Configuration;
@@ -5,10 +6,11 @@ using System.Net;
using System.Security.Cryptography;
using System.Text;
using System.Text.Json;
+using ZLogger;
namespace SharpChat.Flashii;
-public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, BansClient {
+public class FlashiiClient(ILogger logger, HttpClient httpClient, Config config) : AuthClient, BansClient {
private const string DEFAULT_BASE_URL = "https://flashii.net/_sockchat";
private readonly CachedValue<string> BaseURL = config.ReadCached("url", DEFAULT_BASE_URL);
@@ -28,6 +30,9 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
private const string AUTH_VERIFY_SIG = "verify#{0}#{1}#{2}";
public async Task<AuthResult> AuthVerify(IPAddress remoteAddr, string scheme, string token) {
+ logger.ZLogInformation($"Verifying authentication data for {remoteAddr}...");
+ logger.ZLogTrace($"AuthVerify({remoteAddr}, {scheme}, {token})");
+
string remoteAddrStr = remoteAddr.ToString();
HttpRequestMessage request = new(HttpMethod.Post, string.Format(AUTH_VERIFY_URL, BaseURL)) {
@@ -42,6 +47,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
};
using HttpResponseMessage response = await httpClient.SendAsync(request);
+ logger.ZLogTrace($"AuthVerify() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
using Stream stream = await response.Content.ReadAsStreamAsync();
@@ -55,6 +61,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
private const string AUTH_BUMP_USERS_ONLINE_URL = "{0}/bump";
public async Task AuthBumpUsersOnline(IEnumerable<(IPAddress remoteAddr, string userId)> entries) {
+ logger.ZLogInformation($"Bumping online users list...");
if(!entries.Any())
return;
@@ -80,6 +87,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
};
using HttpResponseMessage response = await httpClient.SendAsync(request);
+ logger.ZLogTrace($"AuthBumpUsersOnline() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
}
@@ -95,6 +103,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
IPAddress? issuerRemoteAddr = null,
string? issuerUserId = null
) {
+ logger.ZLogInformation($"Creating ban of kind {kind} with duration {duration} for {remoteAddr}/{userId} issued by {issuerRemoteAddr}/{issuerUserId}...");
if(duration <= TimeSpan.Zero || kind != BanKind.User)
return;
@@ -133,7 +142,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
};
using HttpResponseMessage response = await httpClient.SendAsync(request);
-
+ logger.ZLogTrace($"BanCreate() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
}
@@ -158,6 +167,8 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
target = iabi.Address.ToString();
} else throw new ArgumentException("info argument is set to unsupported implementation", nameof(info));
+ logger.ZLogInformation($"Revoking ban of kind {info.Kind} issued on {target}...");
+
string now = DateTimeOffset.Now.ToUnixTimeSeconds().ToString();
string url = string.Format(BANS_REVOKE_URL, BaseURL, Uri.EscapeDataString(type), Uri.EscapeDataString(target), Uri.EscapeDataString(now));
string sig = string.Format(BANS_REVOKE_SIG, now, type, target);
@@ -172,6 +183,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
if(response.StatusCode == HttpStatusCode.NotFound)
return false;
+ logger.ZLogTrace($"BanRevoke() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
return response.StatusCode == HttpStatusCode.NoContent;
@@ -184,6 +196,8 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
userIdOrName ??= "0";
remoteAddr ??= IPAddress.None;
+ logger.ZLogInformation($"Requesting ban info for {remoteAddr}/{userIdOrName}...");
+
string now = DateTimeOffset.Now.ToUnixTimeSeconds().ToString();
bool usingUserName = string.IsNullOrEmpty(userIdOrName) || userIdOrName.Any(c => c is < '0' or > '9');
string remoteAddrStr = remoteAddr.ToString();
@@ -198,6 +212,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
};
using HttpResponseMessage response = await httpClient.SendAsync(request);
+ logger.ZLogTrace($"BanGet() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
using Stream stream = await response.Content.ReadAsStreamAsync();
@@ -214,6 +229,8 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
private const string BANS_LIST_SIG = "list#{0}";
public async Task<BanInfo[]> BanGetList() {
+ logger.ZLogInformation($"Requesting ban list...");
+
string now = DateTimeOffset.Now.ToUnixTimeSeconds().ToString();
string url = string.Format(BANS_LIST_URL, BaseURL, Uri.EscapeDataString(now));
string sig = string.Format(BANS_LIST_SIG, now);
@@ -225,6 +242,7 @@ public class FlashiiClient(HttpClient httpClient, Config config) : AuthClient, B
};
using HttpResponseMessage response = await httpClient.SendAsync(request);
+ logger.ZLogTrace($"BanGetList() -> HTTP {response.StatusCode}");
response.EnsureSuccessStatusCode();
using Stream stream = await response.Content.ReadAsStreamAsync();
diff --git a/SharpChat.Flashii/SharpChat.Flashii.csproj b/SharpChat.Flashii/SharpChat.Flashii.csproj
index a4d46fe..b536779 100644
--- a/SharpChat.Flashii/SharpChat.Flashii.csproj
+++ b/SharpChat.Flashii/SharpChat.Flashii.csproj
@@ -6,6 +6,10 @@
<Nullable>enable</Nullable>
</PropertyGroup>
+ <ItemGroup>
+ <PackageReference Include="ZLogger" Version="2.5.10" />
+ </ItemGroup>
+
<ItemGroup>
<ProjectReference Include="..\SharpChatCommon\SharpChatCommon.csproj" />
</ItemGroup>
diff --git a/SharpChat.MariaDB/MariaDBMessageStorage.cs b/SharpChat.MariaDB/MariaDBMessageStorage.cs
index b9b1ad6..417f3d9 100644
--- a/SharpChat.MariaDB/MariaDBMessageStorage.cs
+++ b/SharpChat.MariaDB/MariaDBMessageStorage.cs
@@ -1,10 +1,12 @@
+using Microsoft.Extensions.Logging;
using MySqlConnector;
using SharpChat.Messages;
using System.Text.Json;
+using ZLogger;
namespace SharpChat.MariaDB;
-public class MariaDBMessageStorage(MariaDBStorage storage) : MessageStorage {
+public class MariaDBMessageStorage(MariaDBStorage storage, ILogger logger) : MessageStorage {
public async Task LogMessage(
long id,
string type,
@@ -36,7 +38,7 @@ public class MariaDBMessageStorage(MariaDBStorage storage) : MessageStorage {
new MySqlParameter("sender_perms", MariaDBUserPermissionsConverter.To(senderPerms))
);
} catch(MySqlException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in LogMessage(): {ex}");
}
}
@@ -48,7 +50,7 @@ public class MariaDBMessageStorage(MariaDBStorage storage) : MessageStorage {
new MySqlParameter("id", msg.Id)
);
} catch(MySqlException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in DeleteMessage(): {ex}");
}
}
@@ -92,7 +94,7 @@ public class MariaDBMessageStorage(MariaDBStorage storage) : MessageStorage {
return evt;
}
} catch(MySqlException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in GetMessage(): {ex}");
}
return null;
@@ -126,7 +128,7 @@ public class MariaDBMessageStorage(MariaDBStorage storage) : MessageStorage {
msgs.Add(evt);
}
} catch(MySqlException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in GetMessages(): {ex}");
}
msgs.Reverse();
diff --git a/SharpChat.MariaDB/MariaDBMigrations.cs b/SharpChat.MariaDB/MariaDBMigrations.cs
index ddae353..dd90c81 100644
--- a/SharpChat.MariaDB/MariaDBMigrations.cs
+++ b/SharpChat.MariaDB/MariaDBMigrations.cs
@@ -1,15 +1,17 @@
+using Microsoft.Extensions.Logging;
using MySqlConnector;
+using ZLogger;
namespace SharpChat.MariaDB;
-public class MariaDBMigrations(MariaDBConnection conn) {
+public class MariaDBMigrations(ILogger logger, MariaDBConnection conn) {
private async Task DoMigration(string name, Func<Task> action) {
bool done = await conn.RunQueryValue<long>(
"SELECT COUNT(*) FROM sqc_migrations WHERE migration_name = @name",
new MySqlParameter("name", name)
) > 0;
if(!done) {
- Logger.Write($"Running migration '{name}'...");
+ logger.ZLogInformation($@"Running migration ""{name}""...");
await action();
await conn.RunCommand(
"INSERT INTO sqc_migrations (migration_name) VALUES (@name)",
diff --git a/SharpChat.MariaDB/MariaDBStorage.cs b/SharpChat.MariaDB/MariaDBStorage.cs
index 71ccea5..399141f 100644
--- a/SharpChat.MariaDB/MariaDBStorage.cs
+++ b/SharpChat.MariaDB/MariaDBStorage.cs
@@ -1,10 +1,12 @@
+using Microsoft.Extensions.Logging;
using MySqlConnector;
using SharpChat.Configuration;
using SharpChat.Messages;
+using ZLogger;
namespace SharpChat.MariaDB;
-public class MariaDBStorage(string connString) : Storage {
+public class MariaDBStorage(ILogger logger, string connString) : Storage {
public async Task<MariaDBConnection> CreateConnection() {
MySqlConnection conn = new(connString);
await conn.OpenAsync();
@@ -12,12 +14,13 @@ public class MariaDBStorage(string connString) : Storage {
}
public MessageStorage CreateMessageStorage() {
- return new MariaDBMessageStorage(this);
+ return new MariaDBMessageStorage(this, logger);
}
public async Task UpgradeStorage() {
+ logger.ZLogInformation($"Upgrading storage...");
using MariaDBConnection conn = await CreateConnection();
- await new MariaDBMigrations(conn).RunMigrations();
+ await new MariaDBMigrations(logger, conn).RunMigrations();
}
public static string BuildConnectionString(Config config) {
diff --git a/SharpChat.MariaDB/SharpChat.MariaDB.csproj b/SharpChat.MariaDB/SharpChat.MariaDB.csproj
index 25c0291..21b366a 100644
--- a/SharpChat.MariaDB/SharpChat.MariaDB.csproj
+++ b/SharpChat.MariaDB/SharpChat.MariaDB.csproj
@@ -8,6 +8,7 @@
<ItemGroup>
<PackageReference Include="MySqlConnector" Version="2.4.0" />
+ <PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<ItemGroup>
diff --git a/SharpChat.SQLite/SQLiteConnection.cs b/SharpChat.SQLite/SQLiteConnection.cs
index e611c04..1d9da94 100644
--- a/SharpChat.SQLite/SQLiteConnection.cs
+++ b/SharpChat.SQLite/SQLiteConnection.cs
@@ -1,4 +1,3 @@
-using System.Data;
using System.Data.Common;
using System.Data.SQLite;
using NativeSQLiteConnection = System.Data.SQLite.SQLiteConnection;
diff --git a/SharpChat.SQLite/SQLiteMessageStorage.cs b/SharpChat.SQLite/SQLiteMessageStorage.cs
index 7e10924..c5bae50 100644
--- a/SharpChat.SQLite/SQLiteMessageStorage.cs
+++ b/SharpChat.SQLite/SQLiteMessageStorage.cs
@@ -1,13 +1,15 @@
+using Microsoft.Extensions.Logging;
using SharpChat.Messages;
using System.Data;
using System.Data.Common;
using System.Data.SQLite;
using System.Text;
using System.Text.Json;
+using ZLogger;
namespace SharpChat.SQLite;
-public class SQLiteMessageStorage(SQLiteConnection conn) : MessageStorage {
+public class SQLiteMessageStorage(ILogger logger, SQLiteConnection conn) : MessageStorage {
public async Task LogMessage(
long id,
string type,
@@ -37,7 +39,7 @@ public class SQLiteMessageStorage(SQLiteConnection conn) : MessageStorage {
new SQLiteParameter("data", data == null ? "{}" : JsonSerializer.SerializeToUtf8Bytes(data))
);
} catch(SQLiteException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in LogMessage(): {ex}");
}
}
@@ -48,7 +50,7 @@ public class SQLiteMessageStorage(SQLiteConnection conn) : MessageStorage {
new SQLiteParameter("id", msg.Id)
);
} catch(SQLiteException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in DeleteMessage(): {ex}");
}
}
@@ -86,7 +88,7 @@ public class SQLiteMessageStorage(SQLiteConnection conn) : MessageStorage {
return evt;
}
} catch(SQLiteException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in GetMessage(): {ex}");
}
return null;
@@ -116,7 +118,7 @@ public class SQLiteMessageStorage(SQLiteConnection conn) : MessageStorage {
msgs.Add(evt);
}
} catch(SQLiteException ex) {
- Logger.Write(ex);
+ logger.ZLogError($"Error in GetMessages(): {ex}");
}
msgs.Reverse();
diff --git a/SharpChat.SQLite/SQLiteMigrations.cs b/SharpChat.SQLite/SQLiteMigrations.cs
index 1dcc464..234c7a6 100644
--- a/SharpChat.SQLite/SQLiteMigrations.cs
+++ b/SharpChat.SQLite/SQLiteMigrations.cs
@@ -1,12 +1,16 @@
+using Microsoft.Extensions.Logging;
+using ZLogger;
+
namespace SharpChat.SQLite;
-public class SQLiteMigrations(SQLiteConnection conn) {
+public class SQLiteMigrations(ILogger logger, SQLiteConnection conn) {
public async Task RunMigrations() {
long currentVersion = await conn.RunQueryValue<long>("PRAGMA user_version");
long version = currentVersion;
async Task doMigration(int expect, Func<Task> action) {
if(version < expect) {
+ logger.ZLogInformation($"Upgrading to version {version}...");
await action();
++version;
}
diff --git a/SharpChat.SQLite/SQLiteStorage.cs b/SharpChat.SQLite/SQLiteStorage.cs
index b0eec3f..af22136 100644
--- a/SharpChat.SQLite/SQLiteStorage.cs
+++ b/SharpChat.SQLite/SQLiteStorage.cs
@@ -1,22 +1,25 @@
+using Microsoft.Extensions.Logging;
using SharpChat.Configuration;
using SharpChat.Messages;
using System.Data.SQLite;
+using ZLogger;
using NativeSQLiteConnection = System.Data.SQLite.SQLiteConnection;
namespace SharpChat.SQLite;
-public class SQLiteStorage(string connString) : Storage, IDisposable {
+public class SQLiteStorage(ILogger logger, string connString) : Storage, IDisposable {
public const string MEMORY = "file::memory:?cache=shared";
public const string DEFAULT = "sharpchat.db";
public SQLiteConnection Connection { get; } = new SQLiteConnection(new NativeSQLiteConnection(connString).OpenAndReturn());
public MessageStorage CreateMessageStorage() {
- return new SQLiteMessageStorage(Connection);
+ return new SQLiteMessageStorage(logger, Connection);
}
public async Task UpgradeStorage() {
- await new SQLiteMigrations(Connection).RunMigrations();
+ logger.ZLogInformation($"Upgrading storage...");
+ await new SQLiteMigrations(logger, Connection).RunMigrations();
}
public static string BuildConnectionString(Config config) {
diff --git a/SharpChat.SQLite/SharpChat.SQLite.csproj b/SharpChat.SQLite/SharpChat.SQLite.csproj
index b47e6ba..13d5133 100644
--- a/SharpChat.SQLite/SharpChat.SQLite.csproj
+++ b/SharpChat.SQLite/SharpChat.SQLite.csproj
@@ -8,6 +8,7 @@
<ItemGroup>
<PackageReference Include="System.Data.SQLite.Core" Version="1.0.119" />
+ <PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<ItemGroup>
diff --git a/SharpChat/C2SPacketHandlers/AuthC2SPacketHandler.cs b/SharpChat/C2SPacketHandlers/AuthC2SPacketHandler.cs
index 7c4d1d4..1928faf 100644
--- a/SharpChat/C2SPacketHandlers/AuthC2SPacketHandler.cs
+++ b/SharpChat/C2SPacketHandlers/AuthC2SPacketHandler.cs
@@ -5,6 +5,7 @@ using SharpChat.Configuration;
using SharpChat.Messages;
using SharpChat.Snowflake;
using SharpChat.SockChat.S2CPackets;
+using ZLogger;
namespace SharpChat.C2SPacketHandlers;
@@ -47,7 +48,7 @@ public class AuthC2SPacketHandler(
BanInfo? banInfo = await bansClient.BanGet(authResult.UserId, ctx.Connection.RemoteAddress);
if(banInfo is not null) {
- Logger.Write($"<{ctx.Connection.Id}> User is banned.");
+ ctx.Connection.Logger.ZLogInformation($"User {authResult.UserId} is banned.");
await ctx.Connection.Send(new AuthFailS2CPacket(AuthFailS2CPacket.Reason.Banned, banInfo.IsPermanent ? DateTimeOffset.MaxValue : banInfo.ExpiresAt));
ctx.Connection.Dispose();
return;
@@ -139,12 +140,12 @@ public class AuthC2SPacketHandler(
ctx.Chat.ContextAccess.Release();
}
} catch(AuthFailedException ex) {
- Logger.Write($"<{ctx.Connection.Id}> Failed to authenticate: {ex}");
+ ctx.Connection.Logger.ZLogWarning($"Failed to authenticate (expected): {ex}");
await ctx.Connection.Send(new AuthFailS2CPacket(AuthFailS2CPacket.Reason.AuthInvalid));
ctx.Connection.Dispose();
throw;
} catch(Exception ex) {
- Logger.Write($"<{ctx.Connection.Id}> Failed to authenticate: {ex}");
+ ctx.Connection.Logger.ZLogError($"Failed to authenticate (unexpected): {ex}");
await ctx.Connection.Send(new AuthFailS2CPacket(AuthFailS2CPacket.Reason.Exception));
ctx.Connection.Dispose();
throw;
diff --git a/SharpChat/C2SPacketHandlers/SendMessageC2SPacketHandler.cs b/SharpChat/C2SPacketHandlers/SendMessageC2SPacketHandler.cs
index d757ecb..c69d137 100644
--- a/SharpChat/C2SPacketHandlers/SendMessageC2SPacketHandler.cs
+++ b/SharpChat/C2SPacketHandlers/SendMessageC2SPacketHandler.cs
@@ -58,10 +58,6 @@ public class SendMessageC2SPacketHandler(
messageText = messageText.Trim();
-#if DEBUG
- Logger.Write($"<{ctx.Connection.Id} {user.UserName}> {messageText}");
-#endif
-
if(messageText.StartsWith('/')) {
ClientCommandContext context = new(messageText, ctx.Chat, user, ctx.Connection, channel);
foreach(ClientCommand cmd in Commands)
diff --git a/SharpChat/ClientCommands/ShutdownRestartClientCommand.cs b/SharpChat/ClientCommands/ShutdownRestartClientCommand.cs
index 3c47045..d589f9d 100644
--- a/SharpChat/ClientCommands/ShutdownRestartClientCommand.cs
+++ b/SharpChat/ClientCommands/ShutdownRestartClientCommand.cs
@@ -1,4 +1,5 @@
using SharpChat.SockChat.S2CPackets;
+using ZLogger;
namespace SharpChat.ClientCommands;
@@ -18,7 +19,7 @@ public class ShutdownRestartClientCommand(CancellationTokenSource cancellationTo
if(cancellationTokenSource.IsCancellationRequested)
return;
- Logger.Write("Shutdown requested through Sock Chat command...");
+ ctx.Connection.Logger.ZLogInformation($"Shutdown requested through Sock Chat command...");
if(ctx.NameEquals("restart"))
foreach(Connection conn in ctx.Chat.Connections)
diff --git a/SharpChat/Connection.cs b/SharpChat/Connection.cs
index ccd3d27..aa74e8b 100644
--- a/SharpChat/Connection.cs
+++ b/SharpChat/Connection.cs
@@ -1,48 +1,28 @@
using Fleck;
+using Microsoft.Extensions.Logging;
using SharpChat.SockChat;
using System.Net;
namespace SharpChat;
-public class Connection : IDisposable {
- public const int ID_LENGTH = 20;
+public class Connection(ILogger logger, IWebSocketConnection sock, IPEndPoint remoteEndPoint) : IDisposable {
+ public static readonly TimeSpan SessionTimeOut = TimeSpan.FromMinutes(5);
-#if DEBUG
- public static TimeSpan SessionTimeOut { get; } = TimeSpan.FromMinutes(1);
-#else
- public static TimeSpan SessionTimeOut { get; } = TimeSpan.FromMinutes(5);
-#endif
+ public ILogger Logger { get; } = logger;
+ public IWebSocketConnection Socket { get; } = sock;
+ public IPEndPoint RemoteEndPoint { get; } = remoteEndPoint;
- public IWebSocketConnection Socket { get; }
-
- public string Id { get; }
public bool IsDisposed { get; private set; }
public DateTimeOffset LastPing { get; set; } = DateTimeOffset.Now;
public User? User { get; set; }
private int CloseCode { get; set; } = 1000;
- public IPAddress RemoteAddress { get; }
- public ushort RemotePort { get; }
+ public IPAddress RemoteAddress => RemoteEndPoint.Address;
+ public ushort RemotePort => (ushort)RemoteEndPoint.Port;
public bool IsAlive => !IsDisposed && !HasTimedOut;
- public Connection(IWebSocketConnection sock) {
- Socket = sock;
- Id = RNG.SecureRandomString(ID_LENGTH);
-
- if(!IPAddress.TryParse(sock.ConnectionInfo.ClientIpAddress, out IPAddress? addr))
- throw new Exception("Unable to parse remote address?????");
-
- if(IPAddress.IsLoopback(addr)
- && sock.ConnectionInfo.Headers.TryGetValue("X-Real-IP", out string? addrStr)
- && IPAddress.TryParse(addrStr, out IPAddress? realAddr))
- addr = realAddr;
-
- RemoteAddress = addr;
- RemotePort = (ushort)sock.ConnectionInfo.ClientPort;
- }
-
public async Task Send(S2CPacket packet) {
if(!Socket.IsAvailable)
return;
@@ -79,12 +59,4 @@ public class Connection : IDisposable {
IsDisposed = true;
Socket.Close(CloseCode);
}
-
- public override string ToString() {
- return Id;
- }
-
- public override int GetHashCode() {
- return Id.GetHashCode();
- }
}
diff --git a/SharpChat/Context.cs b/SharpChat/Context.cs
index fa41251..05d2dd2 100644
--- a/SharpChat/Context.cs
+++ b/SharpChat/Context.cs
@@ -1,3 +1,4 @@
+using Microsoft.Extensions.Logging;
using SharpChat.Channels;
using SharpChat.Events;
using SharpChat.Messages;
@@ -6,6 +7,7 @@ using SharpChat.SockChat;
using SharpChat.SockChat.S2CPackets;
using System.Dynamic;
using System.Net;
+using ZLogger;
namespace SharpChat;
@@ -14,6 +16,9 @@ public class Context {
public readonly SemaphoreSlim ContextAccess = new(1, 1);
+ public ILoggerFactory LoggerFactory { get; }
+ private readonly ILogger Logger;
+
public SnowflakeGenerator SnowflakeGenerator { get; } = new();
public RandomSnowflake RandomSnowflake { get; }
@@ -25,7 +30,9 @@ public class Context {
public Dictionary<string, RateLimiter> UserRateLimiters { get; } = [];
public Dictionary<string, Channel> UserLastChannel { get; } = [];
- public Context(MessageStorage msgs) {
+ public Context(ILoggerFactory logFactory, MessageStorage msgs) {
+ LoggerFactory = logFactory;
+ Logger = logFactory.CreateLogger("ctx");
Messages = msgs;
RandomSnowflake = new(SnowflakeGenerator);
}
@@ -86,15 +93,15 @@ public class Context {
public async Task Update() {
foreach(Connection conn in Connections)
if(!conn.IsDisposed && conn.HasTimedOut) {
+ conn.Logger.ZLogInformation($"Nuking connection associated with user {conn.User?.UserId ?? "no-one"}");
conn.Dispose();
- Logger.Write($"Nuked connection {conn.Id} associated with {conn.User}.");
}
Connections.RemoveWhere(conn => conn.IsDisposed);
foreach(User user in Users)
if(!Connections.Any(conn => conn.User == user)) {
- Logger.Write($"Timing out {user} (no more connections).");
+ Logger.ZLogInformation($"Timing out user {user.UserId} (no more connections).");
await HandleDisconnect(user, UserDisconnectS2CPacket.Reason.TimeOut);
}
}
@@ -140,8 +147,6 @@ public class Context {
UserPermissions? perms = null,
bool silent = false
) {
- ArgumentNullException.ThrowIfNull(user);
-
bool hasChanged = false;
string previousName = string.Empty;
@@ -313,8 +318,6 @@ public class Context {
}
public async Task ForceChannel(User user, Channel? chan = null) {
- ArgumentNullException.ThrowIfNull(user);
-
if(chan == null && !UserLastChannel.TryGetValue(user.UserId, out chan))
throw new ArgumentException("no channel???");
diff --git a/SharpChat/Program.cs b/SharpChat/Program.cs
index 0437654..39d0e07 100644
--- a/SharpChat/Program.cs
+++ b/SharpChat/Program.cs
@@ -1,9 +1,12 @@
+using Microsoft.Extensions.Logging;
using SharpChat;
using SharpChat.Configuration;
using SharpChat.Flashii;
using SharpChat.MariaDB;
using SharpChat.SQLite;
using System.Text;
+using ZLogger;
+using ZLogger.Providers;
const string CONFIG = "sharpchat.cfg";
@@ -21,6 +24,34 @@ if(SharpInfo.IsDebugBuild) {
} else
Console.WriteLine(SharpInfo.VersionStringShort.PadLeft(28, ' '));
+using ILoggerFactory logFactory = LoggerFactory.Create(logging => {
+ logging.ClearProviders();
+
+#if DEBUG
+ logging.SetMinimumLevel(LogLevel.Trace);
+#else
+ logging.SetMinimumLevel(LogLevel.Information);
+#endif
+
+ logging.AddZLoggerConsole(opts => {
+ opts.OutputEncodingToUtf8 = true;
+ opts.UsePlainTextFormatter(formatter => {
+ formatter.SetPrefixFormatter($"{0} [{1} {2}] ", (in MessageTemplate template, in LogInfo info) => template.Format(info.Timestamp, info.Category, info.LogLevel));
+ });
+ });
+ logging.AddZLoggerRollingFile(opts => {
+ opts.FilePathSelector = (ts, seqNo) => $"logs/{ts.ToLocalTime():yyyy-MM-dd_HH-mm-ss}_{seqNo:000}.json";
+ opts.RollingInterval = RollingInterval.Day;
+ opts.RollingSizeKB = 1024;
+ opts.FileShared = true;
+ opts.UseJsonFormatter(formatter => {
+ formatter.UseUtcTimestamp = true;
+ });
+ });
+});
+
+ILogger logger = logFactory.CreateLogger("main");
+
using CancellationTokenSource cts = new();
void exitHandler() {
@@ -28,7 +59,7 @@ void exitHandler() {
return;
cts.Cancel();
- Logger.Write("Shutdown requested through console...");
+ logger.ZLogInformation($"Shutdown requested through console...");
}
AppDomain.CurrentDomain.ProcessExit += (sender, ev) => { exitHandler(); };
@@ -40,7 +71,7 @@ string configFile = CONFIG;
// If the config file doesn't exist and we're using the default path, run the converter
if(!File.Exists(configFile) && configFile == CONFIG) {
- Logger.Write("Creating example configuration file...");
+ logger.ZLogInformation($"Creating example configuration file...");
using Stream s = new FileStream(CONFIG, FileMode.OpenOrCreate, FileAccess.ReadWrite, FileShare.None);
s.SetLength(0);
@@ -112,12 +143,12 @@ if(!File.Exists(configFile) && configFile == CONFIG) {
sw.Flush();
}
-Logger.Write("Initialising configuration...");
+logger.ZLogInformation($"Initialising configuration...");
using StreamConfig config = StreamConfig.FromPath(configFile);
if(cts.IsCancellationRequested) return;
-Logger.Write("Initialising HTTP client...");
+logger.ZLogInformation($"Initialising HTTP client...");
using HttpClient httpClient = new(new HttpClientHandler() {
UseProxy = false,
});
@@ -125,31 +156,37 @@ httpClient.DefaultRequestHeaders.Add("User-Agent", SharpInfo.ProgramName);
if(cts.IsCancellationRequested) return;
-Logger.Write("Initialising Flashii client...");
-FlashiiClient flashii = new(httpClient, config.ScopeTo("msz"));
+logger.ZLogInformation($"Initialising Flashii client...");
+FlashiiClient flashii = new(logFactory.CreateLogger("flashii"), httpClient, config.ScopeTo("msz"));
if(cts.IsCancellationRequested) return;
-Logger.Write("Initialising storage...");
+logger.ZLogInformation($"Initialising storage...");
Storage storage = string.IsNullOrWhiteSpace(config.SafeReadValue("mariadb:host", string.Empty))
- ? new SQLiteStorage(SQLiteStorage.BuildConnectionString(config.ScopeTo("sqlite")))
- : new MariaDBStorage(MariaDBStorage.BuildConnectionString(config.ScopeTo("mariadb")));
+ ? new SQLiteStorage(logFactory.CreateLogger("sqlite"), SQLiteStorage.BuildConnectionString(config.ScopeTo("sqlite")))
+ : new MariaDBStorage(logFactory.CreateLogger("mariadb"), MariaDBStorage.BuildConnectionString(config.ScopeTo("mariadb")));
try {
if(cts.IsCancellationRequested) return;
- Logger.Write("Upgrading storage...");
await storage.UpgradeStorage();
if(cts.IsCancellationRequested) return;
- Logger.Write("Preparing server...");
- await new SockChatServer(cts, flashii, flashii, storage.CreateMessageStorage(), config.ScopeTo("chat")).Listen(cts.Token);
+ logger.ZLogInformation($"Preparing server...");
+ await new SockChatServer(
+ logFactory,
+ cts,
+ flashii,
+ flashii,
+ storage.CreateMessageStorage(),
+ config.ScopeTo("chat")
+ ).Listen(cts.Token);
} finally {
if(storage is IDisposable disp) {
- Logger.Write("Cleaning storage...");
+ logger.ZLogInformation($"Cleaning storage...");
disp.Dispose();
}
}
-Logger.Write("Exiting...");
+logger.ZLogInformation($"Exiting...");
diff --git a/SharpChat/SharpChat.csproj b/SharpChat/SharpChat.csproj
index e530e41..930df1c 100644
--- a/SharpChat/SharpChat.csproj
+++ b/SharpChat/SharpChat.csproj
@@ -17,6 +17,7 @@
<ItemGroup>
<PackageReference Include="Fleck" Version="1.2.0" />
+ <PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<Target Name="PreBuild" BeforeTargets="PreBuildEvent">
diff --git a/SharpChat/SharpChatWebSocketServer.cs b/SharpChat/SharpChatWebSocketServer.cs
index 701fc34..92f4f0e 100644
--- a/SharpChat/SharpChatWebSocketServer.cs
+++ b/SharpChat/SharpChatWebSocketServer.cs
@@ -1,12 +1,14 @@
#nullable disable
using Fleck;
+using Microsoft.Extensions.Logging;
using System.Net;
using System.Net.Sockets;
using System.Runtime.InteropServices;
using System.Security.Authentication;
using System.Security.Cryptography.X509Certificates;
using System.Text;
+using ZLogger;
// Near direct reimplementation of Fleck's WebSocketServer with address reusing
// Fleck's Socket wrapper doesn't provide any way to do this with the normally provided APIs
@@ -15,12 +17,14 @@ using System.Text;
namespace SharpChat;
public class SharpChatWebSocketServer : IWebSocketServer {
-
+ private readonly ILogger Logger;
private readonly string _scheme;
private readonly IPAddress _locationIP;
private Action<IWebSocketConnection> _config;
- public SharpChatWebSocketServer(string location, bool supportDualStack = true) {
+ public SharpChatWebSocketServer(ILogger logger, string location, bool supportDualStack = true) {
+ Logger = logger;
+
Uri uri = new(location);
Port = uri.Port;
@@ -79,17 +83,17 @@ public class SharpChatWebSocketServer : IWebSocketServer {
ListenerSocket.Bind(ipLocal);
ListenerSocket.Listen(100);
Port = ((IPEndPoint)ListenerSocket.LocalEndPoint).Port;
- FleckLog.Info(string.Format("Server started at {0} (actual port {1})", Location, Port));
+ Logger.ZLogInformation($"Server started at {Location} (actual port {Port})");
if(_scheme == "wss") {
if(Certificate == null) {
- FleckLog.Error("Scheme cannot be 'wss' without a Certificate");
+ Logger.ZLogError($"Scheme cannot be 'wss' without a Certificate");
return;
}
// makes dotnet shut up, TLS is handled by NGINX anyway
// if(EnabledSslProtocols == SslProtocols.None) {
// EnabledSslProtocols = SslProtocols.Tls;
- // FleckLog.Debug("Using default TLS 1.0 security protocol.");
+ // Logger.ZLogDebug($"Using default TLS 1.0 security protocol.");
// }
}
ListenForClients();
@@ -98,18 +102,18 @@ public class SharpChatWebSocketServer : IWebSocketServer {
private void ListenForClients() {
ListenerSocket.Accept(OnClientConnect, e => {
- FleckLog.Error("Listener socket is closed", e);
+ Logger.ZLogError($"Listener socket is closed: {e}");
if(RestartAfterListenError) {
- FleckLog.Info("Listener socket restarting");
+ Logger.ZLogInformation($"Listener socket restarting");
try {
ListenerSocket.Dispose();
Socket socket = new(_locationIP.AddressFamily, SocketType.Stream, ProtocolType.IP);
socket.SetSocketOption(SocketOptionLevel.Socket, SocketOptionName.ReuseAddress, 1);
ListenerSocket = new SocketWrapper(socket);
Start(_config);
- FleckLog.Info("Listener socket restarted");
+ Logger.ZLogInformation($"Listener socket restarted");
} catch(Exception ex) {
- FleckLog.Error("Listener could not be restarted", ex);
+ Logger.ZLogError($"Listener could not be restarted: {ex}");
}
}
});
@@ -118,7 +122,7 @@ public class SharpChatWebSocketServer : IWebSocketServer {
private void OnClientConnect(ISocket clientSocket) {
if(clientSocket == null) return; // socket closed
- FleckLog.Debug(string.Format("Client connected from {0}:{1}", clientSocket.RemoteIpAddress, clientSocket.RemotePort.ToString()));
+ Logger.ZLogDebug($"Client connected from {clientSocket.RemoteIpAddress}:{clientSocket.RemotePort}");
ListenForClients();
WebSocketConnection connection = null;
@@ -154,12 +158,12 @@ public class SharpChatWebSocketServer : IWebSocketServer {
s => SubProtocolNegotiator.Negotiate(SupportedSubProtocols, s));
if(IsSecure) {
- FleckLog.Debug("Authenticating Secure Connection");
+ Logger.ZLogDebug($"Authenticating Secure Connection");
clientSocket
.Authenticate(Certificate,
EnabledSslProtocols,
connection.StartReceiving,
- e => FleckLog.Warn("Failed to Authenticate", e));
+ e => Logger.ZLogWarning($"Failed to Authenticate: {e}"));
} else {
connection.StartReceiving();
}
diff --git a/SharpChat/SockChatServer.cs b/SharpChat/SockChatServer.cs
index d4d49b2..599db67 100644
--- a/SharpChat/SockChatServer.cs
+++ b/SharpChat/SockChatServer.cs
@@ -1,4 +1,4 @@
-using Fleck;
+using Microsoft.Extensions.Logging;
using SharpChat.Auth;
using SharpChat.Bans;
using SharpChat.C2SPacketHandlers;
@@ -7,6 +7,7 @@ using SharpChat.Configuration;
using SharpChat.Messages;
using SharpChat.SockChat.S2CPackets;
using System.Net;
+using ZLogger;
namespace SharpChat;
@@ -19,6 +20,8 @@ public class SockChatServer {
public Context Context { get; }
+ private readonly ILogger Logger;
+
private readonly BansClient BansClient;
private readonly CachedValue<ushort> Port;
@@ -34,24 +37,29 @@ public class SockChatServer {
private static readonly string[] DEFAULT_CHANNELS = ["lounge"];
public SockChatServer(
+ ILoggerFactory logFactory,
CancellationTokenSource cancellationTokenSource,
AuthClient authClient,
BansClient bansClient,
MessageStorage msgStorage,
Config config
) {
- Logger.Write("Initialising Sock Chat server...");
+ Logger = logFactory.CreateLogger("sockchat");
+ Logger.ZLogInformation($"Initialising Sock Chat server...");
BansClient = bansClient;
+ Logger.ZLogDebug($"Fetching configuration values...");
Port = config.ReadCached("port", DEFAULT_PORT);
MaxMessageLength = config.ReadCached("msgMaxLength", DEFAULT_MSG_LENGTH_MAX);
MaxConnections = config.ReadCached("connMaxCount", DEFAULT_MAX_CONNECTIONS);
FloodKickLength = config.ReadCached("floodKickLength", DEFAULT_FLOOD_KICK_LENGTH);
FloodKickExemptRank = config.ReadCached("floodKickExemptRank", DEFAULT_FLOOD_KICK_EXEMPT_RANK);
- Context = new Context(msgStorage ?? throw new ArgumentNullException(nameof(msgStorage)));
+ Logger.ZLogDebug($"Creating context...");
+ Context = new Context(logFactory, msgStorage ?? throw new ArgumentNullException(nameof(msgStorage)));
+ Logger.ZLogDebug($"Creating channel list...");
string[]? channelNames = config.ReadValue("channels", DEFAULT_CHANNELS);
if(channelNames is not null)
foreach(string channelName in channelNames) {
@@ -68,6 +76,7 @@ public class SockChatServer {
);
}
+ Logger.ZLogDebug($"Registering unauthenticated handlers...");
GuestHandlers.Add(new AuthC2SPacketHandler(
authClient,
bansClient,
@@ -77,11 +86,13 @@ public class SockChatServer {
MaxConnections
));
+ Logger.ZLogDebug($"Registering authenticated handlers...");
AuthedHandlers.AddRange([
new PingC2SPacketHandler(authClient),
SendMessageHandler = new SendMessageC2SPacketHandler(Context.RandomSnowflake, MaxMessageLength),
]);
+ Logger.ZLogDebug($"Registering client commands...");
SendMessageHandler.AddCommands([
new AFKClientCommand(),
new NickClientCommand(),
@@ -105,14 +116,31 @@ public class SockChatServer {
}
public async Task Listen(CancellationToken cancellationToken) {
- using IWebSocketServer server = new SharpChatWebSocketServer($"ws://0.0.0.0:{Port}");
+ using SharpChatWebSocketServer server = new(Context.LoggerFactory.CreateLogger("sockchat:server"), $"ws://0.0.0.0:{Port}");
server.Start(sock => {
+ if(!IPAddress.TryParse(sock.ConnectionInfo.ClientIpAddress, out IPAddress? addr)) {
+ Logger.ZLogError($@"A client attempted to connect with an invalid IP address: ""{sock.ConnectionInfo.ClientIpAddress}""");
+ sock.Close(1011);
+ return;
+ }
+
+ if(IPAddress.IsLoopback(addr) && sock.ConnectionInfo.Headers.TryGetValue("X-Real-IP", out string? addrStr)) {
+ if(IPAddress.TryParse(addrStr, out IPAddress? realAddr))
+ addr = realAddr;
+ else
+ Logger.ZLogWarning($@"Connection originated from loopback and supplied an X-Real-IP header, but it could not be parsed: ""{addrStr}""");
+ }
+
+ IPEndPoint endPoint = new(addr, sock.ConnectionInfo.ClientPort);
+
if(cancellationToken.IsCancellationRequested) {
+ Logger.ZLogInformation($"{endPoint} attepted to connect after shutdown was requested. Connection will be dropped.");
sock.Close(1013);
return;
}
- Connection conn = new(sock);
+ ILogger logger = Context.LoggerFactory.CreateLogger($"sockchat:({endPoint})");
+ Connection conn = new(logger, sock, endPoint);
Context.Connections.Add(conn);
sock.OnOpen = () => OnOpen(conn).Wait();
@@ -121,25 +149,27 @@ public class SockChatServer {
sock.OnMessage = msg => OnMessage(conn, msg).Wait();
});
- Logger.Write("Listening...");
+ Logger.ZLogInformation($"Listening...");
await Task.Delay(Timeout.Infinite, cancellationToken).ConfigureAwait(ConfigureAwaitOptions.SuppressThrowing);
+ Logger.ZLogDebug($"Disposing all clients...");
foreach(Connection conn in Context.Connections)
conn.Dispose();
}
private async Task OnOpen(Connection conn) {
- Logger.Write($"Connection opened from {conn.RemoteAddress}:{conn.RemotePort}");
+ conn.Logger.ZLogInformation($"Connection opened.");
await Context.SafeUpdate();
}
private async Task OnError(Connection conn, Exception ex) {
- Logger.Write($"[{conn.Id} {conn.RemoteAddress}] {ex}");
+ conn.Logger.ZLogError($"Error: {ex.Message}");
+ conn.Logger.ZLogDebug($"{ex}");
await Context.SafeUpdate();
}
private async Task OnClose(Connection conn) {
- Logger.Write($"Connection closed from {conn.RemoteAddress}:{conn.RemotePort}");
+ conn.Logger.ZLogInformation($"Connection closed.");
Context.ContextAccess.Wait();
try {
@@ -155,6 +185,8 @@ public class SockChatServer {
}
private async Task OnMessage(Connection conn, string msg) {
+ conn.Logger.ZLogTrace($"Received: {msg}");
+
await Context.SafeUpdate();
// this doesn't affect non-authed connections?????
@@ -178,8 +210,11 @@ public class SockChatServer {
banDuration = TimeSpan.FromSeconds(FloodKickLength);
banUser = conn.User;
banAddr = conn.RemoteAddress.ToString();
+ conn.Logger.ZLogWarning($"Exceeded flood limit! Issuing ban with duration {banDuration} on {banAddr}/{banUser.UserId}...");
} else if(rateLimiter.IsRisky) {
banUser = conn.User;
+ banAddr = conn.RemoteAddress.ToString();
+ conn.Logger.ZLogWarning($"About to exceed flood limit! Issueing warning to {banAddr}/{banUser.UserId}...");
}
if(banUser is not null) {
diff --git a/SharpChatCommon/Configuration/CachedValue.cs b/SharpChatCommon/Configuration/CachedValue.cs
index 214d42c..27b5b5b 100644
--- a/SharpChatCommon/Configuration/CachedValue.cs
+++ b/SharpChatCommon/Configuration/CachedValue.cs
@@ -15,7 +15,6 @@ public class CachedValue<T>(Config config, string name, TimeSpan lifetime, T? fa
if((now - LastRead) >= lifetime) {
LastRead = now;
CurrentValue = Config.ReadValue(Name, fallback);
- Logger.Debug($"Read {Name} ({CurrentValue})");
}
}
return (T?)CurrentValue;
diff --git a/SharpChatCommon/Logger.cs b/SharpChatCommon/Logger.cs
deleted file mode 100644
index f5603c1..0000000
--- a/SharpChatCommon/Logger.cs
+++ /dev/null
@@ -1,33 +0,0 @@
-using System.Diagnostics;
-using System.Text;
-
-namespace SharpChat;
-
-public static class Logger {
- public static void Write(string str) {
- Console.WriteLine(string.Format("[{1}] {0}", str, DateTime.Now));
- }
-
- public static void Write(byte[] bytes) {
- Write(Encoding.UTF8.GetString(bytes));
- }
-
- public static void Write(object obj) {
- Write(obj?.ToString() ?? string.Empty);
- }
-
- [Conditional("DEBUG")]
- public static void Debug(string str) {
- Write(str);
- }
-
- [Conditional("DEBUG")]
- public static void Debug(byte[] bytes) {
- Write(bytes);
- }
-
- [Conditional("DEBUG")]
- public static void Debug(object obj) {
- Write(obj);
- }
-}
diff --git a/SharpChatCommon/SharpChatCommon.csproj b/SharpChatCommon/SharpChatCommon.csproj
index 969c044..c972a18 100644
--- a/SharpChatCommon/SharpChatCommon.csproj
+++ b/SharpChatCommon/SharpChatCommon.csproj
@@ -7,4 +7,8 @@
<RootNamespace>SharpChat</RootNamespace>
</PropertyGroup>
+ <ItemGroup>
+ <PackageReference Include="ZLogger" Version="2.5.10" />
+ </ItemGroup>
+
</Project>