diff --git a/Myriad/Rest/BaseRestClient.cs b/Myriad/Rest/BaseRestClient.cs index d86a3e71..8e8e6f80 100644 --- a/Myriad/Rest/BaseRestClient.cs +++ b/Myriad/Rest/BaseRestClient.cs @@ -6,6 +6,7 @@ using System.Net.Http; using System.Net.Http.Headers; using System.Net.Http.Json; using System.Text.Json; +using System.Text.RegularExpressions; using System.Threading.Tasks; using Myriad.Rest.Exceptions; @@ -60,6 +61,7 @@ namespace Myriad.Rest } public HttpClient Client { get; } + public EventHandler<(string, int, long)> OnResponseEvent; public ValueTask DisposeAsync() { @@ -182,10 +184,23 @@ namespace Myriad.Rest request.Version = _httpVersion; request.VersionPolicy = HttpVersionPolicy.RequestVersionOrHigher; + HttpResponseMessage response; + var stopwatch = new Stopwatch(); stopwatch.Start(); - var response = await Client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead); - stopwatch.Stop(); + try + { + response = await Client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead); + stopwatch.Stop(); + } + catch (Exception exc) + { + _logger.Error(exc, "HTTP error: {RequestMethod} {RequestUrl}", request.Method, request.RequestUri); + + // kill the running thread + // in PluralKit.Bot, this error is ignored in "IsOurProblem" (PluralKit.Bot/Utils/MiscUtils.cs) + throw; + } _logger.Debug( "Response: {RequestMethod} {RequestPath} -> {StatusCode} {ReasonPhrase} (in {ResponseDurationMs} ms)", @@ -193,6 +208,13 @@ namespace Myriad.Rest await HandleApiError(response, ignoreNotFound); + if (OnResponseEvent != null) + OnResponseEvent.Invoke(null, ( + GetEndpointMetricsName(response.RequestMessage!), + (int)response.StatusCode, + stopwatch.ElapsedTicks + )); + return response; }, new Dictionary @@ -248,5 +270,39 @@ namespace Myriad.Rest return null; } + + private string NormalizeRoutePath(string url) + { + url = Regex.Replace(url, @"/channels/\d+", "/channels/{channel_id}"); + url = Regex.Replace(url, @"/messages/\d+", "/messages/{message_id}"); + url = Regex.Replace(url, @"/members/\d+", "/members/{user_id}"); + url = Regex.Replace(url, @"/webhooks/\d+/[^/]+", "/webhooks/{webhook_id}/{webhook_token}"); + url = Regex.Replace(url, @"/webhooks/\d+", "/webhooks/{webhook_id}"); + url = Regex.Replace(url, @"/users/\d+", "/users/{user_id}"); + url = Regex.Replace(url, @"/bans/\d+", "/bans/{user_id}"); + url = Regex.Replace(url, @"/roles/\d+", "/roles/{role_id}"); + url = Regex.Replace(url, @"/pins/\d+", "/pins/{message_id}"); + url = Regex.Replace(url, @"/emojis/\d+", "/emojis/{emoji_id}"); + url = Regex.Replace(url, @"/guilds/\d+", "/guilds/{guild_id}"); + url = Regex.Replace(url, @"/integrations/\d+", "/integrations/{integration_id}"); + url = Regex.Replace(url, @"/permissions/\d+", "/permissions/{overwrite_id}"); + url = Regex.Replace(url, @"/reactions/[^{/]+/\d+", "/reactions/{emoji}/{user_id}"); + url = Regex.Replace(url, @"/reactions/[^{/]+", "/reactions/{emoji}"); + url = Regex.Replace(url, @"/invites/[^{/]+", "/invites/{invite_code}"); + url = Regex.Replace(url, @"/interactions/\d+/[^{/]+", "/interactions/{interaction_id}/{interaction_token}"); + url = Regex.Replace(url, @"/interactions/\d+", "/interactions/{interaction_id}"); + + // catch-all for missed IDs + url = Regex.Replace(url, @"\d{17,19}", "{snowflake}"); + + return url; + } + + private string GetEndpointMetricsName(HttpRequestMessage req) + { + var localPath = Regex.Replace(req.RequestUri!.LocalPath, @"/api/v\d+", ""); + var routePath = NormalizeRoutePath(localPath); + return $"{req.Method} {routePath}"; + } } } \ No newline at end of file diff --git a/Myriad/Rest/DiscordApiClient.cs b/Myriad/Rest/DiscordApiClient.cs index 5ea2d411..a7de74a3 100644 --- a/Myriad/Rest/DiscordApiClient.cs +++ b/Myriad/Rest/DiscordApiClient.cs @@ -18,8 +18,11 @@ namespace Myriad.Rest public DiscordApiClient(string token, ILogger logger) { _client = new BaseRestClient(UserAgent, token, logger); + _client.OnResponseEvent += OnResponseEvent; } + public EventHandler<(string, int, long)> OnResponseEvent; + public Task GetGateway() => _client.Get("/gateway", ("GetGateway", default))!; diff --git a/PluralKit.Bot/Bot.cs b/PluralKit.Bot/Bot.cs index a6e65958..c0f6ec6f 100644 --- a/PluralKit.Bot/Bot.cs +++ b/PluralKit.Bot/Bot.cs @@ -227,8 +227,6 @@ namespace PluralKit.Bot // Make this beforehand so we can access the event ID for logging var sentryEvent = new SentryEvent(exc); - _logger.Error(exc, "Exception in event handler: {SentryEventId}", sentryEvent.EventId); - // If the event is us responding to our own error messages, don't bother logging if (evt is MessageCreateEvent mc && mc.Author.Id == shard.User?.Id) return; @@ -236,6 +234,9 @@ namespace PluralKit.Bot var shouldReport = exc.IsOurProblem(); if (shouldReport) { + // only log exceptions if they're our problem + _logger.Error(exc, "Exception in event handler: {SentryEventId}", sentryEvent.EventId); + // Report error to Sentry // This will just no-op if there's no URL set var sentryScope = serviceScope.Resolve(); diff --git a/PluralKit.Bot/Init.cs b/PluralKit.Bot/Init.cs index 52502542..d305224f 100644 --- a/PluralKit.Bot/Init.cs +++ b/PluralKit.Bot/Init.cs @@ -47,9 +47,6 @@ namespace PluralKit.Bot var bot = services.Resolve(); bot.Init(); - // Install observer for request/responses - DiscordRequestObserver.Install(services); - // Start the Discord shards themselves (handlers already set up) logger.Information("Connecting to Discord"); await StartCluster(services); diff --git a/PluralKit.Bot/Modules.cs b/PluralKit.Bot/Modules.cs index 10c908ed..95eb07a9 100644 --- a/PluralKit.Bot/Modules.cs +++ b/PluralKit.Bot/Modules.cs @@ -3,6 +3,8 @@ using System.Net.Http; using Autofac; +using App.Metrics; + using Myriad.Cache; using Myriad.Gateway; using Myriad.Rest; @@ -40,10 +42,28 @@ namespace PluralKit.Bot }; }).AsSelf().SingleInstance(); builder.RegisterType().AsSelf().SingleInstance(); - builder.Register(c => new Myriad.Rest.DiscordApiClient(c.Resolve().Token, c.Resolve())) - .AsSelf().SingleInstance(); builder.RegisterType().AsSelf().As().SingleInstance(); + builder.Register(c => + { + var client = new Myriad.Rest.DiscordApiClient( + c.Resolve().Token, + c.Resolve() + ); + + client.OnResponseEvent += ((_, ev) => + { + var (endpoint, statusCode, ticks) = ev; + var timer = c.Resolve().Provider.Timer.Instance(BotMetrics.DiscordApiRequests, new MetricTags( + new[] { "endpoint", "status_code" }, + new[] { endpoint, statusCode.ToString() } + )); + timer.Record(ticks / 10, TimeUnit.Microseconds); + }); + + return client; + }).AsSelf().SingleInstance(); + // Commands builder.RegisterType().AsSelf(); builder.RegisterType().AsSelf(); @@ -118,10 +138,8 @@ namespace PluralKit.Bot Timeout = TimeSpan.FromSeconds(5), DefaultRequestHeaders = { { "User-Agent", DiscordApiClient.UserAgent } } }).AsSelf().SingleInstance(); - builder.RegisterInstance(SystemClock.Instance).As(); + builder.RegisterInstance(SystemClock.Instance).As(); builder.RegisterType().AsSelf().SingleInstance(); - - builder.RegisterType().AsSelf().SingleInstance(); } } } \ No newline at end of file diff --git a/PluralKit.Bot/Tracing/DiscordRequestObserver.cs b/PluralKit.Bot/Tracing/DiscordRequestObserver.cs deleted file mode 100644 index d3710445..00000000 --- a/PluralKit.Bot/Tracing/DiscordRequestObserver.cs +++ /dev/null @@ -1,198 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Diagnostics; -using System.Linq; -using System.Net.Http; -using System.Runtime.CompilerServices; -using System.Text.RegularExpressions; -using System.Threading.Tasks; - -using App.Metrics; - -using Autofac; - -using Serilog; -using Serilog.Context; - -namespace PluralKit.Bot -{ - // TODO: phase this out; it currently still handles metrics but that needs to be moved to Myriad probably? - public class DiscordRequestObserver: IObserver> - { - private readonly IMetrics _metrics; - private readonly ILogger _logger; - - private bool ShouldLogHeader(string name) => - name.StartsWith("x-ratelimit"); - - public DiscordRequestObserver(ILogger logger, IMetrics metrics) - { - _metrics = metrics; - _logger = logger.ForContext(); - } - - public void OnCompleted() { } - - public void OnError(Exception error) { } - - private string NormalizeRoutePath(string url) - { - url = Regex.Replace(url, @"/channels/\d+", "/channels/{channel_id}"); - url = Regex.Replace(url, @"/messages/\d+", "/messages/{message_id}"); - url = Regex.Replace(url, @"/members/\d+", "/members/{user_id}"); - url = Regex.Replace(url, @"/webhooks/\d+/[^/]+", "/webhooks/{webhook_id}/{webhook_token}"); - url = Regex.Replace(url, @"/webhooks/\d+", "/webhooks/{webhook_id}"); - url = Regex.Replace(url, @"/users/\d+", "/users/{user_id}"); - url = Regex.Replace(url, @"/bans/\d+", "/bans/{user_id}"); - url = Regex.Replace(url, @"/roles/\d+", "/roles/{role_id}"); - url = Regex.Replace(url, @"/pins/\d+", "/pins/{message_id}"); - url = Regex.Replace(url, @"/emojis/\d+", "/emojis/{emoji_id}"); - url = Regex.Replace(url, @"/guilds/\d+", "/guilds/{guild_id}"); - url = Regex.Replace(url, @"/integrations/\d+", "/integrations/{integration_id}"); - url = Regex.Replace(url, @"/permissions/\d+", "/permissions/{overwrite_id}"); - url = Regex.Replace(url, @"/reactions/[^{/]+/\d+", "/reactions/{emoji}/{user_id}"); - url = Regex.Replace(url, @"/reactions/[^{/]+", "/reactions/{emoji}"); - url = Regex.Replace(url, @"/invites/[^{/]+", "/invites/{invite_code}"); - url = Regex.Replace(url, @"/interactions/\d+/[^{/]+", "/interactions/{interaction_id}/{interaction_token}"); - url = Regex.Replace(url, @"/interactions/\d+", "/interactions/{interaction_id}"); - - // catch-all for missed IDs - url = Regex.Replace(url, @"\d{17,19}", "{snowflake}"); - - return url; - } - - private string GetEndpointName(HttpRequestMessage req) - { - var localPath = Regex.Replace(req.RequestUri.LocalPath, @"/api/v\d+", ""); - var routePath = NormalizeRoutePath(localPath); - return $"{req.Method} {routePath}"; - } - - private void HandleException(Exception exc, HttpRequestMessage req) - { - _logger - .ForContext("RequestUrlRoute", GetEndpointName(req)) - .Error(exc, "HTTP error: {RequestMethod} {RequestUrl}", req.Method, req.RequestUri); - } - - private void HandleResponse(HttpResponseMessage response, Activity activity) - { - var endpoint = GetEndpointName(response.RequestMessage); - - // (see phase-out notice at top of file) - /* - using (LogContext.PushProperty("Elastic", "yes?")) - { - if ((int) response.StatusCode >= 400) - { - var content = await response.Content.ReadAsStringAsync(); - LogContext.PushProperty("ResponseBody", content); - } - - var headers = response.Headers - .Where(header => ShouldLogHeader(header.Key.ToLowerInvariant())) - .ToDictionary(k => k.Key.ToLowerInvariant(), - v => string.Join(';', v.Value)); - - _logger - .ForContext("RequestUrlRoute", endpoint) - .ForContext("ResponseHeaders", headers) - .Debug( - "HTTP: {RequestMethod} {RequestUrl} -> {ResponseStatusCode} {ResponseStatusString} (in {RequestDurationMs:F1} ms)", - response.RequestMessage.Method, - response.RequestMessage.RequestUri, - (int) response.StatusCode, - response.ReasonPhrase, - activity.Duration.TotalMilliseconds); - } - */ - - if (IsDiscordApiRequest(response)) - { - var timer = _metrics.Provider.Timer.Instance(BotMetrics.DiscordApiRequests, new MetricTags( - new[] { "endpoint", "status_code" }, - new[] { endpoint, ((int)response.StatusCode).ToString() } - )); - timer.Record(activity.Duration.Ticks / 10, TimeUnit.Microseconds); - } - } - - private static bool IsDiscordApiRequest(HttpResponseMessage response) - { - // Assume any properly authorized request is coming from D#+ and not some sort of user - var authHeader = response.RequestMessage.Headers.Authorization; - if (authHeader == null || authHeader.Scheme != "Bot") - return false; - - return response.RequestMessage.RequestUri.AbsoluteUri.StartsWith("https://discord.com/api/"); - } - - public void OnNext(KeyValuePair value) - { - switch (value.Key) - { - case "System.Net.Http.HttpRequestOut.Stop": - { - var data = Unsafe.As(value.Value); - if (data.Response != null) - HandleResponse(data.Response, Activity.Current); - - break; - } - case "System.Net.Http.Exception": - { - var data = Unsafe.As(value.Value); - HandleException(data.Exception, data.Request); - break; - } - } - } - - public static void Install(IComponentContext services) - { - DiagnosticListener.AllListeners.Subscribe(new ListenerObserver(services)); - } - -#pragma warning disable 649 - private class ActivityStopData - { - // Field order here matters! - public HttpResponseMessage Response; - public HttpRequestMessage Request; - public TaskStatus RequestTaskStatus; - } - - private class ExceptionData - { - // Field order here matters! - public Exception Exception; - public HttpRequestMessage Request; - } -#pragma warning restore 649 - - public class ListenerObserver: IObserver - { - private readonly IComponentContext _services; - private DiscordRequestObserver _observer; - - public ListenerObserver(IComponentContext services) - { - _services = services; - } - - public void OnCompleted() { } - - public void OnError(Exception error) { } - - public void OnNext(DiagnosticListener value) - { - if (value.Name != "HttpHandlerDiagnosticListener") - return; - - _observer ??= _services.Resolve(); - value.Subscribe(_observer); - } - } - } -} \ No newline at end of file