From d56e878c28d9ed1c690e4488d69b6c119de9a814 Mon Sep 17 00:00:00 2001 From: Ske Date: Sat, 30 Jan 2021 01:07:43 +0100 Subject: [PATCH] Converted shard and logclean service --- Myriad/Extensions/MessageExtensions.cs | 4 +- Myriad/Extensions/SnowflakeExtensions.cs | 20 +++ Myriad/Gateway/Cluster.cs | 6 +- Myriad/Gateway/Shard.cs | 84 +++++---- Myriad/Gateway/ShardConnection.cs | 17 +- Myriad/Rest/BaseRestClient.cs | 2 +- Myriad/Rest/Ratelimit/Bucket.cs | 29 ++- .../JsonSerializerOptionsExtensions.cs | 2 +- PluralKit.Bot/Bot.cs | 2 + PluralKit.Bot/Services/LoggerCleanService.cs | 165 +++++++++++------- PluralKit.Bot/Services/ShardInfoService.cs | 86 +++++---- 11 files changed, 264 insertions(+), 153 deletions(-) create mode 100644 Myriad/Extensions/SnowflakeExtensions.cs diff --git a/Myriad/Extensions/MessageExtensions.cs b/Myriad/Extensions/MessageExtensions.cs index 60adb532..56664154 100644 --- a/Myriad/Extensions/MessageExtensions.cs +++ b/Myriad/Extensions/MessageExtensions.cs @@ -1,4 +1,6 @@ -using Myriad.Gateway; +using System; + +using Myriad.Gateway; using Myriad.Types; namespace Myriad.Extensions diff --git a/Myriad/Extensions/SnowflakeExtensions.cs b/Myriad/Extensions/SnowflakeExtensions.cs new file mode 100644 index 00000000..71446138 --- /dev/null +++ b/Myriad/Extensions/SnowflakeExtensions.cs @@ -0,0 +1,20 @@ +using System; + +using Myriad.Types; + +namespace Myriad.Extensions +{ + public static class SnowflakeExtensions + { + public static readonly DateTimeOffset DiscordEpoch = new(2015, 1, 1, 0, 0, 0, TimeSpan.Zero); + + public static DateTimeOffset SnowflakeToTimestamp(ulong snowflake) => + DiscordEpoch + TimeSpan.FromMilliseconds(snowflake >> 22); + + public static DateTimeOffset Timestamp(this Message msg) => SnowflakeToTimestamp(msg.Id); + public static DateTimeOffset Timestamp(this Channel channel) => SnowflakeToTimestamp(channel.Id); + public static DateTimeOffset Timestamp(this Guild guild) => SnowflakeToTimestamp(guild.Id); + public static DateTimeOffset Timestamp(this Webhook webhook) => SnowflakeToTimestamp(webhook.Id); + public static DateTimeOffset Timestamp(this User user) => SnowflakeToTimestamp(user.Id); + } +} \ No newline at end of file diff --git a/Myriad/Gateway/Cluster.cs b/Myriad/Gateway/Cluster.cs index 63e8a2cc..220eadc1 100644 --- a/Myriad/Gateway/Cluster.cs +++ b/Myriad/Gateway/Cluster.cs @@ -23,6 +23,7 @@ namespace Myriad.Gateway } public Func? EventReceived { get; set; } + public event Action? ShardCreated; public IReadOnlyDictionary Shards => _shards; public ClusterSessionState SessionState => GetClusterState(); @@ -35,7 +36,8 @@ namespace Myriad.Gateway foreach (var (id, shard) in _shards) shards.Add(new ClusterSessionState.ShardState { - Shard = shard.ShardInfo ?? new ShardInfo(id, _shards.Count), Session = shard.SessionInfo + Shard = shard.ShardInfo, + Session = shard.SessionInfo }); return new ClusterSessionState {Shards = shards}; @@ -78,6 +80,8 @@ namespace Myriad.Gateway var shard = new Shard(_logger, new Uri(url), _gatewaySettings, shardInfo, session); shard.OnEventReceived += evt => OnShardEventReceived(shard, evt); _shards[shardInfo.ShardId] = shard; + + ShardCreated?.Invoke(shard); } private async Task OnShardEventReceived(Shard shard, IGatewayEvent evt) diff --git a/Myriad/Gateway/Shard.cs b/Myriad/Gateway/Shard.cs index 1ace1b91..25cbba81 100644 --- a/Myriad/Gateway/Shard.cs +++ b/Myriad/Gateway/Shard.cs @@ -12,10 +12,10 @@ namespace Myriad.Gateway { public class Shard: IAsyncDisposable { - private const string LibraryName = "Newcord Test"; + private const string LibraryName = "Myriad (for PluralKit)"; private readonly JsonSerializerOptions _jsonSerializerOptions = - new JsonSerializerOptions().ConfigureForNewcord(); + new JsonSerializerOptions().ConfigureForMyriad(); private readonly ILogger _logger; private readonly Uri _uri; @@ -26,8 +26,8 @@ namespace Myriad.Gateway private DateTimeOffset? _lastHeartbeatSent; private Task _worker; - public ShardInfo? ShardInfo { get; private set; } - public int ShardId => ShardInfo?.ShardId ?? 0; + public ShardInfo ShardInfo { get; private set; } + public int ShardId => ShardInfo.ShardId; public GatewaySettings Settings { get; } public ShardSessionInfo SessionInfo { get; private set; } public ShardState State { get; private set; } @@ -36,11 +36,16 @@ namespace Myriad.Gateway public ApplicationPartial? Application { get; private set; } public Func? OnEventReceived { get; set; } + public event Action? HeartbeatReceived; + public event Action? SocketOpened; + public event Action? Resumed; + public event Action? Ready; + public event Action? SocketClosed; - public Shard(ILogger logger, Uri uri, GatewaySettings settings, ShardInfo? info = null, + public Shard(ILogger logger, Uri uri, GatewaySettings settings, ShardInfo info, ShardSessionInfo? sessionInfo = null) { - _logger = logger; + _logger = logger.ForContext(); _uri = uri; Settings = settings; @@ -71,23 +76,23 @@ namespace Myriad.Gateway while (true) try { - _logger.Information("Connecting..."); + _logger.Information("Shard {ShardId}: Connecting...", ShardId); State = ShardState.Connecting; await Connect(); - _logger.Information("Connected. Entering main loop..."); + _logger.Information("Shard {ShardId}: Connected. Entering main loop...", ShardId); // Tick returns false if we need to stop and reconnect while (await Tick(_conn!)) await Task.Delay(TimeSpan.FromMilliseconds(1000)); - _logger.Information("Connection closed, reconnecting..."); + _logger.Information("Shard {ShardId}: Connection closed, reconnecting...", ShardId); State = ShardState.Closed; } catch (Exception e) { - _logger.Error(e, "Error in shard state handler"); + _logger.Error(e, "Shard {ShardId}: Error in shard state handler", ShardId); } } @@ -116,8 +121,8 @@ namespace Myriad.Gateway if (!_hasReceivedAck) { _logger.Warning( - "Did not receive heartbeat Ack from gateway within interval ({HeartbeatInterval})", - _currentHeartbeatInterval); + "Shard {ShardId}: Did not receive heartbeat Ack from gateway within interval ({HeartbeatInterval})", + ShardId, _currentHeartbeatInterval); State = ShardState.Closing; await conn.Disconnect(WebSocketCloseStatus.ProtocolError, "Did not receive ACK in time"); return false; @@ -131,7 +136,8 @@ namespace Myriad.Gateway private async Task SendHeartbeat(ShardConnection conn) { - _logger.Debug("Sending heartbeat"); + _logger.Debug("Shard {ShardId}: Sending heartbeat with seq.no. {LastSequence}", + ShardId, SessionInfo.LastSequence); await conn.Send(new GatewayPacket {Opcode = GatewayOpcode.Heartbeat, Payload = SessionInfo.LastSequence}); _lastHeartbeatSent = DateTimeOffset.UtcNow; @@ -144,7 +150,12 @@ namespace Myriad.Gateway _currentHeartbeatInterval = null; - _conn = new ShardConnection(_uri, _logger, _jsonSerializerOptions) {OnReceive = OnReceive}; + _conn = new ShardConnection(_uri, _logger, _jsonSerializerOptions) + { + OnReceive = OnReceive, + OnOpen = () => SocketOpened?.Invoke(), + OnClose = (closeStatus, message) => SocketClosed?.Invoke(closeStatus, message) + }; } private async Task OnReceive(GatewayPacket packet) @@ -158,21 +169,23 @@ namespace Myriad.Gateway } case GatewayOpcode.Heartbeat: { - _logger.Debug("Received heartbeat request from shard, sending Ack"); + _logger.Debug("Shard {ShardId}: Received heartbeat request from shard, sending Ack", ShardId); await _conn!.Send(new GatewayPacket {Opcode = GatewayOpcode.HeartbeatAck}); break; } case GatewayOpcode.HeartbeatAck: { Latency = DateTimeOffset.UtcNow - _lastHeartbeatSent; - _logger.Debug("Received heartbeat Ack (latency {Latency})", Latency); + _logger.Debug("Shard {ShardId}: Received heartbeat Ack with latency {Latency}", ShardId, Latency); + if (Latency != null) + HeartbeatReceived?.Invoke(Latency!.Value); _hasReceivedAck = true; break; } case GatewayOpcode.Reconnect: { - _logger.Information("Received Reconnect, closing and reconnecting"); + _logger.Information("Shard {ShardId}: Received Reconnect, closing and reconnecting", ShardId); await _conn!.Disconnect(WebSocketCloseStatus.Empty, null); break; } @@ -187,8 +200,8 @@ namespace Myriad.Gateway var delay = TimeSpan.FromMilliseconds(new Random().Next(1000, 5000)); _logger.Information( - "Received Invalid Session (can resume? {CanResume}), reconnecting after {ReconnectDelay}", - canResume, delay); + "Shard {ShardId}: Received Invalid Session (can resume? {CanResume}), reconnecting after {ReconnectDelay}", + ShardId, canResume, delay); await _conn!.Disconnect(WebSocketCloseStatus.Empty, null); // Will reconnect after exiting this "loop" @@ -205,15 +218,16 @@ namespace Myriad.Gateway if (State == ShardState.Connecting) await HandleReady(rdy); else - _logger.Warning("Received Ready event in unexpected state {ShardState}, ignoring?", State); + _logger.Warning("Shard {ShardId}: Received Ready event in unexpected state {ShardState}, ignoring?", + ShardId, State); } else if (evt is ResumedEvent) { if (State == ShardState.Connecting) await HandleResumed(); else - _logger.Warning("Received Resumed event in unexpected state {ShardState}, ignoring?", - State); + _logger.Warning("Shard {ShardId}: Received Resumed event in unexpected state {ShardState}, ignoring?", + ShardId, State); } await HandleEvent(evt); @@ -221,7 +235,7 @@ namespace Myriad.Gateway } default: { - _logger.Debug("Received unknown gateway opcode {Opcode}", packet.Opcode); + _logger.Debug("Shard {ShardId}: Received unknown gateway opcode {Opcode}", ShardId, packet.Opcode); break; } } @@ -238,44 +252,47 @@ namespace Myriad.Gateway { if (!IGatewayEvent.EventTypes.TryGetValue(eventType, out var clrType)) { - _logger.Information("Received unknown event type {EventType}", eventType); + _logger.Information("Shard {ShardId}: Received unknown event type {EventType}", ShardId, eventType); return null; } try { - _logger.Verbose("Deserializing {EventType} to {ClrType}", eventType, clrType); + _logger.Verbose("Shard {ShardId}: Deserializing {EventType} to {ClrType}", ShardId, eventType, clrType); return JsonSerializer.Deserialize(data.GetRawText(), clrType, _jsonSerializerOptions) as IGatewayEvent; } catch (JsonException e) { - _logger.Error(e, "Error deserializing event {EventType} to {ClrType}", eventType, clrType); + _logger.Error(e, "Shard {ShardId}: Error deserializing event {EventType} to {ClrType}", ShardId, eventType, clrType); return null; } } private Task HandleReady(ReadyEvent ready) { - ShardInfo = ready.Shard; + // TODO: when is ready.Shard ever null? + ShardInfo = ready.Shard ?? new ShardInfo(0, 0); SessionInfo = SessionInfo with { Session = ready.SessionId }; User = ready.User; Application = ready.Application; State = ShardState.Open; - + + Ready?.Invoke(); return Task.CompletedTask; } private Task HandleResumed() { State = ShardState.Open; + Resumed?.Invoke(); return Task.CompletedTask; } private async Task HandleHello(JsonElement json) { var hello = JsonSerializer.Deserialize(json.GetRawText(), _jsonSerializerOptions)!; - _logger.Debug("Received Hello with interval {Interval} ms", hello.HeartbeatInterval); + _logger.Debug("Shard {ShardId}: Received Hello with interval {Interval} ms", ShardId, hello.HeartbeatInterval); _currentHeartbeatInterval = TimeSpan.FromMilliseconds(hello.HeartbeatInterval); await SendHeartbeat(_conn!); @@ -293,7 +310,7 @@ namespace Myriad.Gateway private async Task SendIdentify() { - _logger.Information("Sending gateway Identify for shard {@ShardInfo}", SessionInfo); + _logger.Information("Shard {ShardId}: Sending gateway Identify for shard {@ShardInfo}", ShardId, ShardInfo); await _conn!.Send(new GatewayPacket { Opcode = GatewayOpcode.Identify, @@ -312,11 +329,12 @@ namespace Myriad.Gateway private async Task SendResume(string session, int lastSequence) { - _logger.Information("Sending gateway Resume for session {@SessionInfo}", ShardInfo, - SessionInfo); + _logger.Information("Shard {ShardId}: Sending gateway Resume for session {@SessionInfo}", + ShardId, SessionInfo); await _conn!.Send(new GatewayPacket { - Opcode = GatewayOpcode.Resume, Payload = new GatewayResume(Settings.Token, session, lastSequence) + Opcode = GatewayOpcode.Resume, + Payload = new GatewayResume(Settings.Token, session, lastSequence) }); } diff --git a/Myriad/Gateway/ShardConnection.cs b/Myriad/Gateway/ShardConnection.cs index 77453de2..886e0664 100644 --- a/Myriad/Gateway/ShardConnection.cs +++ b/Myriad/Gateway/ShardConnection.cs @@ -29,9 +29,12 @@ namespace Myriad.Gateway } public Func? OnReceive { get; set; } + public Action? OnOpen { get; set; } + + public Action? OnClose { get; set; } public WebSocketState State => _client.State; - + public async ValueTask DisposeAsync() { _cts.Cancel(); @@ -50,8 +53,14 @@ namespace Myriad.Gateway }.Uri; _logger.Debug("Connecting to gateway WebSocket at {GatewayUrl}", realUrl); await _client.ConnectAsync(realUrl, default); - + _logger.Debug("Gateway connection opened"); + + OnOpen?.Invoke(); + + // Main worker loop, spins until we manually disconnect (which hits the cancellation token) + // or the server disconnects us (which sets state to closed) while (!_cts.IsCancellationRequested && _client.State == WebSocketState.Open) + { try { await HandleReceive(); @@ -60,6 +69,9 @@ namespace Myriad.Gateway { _logger.Error(e, "Error in WebSocket receive worker"); } + } + + OnClose?.Invoke(_client.CloseStatus ?? default, _client.CloseStatusDescription); } private async Task HandleReceive() @@ -92,6 +104,7 @@ namespace Myriad.Gateway private async Task ReadData(MemoryStream stream) { + // TODO: does this throw if we disconnect mid-read? using var buf = MemoryPool.Shared.Rent(); ValueWebSocketReceiveResult result; do diff --git a/Myriad/Rest/BaseRestClient.cs b/Myriad/Rest/BaseRestClient.cs index ad35cc0a..40a85c68 100644 --- a/Myriad/Rest/BaseRestClient.cs +++ b/Myriad/Rest/BaseRestClient.cs @@ -40,7 +40,7 @@ namespace Myriad.Rest Client.DefaultRequestHeaders.TryAddWithoutValidation("User-Agent", userAgent); Client.DefaultRequestHeaders.TryAddWithoutValidation("Authorization", token); - _jsonSerializerOptions = new JsonSerializerOptions().ConfigureForNewcord(); + _jsonSerializerOptions = new JsonSerializerOptions().ConfigureForMyriad(); _ratelimiter = new Ratelimiter(logger); var discordPolicy = new DiscordRateLimitPolicy(_ratelimiter); diff --git a/Myriad/Rest/Ratelimit/Bucket.cs b/Myriad/Rest/Ratelimit/Bucket.cs index e9d0eb5f..7f49ec33 100644 --- a/Myriad/Rest/Ratelimit/Bucket.cs +++ b/Myriad/Rest/Ratelimit/Bucket.cs @@ -15,9 +15,9 @@ namespace Myriad.Rest.Ratelimit private readonly ILogger _logger; private readonly SemaphoreSlim _semaphore = new(1, 1); - private DateTimeOffset _nextReset; + private DateTimeOffset? _nextReset; private bool _resetTimeValid; - private bool _hasReceivedRemaining; + private bool _hasReceivedHeaders; public Bucket(ILogger logger, string key, ulong major, int limit) { @@ -54,6 +54,7 @@ namespace Myriad.Rest.Ratelimit "{BucketKey}/{BucketMajor}: Bucket has [{BucketRemaining}/{BucketLimit} left], allowing through", Key, Major, Remaining, Limit); Remaining--; + return true; } @@ -78,21 +79,25 @@ namespace Myriad.Rest.Ratelimit var headerNextReset = DateTimeOffset.UtcNow + headers.ResetAfter.Value; // todo: server time if (headerNextReset > _nextReset) { - _logger.Debug("{BucketKey}/{BucketMajor}: Received reset time {NextReset} from server (after: {NextResetAfter}, new remaining: {Remaining})", - Key, Major, headerNextReset, headers.ResetAfter.Value, headers.Remaining); + _logger.Debug("{BucketKey}/{BucketMajor}: Received reset time {NextReset} from server (after: {NextResetAfter}, remaining: {Remaining}, local remaining: {LocalRemaining})", + Key, Major, headerNextReset, headers.ResetAfter.Value, headers.Remaining, Remaining); _nextReset = headerNextReset; _resetTimeValid = true; } } - if (headers.Limit != null) + if (headers.Limit != null) Limit = headers.Limit.Value; - if (headers.Remaining != null && !_hasReceivedRemaining) + if (headers.Remaining != null && !_hasReceivedHeaders) { - _hasReceivedRemaining = true; - Remaining = headers.Remaining.Value; + var oldRemaining = Remaining; + Remaining = Math.Min(headers.Remaining.Value, Remaining); + + _logger.Debug("{BucketKey}/{BucketMajor}: Received first remaining of {HeaderRemaining}, previous local remaining is {LocalRemaining}, new local remaining is {Remaining}", + Key, Major, headers.Remaining.Value, oldRemaining, Remaining); + _hasReceivedHeaders = true; } } finally @@ -106,6 +111,12 @@ namespace Myriad.Rest.Ratelimit try { _semaphore.Wait(); + + // If we don't have any reset data, "snap" it to now + // This happens before first request and at this point the reset is invalid anyway, so it's fine + // but it ensures the stale timeout doesn't trigger early by using `default` value + if (_nextReset == null) + _nextReset = now; // If we're past the reset time *and* we haven't reset already, do that var timeSinceReset = now - _nextReset; @@ -147,7 +158,7 @@ namespace Myriad.Rest.Ratelimit if (!_resetTimeValid) return FallbackDelay; - var delay = _nextReset - now; + var delay = (_nextReset ?? now) - now; // If we have a really small (or negative) value, return a fallback delay too if (delay < Epsilon) diff --git a/Myriad/Serialization/JsonSerializerOptionsExtensions.cs b/Myriad/Serialization/JsonSerializerOptionsExtensions.cs index 5f45bba0..50b1192f 100644 --- a/Myriad/Serialization/JsonSerializerOptionsExtensions.cs +++ b/Myriad/Serialization/JsonSerializerOptionsExtensions.cs @@ -5,7 +5,7 @@ namespace Myriad.Serialization { public static class JsonSerializerOptionsExtensions { - public static JsonSerializerOptions ConfigureForNewcord(this JsonSerializerOptions opts) + public static JsonSerializerOptions ConfigureForMyriad(this JsonSerializerOptions opts) { opts.PropertyNamingPolicy = new JsonSnakeCaseNamingPolicy(); opts.NumberHandling = JsonNumberHandling.AllowReadingFromString; diff --git a/PluralKit.Bot/Bot.cs b/PluralKit.Bot/Bot.cs index b73a6db3..17c8bfad 100644 --- a/PluralKit.Bot/Bot.cs +++ b/PluralKit.Bot/Bot.cs @@ -173,6 +173,8 @@ namespace PluralKit.Bot async Task HandleEventInner() { + await Task.Yield(); + using var _ = LogContext.PushProperty("EventId", Guid.NewGuid()); _logger .ForContext("Elastic", "yes?") diff --git a/PluralKit.Bot/Services/LoggerCleanService.cs b/PluralKit.Bot/Services/LoggerCleanService.cs index b0b56b9e..9b97104d 100644 --- a/PluralKit.Bot/Services/LoggerCleanService.cs +++ b/PluralKit.Bot/Services/LoggerCleanService.cs @@ -4,31 +4,40 @@ using System.Linq; using System.Text.RegularExpressions; using System.Threading.Tasks; -using DSharpPlus; -using DSharpPlus.Entities; - +using Myriad.Cache; +using Myriad.Extensions; +using Myriad.Rest; +using Myriad.Rest.Exceptions; using Myriad.Types; +using Dapper; + +using NodaTime; +using NodaTime.Extensions; +using NodaTime.Text; + using PluralKit.Core; +using Serilog; + namespace PluralKit.Bot { public class LoggerCleanService { - private static readonly Regex _basicRegex = new Regex("(\\d{17,19})"); - private static readonly Regex _dynoRegex = new Regex("Message ID: (\\d{17,19})"); - private static readonly Regex _carlRegex = new Regex("ID: (\\d{17,19})"); - private static readonly Regex _circleRegex = new Regex("\\(`(\\d{17,19})`\\)"); - private static readonly Regex _loggerARegex = new Regex("Message = (\\d{17,19})"); - private static readonly Regex _loggerBRegex = new Regex("MessageID:(\\d{17,19})"); - private static readonly Regex _auttajaRegex = new Regex("Message (\\d{17,19}) deleted"); - private static readonly Regex _mantaroRegex = new Regex("Message \\(?ID:? (\\d{17,19})\\)? created by .* in channel .* was deleted\\."); - private static readonly Regex _pancakeRegex = new Regex("Message from <@(\\d{17,19})> deleted in"); - private static readonly Regex _unbelievaboatRegex = new Regex("Message ID: (\\d{17,19})"); - private static readonly Regex _vanessaRegex = new Regex("Message sent by <@!?(\\d{17,19})> deleted in"); - private static readonly Regex _salRegex = new Regex("\\(ID: (\\d{17,19})\\)"); - private static readonly Regex _GearBotRegex = new Regex("\\(``(\\d{17,19})``\\) in <#\\d{17,19}> has been removed."); - private static readonly Regex _GiselleRegex = new Regex("\\*\\*Message ID\\*\\*: `(\\d{17,19})`"); + private static readonly Regex _basicRegex = new("(\\d{17,19})"); + private static readonly Regex _dynoRegex = new("Message ID: (\\d{17,19})"); + private static readonly Regex _carlRegex = new("ID: (\\d{17,19})"); + private static readonly Regex _circleRegex = new("\\(`(\\d{17,19})`\\)"); + private static readonly Regex _loggerARegex = new("Message = (\\d{17,19})"); + private static readonly Regex _loggerBRegex = new("MessageID:(\\d{17,19})"); + private static readonly Regex _auttajaRegex = new("Message (\\d{17,19}) deleted"); + private static readonly Regex _mantaroRegex = new("Message \\(?ID:? (\\d{17,19})\\)? created by .* in channel .* was deleted\\."); + private static readonly Regex _pancakeRegex = new("Message from <@(\\d{17,19})> deleted in"); + private static readonly Regex _unbelievaboatRegex = new("Message ID: (\\d{17,19})"); + private static readonly Regex _vanessaRegex = new("Message sent by <@!?(\\d{17,19})> deleted in"); + private static readonly Regex _salRegex = new("\\(ID: (\\d{17,19})\\)"); + private static readonly Regex _GearBotRegex = new("\\(``(\\d{17,19})``\\) in <#\\d{17,19}> has been removed."); + private static readonly Regex _GiselleRegex = new("\\*\\*Message ID\\*\\*: `(\\d{17,19})`"); private static readonly Dictionary _bots = new[] { @@ -57,29 +66,35 @@ namespace PluralKit.Bot .ToDictionary(b => b.WebhookName); private readonly IDatabase _db; - private DiscordShardedClient _client; + private readonly DiscordApiClient _client; + private readonly IDiscordCache _cache; + private readonly Bot _bot; // todo: get rid of this nasty + private readonly ILogger _logger; - public LoggerCleanService(IDatabase db, DiscordShardedClient client) + public LoggerCleanService(IDatabase db, DiscordApiClient client, IDiscordCache cache, Bot bot, ILogger logger) { _db = db; _client = client; + _cache = cache; + _bot = bot; + _logger = logger.ForContext(); } public ICollection Bots => _bots.Values; public async ValueTask HandleLoggerBotCleanup(Message msg) { - // TODO: fix!! - /* - if (msg.Channel.Type != ChannelType.Text) return; - if (!msg.Channel.BotHasAllPermissions(Permissions.ManageMessages)) return; + var channel = _cache.GetChannel(msg.ChannelId); + + if (channel.Type != Channel.ChannelType.GuildText) return; + if (!_bot.PermissionsIn(channel.Id).HasFlag(PermissionSet.ManageMessages)) return; // If this message is from a *webhook*, check if the name matches one of the bots we know // TODO: do we need to do a deeper webhook origin check, or would that be too hard on the rate limit? // If it's from a *bot*, check the bot ID to see if we know it. LoggerBot bot = null; - if (msg.WebhookMessage) _botsByWebhookName.TryGetValue(msg.Author.Username, out bot); - else if (msg.Author.IsBot) _bots.TryGetValue(msg.Author.Id, out bot); + if (msg.WebhookId != null) _botsByWebhookName.TryGetValue(msg.Author.Username, out bot); + else if (msg.Author.Bot) _bots.TryGetValue(msg.Author.Id, out bot); // If we didn't find anything before, or what we found is an unsupported bot, bail if (bot == null) return; @@ -96,33 +111,43 @@ namespace PluralKit.Bot // either way but shouldn't be too much, given it's constrained by user ID and guild. var fuzzy = bot.FuzzyExtractFunc(msg); if (fuzzy == null) return; - + + _logger.Debug("Fuzzy logclean for {BotName} on {MessageId}: {@FuzzyExtractResult}", + bot.Name, msg.Id, fuzzy); + var mid = await _db.Execute(conn => conn.QuerySingleOrDefaultAsync( "select mid from messages where sender = @User and mid > @ApproxID and guild = @Guild limit 1", new { fuzzy.Value.User, - Guild = msg.Channel.GuildId, + Guild = msg.GuildId, ApproxId = DiscordUtils.InstantToSnowflake( - fuzzy.Value.ApproxTimestamp - TimeSpan.FromSeconds(3)) + fuzzy.Value.ApproxTimestamp - Duration.FromSeconds(3)) })); - if (mid == null) return; // If we didn't find a corresponding message, bail + + // If we didn't find a corresponding message, bail + if (mid == null) + return; + // Otherwise, we can *reasonably assume* that this is a logged deletion, so delete the log message. - await msg.DeleteAsync(); + await _client.DeleteMessage(msg.ChannelId, msg.Id); } else if (bot.ExtractFunc != null) { // Other bots give us the message ID itself, and we can just extract that from the database directly. var extractedId = bot.ExtractFunc(msg); if (extractedId == null) return; // If we didn't find anything, bail. + + _logger.Debug("Pure logclean for {BotName} on {MessageId}: {@FuzzyExtractResult}", + bot.Name, msg.Id, extractedId); var mid = await _db.Execute(conn => conn.QuerySingleOrDefaultAsync( "select mid from messages where original_mid = @Mid", new {Mid = extractedId.Value})); if (mid == null) return; // If we've gotten this far, we found a logged deletion of a trigger message. Just yeet it! - await msg.DeleteAsync(); + await _client.DeleteMessage(msg.ChannelId, msg.Id); } // else should not happen, but idk, it might } catch (NotFoundException) @@ -131,10 +156,9 @@ namespace PluralKit.Bot // The only thing I can think of that'd cause this are the DeleteAsync() calls which 404 when // the message doesn't exist anyway - so should be safe to just ignore it, right? } - */ } - private static ulong? ExtractAuttaja(DiscordMessage msg) + private static ulong? ExtractAuttaja(Message msg) { // Auttaja has an optional "compact mode" that logs without embeds // That one puts the ID in the message content, non-compact puts it in the embed description. @@ -146,7 +170,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractDyno(DiscordMessage msg) + private static ulong? ExtractDyno(Message msg) { // Embed *description* contains "Message sent by [mention] deleted in [channel]", contains message ID in footer per regex var embed = msg.Embeds.FirstOrDefault(); @@ -155,7 +179,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractLoggerA(DiscordMessage msg) + private static ulong? ExtractLoggerA(Message msg) { // This is for Logger#6088 (298822483060981760), distinct from Logger#6278 (327424261180620801). // Embed contains title "Message deleted in [channel]", and an ID field containing both message and user ID (see regex). @@ -169,7 +193,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractLoggerB(DiscordMessage msg) + private static ulong? ExtractLoggerB(Message msg) { // This is for Logger#6278 (327424261180620801), distinct from Logger#6088 (298822483060981760). // Embed title ends with "A Message Was Deleted!", footer contains message ID as per regex. @@ -179,7 +203,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractGenericBot(DiscordMessage msg) + private static ulong? ExtractGenericBot(Message msg) { // Embed, title is "Message Deleted", ID plain in footer. var embed = msg.Embeds.FirstOrDefault(); @@ -188,7 +212,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractBlargBot(DiscordMessage msg) + private static ulong? ExtractBlargBot(Message msg) { // Embed, title ends with "Message Deleted", contains ID plain in a field. var embed = msg.Embeds.FirstOrDefault(); @@ -198,7 +222,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static ulong? ExtractMantaro(DiscordMessage msg) + private static ulong? ExtractMantaro(Message msg) { // Plain message, "Message (ID: [id]) created by [user] (ID: [id]) in channel [channel] was deleted. if (!(msg.Content?.Contains("was deleted.") ?? false)) return null; @@ -206,7 +230,7 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static FuzzyExtractResult? ExtractCarlBot(DiscordMessage msg) + private static FuzzyExtractResult? ExtractCarlBot(Message msg) { // Embed, title is "Message deleted in [channel], **user** ID in the footer, timestamp as, well, timestamp in embed. // This is the *deletion* timestamp, which we can assume is a couple seconds at most after the message was originally sent @@ -214,17 +238,21 @@ namespace PluralKit.Bot if (embed?.Footer == null || embed.Timestamp == null || !(embed.Title?.StartsWith("Message deleted in") ?? false)) return null; var match = _carlRegex.Match(embed.Footer.Text ?? ""); return match.Success - ? new FuzzyExtractResult { User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = embed.Timestamp.Value } + ? new FuzzyExtractResult + { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = OffsetDateTimePattern.Rfc3339.Parse(embed.Timestamp).GetValueOrThrow().ToInstant() + } : (FuzzyExtractResult?) null; } - private static FuzzyExtractResult? ExtractCircle(DiscordMessage msg) + private static FuzzyExtractResult? ExtractCircle(Message msg) { // Like Auttaja, Circle has both embed and compact modes, but the regex works for both. // Compact: "Message from [user] ([id]) deleted in [channel]", no timestamp (use message time) // Embed: Message Author field: "[user] ([id])", then an embed timestamp string stringWithId = msg.Content; - if (msg.Embeds.Count > 0) + if (msg.Embeds.Length > 0) { var embed = msg.Embeds.First(); if (embed.Author?.Name == null || !embed.Author.Name.StartsWith("Message Deleted in")) return null; @@ -236,11 +264,14 @@ namespace PluralKit.Bot var match = _circleRegex.Match(stringWithId); return match.Success - ? new FuzzyExtractResult {User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = msg.Timestamp} + ? new FuzzyExtractResult { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = msg.Timestamp().ToInstant() + } : (FuzzyExtractResult?) null; } - private static FuzzyExtractResult? ExtractPancake(DiscordMessage msg) + private static FuzzyExtractResult? ExtractPancake(Message msg) { // Embed, author is "Message Deleted", description includes a mention, timestamp is *message send time* (but no ID) // so we use the message timestamp to get somewhere *after* the message was proxied @@ -248,11 +279,15 @@ namespace PluralKit.Bot if (embed?.Description == null || embed.Author?.Name != "Message Deleted") return null; var match = _pancakeRegex.Match(embed.Description); return match.Success - ? new FuzzyExtractResult {User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = msg.Timestamp} + ? new FuzzyExtractResult + { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = msg.Timestamp().ToInstant() + } : (FuzzyExtractResult?) null; } - private static ulong? ExtractUnbelievaBoat(DiscordMessage msg) + private static ulong? ExtractUnbelievaBoat(Message msg) { // Embed author is "Message Deleted", footer contains message ID per regex var embed = msg.Embeds.FirstOrDefault(); @@ -261,18 +296,22 @@ namespace PluralKit.Bot return match.Success ? ulong.Parse(match.Groups[1].Value) : (ulong?) null; } - private static FuzzyExtractResult? ExtractVanessa(DiscordMessage msg) + private static FuzzyExtractResult? ExtractVanessa(Message msg) { // Title is "Message Deleted", embed description contains mention var embed = msg.Embeds.FirstOrDefault(); if (embed?.Title == null || embed.Title != "Message Deleted" || embed.Description == null) return null; var match = _vanessaRegex.Match(embed.Description); return match.Success - ? new FuzzyExtractResult {User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = msg.Timestamp} + ? new FuzzyExtractResult + { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = msg.Timestamp().ToInstant() + } : (FuzzyExtractResult?) null; } - private static FuzzyExtractResult? ExtractSAL(DiscordMessage msg) + private static FuzzyExtractResult? ExtractSAL(Message msg) { // Title is "Message Deleted!", field "Message Author" contains ID var embed = msg.Embeds.FirstOrDefault(); @@ -281,22 +320,30 @@ namespace PluralKit.Bot if (authorField == null) return null; var match = _salRegex.Match(authorField.Value); return match.Success - ? new FuzzyExtractResult {User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = msg.Timestamp} + ? new FuzzyExtractResult + { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = msg.Timestamp().ToInstant() + } : (FuzzyExtractResult?) null; } - private static FuzzyExtractResult? ExtractGearBot(DiscordMessage msg) + private static FuzzyExtractResult? ExtractGearBot(Message msg) { // Simple text based message log. // No message ID, but we have timestamp and author ID. // Not using timestamp here though (seems to be same as message timestamp), might be worth implementing in the future. var match = _GearBotRegex.Match(msg.Content); return match.Success - ? new FuzzyExtractResult {User = ulong.Parse(match.Groups[1].Value), ApproxTimestamp = msg.Timestamp} + ? new FuzzyExtractResult + { + User = ulong.Parse(match.Groups[1].Value), + ApproxTimestamp = msg.Timestamp().ToInstant() + } : (FuzzyExtractResult?) null; } - private static ulong? ExtractGiselleBot(DiscordMessage msg) + private static ulong? ExtractGiselleBot(Message msg) { var embed = msg.Embeds.FirstOrDefault(); if (embed?.Title == null || embed.Title != "🗑 Message Deleted") return null; @@ -308,11 +355,11 @@ namespace PluralKit.Bot { public string Name; public ulong Id; - public Func ExtractFunc; - public Func FuzzyExtractFunc; + public Func ExtractFunc; + public Func FuzzyExtractFunc; public string WebhookName; - public LoggerBot(string name, ulong id, Func extractFunc = null, Func fuzzyExtractFunc = null, string webhookName = null) + public LoggerBot(string name, ulong id, Func extractFunc = null, Func fuzzyExtractFunc = null, string webhookName = null) { Name = name; Id = id; @@ -324,8 +371,8 @@ namespace PluralKit.Bot public struct FuzzyExtractResult { - public ulong User; - public DateTimeOffset ApproxTimestamp; + public ulong User { get; set; } + public Instant ApproxTimestamp { get; set; } } } } \ No newline at end of file diff --git a/PluralKit.Bot/Services/ShardInfoService.cs b/PluralKit.Bot/Services/ShardInfoService.cs index a89a0bd2..d35cc299 100644 --- a/PluralKit.Bot/Services/ShardInfoService.cs +++ b/PluralKit.Bot/Services/ShardInfoService.cs @@ -1,12 +1,11 @@ +using System; using System.Collections.Generic; using System.Linq; +using System.Net.WebSockets; using System.Threading.Tasks; using App.Metrics; -using DSharpPlus; -using DSharpPlus.EventArgs; - using Myriad.Gateway; using NodaTime; @@ -16,6 +15,8 @@ using Serilog; namespace PluralKit.Bot { + // TODO: how much of this do we need now that we have logging in the shard library? + // A lot could probably be cleaned up... public class ShardInfoService { public class ShardInfo @@ -30,10 +31,10 @@ namespace PluralKit.Bot private readonly IMetrics _metrics; private readonly ILogger _logger; - private readonly DiscordShardedClient _client; - private readonly Dictionary _shardInfo = new Dictionary(); + private readonly Cluster _client; + private readonly Dictionary _shardInfo = new(); - public ShardInfoService(ILogger logger, DiscordShardedClient client, IMetrics metrics) + public ShardInfoService(ILogger logger, Cluster client, IMetrics metrics) { _client = client; _metrics = metrics; @@ -44,7 +45,7 @@ namespace PluralKit.Bot { // We initialize this before any shards are actually created and connected // This means the client won't know the shard count, so we attach a listener every time a shard gets connected - _client.SocketOpened += (_, __) => RefreshShardList(); + _client.ShardCreated += InitializeShard; } private void ReportShardStatus() @@ -54,44 +55,40 @@ namespace PluralKit.Bot _metrics.Measure.Gauge.SetValue(BotMetrics.ShardsConnected, _shardInfo.Count(s => s.Value.Connected)); } - private async Task RefreshShardList() + private void InitializeShard(Shard shard) { - // This callback doesn't actually receive the shard that was opening, so we just try to check we have 'em all (so far) - foreach (var (id, shard) in _client.ShardClients) + // Get or insert info in the client dict + if (_shardInfo.TryGetValue(shard.ShardId, out var info)) { - // Get or insert info in the client dict - if (_shardInfo.TryGetValue(id, out var info)) - { - // Skip adding listeners if we've seen this shard & already added listeners to it - if (info.HasAttachedListeners) continue; - } else _shardInfo[id] = info = new ShardInfo(); + // Skip adding listeners if we've seen this shard & already added listeners to it + if (info.HasAttachedListeners) + return; + } else _shardInfo[shard.ShardId] = info = new ShardInfo(); + + // Call our own SocketOpened listener manually (and then attach the listener properly) + SocketOpened(shard); + shard.SocketOpened += () => SocketOpened(shard); + // Register listeners for new shards + _logger.Information("Attaching listeners to new shard #{Shard}", shard.ShardId); + shard.Resumed += () => Resumed(shard); + shard.Ready += () => Ready(shard); + shard.SocketClosed += (closeStatus, message) => SocketClosed(shard, closeStatus, message); + shard.HeartbeatReceived += latency => Heartbeated(shard, latency); - // Call our own SocketOpened listener manually (and then attach the listener properly) - await SocketOpened(shard, null); - shard.SocketOpened += SocketOpened; - - // Register listeners for new shards - _logger.Information("Attaching listeners to new shard #{Shard}", shard.ShardId); - shard.Resumed += Resumed; - shard.Ready += Ready; - shard.SocketClosed += SocketClosed; - shard.Heartbeated += Heartbeated; - - // Register that we've seen it - info.HasAttachedListeners = true; - } + // Register that we've seen it + info.HasAttachedListeners = true; + } - private Task SocketOpened(DiscordClient shard, SocketEventArgs _) + private void SocketOpened(Shard shard) { // We do nothing else here, since this kinda doesn't mean *much*? It's only really started once we get Ready/Resumed // And it doesn't get fired first time around since we don't have time to add the event listener before it's fired' _logger.Information("Shard #{Shard} opened socket", shard.ShardId); - return Task.CompletedTask; } - private ShardInfo TryGetShard(DiscordClient shard) + private ShardInfo TryGetShard(Shard shard) { // If we haven't seen this shard before, add it to the dict! // I don't think this will ever occur since the shard number is constant up-front and we handle those @@ -101,7 +98,7 @@ namespace PluralKit.Bot return info; } - private Task Resumed(DiscordClient shard, ReadyEventArgs e) + private void Resumed(Shard shard) { _logger.Information("Shard #{Shard} resumed connection", shard.ShardId); @@ -109,10 +106,9 @@ namespace PluralKit.Bot // info.LastConnectionTime = SystemClock.Instance.GetCurrentInstant(); info.Connected = true; ReportShardStatus(); - return Task.CompletedTask; } - private Task Ready(DiscordClient shard, ReadyEventArgs e) + private void Ready(Shard shard) { _logger.Information("Shard #{Shard} sent Ready event", shard.ShardId); @@ -120,30 +116,28 @@ namespace PluralKit.Bot info.LastConnectionTime = SystemClock.Instance.GetCurrentInstant(); info.Connected = true; ReportShardStatus(); - return Task.CompletedTask; } - private Task SocketClosed(DiscordClient shard, SocketCloseEventArgs e) + private void SocketClosed(Shard shard, WebSocketCloseStatus closeStatus, string message) { - _logger.Warning("Shard #{Shard} disconnected ({CloseCode}: {CloseMessage})", shard.ShardId, e.CloseCode, e.CloseMessage); + _logger.Warning("Shard #{Shard} disconnected ({CloseCode}: {CloseMessage})", + shard.ShardId, closeStatus, message); var info = TryGetShard(shard); info.DisconnectionCount++; info.Connected = false; ReportShardStatus(); - return Task.CompletedTask; } - private Task Heartbeated(DiscordClient shard, HeartbeatEventArgs e) + private void Heartbeated(Shard shard, TimeSpan latency) { - var latency = Duration.FromMilliseconds(e.Ping); - _logger.Information("Shard #{Shard} received heartbeat (latency: {Latency} ms)", shard.ShardId, latency.Milliseconds); + _logger.Information("Shard #{Shard} received heartbeat (latency: {Latency} ms)", + shard.ShardId, latency.Milliseconds); var info = TryGetShard(shard); - info.LastHeartbeatTime = e.Timestamp.ToInstant(); + info.LastHeartbeatTime = SystemClock.Instance.GetCurrentInstant(); info.Connected = true; - info.ShardLatency = latency; - return Task.CompletedTask; + info.ShardLatency = latency.ToDuration(); } public ShardInfo GetShardInfo(Shard shard) => _shardInfo[shard.ShardId];