From 84973ce5727ad20fe8b8ba4f89e59c8b754f799e Mon Sep 17 00:00:00 2001 From: Drachenkaetzchen Date: Wed, 15 Jan 2020 19:08:50 +0100 Subject: Added peak execution time over the last 60 seconds --- .../Commands/Other/PerformanceCounterCommand.cs | 12 ++++-- .../Framework/PerformanceCounter/PeakEntry.cs | 24 +++++++++++ .../PerformanceCounter/PerformanceCounter.cs | 20 +++++++++ .../PerformanceCounterCollection.cs | 47 ++++++++++++++++++---- .../PerformanceCounterManager.cs | 5 +++ 5 files changed, 96 insertions(+), 12 deletions(-) create mode 100644 src/SMAPI/Framework/PerformanceCounter/PeakEntry.cs (limited to 'src') diff --git a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs index f096614f..d49fc537 100644 --- a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs +++ b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs @@ -118,17 +118,20 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands.Other StringBuilder sb = new StringBuilder(); + TimeSpan peakSpan = TimeSpan.FromSeconds(60); + sb.AppendLine("Summary:"); sb.AppendLine(this.GetTableString( data: data, - header: new[] {"Collection", "Avg Calls/s", "Avg Execution Time (Game)", "Avg Execution Time (Mods)", "Avg Execution Time (Game+Mods)"}, + header: new[] {"Collection", "Avg Calls/s", "Avg Exec Time (Game)", "Avg Exec Time (Mods)", "Avg Exec Time (Game+Mods)", "Peak Exec Time (60s)"}, getRow: item => new[] { item.Name, item.GetAverageCallsPerSecond().ToString(), this.FormatMilliseconds(item.GetGameAverageExecutionTime(), threshold), this.FormatMilliseconds(item.GetModsAverageExecutionTime(), threshold), - this.FormatMilliseconds(item.GetAverageExecutionTime(), threshold) + this.FormatMilliseconds(item.GetAverageExecutionTime(), threshold), + this.FormatMilliseconds(item.GetPeakExecutionTime(peakSpan), threshold) }, true )); @@ -459,13 +462,14 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands.Other { sb.AppendLine(this.GetTableString( data: data, - header: new[] {"Mod", $"Avg Execution Time (last {(int) averageInterval.TotalSeconds}s)", "Last Execution Time", "Peak Execution Time"}, + header: new[] {"Mod", $"Avg Exec Time (last {(int) averageInterval.TotalSeconds}s)", "Last Exec Time", "Peak Exec Time", $"Peak Exec Time (last {(int) averageInterval.TotalSeconds}s)"}, getRow: item => new[] { item.Key, this.FormatMilliseconds(item.Value.GetAverage(averageInterval), thresholdMilliseconds), this.FormatMilliseconds(item.Value.GetLastEntry()?.ElapsedMilliseconds), - this.FormatMilliseconds(item.Value.GetPeak()?.ElapsedMilliseconds) + this.FormatMilliseconds(item.Value.GetPeak()?.ElapsedMilliseconds), + this.FormatMilliseconds(item.Value.GetPeak(averageInterval)?.ElapsedMilliseconds) }, true )); diff --git a/src/SMAPI/Framework/PerformanceCounter/PeakEntry.cs b/src/SMAPI/Framework/PerformanceCounter/PeakEntry.cs new file mode 100644 index 00000000..95dc11f4 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceCounter/PeakEntry.cs @@ -0,0 +1,24 @@ +using System; +using System.Collections.Generic; + +namespace StardewModdingAPI.Framework.PerformanceCounter +{ + internal struct PeakEntry + { + /// The actual execution time in milliseconds. + public readonly double ExecutionTimeMilliseconds; + + /// The DateTime when the entry occured. + public DateTime EventTime; + + /// The context list, which records all sources involved in exceeding the threshold. + public readonly List Context; + + public PeakEntry(double executionTimeMilliseconds, DateTime eventTime, List context) + { + this.ExecutionTimeMilliseconds = executionTimeMilliseconds; + this.EventTime = eventTime; + this.Context = context; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs index 33ddde2f..3d902e16 100644 --- a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs @@ -68,6 +68,26 @@ namespace StardewModdingAPI.Framework.PerformanceCounter return this.PeakPerformanceCounterEntry; } + /// Returns the peak entry. + /// The peak entry. + public PerformanceCounterEntry? GetPeak(TimeSpan range, DateTime? relativeTo = null) + { + if (this._counter.IsEmpty) + return null; + + if (relativeTo == null) + relativeTo = DateTime.UtcNow; + + DateTime start = relativeTo.Value.Subtract(range); + + var entries = this._counter.Where(x => (x.EventTime >= start) && (x.EventTime <= relativeTo)).ToList(); + + if (!entries.Any()) + return null; + + return entries.OrderByDescending(x => x.ElapsedMilliseconds).First(); + } + /// Resets the peak entry. public void ResetPeak() { diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs index b48efd67..fe14ebf8 100644 --- a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs @@ -2,11 +2,15 @@ using System; using System.Collections.Generic; using System.Diagnostics; using System.Linq; +using Cyotek.Collections.Generic; namespace StardewModdingAPI.Framework.PerformanceCounter { internal class PerformanceCounterCollection { + /// The size of the ring buffer. + private const int MAX_ENTRIES = 16384; + /// The list of triggered performance counters. private readonly List TriggeredPerformanceCounters = new List(); @@ -22,6 +26,10 @@ namespace StardewModdingAPI.Framework.PerformanceCounter /// The number of invocations of this collection. private long CallCount; + /// The circular buffer which stores all peak invocations + private readonly CircularBuffer PeakInvocations; + + /// The associated performance counters. public IDictionary PerformanceCounters { get; } = new Dictionary(); /// The name of this collection. @@ -39,6 +47,7 @@ namespace StardewModdingAPI.Framework.PerformanceCounter public PerformanceCounterCollection(PerformanceCounterManager performanceCounterManager, string name, bool isImportant) { + this.PeakInvocations = new CircularBuffer(PerformanceCounterCollection.MAX_ENTRIES); this.Name = name; this.PerformanceCounterManager = performanceCounterManager; this.IsImportant = isImportant; @@ -46,6 +55,7 @@ namespace StardewModdingAPI.Framework.PerformanceCounter public PerformanceCounterCollection(PerformanceCounterManager performanceCounterManager, string name) { + this.PeakInvocations = new CircularBuffer(PerformanceCounterCollection.MAX_ENTRIES); this.PerformanceCounterManager = performanceCounterManager; this.Name = name; } @@ -89,15 +99,30 @@ namespace StardewModdingAPI.Framework.PerformanceCounter return 0; } + public double GetPeakExecutionTime(TimeSpan range, DateTime? relativeTo = null) + { + if (this.PeakInvocations.IsEmpty) + return 0; + + if (relativeTo == null) + relativeTo = DateTime.UtcNow; + + DateTime start = relativeTo.Value.Subtract(range); + + var entries = this.PeakInvocations.Where(x => (x.EventTime >= start) && (x.EventTime <= relativeTo)).ToList(); + + if (!entries.Any()) + return 0; + + return entries.OrderByDescending(x => x.ExecutionTimeMilliseconds).First().ExecutionTimeMilliseconds; + } + /// Begins tracking the invocation of this collection. public void BeginTrackInvocation() { - if (this.EnableAlerts) - { - this.TriggeredPerformanceCounters.Clear(); - this.InvocationStopwatch.Reset(); - this.InvocationStopwatch.Start(); - } + this.TriggeredPerformanceCounters.Clear(); + this.InvocationStopwatch.Reset(); + this.InvocationStopwatch.Start(); this.CallCount++; } @@ -106,10 +131,15 @@ namespace StardewModdingAPI.Framework.PerformanceCounter /// and the invocation time exceeds the threshold. public void EndTrackInvocation() { - if (!this.EnableAlerts) return; - this.InvocationStopwatch.Stop(); + this.PeakInvocations.Put( + new PeakEntry(this.InvocationStopwatch.Elapsed.TotalMilliseconds, + DateTime.UtcNow, + this.TriggeredPerformanceCounters)); + + if (!this.EnableAlerts) return; + if (this.InvocationStopwatch.Elapsed.TotalMilliseconds >= this.AlertThresholdMilliseconds) this.AddAlert(this.InvocationStopwatch.Elapsed.TotalMilliseconds, this.AlertThresholdMilliseconds, this.TriggeredPerformanceCounters); @@ -144,6 +174,7 @@ namespace StardewModdingAPI.Framework.PerformanceCounter /// Resets all performance counters in this collection. public void Reset() { + this.PeakInvocations.Clear(); foreach (var i in this.PerformanceCounters) i.Value.Reset(); } diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs index 49720431..a8e20eda 100644 --- a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs @@ -33,6 +33,11 @@ namespace StardewModdingAPI.Framework.PerformanceCounter /// Resets all performance counters in all collections. public void Reset() { + foreach (PerformanceCounterCollection collection in this.PerformanceCounterCollections) + { + collection.Reset(); + } + foreach (var eventPerformanceCounter in this.PerformanceCounterCollections.SelectMany(performanceCounter => performanceCounter.PerformanceCounters)) { -- cgit