diff --git a/src/Octobot.cs b/src/Octobot.cs index 2e810ed..063bd14 100644 --- a/src/Octobot.cs +++ b/src/Octobot.cs @@ -4,6 +4,7 @@ using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Octobot.Commands.Events; using Octobot.Services; +using Octobot.Services.Profiler; using Octobot.Services.Update; using Remora.Discord.API.Abstractions.Gateway.Commands; using Remora.Discord.API.Abstractions.Objects; @@ -86,6 +87,8 @@ public sealed class Octobot .AddPreparationErrorEvent() .AddPostExecutionEvent() // Services + .AddTransient() + .AddSingleton() .AddSingleton() .AddSingleton() .AddHostedService(provider => provider.GetRequiredService()) diff --git a/src/Services/Profiler/Profiler.cs b/src/Services/Profiler/Profiler.cs new file mode 100644 index 0000000..8d4ca98 --- /dev/null +++ b/src/Services/Profiler/Profiler.cs @@ -0,0 +1,114 @@ +using System.Diagnostics; +using System.Text; +using Microsoft.Extensions.Logging; +using Remora.Results; + +// TODO: remove in future profiler PRs +// ReSharper disable All + +namespace Octobot.Services.Profiler; + +/// +/// Provides the ability to profile how long certain parts of code take to complete using es. +/// +/// Resolve instead in singletons. +public sealed class Profiler +{ + private const int MaxProfilerTime = 1000; // milliseconds + private readonly List _events = []; + private readonly ILogger _logger; + + public Profiler(ILogger logger) + { + _logger = logger; + } + + /// + /// Pushes an event to the profiler. + /// + /// The ID of the event. + public void Push(string id) + { + _events.Add(new ProfilerEvent + { + Id = id, + Stopwatch = Stopwatch.StartNew() + }); + } + + /// + /// Pops the last pushed event from the profiler. + /// + /// Thrown if the profiler contains no events. + public void Pop() + { + if (_events.Count is 0) + { + throw new InvalidOperationException("Nothing to pop"); + } + + _events.Last().Stopwatch.Stop(); + } + + /// + /// If the profiler took too long to execute, this will log a warning with per-event time usage + /// + /// + private void Report() + { + var main = _events[0]; + if (main.Stopwatch.ElapsedMilliseconds < MaxProfilerTime) + { + return; + } + + var unprofiled = main.Stopwatch.ElapsedMilliseconds; + var builder = new StringBuilder().AppendLine(); + for (var i = 1; i < _events.Count; i++) + { + var profilerEvent = _events[i]; + if (profilerEvent.Stopwatch.IsRunning) + { + throw new InvalidOperationException( + $"Tried to report on a profiler with running stopwatches: {profilerEvent.Id}"); + } + + builder.AppendLine($"{profilerEvent.Id}: {profilerEvent.Stopwatch.ElapsedMilliseconds}ms"); + unprofiled -= profilerEvent.Stopwatch.ElapsedMilliseconds; + } + + builder.AppendLine($": {unprofiled}ms"); + + _logger.LogWarning("Profiler {ID} took {Elapsed} milliseconds to execute (max: {Max}ms):{Events}", main.Id, + main.Stopwatch.ElapsedMilliseconds, MaxProfilerTime, builder.ToString()); + } + + /// + /// the profiler and on it afterwards. + /// + public void PopAndReport() + { + Pop(); + Report(); + } + + /// + /// on the profiler and return a . + /// + /// + /// + public Result ReportWithResult(Result result) + { + PopAndReport(); + return result; + } + + /// + /// Calls with + /// + /// A successful result. + public Result ReportWithSuccess() + { + return ReportWithResult(Result.FromSuccess()); + } +} diff --git a/src/Services/Profiler/ProfilerEvent.cs b/src/Services/Profiler/ProfilerEvent.cs new file mode 100644 index 0000000..f655fc4 --- /dev/null +++ b/src/Services/Profiler/ProfilerEvent.cs @@ -0,0 +1,9 @@ +using System.Diagnostics; + +namespace Octobot.Services.Profiler; + +public struct ProfilerEvent +{ + public string Id { get; init; } + public Stopwatch Stopwatch { get; init; } +} diff --git a/src/Services/Profiler/ProfilerFactory.cs b/src/Services/Profiler/ProfilerFactory.cs new file mode 100644 index 0000000..0135771 --- /dev/null +++ b/src/Services/Profiler/ProfilerFactory.cs @@ -0,0 +1,27 @@ +using Microsoft.Extensions.DependencyInjection; + +namespace Octobot.Services.Profiler; + +/// +/// Provides a method to create a . Useful in singletons. +/// +public sealed class ProfilerFactory +{ + private readonly IServiceScopeFactory _scopeFactory; + + public ProfilerFactory(IServiceScopeFactory scopeFactory) + { + _scopeFactory = scopeFactory; + } + + /// + /// Creates a new . + /// + /// A new . + // TODO: remove in future profiler PRs + // ReSharper disable once UnusedMember.Global + public Profiler Create() + { + return _scopeFactory.CreateScope().ServiceProvider.GetRequiredService(); + } +}