diff options
Diffstat (limited to 'src/SMAPI/Framework/PerformanceMonitoring')
7 files changed, 651 insertions, 0 deletions
diff --git a/src/SMAPI/Framework/PerformanceMonitoring/AlertContext.cs b/src/SMAPI/Framework/PerformanceMonitoring/AlertContext.cs new file mode 100644 index 00000000..01197f74 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/AlertContext.cs @@ -0,0 +1,34 @@ +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>The context for an alert.</summary> + internal struct AlertContext + { + /********* + ** Accessors + *********/ + /// <summary>The source which triggered the alert.</summary> + public string Source { get; } + + /// <summary>The elapsed milliseconds.</summary> + public double Elapsed { get; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="source">The source which triggered the alert.</param> + /// <param name="elapsed">The elapsed milliseconds.</param> + public AlertContext(string source, double elapsed) + { + this.Source = source; + this.Elapsed = elapsed; + } + + /// <summary>Get a human-readable text form of this instance.</summary> + public override string ToString() + { + return $"{this.Source}: {this.Elapsed:F2}ms"; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/AlertEntry.cs b/src/SMAPI/Framework/PerformanceMonitoring/AlertEntry.cs new file mode 100644 index 00000000..f5b80189 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/AlertEntry.cs @@ -0,0 +1,38 @@ +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>A single alert entry.</summary> + internal struct AlertEntry + { + /********* + ** Accessors + *********/ + /// <summary>The collection in which the alert occurred.</summary> + public PerformanceCounterCollection Collection { get; } + + /// <summary>The actual execution time in milliseconds.</summary> + public double ExecutionTimeMilliseconds { get; } + + /// <summary>The configured alert threshold in milliseconds.</summary> + public double ThresholdMilliseconds { get; } + + /// <summary>The sources involved in exceeding the threshold.</summary> + public AlertContext[] Context { get; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="collection">The collection in which the alert occurred.</param> + /// <param name="executionTimeMilliseconds">The actual execution time in milliseconds.</param> + /// <param name="thresholdMilliseconds">The configured alert threshold in milliseconds.</param> + /// <param name="context">The sources involved in exceeding the threshold.</param> + public AlertEntry(PerformanceCounterCollection collection, double executionTimeMilliseconds, double thresholdMilliseconds, AlertContext[] context) + { + this.Collection = collection; + this.ExecutionTimeMilliseconds = executionTimeMilliseconds; + this.ThresholdMilliseconds = thresholdMilliseconds; + this.Context = context; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/PeakEntry.cs b/src/SMAPI/Framework/PerformanceMonitoring/PeakEntry.cs new file mode 100644 index 00000000..cff502ad --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/PeakEntry.cs @@ -0,0 +1,35 @@ +using System; + +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>A peak invocation time.</summary> + internal struct PeakEntry + { + /********* + ** Accessors + *********/ + /// <summary>The actual execution time in milliseconds.</summary> + public double ExecutionTimeMilliseconds { get; } + + /// <summary>When the entry occurred.</summary> + public DateTime EventTime { get; } + + /// <summary>The sources involved in exceeding the threshold.</summary> + public AlertContext[] Context { get; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="executionTimeMilliseconds">The actual execution time in milliseconds.</param> + /// <param name="eventTime">When the entry occurred.</param> + /// <param name="context">The sources involved in exceeding the threshold.</param> + public PeakEntry(double executionTimeMilliseconds, DateTime eventTime, AlertContext[] context) + { + this.ExecutionTimeMilliseconds = executionTimeMilliseconds; + this.EventTime = eventTime; + this.Context = context; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounter.cs b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounter.cs new file mode 100644 index 00000000..3cf668ee --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounter.cs @@ -0,0 +1,125 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using Harmony; + +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>Tracks metadata about a particular code event.</summary> + internal class PerformanceCounter + { + /********* + ** Fields + *********/ + /// <summary>The size of the ring buffer.</summary> + private readonly int MaxEntries = 16384; + + /// <summary>The collection to which this performance counter belongs.</summary> + private readonly PerformanceCounterCollection ParentCollection; + + /// <summary>The performance counter entries.</summary> + private readonly Stack<PerformanceCounterEntry> Entries; + + /// <summary>The entry with the highest execution time.</summary> + private PerformanceCounterEntry? PeakPerformanceCounterEntry; + + + /********* + ** Accessors + *********/ + /// <summary>The name of the source.</summary> + public string Source { get; } + + /// <summary>The alert threshold in milliseconds</summary> + public double AlertThresholdMilliseconds { get; set; } + + /// <summary>If alerting is enabled or not</summary> + public bool EnableAlerts { get; set; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="parentCollection">The collection to which this performance counter belongs.</param> + /// <param name="source">The name of the source.</param> + public PerformanceCounter(PerformanceCounterCollection parentCollection, string source) + { + this.ParentCollection = parentCollection; + this.Source = source; + this.Entries = new Stack<PerformanceCounterEntry>(this.MaxEntries); + } + + /// <summary>Add a performance counter entry to the list, update monitoring, and raise alerts if needed.</summary> + /// <param name="entry">The entry to add.</param> + public void Add(PerformanceCounterEntry entry) + { + // add entry + if (this.Entries.Count > this.MaxEntries) + this.Entries.Pop(); + this.Entries.Add(entry); + + // update metrics + if (this.PeakPerformanceCounterEntry == null || entry.ElapsedMilliseconds > this.PeakPerformanceCounterEntry.Value.ElapsedMilliseconds) + this.PeakPerformanceCounterEntry = entry; + + // raise alert + if (this.EnableAlerts && entry.ElapsedMilliseconds > this.AlertThresholdMilliseconds) + this.ParentCollection.AddAlert(entry.ElapsedMilliseconds, this.AlertThresholdMilliseconds, new AlertContext(this.Source, entry.ElapsedMilliseconds)); + } + + /// <summary>Clear all performance counter entries and monitoring.</summary> + public void Reset() + { + this.Entries.Clear(); + this.PeakPerformanceCounterEntry = null; + } + + /// <summary>Get the peak entry.</summary> + public PerformanceCounterEntry? GetPeak() + { + return this.PeakPerformanceCounterEntry; + } + + /// <summary>Get the entry with the highest execution time.</summary> + /// <param name="range">The time range to search.</param> + /// <param name="endTime">The end time for the <paramref name="range"/>, or null for the current time.</param> + public PerformanceCounterEntry? GetPeak(TimeSpan range, DateTime? endTime = null) + { + endTime ??= DateTime.UtcNow; + DateTime startTime = endTime.Value.Subtract(range); + + return this.Entries + .Where(entry => entry.EventTime >= startTime && entry.EventTime <= endTime) + .OrderByDescending(x => x.ElapsedMilliseconds) + .FirstOrDefault(); + } + + /// <summary>Get the last entry added to the list.</summary> + public PerformanceCounterEntry? GetLastEntry() + { + if (this.Entries.Count == 0) + return null; + + return this.Entries.Peek(); + } + + /// <summary>Get the average over a given time span.</summary> + /// <param name="range">The time range to search.</param> + /// <param name="endTime">The end time for the <paramref name="range"/>, or null for the current time.</param> + public double GetAverage(TimeSpan range, DateTime? endTime = null) + { + endTime ??= DateTime.UtcNow; + DateTime startTime = endTime.Value.Subtract(range); + + double[] entries = this.Entries + .Where(entry => entry.EventTime >= startTime && entry.EventTime <= endTime) + .Select(p => p.ElapsedMilliseconds) + .ToArray(); + + return entries.Length > 0 + ? entries.Average() + : 0; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterCollection.cs b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterCollection.cs new file mode 100644 index 00000000..0bb78c74 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterCollection.cs @@ -0,0 +1,205 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; + +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + internal class PerformanceCounterCollection + { + /********* + ** Fields + *********/ + /// <summary>The number of peak invocations to keep.</summary> + private readonly int MaxEntries = 16384; + + /// <summary>The sources involved in exceeding alert thresholds.</summary> + private readonly List<AlertContext> TriggeredPerformanceCounters = new List<AlertContext>(); + + /// <summary>The stopwatch used to track the invocation time.</summary> + private readonly Stopwatch InvocationStopwatch = new Stopwatch(); + + /// <summary>The performance counter manager.</summary> + private readonly PerformanceMonitor PerformanceMonitor; + + /// <summary>The time to calculate average calls per second.</summary> + private DateTime CallsPerSecondStart = DateTime.UtcNow; + + /// <summary>The number of invocations.</summary> + private long CallCount; + + /// <summary>The peak invocations.</summary> + private readonly Stack<PeakEntry> PeakInvocations; + + + /********* + ** Accessors + *********/ + /// <summary>The associated performance counters.</summary> + public IDictionary<string, PerformanceCounter> PerformanceCounters { get; } = new Dictionary<string, PerformanceCounter>(); + + /// <summary>The name of this collection.</summary> + public string Name { get; } + + /// <summary>Whether the source is typically invoked at least once per second.</summary> + public bool IsPerformanceCritical { get; } + + /// <summary>The alert threshold in milliseconds.</summary> + public double AlertThresholdMilliseconds { get; set; } + + /// <summary>Whether alerts are enabled.</summary> + public bool EnableAlerts { get; set; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="performanceMonitor">The performance counter manager.</param> + /// <param name="name">The name of this collection.</param> + /// <param name="isPerformanceCritical">Whether the source is typically invoked at least once per second.</param> + public PerformanceCounterCollection(PerformanceMonitor performanceMonitor, string name, bool isPerformanceCritical = false) + { + this.PeakInvocations = new Stack<PeakEntry>(this.MaxEntries); + this.Name = name; + this.PerformanceMonitor = performanceMonitor; + this.IsPerformanceCritical = isPerformanceCritical; + } + + /// <summary>Track a single invocation for a named source.</summary> + /// <param name="source">The name of the source.</param> + /// <param name="entry">The entry.</param> + public void Track(string source, PerformanceCounterEntry entry) + { + // add entry + if (!this.PerformanceCounters.ContainsKey(source)) + this.PerformanceCounters.Add(source, new PerformanceCounter(this, source)); + this.PerformanceCounters[source].Add(entry); + + // raise alert + if (this.EnableAlerts) + this.TriggeredPerformanceCounters.Add(new AlertContext(source, entry.ElapsedMilliseconds)); + } + + /// <summary>Get the average execution time for all non-game internal sources in milliseconds.</summary> + /// <param name="interval">The interval for which to get the average, relative to now</param> + public double GetModsAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters + .Where(entry => entry.Key != Constants.GamePerformanceCounterName) + .Sum(entry => entry.Value.GetAverage(interval)); + } + + /// <summary>Get the overall average execution time in milliseconds.</summary> + /// <param name="interval">The interval for which to get the average, relative to now</param> + public double GetAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters + .Sum(entry => entry.Value.GetAverage(interval)); + } + + /// <summary>Get the average execution time for game-internal sources in milliseconds.</summary> + public double GetGameAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters.TryGetValue(Constants.GamePerformanceCounterName, out PerformanceCounter gameExecTime) + ? gameExecTime.GetAverage(interval) + : 0; + } + + /// <summary>Get the peak execution time in milliseconds.</summary> + /// <param name="range">The time range to search.</param> + /// <param name="endTime">The end time for the <paramref name="range"/>, or null for the current time.</param> + public double GetPeakExecutionTime(TimeSpan range, DateTime? endTime = null) + { + if (this.PeakInvocations.Count == 0) + return 0; + + endTime ??= DateTime.UtcNow; + DateTime startTime = endTime.Value.Subtract(range); + + return this.PeakInvocations + .Where(entry => entry.EventTime >= startTime && entry.EventTime <= endTime) + .OrderByDescending(x => x.ExecutionTimeMilliseconds) + .Select(p => p.ExecutionTimeMilliseconds) + .FirstOrDefault(); + } + + /// <summary>Start tracking the invocation of this collection.</summary> + public void BeginTrackInvocation() + { + this.TriggeredPerformanceCounters.Clear(); + this.InvocationStopwatch.Reset(); + this.InvocationStopwatch.Start(); + + this.CallCount++; + } + + /// <summary>End tracking the invocation of this collection, and raise an alert if needed.</summary> + public void EndTrackInvocation() + { + this.InvocationStopwatch.Stop(); + + // add invocation + if (this.PeakInvocations.Count >= this.MaxEntries) + this.PeakInvocations.Pop(); + this.PeakInvocations.Push(new PeakEntry(this.InvocationStopwatch.Elapsed.TotalMilliseconds, DateTime.UtcNow, this.TriggeredPerformanceCounters.ToArray())); + + // raise alert + if (this.EnableAlerts && this.InvocationStopwatch.Elapsed.TotalMilliseconds >= this.AlertThresholdMilliseconds) + this.AddAlert(this.InvocationStopwatch.Elapsed.TotalMilliseconds, this.AlertThresholdMilliseconds, this.TriggeredPerformanceCounters.ToArray()); + } + + /// <summary>Add an alert.</summary> + /// <param name="executionTimeMilliseconds">The execution time in milliseconds.</param> + /// <param name="thresholdMilliseconds">The configured threshold.</param> + /// <param name="alerts">The sources involved in exceeding the threshold.</param> + public void AddAlert(double executionTimeMilliseconds, double thresholdMilliseconds, AlertContext[] alerts) + { + this.PerformanceMonitor.AddAlert( + new AlertEntry(this, executionTimeMilliseconds, thresholdMilliseconds, alerts) + ); + } + + /// <summary>Add an alert.</summary> + /// <param name="executionTimeMilliseconds">The execution time in milliseconds.</param> + /// <param name="thresholdMilliseconds">The configured threshold.</param> + /// <param name="alert">The source involved in exceeding the threshold.</param> + public void AddAlert(double executionTimeMilliseconds, double thresholdMilliseconds, AlertContext alert) + { + this.AddAlert(executionTimeMilliseconds, thresholdMilliseconds, new[] { alert }); + } + + /// <summary>Reset the calls per second counter.</summary> + public void ResetCallsPerSecond() + { + this.CallCount = 0; + this.CallsPerSecondStart = DateTime.UtcNow; + } + + /// <summary>Reset all performance counters in this collection.</summary> + public void Reset() + { + this.PeakInvocations.Clear(); + foreach (var counter in this.PerformanceCounters) + counter.Value.Reset(); + } + + /// <summary>Reset the performance counter for a specific source.</summary> + /// <param name="source">The source name.</param> + public void ResetSource(string source) + { + foreach (var i in this.PerformanceCounters) + if (i.Value.Source.Equals(source, StringComparison.InvariantCultureIgnoreCase)) + i.Value.Reset(); + } + + /// <summary>Get the average calls per second.</summary> + public long GetAverageCallsPerSecond() + { + long runtimeInSeconds = (long)DateTime.UtcNow.Subtract(this.CallsPerSecondStart).TotalSeconds; + return runtimeInSeconds > 0 + ? this.CallCount / runtimeInSeconds + : 0; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterEntry.cs b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterEntry.cs new file mode 100644 index 00000000..8adbd88d --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterEntry.cs @@ -0,0 +1,30 @@ +using System; + +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>A single performance counter entry.</summary> + internal struct PerformanceCounterEntry + { + /********* + ** Accessors + *********/ + /// <summary>When the entry occurred.</summary> + public DateTime EventTime { get; } + + /// <summary>The elapsed milliseconds.</summary> + public double ElapsedMilliseconds { get; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="eventTime">When the entry occurred.</param> + /// <param name="elapsedMilliseconds">The elapsed milliseconds.</param> + public PerformanceCounterEntry(DateTime eventTime, double elapsedMilliseconds) + { + this.EventTime = eventTime; + this.ElapsedMilliseconds = elapsedMilliseconds; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceMonitoring/PerformanceMonitor.cs b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceMonitor.cs new file mode 100644 index 00000000..dfc4f31a --- /dev/null +++ b/src/SMAPI/Framework/PerformanceMonitoring/PerformanceMonitor.cs @@ -0,0 +1,184 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; +using StardewModdingAPI.Framework.Events; + +namespace StardewModdingAPI.Framework.PerformanceMonitoring +{ + /// <summary>Tracks performance metrics.</summary> + internal class PerformanceMonitor + { + /********* + ** Fields + *********/ + /// <summary>The recorded alerts.</summary> + private readonly IList<AlertEntry> Alerts = new List<AlertEntry>(); + + /// <summary>The monitor for output logging.</summary> + private readonly IMonitor Monitor; + + /// <summary>The invocation stopwatch.</summary> + private readonly Stopwatch InvocationStopwatch = new Stopwatch(); + + /// <summary>The underlying performance counter collections.</summary> + private readonly IDictionary<string, PerformanceCounterCollection> Collections = new Dictionary<string, PerformanceCounterCollection>(StringComparer.InvariantCultureIgnoreCase); + + + /********* + ** Accessors + *********/ + /// <summary>Whether alerts are paused.</summary> + public bool PauseAlerts { get; set; } + + /// <summary>Whether performance counter tracking is enabled.</summary> + public bool EnableTracking { get; set; } + + + /********* + ** Public methods + *********/ + /// <summary>Construct an instance.</summary> + /// <param name="monitor">The monitor for output logging.</param> + public PerformanceMonitor(IMonitor monitor) + { + this.Monitor = monitor; + } + + /// <summary>Reset all performance counters in all collections.</summary> + public void Reset() + { + foreach (PerformanceCounterCollection collection in this.Collections.Values) + collection.Reset(); + } + + /// <summary>Track the invocation time for a collection.</summary> + /// <param name="collectionName">The name of the collection.</param> + /// <param name="action">The action to execute and track.</param> + public void Track(string collectionName, Action action) + { + if (!this.EnableTracking) + { + action(); + return; + } + + PerformanceCounterCollection collection = this.GetOrCreateCollectionByName(collectionName); + collection.BeginTrackInvocation(); + try + { + action(); + } + finally + { + collection.EndTrackInvocation(); + } + } + + /// <summary>Track a single performance counter invocation in a specific collection.</summary> + /// <param name="collectionName">The name of the collection.</param> + /// <param name="sourceName">The name of the source.</param> + /// <param name="action">The action to execute and track.</param> + public void Track(string collectionName, string sourceName, Action action) + { + if (!this.EnableTracking) + { + action(); + return; + } + + PerformanceCounterCollection collection = this.GetOrCreateCollectionByName(collectionName); + DateTime eventTime = DateTime.UtcNow; + this.InvocationStopwatch.Reset(); + this.InvocationStopwatch.Start(); + + try + { + action(); + } + finally + { + this.InvocationStopwatch.Stop(); + collection.Track(sourceName, new PerformanceCounterEntry(eventTime, this.InvocationStopwatch.Elapsed.TotalMilliseconds)); + } + } + + /// <summary>Reset the performance counters for a specific collection.</summary> + /// <param name="name">The collection name.</param> + public void ResetCollection(string name) + { + if (this.Collections.TryGetValue(name, out PerformanceCounterCollection collection)) + { + collection.ResetCallsPerSecond(); + collection.Reset(); + } + } + + /// <summary>Reset performance counters for a specific source.</summary> + /// <param name="name">The name of the source.</param> + public void ResetSource(string name) + { + foreach (PerformanceCounterCollection performanceCounterCollection in this.Collections.Values) + performanceCounterCollection.ResetSource(name); + } + + /// <summary>Print any queued alerts.</summary> + public void PrintQueuedAlerts() + { + if (this.Alerts.Count == 0) + return; + + StringBuilder report = new StringBuilder(); + + foreach (AlertEntry alert in this.Alerts) + { + report.AppendLine($"{alert.Collection.Name} took {alert.ExecutionTimeMilliseconds:F2}ms (exceeded threshold of {alert.ThresholdMilliseconds:F2}ms)"); + + foreach (AlertContext context in alert.Context.OrderByDescending(p => p.Elapsed)) + report.AppendLine(context.ToString()); + } + + this.Alerts.Clear(); + this.Monitor.Log(report.ToString(), LogLevel.Error); + } + + /// <summary>Add an alert to the queue.</summary> + /// <param name="entry">The alert to add.</param> + public void AddAlert(AlertEntry entry) + { + if (!this.PauseAlerts) + this.Alerts.Add(entry); + } + + /// <summary>Initialize the default performance counter collections.</summary> + /// <param name="eventManager">The event manager.</param> + public void InitializePerformanceCounterCollections(EventManager eventManager) + { + foreach (IManagedEvent @event in eventManager.GetAllEvents()) + this.Collections[@event.EventName] = new PerformanceCounterCollection(this, @event.EventName, @event.IsPerformanceCritical); + } + + /// <summary>Get the underlying performance counters.</summary> + public IEnumerable<PerformanceCounterCollection> GetCollections() + { + return this.Collections.Values; + } + + + /********* + ** Public methods + *********/ + /// <summary>Get a collection by name and creates it if it doesn't exist.</summary> + /// <param name="name">The name of the collection.</param> + private PerformanceCounterCollection GetOrCreateCollectionByName(string name) + { + if (!this.Collections.TryGetValue(name, out PerformanceCounterCollection collection)) + { + collection = new PerformanceCounterCollection(this, name); + this.Collections[name] = collection; + } + return collection; + } + } +} |