Properly associate trigger events with Sentry errors

This commit is contained in:
Ske 2019-08-09 12:47:46 +02:00
parent 606f48fdb5
commit 3f6a260fac
3 changed files with 198 additions and 88 deletions

View File

@ -48,7 +48,7 @@ namespace PluralKit.Bot
var coreConfig = services.GetRequiredService<CoreConfig>(); var coreConfig = services.GetRequiredService<CoreConfig>();
var botConfig = services.GetRequiredService<BotConfig>(); var botConfig = services.GetRequiredService<BotConfig>();
using (SentrySdk.Init(coreConfig.SentryUrl)) using (Sentry.SentrySdk.Init(coreConfig.SentryUrl))
{ {
logger.Information("Connecting to database"); logger.Information("Connecting to database");
@ -88,7 +88,7 @@ namespace PluralKit.Bot
})) }))
.AddSingleton<Bot>() .AddSingleton<Bot>()
.AddTransient<CommandService>(_ => new CommandService(new CommandServiceConfig .AddSingleton(_ => new CommandService(new CommandServiceConfig
{ {
CaseSensitiveCommands = false, CaseSensitiveCommands = false,
QuotationMarkAliasMap = new Dictionary<char, char> QuotationMarkAliasMap = new Dictionary<char, char>
@ -99,7 +99,10 @@ namespace PluralKit.Bot
{'“', '”'}, {'“', '”'},
{'„', '‟'}, {'„', '‟'},
}, },
DefaultRunMode = RunMode.Async // We're already asyncing stuff by forking off at the client event handlers
// So adding an additional layer of forking is pointless
// and leads to the service scope being disposed of prematurely
DefaultRunMode = RunMode.Sync
})) }))
.AddTransient<EmbedService>() .AddTransient<EmbedService>()
.AddTransient<ProxyService>() .AddTransient<ProxyService>()
@ -123,6 +126,9 @@ namespace PluralKit.Bot
}) })
.AddSingleton<PeriodicStatCollector>() .AddSingleton<PeriodicStatCollector>()
.AddScoped(_ => new Sentry.Scope(null))
.AddTransient<PKEventHandler>()
.AddSingleton(svc => InitUtils.InitLogger(svc.GetRequiredService<CoreConfig>(), "bot")) .AddSingleton(svc => InitUtils.InitLogger(svc.GetRequiredService<CoreConfig>(), "bot"))
.BuildServiceProvider(); .BuildServiceProvider();
} }
@ -139,10 +145,10 @@ namespace PluralKit.Bot
public Bot(IServiceProvider services, IDiscordClient client, CommandService commands, ProxyService proxy, IMetrics metrics, PeriodicStatCollector collector, ILogger logger) public Bot(IServiceProvider services, IDiscordClient client, CommandService commands, ProxyService proxy, IMetrics metrics, PeriodicStatCollector collector, ILogger logger)
{ {
this._services = services; _services = services;
this._client = client as DiscordShardedClient; _client = client as DiscordShardedClient;
this._commands = commands; _commands = commands;
this._proxy = proxy; _proxy = proxy;
_metrics = metrics; _metrics = metrics;
_collector = collector; _collector = collector;
_logger = logger.ForContext<Bot>(); _logger = logger.ForContext<Bot>();
@ -156,42 +162,30 @@ namespace PluralKit.Bot
await _commands.AddModulesAsync(Assembly.GetEntryAssembly(), _services); await _commands.AddModulesAsync(Assembly.GetEntryAssembly(), _services);
_client.ShardReady += ShardReady; _client.ShardReady += ShardReady;
// Deliberately wrapping in a fake-"async" function *without* awaiting, we don't want to "block" since this'd hold up the main loop
// These handlers return Task so we gotta be careful not to return the Task itself (which would then be awaited) - kinda weird design but eh
_client.MessageReceived += (msg) => { var _ = MessageReceived(msg).CatchException(HandleRuntimeError); return Task.CompletedTask; };
_client.ReactionAdded += (message, channel, reaction) => { var _ = _proxy.HandleReactionAddedAsync(message, channel, reaction).CatchException(HandleRuntimeError); return Task.CompletedTask; };
_client.MessageDeleted += (message, channel) => { var _ = _proxy.HandleMessageDeletedAsync(message, channel).CatchException(HandleRuntimeError); return Task.CompletedTask; };
_client.MessagesBulkDeleted += (messages, channel) => { var _ = _proxy.HandleMessageBulkDeleteAsync(messages, channel).CatchException(HandleRuntimeError); return Task.CompletedTask; };
_client.Log += FrameworkLog; _client.Log += FrameworkLog;
_client.MessageReceived += (msg) => HandleEvent(s => s.AddMessageBreadcrumb(msg), eh => eh.HandleMessage(msg));
_client.ReactionAdded += (msg, channel, reaction) => HandleEvent(s => s.AddReactionAddedBreadcrumb(msg, channel, reaction), eh => eh.HandleReactionAdded(msg, channel, reaction));
_client.MessageDeleted += (msg, channel) => HandleEvent(s => s.AddMessageDeleteBreadcrumb(msg, channel), eh => eh.HandleMessageDeleted(msg, channel));
_client.MessagesBulkDeleted += (msgs, channel) => HandleEvent(s => s.AddMessageBulkDeleteBreadcrumb(msgs, channel), eh => eh.HandleMessagesBulkDelete(msgs, channel));
} }
private Task FrameworkLog(LogMessage msg) private Task FrameworkLog(LogMessage msg)
{ {
// Bridge D.NET logging to Serilog // Bridge D.NET logging to Serilog
LogEventLevel level = LogEventLevel.Verbose; LogEventLevel level = LogEventLevel.Verbose;
switch (msg.Severity) if (msg.Severity == LogSeverity.Critical)
{
case LogSeverity.Critical:
level = LogEventLevel.Fatal; level = LogEventLevel.Fatal;
break; else if (msg.Severity == LogSeverity.Debug)
case LogSeverity.Debug:
level = LogEventLevel.Debug; level = LogEventLevel.Debug;
break; else if (msg.Severity == LogSeverity.Error)
case LogSeverity.Error:
level = LogEventLevel.Error; level = LogEventLevel.Error;
break; else if (msg.Severity == LogSeverity.Info)
case LogSeverity.Info:
level = LogEventLevel.Information; level = LogEventLevel.Information;
break; else if (msg.Severity == LogSeverity.Verbose)
case LogSeverity.Verbose:
level = LogEventLevel.Verbose; level = LogEventLevel.Verbose;
break; else if (msg.Severity == LogSeverity.Warning)
case LogSeverity.Warning:
level = LogEventLevel.Warning; level = LogEventLevel.Warning;
break;
}
_logger.Write(level, msg.Exception, "Discord.Net {Source}: {Message}", msg.Source, msg.Message); _logger.Write(level, msg.Exception, "Discord.Net {Source}: {Message}", msg.Source, msg.Message);
return Task.CompletedTask; return Task.CompletedTask;
@ -216,7 +210,9 @@ namespace PluralKit.Bot
if (shardClient.ShardId == 0) if (shardClient.ShardId == 0)
{ {
_updateTimer = new Timer((_) => UpdatePeriodic().CatchException(HandleRuntimeError), null, 0, 60*1000); _updateTimer = new Timer((_) => {
HandleEvent(s => s.AddPeriodicBreadcrumb(), __ => UpdatePeriodic());
}, null, TimeSpan.Zero, TimeSpan.FromMinutes(1));
Console.WriteLine( Console.WriteLine(
$"PluralKit started as {_client.CurrentUser.Username}#{_client.CurrentUser.Discriminator} ({_client.CurrentUser.Id})."); $"PluralKit started as {_client.CurrentUser.Username}#{_client.CurrentUser.Discriminator} ({_client.CurrentUser.Id}).");
@ -243,7 +239,7 @@ namespace PluralKit.Bot
{ {
await ctx.Message.Channel.SendMessageAsync($"{Emojis.Error} {_result.ErrorReason}"); await ctx.Message.Channel.SendMessageAsync($"{Emojis.Error} {_result.ErrorReason}");
} else { } else {
HandleRuntimeError((_result as ExecuteResult?)?.Exception); HandleRuntimeError((_result as ExecuteResult?)?.Exception, ((PKCommandContext) ctx).ServiceProvider.GetRequiredService<Scope>());
} }
} else if ((_result.Error == CommandError.BadArgCount || _result.Error == CommandError.MultipleMatches) && cmd.IsSpecified) { } else if ((_result.Error == CommandError.BadArgCount || _result.Error == CommandError.MultipleMatches) && cmd.IsSpecified) {
await ctx.Message.Channel.SendMessageAsync($"{Emojis.Error} {_result.ErrorReason}\n**Usage: **pk;{cmd.Value.Remarks}"); await ctx.Message.Channel.SendMessageAsync($"{Emojis.Error} {_result.ErrorReason}\n**Usage: **pk;{cmd.Value.Remarks}");
@ -253,7 +249,68 @@ namespace PluralKit.Bot
} }
} }
private async Task MessageReceived(SocketMessage _arg) private Task HandleEvent(Action<Scope> breadcrumbFactory, Func<PKEventHandler, Task> handler)
{
// Inner function so we can await the handler without stalling the entire pipeline
async Task Inner()
{
// Create a DI scope for this event
// and log the breadcrumb to the newly created (in-svc-scope) Sentry scope
using (var scope = _services.CreateScope())
{
var sentryScope = scope.ServiceProvider.GetRequiredService<Scope>();
breadcrumbFactory(sentryScope);
try
{
await handler(scope.ServiceProvider.GetRequiredService<PKEventHandler>());
}
catch (Exception e)
{
HandleRuntimeError(e, sentryScope);
}
}
}
#pragma warning disable 4014
Inner();
#pragma warning restore 4014
return Task.CompletedTask;
}
private void HandleRuntimeError(Exception e, Scope scope = null)
{
_logger.Error(e, "Exception in bot event handler");
var evt = new SentryEvent(e);
SentrySdk.CaptureEvent(evt, scope);
Console.Error.WriteLine(e);
}
}
class PKEventHandler {
private CommandService _commands;
private ProxyService _proxy;
private ILogger _logger;
private IMetrics _metrics;
private DiscordShardedClient _client;
private DbConnectionFactory _connectionFactory;
private IServiceProvider _services;
public PKEventHandler(CommandService commands, ProxyService proxy, ILogger logger, IMetrics metrics, IDiscordClient client, DbConnectionFactory connectionFactory, IServiceProvider services)
{
_commands = commands;
_proxy = proxy;
_logger = logger;
_metrics = metrics;
_client = (DiscordShardedClient) client;
_connectionFactory = connectionFactory;
_services = services;
}
public async Task HandleMessage(SocketMessage msg)
{ {
_metrics.Measure.Meter.Mark(BotMetrics.MessagesReceived); _metrics.Measure.Meter.Mark(BotMetrics.MessagesReceived);
@ -262,17 +319,8 @@ namespace PluralKit.Bot
// until we properly connect. TODO: can we do this without chucking away a bunch of messages? // until we properly connect. TODO: can we do this without chucking away a bunch of messages?
if (_client.CurrentUser == null) return; if (_client.CurrentUser == null) return;
using (var serviceScope = _services.CreateScope())
{
SentrySdk.AddBreadcrumb(message: _arg.Content, category: "event.message", data: new Dictionary<string, string>()
{
{"user", _arg.Author.Id.ToString()},
{"channel", _arg.Channel.Id.ToString()},
{"guild", ((_arg.Channel as IGuildChannel)?.GuildId ?? 0).ToString()}
});
// Ignore system messages (member joined, message pinned, etc) // Ignore system messages (member joined, message pinned, etc)
var arg = _arg as SocketUserMessage; var arg = msg as SocketUserMessage;
if (arg == null) return; if (arg == null) return;
// Ignore bot messages // Ignore bot messages
@ -293,12 +341,12 @@ namespace PluralKit.Bot
// and start command execution // and start command execution
// Note system may be null if user has no system, hence `OrDefault` // Note system may be null if user has no system, hence `OrDefault`
PKSystem system; PKSystem system;
using (var conn = await serviceScope.ServiceProvider.GetService<DbConnectionFactory>().Obtain()) using (var conn = await _connectionFactory.Obtain())
system = await conn.QueryFirstOrDefaultAsync<PKSystem>( system = await conn.QueryFirstOrDefaultAsync<PKSystem>(
"select systems.* from systems, accounts where accounts.uid = @Id and systems.id = accounts.system", "select systems.* from systems, accounts where accounts.uid = @Id and systems.id = accounts.system",
new {Id = arg.Author.Id}); new {Id = arg.Author.Id});
await _commands.ExecuteAsync(new PKCommandContext(_client, arg, system), argPos, await _commands.ExecuteAsync(new PKCommandContext(_client, arg, system, _services), argPos,
serviceScope.ServiceProvider); _services);
} }
else else
{ {
@ -306,13 +354,14 @@ namespace PluralKit.Bot
await _proxy.HandleMessageAsync(arg); await _proxy.HandleMessageAsync(arg);
} }
} }
}
private void HandleRuntimeError(Exception e) public Task HandleReactionAdded(Cacheable<IUserMessage, ulong> message, ISocketMessageChannel channel,
{ SocketReaction reaction) => _proxy.HandleReactionAddedAsync(message, channel, reaction);
_logger.Error(e, "Exception in bot event handler");
SentrySdk.CaptureException(e); public Task HandleMessageDeleted(Cacheable<IMessage, ulong> message, ISocketMessageChannel channel) =>
Console.Error.WriteLine(e); _proxy.HandleMessageDeletedAsync(message, channel);
}
public Task HandleMessagesBulkDelete(IReadOnlyCollection<Cacheable<IMessage, ulong>> messages,
IMessageChannel channel) => _proxy.HandleMessageBulkDeleteAsync(messages, channel);
} }
} }

View File

@ -0,0 +1,59 @@
using System.Collections.Generic;
using System.Linq;
using Discord;
using Discord.WebSocket;
using Sentry;
namespace PluralKit.Bot
{
public static class BreadcrumbExtensions
{
public static void AddMessageBreadcrumb(this Scope scope, SocketMessage msg)
{
scope.AddBreadcrumb(msg.Content, "event.message", data: new Dictionary<string, string>()
{
{"user", msg.Author.Id.ToString()},
{"channel", msg.Channel.Id.ToString()},
{"guild", ((msg.Channel as IGuildChannel)?.GuildId ?? 0).ToString()},
{"message", msg.Id.ToString()},
});
}
public static void AddReactionAddedBreadcrumb(this Scope scope, Cacheable<IUserMessage, ulong> message,
ISocketMessageChannel channel, SocketReaction reaction)
{
scope.AddBreadcrumb("", "event.reaction", data: new Dictionary<string, string>()
{
{"user", reaction.UserId.ToString()},
{"channel", channel.Id.ToString()},
{"guild", ((channel as IGuildChannel)?.GuildId ?? 0).ToString()},
{"message", message.Id.ToString()},
{"reaction", reaction.Emote.Name}
});
}
public static void AddMessageDeleteBreadcrumb(this Scope scope, Cacheable<IMessage, ulong> message,
ISocketMessageChannel channel)
{
scope.AddBreadcrumb("", "event.messageDelete", data: new Dictionary<string, string>()
{
{"channel", channel.Id.ToString()},
{"guild", ((channel as IGuildChannel)?.GuildId ?? 0).ToString()},
{"message", message.Id.ToString()},
});
}
public static void AddMessageBulkDeleteBreadcrumb(this Scope scope, IReadOnlyCollection<Cacheable<IMessage, ulong>> messages,
ISocketMessageChannel channel)
{
scope.AddBreadcrumb("", "event.messageDelete", data: new Dictionary<string, string>()
{
{"channel", channel.Id.ToString()},
{"guild", ((channel as IGuildChannel)?.GuildId ?? 0).ToString()},
{"messages", string.Join(",", messages.Select(m => m.Id))},
});
}
public static void AddPeriodicBreadcrumb(this Scope scope) => scope.AddBreadcrumb("", "periodic");
}
}

View File

@ -171,12 +171,14 @@ namespace PluralKit.Bot
public class PKCommandContext : ShardedCommandContext public class PKCommandContext : ShardedCommandContext
{ {
public PKSystem SenderSystem { get; } public PKSystem SenderSystem { get; }
public IServiceProvider ServiceProvider { get; }
private object _entity; private object _entity;
public PKCommandContext(DiscordShardedClient client, SocketUserMessage msg, PKSystem system) : base(client, msg) public PKCommandContext(DiscordShardedClient client, SocketUserMessage msg, PKSystem system, IServiceProvider serviceProvider) : base(client, msg)
{ {
SenderSystem = system; SenderSystem = system;
ServiceProvider = serviceProvider;
} }
public T GetContextEntity<T>() where T: class { public T GetContextEntity<T>() where T: class {