Improved logging system.

This commit is contained in:
flash 2025-04-28 12:29:11 +00:00
parent d94b1cb813
commit 98d13ebbbb
Signed by: flash
GPG key ID: 2C9C2C574D47FE3E
24 changed files with 202 additions and 142 deletions

1
.gitignore vendored
View file

@ -12,6 +12,7 @@ sharpchat.db
sharpchat.db-wal
sharpchat.db-shm
SharpChat/version.txt
logs/
# User-specific files
*.suo

View file

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

View file

@ -6,6 +6,10 @@
<Nullable>enable</Nullable>
</PropertyGroup>
<ItemGroup>
<PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<ItemGroup>
<ProjectReference Include="..\SharpChatCommon\SharpChatCommon.csproj" />
</ItemGroup>

View file

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

View file

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

View file

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

View file

@ -8,6 +8,7 @@
<ItemGroup>
<PackageReference Include="MySqlConnector" Version="2.4.0" />
<PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<ItemGroup>

View file

@ -1,4 +1,3 @@
using System.Data;
using System.Data.Common;
using System.Data.SQLite;
using NativeSQLiteConnection = System.Data.SQLite.SQLiteConnection;

View file

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

View file

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

View file

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

View file

@ -8,6 +8,7 @@
<ItemGroup>
<PackageReference Include="System.Data.SQLite.Core" Version="1.0.119" />
<PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
<ItemGroup>

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

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

View file

@ -7,4 +7,8 @@
<RootNamespace>SharpChat</RootNamespace>
</PropertyGroup>
<ItemGroup>
<PackageReference Include="ZLogger" Version="2.5.10" />
</ItemGroup>
</Project>