From 910b4a2c4361c429b09bd35fa52d51b24cc17bc2 Mon Sep 17 00:00:00 2001 From: Jesse Plamondon-Willard Date: Sun, 26 Jan 2020 19:52:31 -0500 Subject: tweak namespace --- .../PerformanceMonitoring/AlertContext.cs | 34 ++++ .../Framework/PerformanceMonitoring/AlertEntry.cs | 38 ++++ .../Framework/PerformanceMonitoring/PeakEntry.cs | 35 ++++ .../PerformanceMonitoring/PerformanceCounter.cs | 125 +++++++++++++ .../PerformanceCounterCollection.cs | 205 +++++++++++++++++++++ .../PerformanceCounterEntry.cs | 30 +++ .../PerformanceMonitoring/PerformanceMonitor.cs | 184 ++++++++++++++++++ 7 files changed, 651 insertions(+) create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/AlertContext.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/AlertEntry.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/PeakEntry.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounter.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterCollection.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/PerformanceCounterEntry.cs create mode 100644 src/SMAPI/Framework/PerformanceMonitoring/PerformanceMonitor.cs (limited to 'src/SMAPI/Framework/PerformanceMonitoring') 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 +{ + /// The context for an alert. + internal struct AlertContext + { + /********* + ** Accessors + *********/ + /// The source which triggered the alert. + public string Source { get; } + + /// The elapsed milliseconds. + public double Elapsed { get; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The source which triggered the alert. + /// The elapsed milliseconds. + public AlertContext(string source, double elapsed) + { + this.Source = source; + this.Elapsed = elapsed; + } + + /// Get a human-readable text form of this instance. + 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 +{ + /// A single alert entry. + internal struct AlertEntry + { + /********* + ** Accessors + *********/ + /// The collection in which the alert occurred. + public PerformanceCounterCollection Collection { get; } + + /// The actual execution time in milliseconds. + public double ExecutionTimeMilliseconds { get; } + + /// The configured alert threshold in milliseconds. + public double ThresholdMilliseconds { get; } + + /// The sources involved in exceeding the threshold. + public AlertContext[] Context { get; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The collection in which the alert occurred. + /// The actual execution time in milliseconds. + /// The configured alert threshold in milliseconds. + /// The sources involved in exceeding the threshold. + 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 +{ + /// A peak invocation time. + internal struct PeakEntry + { + /********* + ** Accessors + *********/ + /// The actual execution time in milliseconds. + public double ExecutionTimeMilliseconds { get; } + + /// When the entry occurred. + public DateTime EventTime { get; } + + /// The sources involved in exceeding the threshold. + public AlertContext[] Context { get; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The actual execution time in milliseconds. + /// When the entry occurred. + /// The sources involved in exceeding the threshold. + 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 +{ + /// Tracks metadata about a particular code event. + internal class PerformanceCounter + { + /********* + ** Fields + *********/ + /// The size of the ring buffer. + private readonly int MaxEntries = 16384; + + /// The collection to which this performance counter belongs. + private readonly PerformanceCounterCollection ParentCollection; + + /// The performance counter entries. + private readonly Stack Entries; + + /// The entry with the highest execution time. + private PerformanceCounterEntry? PeakPerformanceCounterEntry; + + + /********* + ** Accessors + *********/ + /// The name of the source. + public string Source { get; } + + /// The alert threshold in milliseconds + public double AlertThresholdMilliseconds { get; set; } + + /// If alerting is enabled or not + public bool EnableAlerts { get; set; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The collection to which this performance counter belongs. + /// The name of the source. + public PerformanceCounter(PerformanceCounterCollection parentCollection, string source) + { + this.ParentCollection = parentCollection; + this.Source = source; + this.Entries = new Stack(this.MaxEntries); + } + + /// Add a performance counter entry to the list, update monitoring, and raise alerts if needed. + /// The entry to add. + 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)); + } + + /// Clear all performance counter entries and monitoring. + public void Reset() + { + this.Entries.Clear(); + this.PeakPerformanceCounterEntry = null; + } + + /// Get the peak entry. + public PerformanceCounterEntry? GetPeak() + { + return this.PeakPerformanceCounterEntry; + } + + /// Get the entry with the highest execution time. + /// The time range to search. + /// The end time for the , or null for the current time. + 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(); + } + + /// Get the last entry added to the list. + public PerformanceCounterEntry? GetLastEntry() + { + if (this.Entries.Count == 0) + return null; + + return this.Entries.Peek(); + } + + /// Get the average over a given time span. + /// The time range to search. + /// The end time for the , or null for the current time. + 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 + *********/ + /// The number of peak invocations to keep. + private readonly int MaxEntries = 16384; + + /// The sources involved in exceeding alert thresholds. + private readonly List TriggeredPerformanceCounters = new List(); + + /// The stopwatch used to track the invocation time. + private readonly Stopwatch InvocationStopwatch = new Stopwatch(); + + /// The performance counter manager. + private readonly PerformanceMonitor PerformanceMonitor; + + /// The time to calculate average calls per second. + private DateTime CallsPerSecondStart = DateTime.UtcNow; + + /// The number of invocations. + private long CallCount; + + /// The peak invocations. + private readonly Stack PeakInvocations; + + + /********* + ** Accessors + *********/ + /// The associated performance counters. + public IDictionary PerformanceCounters { get; } = new Dictionary(); + + /// The name of this collection. + public string Name { get; } + + /// Whether the source is typically invoked at least once per second. + public bool IsPerformanceCritical { get; } + + /// The alert threshold in milliseconds. + public double AlertThresholdMilliseconds { get; set; } + + /// Whether alerts are enabled. + public bool EnableAlerts { get; set; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The performance counter manager. + /// The name of this collection. + /// Whether the source is typically invoked at least once per second. + public PerformanceCounterCollection(PerformanceMonitor performanceMonitor, string name, bool isPerformanceCritical = false) + { + this.PeakInvocations = new Stack(this.MaxEntries); + this.Name = name; + this.PerformanceMonitor = performanceMonitor; + this.IsPerformanceCritical = isPerformanceCritical; + } + + /// Track a single invocation for a named source. + /// The name of the source. + /// The entry. + 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)); + } + + /// Get the average execution time for all non-game internal sources in milliseconds. + /// The interval for which to get the average, relative to now + public double GetModsAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters + .Where(entry => entry.Key != Constants.GamePerformanceCounterName) + .Sum(entry => entry.Value.GetAverage(interval)); + } + + /// Get the overall average execution time in milliseconds. + /// The interval for which to get the average, relative to now + public double GetAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters + .Sum(entry => entry.Value.GetAverage(interval)); + } + + /// Get the average execution time for game-internal sources in milliseconds. + public double GetGameAverageExecutionTime(TimeSpan interval) + { + return this.PerformanceCounters.TryGetValue(Constants.GamePerformanceCounterName, out PerformanceCounter gameExecTime) + ? gameExecTime.GetAverage(interval) + : 0; + } + + /// Get the peak execution time in milliseconds. + /// The time range to search. + /// The end time for the , or null for the current time. + 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(); + } + + /// Start tracking the invocation of this collection. + public void BeginTrackInvocation() + { + this.TriggeredPerformanceCounters.Clear(); + this.InvocationStopwatch.Reset(); + this.InvocationStopwatch.Start(); + + this.CallCount++; + } + + /// End tracking the invocation of this collection, and raise an alert if needed. + 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()); + } + + /// Add an alert. + /// The execution time in milliseconds. + /// The configured threshold. + /// The sources involved in exceeding the threshold. + public void AddAlert(double executionTimeMilliseconds, double thresholdMilliseconds, AlertContext[] alerts) + { + this.PerformanceMonitor.AddAlert( + new AlertEntry(this, executionTimeMilliseconds, thresholdMilliseconds, alerts) + ); + } + + /// Add an alert. + /// The execution time in milliseconds. + /// The configured threshold. + /// The source involved in exceeding the threshold. + public void AddAlert(double executionTimeMilliseconds, double thresholdMilliseconds, AlertContext alert) + { + this.AddAlert(executionTimeMilliseconds, thresholdMilliseconds, new[] { alert }); + } + + /// Reset the calls per second counter. + public void ResetCallsPerSecond() + { + this.CallCount = 0; + this.CallsPerSecondStart = DateTime.UtcNow; + } + + /// Reset all performance counters in this collection. + public void Reset() + { + this.PeakInvocations.Clear(); + foreach (var counter in this.PerformanceCounters) + counter.Value.Reset(); + } + + /// Reset the performance counter for a specific source. + /// The source name. + public void ResetSource(string source) + { + foreach (var i in this.PerformanceCounters) + if (i.Value.Source.Equals(source, StringComparison.InvariantCultureIgnoreCase)) + i.Value.Reset(); + } + + /// Get the average calls per second. + 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 +{ + /// A single performance counter entry. + internal struct PerformanceCounterEntry + { + /********* + ** Accessors + *********/ + /// When the entry occurred. + public DateTime EventTime { get; } + + /// The elapsed milliseconds. + public double ElapsedMilliseconds { get; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// When the entry occurred. + /// The elapsed milliseconds. + 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 +{ + /// Tracks performance metrics. + internal class PerformanceMonitor + { + /********* + ** Fields + *********/ + /// The recorded alerts. + private readonly IList Alerts = new List(); + + /// The monitor for output logging. + private readonly IMonitor Monitor; + + /// The invocation stopwatch. + private readonly Stopwatch InvocationStopwatch = new Stopwatch(); + + /// The underlying performance counter collections. + private readonly IDictionary Collections = new Dictionary(StringComparer.InvariantCultureIgnoreCase); + + + /********* + ** Accessors + *********/ + /// Whether alerts are paused. + public bool PauseAlerts { get; set; } + + /// Whether performance counter tracking is enabled. + public bool EnableTracking { get; set; } + + + /********* + ** Public methods + *********/ + /// Construct an instance. + /// The monitor for output logging. + public PerformanceMonitor(IMonitor monitor) + { + this.Monitor = monitor; + } + + /// Reset all performance counters in all collections. + public void Reset() + { + foreach (PerformanceCounterCollection collection in this.Collections.Values) + collection.Reset(); + } + + /// Track the invocation time for a collection. + /// The name of the collection. + /// The action to execute and track. + public void Track(string collectionName, Action action) + { + if (!this.EnableTracking) + { + action(); + return; + } + + PerformanceCounterCollection collection = this.GetOrCreateCollectionByName(collectionName); + collection.BeginTrackInvocation(); + try + { + action(); + } + finally + { + collection.EndTrackInvocation(); + } + } + + /// Track a single performance counter invocation in a specific collection. + /// The name of the collection. + /// The name of the source. + /// The action to execute and track. + 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)); + } + } + + /// Reset the performance counters for a specific collection. + /// The collection name. + public void ResetCollection(string name) + { + if (this.Collections.TryGetValue(name, out PerformanceCounterCollection collection)) + { + collection.ResetCallsPerSecond(); + collection.Reset(); + } + } + + /// Reset performance counters for a specific source. + /// The name of the source. + public void ResetSource(string name) + { + foreach (PerformanceCounterCollection performanceCounterCollection in this.Collections.Values) + performanceCounterCollection.ResetSource(name); + } + + /// Print any queued alerts. + 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); + } + + /// Add an alert to the queue. + /// The alert to add. + public void AddAlert(AlertEntry entry) + { + if (!this.PauseAlerts) + this.Alerts.Add(entry); + } + + /// Initialize the default performance counter collections. + /// The event manager. + public void InitializePerformanceCounterCollections(EventManager eventManager) + { + foreach (IManagedEvent @event in eventManager.GetAllEvents()) + this.Collections[@event.EventName] = new PerformanceCounterCollection(this, @event.EventName, @event.IsPerformanceCritical); + } + + /// Get the underlying performance counters. + public IEnumerable GetCollections() + { + return this.Collections.Values; + } + + + /********* + ** Public methods + *********/ + /// Get a collection by name and creates it if it doesn't exist. + /// The name of the collection. + private PerformanceCounterCollection GetOrCreateCollectionByName(string name) + { + if (!this.Collections.TryGetValue(name, out PerformanceCounterCollection collection)) + { + collection = new PerformanceCounterCollection(this, name); + this.Collections[name] = collection; + } + return collection; + } + } +} -- cgit