diff options
18 files changed, 1027 insertions, 352 deletions
diff --git a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/ArgumentParser.cs b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/ArgumentParser.cs index 10007b42..40691a3e 100644 --- a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/ArgumentParser.cs +++ b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/ArgumentParser.cs @@ -1,6 +1,7 @@ using System; using System.Collections; using System.Collections.Generic; +using System.Globalization; using System.Linq; namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands @@ -113,6 +114,51 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands return true; } + public bool IsDecimal(int index) + { + if (!this.TryGet(index, "", out string raw, false)) + return false; + + if (!decimal.TryParse(raw, NumberStyles.Number, CultureInfo.InvariantCulture, out decimal value)) + { + return false; + } + + return true; + } + + /// <summary>Try to read a decimal argument.</summary> + /// <param name="index">The argument index.</param> + /// <param name="name">The argument name for error messages.</param> + /// <param name="value">The parsed value.</param> + /// <param name="required">Whether to show an error if the argument is missing.</param> + /// <param name="min">The minimum value allowed.</param> + /// <param name="max">The maximum value allowed.</param> + public bool TryGetDecimal(int index, string name, out decimal value, bool required = true, decimal? min = null, decimal? max = null) + { + value = 0; + + // get argument + if (!this.TryGet(index, name, out string raw, required)) + return false; + + // parse + if (!decimal.TryParse(raw, NumberStyles.Number, CultureInfo.InvariantCulture, out value)) + { + this.LogDecimalFormatError(index, name, min, max); + return false; + } + + // validate + if ((min.HasValue && value < min) || (max.HasValue && value > max)) + { + this.LogDecimalFormatError(index, name, min, max); + return false; + } + + return true; + } + /// <summary>Returns an enumerator that iterates through the collection.</summary> /// <returns>An enumerator that can be used to iterate through the collection.</returns> public IEnumerator<string> GetEnumerator() @@ -154,5 +200,22 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands else this.LogError($"Argument {index} ({name}) must be an integer."); } + + /// <summary>Print an error for an invalid decimal argument.</summary> + /// <param name="index">The argument index.</param> + /// <param name="name">The argument name for error messages.</param> + /// <param name="min">The minimum value allowed.</param> + /// <param name="max">The maximum value allowed.</param> + private void LogDecimalFormatError(int index, string name, decimal? min, decimal? max) + { + if (min.HasValue && max.HasValue) + this.LogError($"Argument {index} ({name}) must be a decimal between {min} and {max}."); + else if (min.HasValue) + this.LogError($"Argument {index} ({name}) must be a decimal and at least {min}."); + else if (max.HasValue) + this.LogError($"Argument {index} ({name}) must be a decimal and at most {max}."); + else + this.LogError($"Argument {index} ({name}) must be a decimal."); + } } } diff --git a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs index b7e56359..84b9504e 100644 --- a/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs +++ b/src/SMAPI.Mods.ConsoleCommands/Framework/Commands/Other/PerformanceCounterCommand.cs @@ -1,14 +1,543 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using StardewModdingAPI.Framework; +using StardewModdingAPI.Framework.PerformanceCounter; + namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands.Other { - internal class PerformanceCounterCommand: TrainerCommand + internal class PerformanceCounterCommand : TrainerCommand { - public PerformanceCounterCommand(string name, string description) : base("performance_counters", "Displays performance counters") + private readonly Dictionary<Command, string[]> CommandNames = new Dictionary<Command, string[]>() + { + {Command.Summary, new[] {"summary", "sum", "s"}}, + {Command.Detail, new[] {"detail", "d"}}, + {Command.Reset, new[] {"reset", "r"}}, + {Command.Monitor, new[] {"monitor"}}, + {Command.Examples, new[] {"examples"}}, + {Command.Concepts, new[] {"concepts"}}, + {Command.Help, new[] {"help"}}, + }; + + private enum Command + { + Summary, + Detail, + Reset, + Monitor, + Examples, + Help, + Concepts, + None + } + + public PerformanceCounterCommand() : base("pc", PerformanceCounterCommand.GetDescription()) { } public override void Handle(IMonitor monitor, string command, ArgumentParser args) { + if (args.TryGet(0, "command", out string subCommandString, false)) + { + Command subCommand = this.ParseCommandString(subCommandString); + + switch (subCommand) + { + case Command.Summary: + this.DisplayPerformanceCounterSummary(monitor, args); + break; + case Command.Detail: + this.DisplayPerformanceCounterDetail(monitor, args); + break; + case Command.Reset: + this.ResetCounter(monitor, args); + break; + case Command.Monitor: + this.HandleMonitor(monitor, args); + break; + case Command.Examples: + break; + case Command.Concepts: + this.ShowHelp(monitor, Command.Concepts); + break; + case Command.Help: + args.TryGet(1, "command", out string commandString, true); + + var helpCommand = this.ParseCommandString(commandString); + this.ShowHelp(monitor, helpCommand); + break; + default: + this.LogUsageError(monitor, $"Unknown command {subCommandString}"); + break; + } + } + else + { + this.DisplayPerformanceCounterSummary(monitor, args); + } + } + + private Command ParseCommandString(string command) + { + foreach (var i in this.CommandNames.Where(i => i.Value.Any(str => str.Equals(command, StringComparison.InvariantCultureIgnoreCase)))) + { + return i.Key; + } + + return Command.None; + } + + private void HandleMonitor(IMonitor monitor, ArgumentParser args) + { + if (args.TryGet(1, "mode", out string mode, false)) + { + switch (mode) + { + case "list": + this.ListMonitors(monitor); + break; + case "collection": + args.TryGet(2, "name", out string collectionName); + decimal threshold = 0; + if (args.IsDecimal(3) && args.TryGetDecimal(3, "threshold", out threshold, false)) + { + this.SetCollectionMonitor(monitor, collectionName, null, (double)threshold); + } else if (args.TryGet(3, "source", out string source)) + { + if (args.TryGetDecimal(4, "threshold", out threshold)) + { + this.SetCollectionMonitor(monitor, collectionName, source, (double) threshold); + } + } + break; + case "clear": + this.ClearMonitors(monitor); + break; + default: + monitor.Log($"Unknown mode {mode}. See 'pc help monitor' for usage."); + break; + } + + } + else + { + this.ListMonitors(monitor); + } + } + + private void SetCollectionMonitor(IMonitor monitor, string collectionName, string sourceName, double threshold) + { + foreach (PerformanceCounterCollection collection in SCore.PerformanceCounterManager.PerformanceCounterCollections) + { + if (collection.Name.ToLowerInvariant().Equals(collectionName.ToLowerInvariant())) + { + if (sourceName == null) + { + collection.Monitor = true; + collection.MonitorThresholdMilliseconds = threshold; + monitor.Log($"Set up monitor for '{collectionName}' with '{this.FormatMilliseconds(threshold)}'", LogLevel.Info); + return; + } + else + { + foreach (var performanceCounter in collection.PerformanceCounters) + { + if (performanceCounter.Value.Source.ToLowerInvariant().Equals(sourceName.ToLowerInvariant())) + { + performanceCounter.Value.Monitor = true; + performanceCounter.Value.MonitorThresholdMilliseconds = threshold; + monitor.Log($"Set up monitor for '{sourceName}' in collection '{collectionName}' with '{this.FormatMilliseconds(threshold)}", LogLevel.Info); + return; + } + } + + monitor.Log($"Could not find the source '{sourceName}' in collection '{collectionName}'", LogLevel.Warn); + return; + } + } + } + + monitor.Log($"Could not find the collection '{collectionName}'", LogLevel.Warn); + } + + + private void ClearMonitors(IMonitor monitor) + { + int clearedCounters = 0; + foreach (PerformanceCounterCollection collection in SCore.PerformanceCounterManager.PerformanceCounterCollections) + { + if (collection.Monitor) + { + collection.Monitor = false; + clearedCounters++; + } + + foreach (var performanceCounter in collection.PerformanceCounters) + { + if (performanceCounter.Value.Monitor) + { + performanceCounter.Value.Monitor = false; + clearedCounters++; + } + } + + } + + monitor.Log($"Cleared {clearedCounters} counters.", LogLevel.Info); + } + + private void ListMonitors(IMonitor monitor) + { + StringBuilder sb = new StringBuilder(); + sb.AppendLine(); + sb.AppendLine(); + var collectionMonitors = new List<(string collectionName, double threshold)>(); + var sourceMonitors = new List<(string collectionName, string sourceName, double threshold)>(); + + foreach (PerformanceCounterCollection collection in SCore.PerformanceCounterManager.PerformanceCounterCollections) + { + if (collection.Monitor) + { + collectionMonitors.Add((collection.Name, collection.MonitorThresholdMilliseconds)); + } + + sourceMonitors.AddRange(from performanceCounter in + collection.PerformanceCounters where performanceCounter.Value.Monitor + select (collection.Name, performanceCounter.Value.Source, performanceCounter.Value.MonitorThresholdMilliseconds)); + } + + if (collectionMonitors.Count > 0) + { + sb.AppendLine("Collection Monitors:"); + sb.AppendLine(); + sb.AppendLine(this.GetTableString( + data: collectionMonitors, + header: new[] {"Collection", "Threshold"}, + getRow: item => new[] + { + item.collectionName, + this.FormatMilliseconds(item.threshold) + } + )); + + sb.AppendLine(); + + + } + + if (sourceMonitors.Count > 0) + { + sb.AppendLine("Source Monitors:"); + sb.AppendLine(); + sb.AppendLine(this.GetTableString( + data: sourceMonitors, + header: new[] {"Collection", "Source", "Threshold"}, + getRow: item => new[] + { + item.collectionName, + item.sourceName, + this.FormatMilliseconds(item.threshold) + } + )); + + sb.AppendLine(); + } + + monitor.Log(sb.ToString(), LogLevel.Info); + } + + private void ShowHelp(IMonitor monitor, Command command) + { + StringBuilder sb = new StringBuilder(); + sb.AppendLine(); + switch (command) + { + case Command.Concepts: + sb.AppendLine("A performance counter is a metric which measures execution time. Each performance"); + sb.AppendLine("counter consists of:"); + sb.AppendLine(); + sb.AppendLine(" - A source, which typically is a mod or the game itself."); + sb.AppendLine(" - A ring buffer which stores the data points (execution time and time when it was executed)"); + sb.AppendLine(); + sb.AppendLine("A set of performance counters is organized in a collection to group various areas."); + sb.AppendLine("Per default, collections for all game events [1] are created."); + sb.AppendLine(); + sb.AppendLine("Example:"); + sb.AppendLine(); + sb.AppendLine("The performance counter collection named 'Display.Rendered' contains one performance"); + sb.AppendLine("counters when the game executes the 'Display.Rendered' event, and one additional"); + sb.AppendLine("performance counter for each mod which handles the 'Display.Rendered' event."); + sb.AppendLine(); + sb.AppendLine("[1] https://stardewvalleywiki.com/Modding:Modder_Guide/APIs/Events"); + break; + case Command.Detail: + sb.AppendLine("Usage: pc detail <collection> <source>"); + sb.AppendLine(" pc detail <collection> <threshold>"); + sb.AppendLine(); + sb.AppendLine("Displays details for a specific collection."); + sb.AppendLine(); + sb.AppendLine("Arguments:"); + sb.AppendLine(" <collection> Required. The full or partial name of the collection to display."); + sb.AppendLine(" <source> Optional. The full or partial name of the source."); + sb.AppendLine(" <threshold> Optional. The threshold in milliseconds. Any average execution time below that"); + sb.AppendLine(" threshold is not reported."); + sb.AppendLine(); + sb.AppendLine("Examples:"); + sb.AppendLine("pc detail Display.Rendering Displays all performance counters for the 'Display.Rendering' collection"); + sb.AppendLine("pc detail Display.Rendering Pathoschild.ChestsAnywhere Displays the 'Display.Rendering' performance counter for 'Pathoschild.ChestsAnywhere'"); + sb.AppendLine("pc detail Display.Rendering 5 Displays the 'Display.Rendering' performance counters exceeding an average of 5ms"); + break; + case Command.Summary: + sb.AppendLine("Usage: pc summary <mode|name>"); + sb.AppendLine(); + sb.AppendLine("Displays the performance counter summary."); + sb.AppendLine(); + sb.AppendLine("Arguments:"); + sb.AppendLine(" <mode> Optional. Defaults to 'important' if omitted. Specifies one of these modes:"); + sb.AppendLine(" - all Displays performance counters from all collections"); + sb.AppendLine(" - important Displays only important performance counter collections"); + sb.AppendLine(); + sb.AppendLine(" <name> Optional. Only shows performance counter collections matching the given name"); + sb.AppendLine(); + sb.AppendLine("Examples:"); + sb.AppendLine("pc summary all Shows all events"); + sb.AppendLine("pc summary Display.Rendering Shows only the 'Display.Rendering' collection"); + break; + case Command.Monitor: + sb.AppendLine("Usage: pc monitor <mode> <collectionName> <threshold>"); + sb.AppendLine("Usage: pc monitor <mode> <collectionName> <sourceName> <threshold>"); + sb.AppendLine(); + sb.AppendLine("Manages monitoring settings."); + sb.AppendLine(); + sb.AppendLine("Arguments:"); + sb.AppendLine(" <mode> Optional. Specifies if a specific source or a specific collection should be monitored."); + sb.AppendLine(" - list Lists current monitoring settings"); + sb.AppendLine(" - collection Sets up a monitor for a collection"); + sb.AppendLine(" - clear Clears all monitoring entries"); + sb.AppendLine(" Defaults to 'list' if not specified."); + sb.AppendLine(); + sb.AppendLine(" <collectionName> Required if the mode 'collection' is specified."); + sb.AppendLine(" Specifies the name of the collection to be monitored. Must be an exact match."); + sb.AppendLine(); + sb.AppendLine(" <sourceName> Optional. Specifies the name of a specific source. Must be an exact match."); + sb.AppendLine(); + sb.AppendLine(" <threshold> Required if the mode 'collection' is specified."); + sb.AppendLine(" Specifies the threshold in milliseconds (fractions allowed)."); + sb.AppendLine(" Can also be 'remove' to remove the threshold."); + sb.AppendLine(); + sb.AppendLine("Examples:"); + sb.AppendLine(); + sb.AppendLine("pc monitor collection Display.Rendering 10"); + sb.AppendLine(" Sets up monitoring to write an alert on the console if the execution time of all performance counters in"); + sb.AppendLine(" the 'Display.Rendering' collection exceed 10 milliseconds."); + sb.AppendLine(); + sb.AppendLine("pc monitor collection Display.Rendering Pathoschild.ChestsAnywhere 5"); + sb.AppendLine(" Sets up monitoring to write an alert on the console if the execution time of Pathoschild.ChestsAnywhere in"); + sb.AppendLine(" the 'Display.Rendering' collection exceed 5 milliseconds."); + sb.AppendLine(); + sb.AppendLine("pc monitor collection Display.Rendering remove"); + sb.AppendLine(" Removes the threshold previously defined from the collection. Note that source-specific thresholds are left intact."); + sb.AppendLine(); + sb.AppendLine("pc monitor clear"); + sb.AppendLine(" Clears all previously setup monitors."); + break; + case Command.Reset: + sb.AppendLine("Usage: pc reset <type> <name>"); + sb.AppendLine(); + sb.AppendLine("Resets performance counters."); + sb.AppendLine(); + sb.AppendLine("Arguments:"); + sb.AppendLine(" <type> Optional. Specifies if a collection or source should be reset."); + sb.AppendLine(" If omitted, all performance counters are reset."); + sb.AppendLine(); + sb.AppendLine(" - source Clears performance counters for a specific source"); + sb.AppendLine(" - collection Clears performance counters for a specific collection"); + sb.AppendLine(); + sb.AppendLine(" <name> Required if a <type> is given. Specifies the name of either the collection"); + sb.AppendLine(" or the source. The name must be an exact match."); + sb.AppendLine(); + sb.AppendLine("Examples:"); + sb.AppendLine("pc reset Resets all performance counters"); + sb.AppendLine("pc reset source Pathoschild.ChestsAnywhere Resets all performance for the source named Pathoschild.ChestsAnywhere"); + sb.AppendLine("pc reset collection Display.Rendering Resets all performance for the collection named Display.Rendering"); + break; + } + + sb.AppendLine(); + monitor.Log(sb.ToString(), LogLevel.Info); + } + + private void ResetCounter(IMonitor monitor, ArgumentParser args) + { + if (args.TryGet(1, "type", out string type, false)) + { + args.TryGet(2, "name", out string name); + + switch (type) + { + case "category": + SCore.PerformanceCounterManager.ResetCategory(name); + monitor.Log($"All performance counters for category {name} are now cleared.", LogLevel.Info); + break; + case "mod": + SCore.PerformanceCounterManager.ResetSource(name); + monitor.Log($"All performance counters for mod {name} are now cleared.", LogLevel.Info); + break; + } + } + else + { + SCore.PerformanceCounterManager.Reset(); + monitor.Log("All performance counters are now cleared.", LogLevel.Info); + } + } + + private void DisplayPerformanceCounterSummary(IMonitor monitor, ArgumentParser args) + { + IEnumerable<PerformanceCounterCollection> data; + + if (!args.TryGet(1, "mode", out string mode, false)) + { + mode = "important"; + } + + switch (mode) + { + case null: + case "important": + data = SCore.PerformanceCounterManager.PerformanceCounterCollections.Where(p => p.IsImportant); + break; + case "all": + data = SCore.PerformanceCounterManager.PerformanceCounterCollections; + break; + default: + data = SCore.PerformanceCounterManager.PerformanceCounterCollections.Where(p => + p.Name.ToLowerInvariant().Contains(mode.ToLowerInvariant())); + break; + } + + StringBuilder sb = new StringBuilder(); + + 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)"}, + getRow: item => new[] + { + item.Name, + item.GetAverageCallsPerSecond().ToString(), + this.FormatMilliseconds(item.GetGameAverageExecutionTime()), + this.FormatMilliseconds(item.GetModsAverageExecutionTime()), + this.FormatMilliseconds(item.GetAverageExecutionTime()) + } + )); + + monitor.Log(sb.ToString(), LogLevel.Info); + } + + private void DisplayPerformanceCounterDetail(IMonitor monitor, ArgumentParser args) + { + List<PerformanceCounterCollection> collections = new List<PerformanceCounterCollection>(); + TimeSpan averageInterval = TimeSpan.FromSeconds(60); + double? thresholdMilliseconds = null; + string sourceFilter = null; + + if (args.TryGet(1, "collection", out string collectionName)) + { + collections.AddRange(SCore.PerformanceCounterManager.PerformanceCounterCollections.Where(collection => collection.Name.ToLowerInvariant().Contains(collectionName.ToLowerInvariant()))); + + if (args.IsDecimal(2) && args.TryGetDecimal(2, "threshold", out decimal value, false)) + { + thresholdMilliseconds = (double?) value; + } + else + { + if (args.TryGet(2, "source", out string sourceName, false)) + { + sourceFilter = sourceName; + } + } + } + + foreach (var c in collections) + { + this.DisplayPerformanceCollectionDetail(monitor, c, averageInterval, thresholdMilliseconds, sourceFilter); + } + } + + private void DisplayPerformanceCollectionDetail(IMonitor monitor, PerformanceCounterCollection collection, + TimeSpan averageInterval, double? thresholdMilliseconds, string sourceFilter = null) + { + StringBuilder sb = new StringBuilder($"Performance Counter for {collection.Name}:\n\n"); + + IEnumerable<KeyValuePair<string, PerformanceCounter>> data = collection.PerformanceCounters; + + if (sourceFilter != null) + { + data = collection.PerformanceCounters.Where(p => + p.Value.Source.ToLowerInvariant().Contains(sourceFilter.ToLowerInvariant())); + } + + if (thresholdMilliseconds != null) + { + data = data.Where(p => p.Value.GetAverage(averageInterval) >= thresholdMilliseconds); + } + + sb.AppendLine(this.GetTableString( + data: data, + header: new[] {"Mod", $"Avg Execution Time (last {(int) averageInterval.TotalSeconds}s)", "Last Execution Time", "Peak Execution Time"}, + getRow: item => new[] + { + item.Key, + this.FormatMilliseconds(item.Value.GetAverage(averageInterval), thresholdMilliseconds), + this.FormatMilliseconds(item.Value.GetLastEntry()?.Elapsed.TotalMilliseconds), + this.FormatMilliseconds(item.Value.GetPeak()?.Elapsed.TotalMilliseconds) + } + )); + + monitor.Log(sb.ToString(), LogLevel.Info); + } + + private string FormatMilliseconds(double? milliseconds, double? thresholdMilliseconds = null) + { + if (milliseconds == null || (thresholdMilliseconds != null && milliseconds < thresholdMilliseconds)) + { + return "-"; + } + + return ((double) milliseconds).ToString("F2"); + } + + /// <summary>Get the command description.</summary> + private static string GetDescription() + { + StringBuilder sb = new StringBuilder(); + + sb.AppendLine("Displays and configured performance counters."); + sb.AppendLine(); + sb.AppendLine("A performance counter records the invocation time of in-game events being"); + sb.AppendLine("processed by mods or the game itself. See 'concepts' for a detailed explanation."); + sb.AppendLine(); + sb.AppendLine("Usage: pc <command> <action>"); + sb.AppendLine(); + sb.AppendLine("Commands:"); + sb.AppendLine(); + sb.AppendLine(" summary|sum|s Displays a summary of important or all collections"); + sb.AppendLine(" detail|d Shows performance counter information for a given collection"); + sb.AppendLine(" reset|r Resets the performance counters"); + sb.AppendLine(" monitor Configures monitoring settings"); + sb.AppendLine(" examples Displays various examples"); + sb.AppendLine(" concepts Displays an explanation of the performance counter concepts"); + sb.AppendLine(" help Displays verbose help for the available commands"); + sb.AppendLine(); + sb.AppendLine("To get help for a specific command, use 'pc help <command>', for example:"); + sb.AppendLine("pc help summary"); + sb.AppendLine(); + sb.AppendLine("Defaults to summary if no command is given."); + sb.AppendLine(); + return sb.ToString(); } } } diff --git a/src/SMAPI.Mods.ConsoleCommands/SMAPI.Mods.ConsoleCommands.csproj b/src/SMAPI.Mods.ConsoleCommands/SMAPI.Mods.ConsoleCommands.csproj index ce35bf73..f073ac21 100644 --- a/src/SMAPI.Mods.ConsoleCommands/SMAPI.Mods.ConsoleCommands.csproj +++ b/src/SMAPI.Mods.ConsoleCommands/SMAPI.Mods.ConsoleCommands.csproj @@ -67,6 +67,10 @@ </None> </ItemGroup> + <ItemGroup> + <PackageReference Include="System.ValueTuple" Version="4.5.0" /> + </ItemGroup> + <Import Project="..\SMAPI.Internal\SMAPI.Internal.projitems" Label="Shared" /> <Import Project="..\..\build\common.targets" /> diff --git a/src/SMAPI/Constants.cs b/src/SMAPI/Constants.cs index 0923494c..76cb6f89 100644 --- a/src/SMAPI/Constants.cs +++ b/src/SMAPI/Constants.cs @@ -56,7 +56,7 @@ namespace StardewModdingAPI internal const string HomePageUrl = "https://smapi.io"; /// <summary>The URL of the SMAPI home page.</summary> - internal const string GamePerformanceCounterName = "-internal-"; + internal const string GamePerformanceCounterName = "<StardewValley>"; /// <summary>The absolute path to the folder containing SMAPI's internal files.</summary> internal static readonly string InternalFilesPath = Program.DllSearchPath; diff --git a/src/SMAPI/Framework/Events/EventManager.cs b/src/SMAPI/Framework/Events/EventManager.cs index 892cbc7b..9c65a6cc 100644 --- a/src/SMAPI/Framework/Events/EventManager.cs +++ b/src/SMAPI/Framework/Events/EventManager.cs @@ -1,5 +1,6 @@ using System.Diagnostics.CodeAnalysis; using StardewModdingAPI.Events; +using StardewModdingAPI.Framework.PerformanceCounter; namespace StardewModdingAPI.Framework.Events { @@ -173,10 +174,10 @@ namespace StardewModdingAPI.Framework.Events /// <summary>Construct an instance.</summary> /// <param name="monitor">Writes messages to the log.</param> /// <param name="modRegistry">The mod registry with which to identify mods.</param> - public EventManager(IMonitor monitor, ModRegistry modRegistry) + public EventManager(IMonitor monitor, ModRegistry modRegistry, PerformanceCounterManager performanceCounterManager) { // create shortcut initializers - ManagedEvent<TEventArgs> ManageEventOf<TEventArgs>(string typeName, string eventName) => new ManagedEvent<TEventArgs>($"{typeName}.{eventName}", monitor, modRegistry); + ManagedEvent<TEventArgs> ManageEventOf<TEventArgs>(string typeName, string eventName) => new ManagedEvent<TEventArgs>($"{typeName}.{eventName}", monitor, modRegistry, performanceCounterManager); // init events (new) this.MenuChanged = ManageEventOf<MenuChangedEventArgs>(nameof(IModEvents.Display), nameof(IDisplayEvents.MenuChanged)); diff --git a/src/SMAPI/Framework/Events/IManagedEvent.cs b/src/SMAPI/Framework/Events/IManagedEvent.cs new file mode 100644 index 00000000..04476866 --- /dev/null +++ b/src/SMAPI/Framework/Events/IManagedEvent.cs @@ -0,0 +1,7 @@ +namespace StardewModdingAPI.Framework.Events +{ + internal interface IManagedEvent + { + string GetName(); + } +} diff --git a/src/SMAPI/Framework/Events/ManagedEvent.cs b/src/SMAPI/Framework/Events/ManagedEvent.cs index bb915738..bba94c35 100644 --- a/src/SMAPI/Framework/Events/ManagedEvent.cs +++ b/src/SMAPI/Framework/Events/ManagedEvent.cs @@ -1,15 +1,13 @@ using System; using System.Collections.Generic; -using System.Diagnostics; using System.Linq; -using StardewModdingAPI.Framework.Utilities; -using PerformanceCounter = StardewModdingAPI.Framework.PerformanceCounter.PerformanceCounter; +using PerformanceCounterManager = StardewModdingAPI.Framework.PerformanceCounter.PerformanceCounterManager; namespace StardewModdingAPI.Framework.Events { /// <summary>An event wrapper which intercepts and logs errors in handler code.</summary> /// <typeparam name="TEventArgs">The event arguments type.</typeparam> - internal class ManagedEvent<TEventArgs>: IPerformanceCounterEvent + internal class ManagedEvent<TEventArgs>: IManagedEvent { /********* ** Fields @@ -32,38 +30,8 @@ namespace StardewModdingAPI.Framework.Events /// <summary>The cached invocation list.</summary> private EventHandler<TEventArgs>[] CachedInvocationList; - public IDictionary<string, PerformanceCounter.PerformanceCounter> PerformanceCounters { get; } = new Dictionary<string, PerformanceCounter.PerformanceCounter>(); - - private readonly Stopwatch Stopwatch = new Stopwatch(); - - private long EventCallCount = 0; - - private readonly DateTime StartDateTime = DateTime.Now; - - public string GetEventName() - { - return this.EventName; - } - - public double GetGameAverageExecutionTime() - { - if (this.PerformanceCounters.TryGetValue(Constants.GamePerformanceCounterName, out PerformanceCounter.PerformanceCounter gameExecTime)) - { - return gameExecTime.GetAverage(); - } - - return 0; - } - - public double GetModsAverageExecutionTime() - { - return this.PerformanceCounters.Where(p => p.Key != Constants.GamePerformanceCounterName).Sum(p => p.Value.GetAverage()); - } - - public double GetAverageExecutionTime() - { - return this.PerformanceCounters.Sum(p => p.Value.GetAverage()); - } + /// <summary>The performance counter manager.</summary> + private readonly PerformanceCounterManager PerformanceCounterManager; /********* ** Public methods @@ -72,11 +40,18 @@ namespace StardewModdingAPI.Framework.Events /// <param name="eventName">A human-readable name for the event.</param> /// <param name="monitor">Writes messages to the log.</param> /// <param name="modRegistry">The mod registry with which to identify mods.</param> - public ManagedEvent(string eventName, IMonitor monitor, ModRegistry modRegistry) + public ManagedEvent(string eventName, IMonitor monitor, ModRegistry modRegistry, PerformanceCounterManager performanceCounterManager) { this.EventName = eventName; this.Monitor = monitor; this.ModRegistry = modRegistry; + this.PerformanceCounterManager = performanceCounterManager; + } + + /// <summary>Gets the event name.</summary> + public string GetName() + { + return this.EventName; } /// <summary>Get whether anything is listening to the event.</summary> @@ -99,8 +74,6 @@ namespace StardewModdingAPI.Framework.Events { this.Event += handler; this.AddTracking(mod, handler, this.Event?.GetInvocationList().Cast<EventHandler<TEventArgs>>()); - - } /// <summary>Remove an event handler.</summary> @@ -111,18 +84,6 @@ namespace StardewModdingAPI.Framework.Events this.RemoveTracking(handler, this.Event?.GetInvocationList().Cast<EventHandler<TEventArgs>>()); } - public long GetAverageCallsPerSecond() - { - long runtimeInSeconds = (long)DateTime.Now.Subtract(this.StartDateTime).TotalSeconds; - - if (runtimeInSeconds == 0) - { - return 0; - } - - return this.EventCallCount / runtimeInSeconds; - } - /// <summary>Raise the event and notify all handlers.</summary> /// <param name="args">The event arguments to pass.</param> public void Raise(TEventArgs args) @@ -130,37 +91,23 @@ namespace StardewModdingAPI.Framework.Events if (this.Event == null) return; - this.EventCallCount++; + + this.PerformanceCounterManager.BeginTrackInvocation(this.EventName); foreach (EventHandler<TEventArgs> handler in this.CachedInvocationList) { try { - var performanceCounterEntry = new PerformanceCounterEntry() - { - EventTime = DateTime.Now - }; - - this.Stopwatch.Reset(); - this.Stopwatch.Start(); - handler.Invoke(null, args); - this.Stopwatch.Stop(); - performanceCounterEntry.Elapsed = this.Stopwatch.Elapsed; - - string modName = this.GetSourceMod(handler)?.DisplayName ?? Constants.GamePerformanceCounterName; - - if (!this.PerformanceCounters.ContainsKey(modName)) - { - this.PerformanceCounters.Add(modName, new PerformanceCounter.PerformanceCounter($"{modName}.{this.EventName}")); - } - this.PerformanceCounters[modName].Add(performanceCounterEntry); - + this.PerformanceCounterManager.Track(this.EventName, this.GetModNameForPerformanceCounters(handler), + () => handler.Invoke(null, args)); } catch (Exception ex) { this.LogError(handler, ex); } } + + this.PerformanceCounterManager.EndTrackInvocation(this.EventName); } /// <summary>Raise the event and notify all handlers.</summary> @@ -191,6 +138,20 @@ namespace StardewModdingAPI.Framework.Events /********* ** Private methods *********/ + + private string GetModNameForPerformanceCounters(EventHandler<TEventArgs> handler) + { + IModMetadata mod = this.GetSourceMod(handler); + + if (mod == null) + { + return Constants.GamePerformanceCounterName; + } + + return mod.HasManifest() ? mod.Manifest.UniqueID : mod.DisplayName; + + } + /// <summary>Track an event handler.</summary> /// <param name="mod">The mod which added the handler.</param> /// <param name="handler">The event handler.</param> diff --git a/src/SMAPI/Framework/PerformanceCounter/AlertContext.cs b/src/SMAPI/Framework/PerformanceCounter/AlertContext.cs new file mode 100644 index 00000000..c4a57a49 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceCounter/AlertContext.cs @@ -0,0 +1,14 @@ +namespace StardewModdingAPI.Framework.PerformanceCounter +{ + public struct AlertContext + { + public string Source; + public double Elapsed; + + public AlertContext(string source, double elapsed) + { + this.Source = source; + this.Elapsed = elapsed; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceCounter/AlertEntry.cs b/src/SMAPI/Framework/PerformanceCounter/AlertEntry.cs new file mode 100644 index 00000000..284af1ce --- /dev/null +++ b/src/SMAPI/Framework/PerformanceCounter/AlertEntry.cs @@ -0,0 +1,20 @@ +using System.Collections.Generic; + +namespace StardewModdingAPI.Framework.PerformanceCounter +{ + internal struct AlertEntry + { + public PerformanceCounterCollection Collection; + public double ExecutionTimeMilliseconds; + public double Threshold; + public List<AlertContext> Context; + + public AlertEntry(PerformanceCounterCollection collection, double executionTimeMilliseconds, double threshold, List<AlertContext> context) + { + this.Collection = collection; + this.ExecutionTimeMilliseconds = executionTimeMilliseconds; + this.Threshold = threshold; + this.Context = context; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCategory.cs b/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCategory.cs deleted file mode 100644 index 14f74317..00000000 --- a/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCategory.cs +++ /dev/null @@ -1,16 +0,0 @@ -namespace StardewModdingAPI.Framework.Utilities -{ - public class EventPerformanceCounterCategory - { - public IPerformanceCounterEvent Event { get; } - public double MonitorThreshold { get; } - public bool IsImportant { get; } - public bool Monitor { get; } - - public EventPerformanceCounterCategory(IPerformanceCounterEvent @event, bool isImportant) - { - this.Event = @event; - this.IsImportant = isImportant; - } - } -} diff --git a/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCollection.cs b/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCollection.cs new file mode 100644 index 00000000..1aec28f3 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceCounter/EventPerformanceCounterCollection.cs @@ -0,0 +1,11 @@ +using StardewModdingAPI.Framework.Events; + +namespace StardewModdingAPI.Framework.PerformanceCounter +{ + internal class EventPerformanceCounterCollection: PerformanceCounterCollection + { + public EventPerformanceCounterCollection(PerformanceCounterManager manager, IManagedEvent @event, bool isImportant) : base(manager, @event.GetName(), isImportant) + { + } + } +} diff --git a/src/SMAPI/Framework/PerformanceCounter/IPerformanceCounterEvent.cs b/src/SMAPI/Framework/PerformanceCounter/IPerformanceCounterEvent.cs index 6b83586d..1bcf4fa0 100644 --- a/src/SMAPI/Framework/PerformanceCounter/IPerformanceCounterEvent.cs +++ b/src/SMAPI/Framework/PerformanceCounter/IPerformanceCounterEvent.cs @@ -7,7 +7,6 @@ namespace StardewModdingAPI.Framework.Utilities { string GetEventName(); long GetAverageCallsPerSecond(); - IDictionary<string, PerformanceCounter.PerformanceCounter> PerformanceCounters { get; } double GetGameAverageExecutionTime(); double GetModsAverageExecutionTime(); diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs index 0b0275b7..3dbc693a 100644 --- a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounter.cs @@ -6,22 +6,25 @@ using StardewModdingAPI.Framework.Utilities; namespace StardewModdingAPI.Framework.PerformanceCounter { - public class PerformanceCounter + internal class PerformanceCounter { private const int MAX_ENTRIES = 16384; - public string Name { get; } + public string Source { get; } public static Stopwatch Stopwatch = new Stopwatch(); public static long TotalNumEventsLogged; - + public double MonitorThresholdMilliseconds { get; set; } + public bool Monitor { get; set; } + private readonly PerformanceCounterCollection ParentCollection; private readonly CircularBuffer<PerformanceCounterEntry> _counter; private PerformanceCounterEntry? PeakPerformanceCounterEntry; - public PerformanceCounter(string name) + public PerformanceCounter(PerformanceCounterCollection parentCollection, string source) { - this.Name = name; + this.ParentCollection = parentCollection; + this.Source = source; this._counter = new CircularBuffer<PerformanceCounterEntry>(PerformanceCounter.MAX_ENTRIES); } @@ -47,6 +50,11 @@ namespace StardewModdingAPI.Framework.PerformanceCounter PerformanceCounter.Stopwatch.Start(); this._counter.Put(entry); + if (this.Monitor && entry.Elapsed.TotalMilliseconds > this.MonitorThresholdMilliseconds) + { + this.ParentCollection.AddAlert(entry.Elapsed.TotalMilliseconds, this.MonitorThresholdMilliseconds, new AlertContext(this.Source, entry.Elapsed.TotalMilliseconds)); + } + if (this.PeakPerformanceCounterEntry == null) { this.PeakPerformanceCounterEntry = entry; diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs new file mode 100644 index 00000000..343fddf6 --- /dev/null +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterCollection.cs @@ -0,0 +1,144 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using StardewModdingAPI.Framework.Utilities; + +namespace StardewModdingAPI.Framework.PerformanceCounter +{ + internal class PerformanceCounterCollection + { + public IDictionary<string, PerformanceCounter> PerformanceCounters { get; } = new Dictionary<string, PerformanceCounter>(); + private DateTime StartDateTime = DateTime.Now; + private long CallCount; + public string Name { get; private set; } + public bool IsImportant { get; set; } + private readonly Stopwatch Stopwatch = new Stopwatch(); + private readonly PerformanceCounterManager PerformanceCounterManager; + public double MonitorThresholdMilliseconds { get; set; } + public bool Monitor { get; set; } + private readonly List<AlertContext> TriggeredPerformanceCounters = new List<AlertContext>(); + + public PerformanceCounterCollection(PerformanceCounterManager performanceCounterManager, string name, bool isImportant) + { + this.Name = name; + this.PerformanceCounterManager = performanceCounterManager; + this.IsImportant = isImportant; + } + + public PerformanceCounterCollection(PerformanceCounterManager performanceCounterManager, string name) + { + this.PerformanceCounterManager = performanceCounterManager; + this.Name = name; + } + + public void Track(string source, PerformanceCounterEntry entry) + { + if (!this.PerformanceCounters.ContainsKey(source)) + { + this.PerformanceCounters.Add(source, new PerformanceCounter(this, source)); + } + this.PerformanceCounters[source].Add(entry); + + if (this.Monitor) + { + this.TriggeredPerformanceCounters.Add(new AlertContext(source, entry.Elapsed.TotalMilliseconds)); + } + } + + public double GetModsAverageExecutionTime() + { + return this.PerformanceCounters.Where(p => p.Key != Constants.GamePerformanceCounterName).Sum(p => p.Value.GetAverage()); + } + + public double GetAverageExecutionTime() + { + return this.PerformanceCounters.Sum(p => p.Value.GetAverage()); + } + + public double GetGameAverageExecutionTime() + { + if (this.PerformanceCounters.TryGetValue(Constants.GamePerformanceCounterName, out PerformanceCounter gameExecTime)) + { + return gameExecTime.GetAverage(); + } + + return 0; + } + + public void BeginTrackInvocation() + { + if (this.Monitor) + { + this.TriggeredPerformanceCounters.Clear(); + this.Stopwatch.Reset(); + this.Stopwatch.Start(); + } + + this.CallCount++; + + } + + public void EndTrackInvocation() + { + if (!this.Monitor) return; + + this.Stopwatch.Stop(); + if (this.Stopwatch.Elapsed.TotalMilliseconds >= this.MonitorThresholdMilliseconds) + { + this.AddAlert(this.Stopwatch.Elapsed.TotalMilliseconds, + this.MonitorThresholdMilliseconds, this.TriggeredPerformanceCounters); + } + } + + public void AddAlert(double executionTimeMilliseconds, double threshold, List<AlertContext> alerts) + { + this.PerformanceCounterManager.AddAlert(new AlertEntry(this, executionTimeMilliseconds, + threshold, alerts)); + } + + public void AddAlert(double executionTimeMilliseconds, double threshold, AlertContext alert) + { + this.AddAlert(executionTimeMilliseconds, threshold, new List<AlertContext>() {alert}); + } + + public void ResetCallsPerSecond() + { + this.CallCount = 0; + this.StartDateTime = DateTime.Now; + } + + public void Reset() + { + foreach (var i in this.PerformanceCounters) + { + i.Value.Reset(); + i.Value.ResetPeak(); + } + } + + public void ResetSource(string source) + { + foreach (var i in this.PerformanceCounters) + { + if (i.Value.Source.Equals(source, StringComparison.InvariantCultureIgnoreCase)) + { + i.Value.Reset(); + i.Value.ResetPeak(); + } + } + } + + public long GetAverageCallsPerSecond() + { + long runtimeInSeconds = (long) DateTime.Now.Subtract(this.StartDateTime).TotalSeconds; + + if (runtimeInSeconds == 0) + { + return 0; + } + + return this.CallCount / runtimeInSeconds; + } + } +} diff --git a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs index ae7258e2..9e77e2fa 100644 --- a/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs +++ b/src/SMAPI/Framework/PerformanceCounter/PerformanceCounterManager.cs @@ -1,4 +1,8 @@ +using System; using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; using StardewModdingAPI.Framework.Events; using StardewModdingAPI.Framework.Utilities; @@ -6,92 +10,187 @@ namespace StardewModdingAPI.Framework.PerformanceCounter { internal class PerformanceCounterManager { - public HashSet<EventPerformanceCounterCategory> PerformanceCounterEvents = new HashSet<EventPerformanceCounterCategory>(); + public HashSet<PerformanceCounterCollection> PerformanceCounterCollections = new HashSet<PerformanceCounterCollection>(); + public List<AlertEntry> Alerts = new List<AlertEntry>(); + private readonly IMonitor Monitor; + private readonly Stopwatch Stopwatch = new Stopwatch(); - private readonly EventManager EventManager; - - public PerformanceCounterManager(EventManager eventManager) + public PerformanceCounterManager(IMonitor monitor) { - this.EventManager = eventManager; - this.InitializePerformanceCounterEvents(); + this.Monitor = monitor; } public void Reset() { - foreach (var performanceCounter in this.PerformanceCounterEvents) + foreach (var performanceCounter in this.PerformanceCounterCollections) { - this.ResetCategory(performanceCounter); + foreach (var eventPerformanceCounter in performanceCounter.PerformanceCounters) + { + eventPerformanceCounter.Value.Reset(); + } } } - public void ResetCategory(EventPerformanceCounterCategory category) + /// <summary>Print any queued messages.</summary> + public void PrintQueued() { - foreach (var eventPerformanceCounter in category.Event.PerformanceCounters) + if (this.Alerts.Count == 0) + { + return; + } + StringBuilder sb = new StringBuilder(); + + foreach (var alert in this.Alerts) { - eventPerformanceCounter.Value.Reset(); + sb.AppendLine($"{alert.Collection.Name} took {alert.ExecutionTimeMilliseconds:F2}ms (exceeded threshold of {alert.Threshold:F2}ms)"); + + foreach (var context in alert.Context) + { + sb.AppendLine($"{context.Source}: {context.Elapsed:F2}ms"); + } } + + this.Alerts.Clear(); + + this.Monitor.Log(sb.ToString(), LogLevel.Error); + } + + public void BeginTrackInvocation(string collectionName) + { + this.GetOrCreateCollectionByName(collectionName).BeginTrackInvocation(); + } + + public void EndTrackInvocation(string collectionName) + { + this.GetOrCreateCollectionByName(collectionName).EndTrackInvocation(); } - private void InitializePerformanceCounterEvents() + public void Track(string collectionName, string modName, Action action) { - this.PerformanceCounterEvents = new HashSet<EventPerformanceCounterCategory>() + DateTime eventTime = DateTime.UtcNow; + this.Stopwatch.Reset(); + this.Stopwatch.Start(); + + try + { + action(); + } + finally { - new EventPerformanceCounterCategory(this.EventManager.MenuChanged, false), + this.Stopwatch.Stop(); - // Rendering Events - new EventPerformanceCounterCategory(this.EventManager.Rendering, true), - new EventPerformanceCounterCategory(this.EventManager.Rendered, true), - new EventPerformanceCounterCategory(this.EventManager.RenderingWorld, true), - new EventPerformanceCounterCategory(this.EventManager.RenderedWorld, true), - new EventPerformanceCounterCategory(this.EventManager.RenderingActiveMenu, true), - new EventPerformanceCounterCategory(this.EventManager.RenderedActiveMenu, true), - new EventPerformanceCounterCategory(this.EventManager.RenderingHud, true), - new EventPerformanceCounterCategory(this.EventManager.RenderedHud, true), - - new EventPerformanceCounterCategory(this.EventManager.WindowResized, false), - new EventPerformanceCounterCategory(this.EventManager.GameLaunched, false), - new EventPerformanceCounterCategory(this.EventManager.UpdateTicking, true), - new EventPerformanceCounterCategory(this.EventManager.UpdateTicked, true), - new EventPerformanceCounterCategory(this.EventManager.OneSecondUpdateTicking, true), - new EventPerformanceCounterCategory(this.EventManager.OneSecondUpdateTicked, true), - - new EventPerformanceCounterCategory(this.EventManager.SaveCreating, false), - new EventPerformanceCounterCategory(this.EventManager.SaveCreated, false), - new EventPerformanceCounterCategory(this.EventManager.Saving, false), - new EventPerformanceCounterCategory(this.EventManager.Saved, false), - - new EventPerformanceCounterCategory(this.EventManager.DayStarted, false), - new EventPerformanceCounterCategory(this.EventManager.DayEnding, false), - - new EventPerformanceCounterCategory(this.EventManager.TimeChanged, true), - - new EventPerformanceCounterCategory(this.EventManager.ReturnedToTitle, false), - - new EventPerformanceCounterCategory(this.EventManager.ButtonPressed, true), - new EventPerformanceCounterCategory(this.EventManager.ButtonReleased, true), - new EventPerformanceCounterCategory(this.EventManager.CursorMoved, true), - new EventPerformanceCounterCategory(this.EventManager.MouseWheelScrolled, true), - - new EventPerformanceCounterCategory(this.EventManager.PeerContextReceived, true), - new EventPerformanceCounterCategory(this.EventManager.ModMessageReceived, true), - new EventPerformanceCounterCategory(this.EventManager.PeerDisconnected, true), - new EventPerformanceCounterCategory(this.EventManager.InventoryChanged, true), - new EventPerformanceCounterCategory(this.EventManager.LevelChanged, true), - new EventPerformanceCounterCategory(this.EventManager.Warped, true), - - new EventPerformanceCounterCategory(this.EventManager.LocationListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.BuildingListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.LocationListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.DebrisListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.LargeTerrainFeatureListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.NpcListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.ObjectListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.ChestInventoryChanged, true), - new EventPerformanceCounterCategory(this.EventManager.TerrainFeatureListChanged, true), - new EventPerformanceCounterCategory(this.EventManager.LoadStageChanged, false), - new EventPerformanceCounterCategory(this.EventManager.UnvalidatedUpdateTicking, true), - new EventPerformanceCounterCategory(this.EventManager.UnvalidatedUpdateTicked, true), + this.GetOrCreateCollectionByName(collectionName).Track(modName, new PerformanceCounterEntry + { + EventTime = eventTime, + Elapsed = this.Stopwatch.Elapsed + }); + } + } + + public PerformanceCounterCollection GetCollectionByName(string name) + { + return this.PerformanceCounterCollections.FirstOrDefault(collection => collection.Name == name); + } + + public PerformanceCounterCollection GetOrCreateCollectionByName(string name) + { + PerformanceCounterCollection collection = this.GetCollectionByName(name); + if (collection == null) + { + collection = new PerformanceCounterCollection(this, name); + this.PerformanceCounterCollections.Add(collection); + } + + return collection; + } + + public void ResetCategory(string name) + { + foreach (var performanceCounterCollection in this.PerformanceCounterCollections) + { + if (performanceCounterCollection.Name.Equals(name, StringComparison.InvariantCultureIgnoreCase)) + { + performanceCounterCollection.ResetCallsPerSecond(); + performanceCounterCollection.Reset(); + } + } + } + + public void ResetSource(string name) + { + foreach (var performanceCounterCollection in this.PerformanceCounterCollections) + { + performanceCounterCollection.ResetSource(name); + } + } + + + public void AddAlert(AlertEntry entry) + { + this.Alerts.Add(entry); + } + + public void InitializePerformanceCounterEvents(EventManager eventManager) + { + this.PerformanceCounterCollections = new HashSet<PerformanceCounterCollection>() + { + new EventPerformanceCounterCollection(this, eventManager.MenuChanged, false), + + + // Rendering Events + new EventPerformanceCounterCollection(this, eventManager.Rendering, true), + new EventPerformanceCounterCollection(this, eventManager.Rendered, true), + new EventPerformanceCounterCollection(this, eventManager.RenderingWorld, true), + new EventPerformanceCounterCollection(this, eventManager.RenderedWorld, true), + new EventPerformanceCounterCollection(this, eventManager.RenderingActiveMenu, true), + new EventPerformanceCounterCollection(this, eventManager.RenderedActiveMenu, true), + new EventPerformanceCounterCollection(this, eventManager.RenderingHud, true), + new EventPerformanceCounterCollection(this, eventManager.RenderedHud, true), + + new EventPerformanceCounterCollection(this, eventManager.WindowResized, false), + new EventPerformanceCounterCollection(this, eventManager.GameLaunched, false), + new EventPerformanceCounterCollection(this, eventManager.UpdateTicking, true), + new EventPerformanceCounterCollection(this, eventManager.UpdateTicked, true), + new EventPerformanceCounterCollection(this, eventManager.OneSecondUpdateTicking, true), + new EventPerformanceCounterCollection(this, eventManager.OneSecondUpdateTicked, true), + + new EventPerformanceCounterCollection(this, eventManager.SaveCreating, false), + new EventPerformanceCounterCollection(this, eventManager.SaveCreated, false), + new EventPerformanceCounterCollection(this, eventManager.Saving, false), + new EventPerformanceCounterCollection(this, eventManager.Saved, false), + + new EventPerformanceCounterCollection(this, eventManager.DayStarted, false), + new EventPerformanceCounterCollection(this, eventManager.DayEnding, false), + + new EventPerformanceCounterCollection(this, eventManager.TimeChanged, true), + + new EventPerformanceCounterCollection(this, eventManager.ReturnedToTitle, false), + + new EventPerformanceCounterCollection(this, eventManager.ButtonPressed, true), + new EventPerformanceCounterCollection(this, eventManager.ButtonReleased, true), + new EventPerformanceCounterCollection(this, eventManager.CursorMoved, true), + new EventPerformanceCounterCollection(this, eventManager.MouseWheelScrolled, true), + + new EventPerformanceCounterCollection(this, eventManager.PeerContextReceived, true), + new EventPerformanceCounterCollection(this, eventManager.ModMessageReceived, true), + new EventPerformanceCounterCollection(this, eventManager.PeerDisconnected, true), + new EventPerformanceCounterCollection(this, eventManager.InventoryChanged, true), + new EventPerformanceCounterCollection(this, eventManager.LevelChanged, true), + new EventPerformanceCounterCollection(this, eventManager.Warped, true), + + new EventPerformanceCounterCollection(this, eventManager.LocationListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.BuildingListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.LocationListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.DebrisListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.LargeTerrainFeatureListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.NpcListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.ObjectListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.ChestInventoryChanged, true), + new EventPerformanceCounterCollection(this, eventManager.TerrainFeatureListChanged, true), + new EventPerformanceCounterCollection(this, eventManager.LoadStageChanged, false), + new EventPerformanceCounterCollection(this, eventManager.UnvalidatedUpdateTicking, false), + new EventPerformanceCounterCollection(this, eventManager.UnvalidatedUpdateTicked, false), }; } } diff --git a/src/SMAPI/Framework/SCore.cs b/src/SMAPI/Framework/SCore.cs index d1dba9ea..5b0c6691 100644 --- a/src/SMAPI/Framework/SCore.cs +++ b/src/SMAPI/Framework/SCore.cs @@ -25,7 +25,6 @@ using StardewModdingAPI.Framework.ModLoading; using StardewModdingAPI.Framework.Patching; using StardewModdingAPI.Framework.Reflection; using StardewModdingAPI.Framework.Serialization; -using StardewModdingAPI.Framework.Utilities; using StardewModdingAPI.Patches; using StardewModdingAPI.Toolkit; using StardewModdingAPI.Toolkit.Framework.Clients.WebApi; @@ -82,8 +81,6 @@ namespace StardewModdingAPI.Framework /// <summary>Manages SMAPI events for mods.</summary> private readonly EventManager EventManager; - private readonly PerformanceCounterManager PerformanceCounterManager; - /// <summary>Whether the game is currently running.</summary> private bool IsGameRunning; @@ -137,6 +134,10 @@ namespace StardewModdingAPI.Framework /// <remarks>This is initialized after the game starts. This is accessed directly because it's not part of the normal class model.</remarks> internal static DeprecationManager DeprecationManager { get; private set; } + /// <summary>Manages performance counters.</summary> + /// <remarks>This is initialized after the game starts. This is accessed directly because it's not part of the normal class model.</remarks> + internal static PerformanceCounterManager PerformanceCounterManager { get; private set; } + /********* ** Public methods @@ -165,8 +166,10 @@ namespace StardewModdingAPI.Framework ShowFullStampInConsole = this.Settings.DeveloperMode }; this.MonitorForGame = this.GetSecondaryMonitor("game"); - this.EventManager = new EventManager(this.Monitor, this.ModRegistry); - this.PerformanceCounterManager = new PerformanceCounterManager(this.EventManager); + + SCore.PerformanceCounterManager = new PerformanceCounterManager(this.Monitor); + this.EventManager = new EventManager(this.Monitor, this.ModRegistry, SCore.PerformanceCounterManager); + SCore.PerformanceCounterManager.InitializePerformanceCounterEvents(this.EventManager); SCore.DeprecationManager = new DeprecationManager(this.Monitor, this.ModRegistry); @@ -245,6 +248,7 @@ namespace StardewModdingAPI.Framework jsonHelper: this.Toolkit.JsonHelper, modRegistry: this.ModRegistry, deprecationManager: SCore.DeprecationManager, + performanceCounterManager: SCore.PerformanceCounterManager, onGameInitialized: this.InitializeAfterGameStart, onGameExiting: this.Dispose, cancellationToken: this.CancellationToken, @@ -488,20 +492,6 @@ namespace StardewModdingAPI.Framework this.Monitor.Log("Type 'help' for help, or 'help <cmd>' for a command's usage", LogLevel.Info); this.GameInstance.CommandManager.Add(null, "help", "Lists command documentation.\n\nUsage: help\nLists all available commands.\n\nUsage: help <cmd>\n- cmd: The name of a command whose documentation to display.", this.HandleCommand); this.GameInstance.CommandManager.Add(null, "reload_i18n", "Reloads translation files for all mods.\n\nUsage: reload_i18n", this.HandleCommand); - this.GameInstance.CommandManager.Add(null, "performance_counters", - "Displays performance counters.\n\n"+ - "Usage: performance_counters\n" + - "Shows the most important event invocation times\n\n"+ - "Usage: performance_counters summary|sum [all|important|name]\n"+ - "- summary or sum: Forces summary mode\n"+ - "- all, important or name: Displays all event performance counters, only important ones, or a specific event by name (defaults to important)\n\n"+ - "Usage: performance_counters [name] [threshold]\n"+ - "Shows detailed performance counters for a specific event\n"+ - "- name: The (partial) name of the event\n"+ - "- threshold: The minimum avg execution time (ms) of the event\n\n"+ - "Usage: performance_counters reset\n"+ - "Resets all performance counters\n", this.HandleCommand); - this.GameInstance.CommandManager.Add(null, "pc", "Alias for performance_counters", this.HandleCommand); // start handling command line input Thread inputThread = new Thread(() => @@ -1317,176 +1307,11 @@ namespace StardewModdingAPI.Framework this.ReloadTranslations(this.ModRegistry.GetAll(contentPacks: false)); this.Monitor.Log("Reloaded translation files for all mods. This only affects new translations the mods fetch; if they cached some text, it may not be updated.", LogLevel.Info); break; - case "performance_counters": - case "pc": - this.DisplayPerformanceCounters(arguments.ToList()); - break; default: throw new NotSupportedException($"Unrecognized core SMAPI command '{name}'."); } } - /// <summary>Get an ASCII table to show tabular data in the console.</summary> - /// <typeparam name="T">The data type.</typeparam> - /// <param name="data">The data to display.</param> - /// <param name="header">The table header.</param> - /// <param name="getRow">Returns a set of fields for a data value.</param> - protected string GetTableString<T>(IEnumerable<T> data, string[] header, Func<T, string[]> getRow) - { - // get table data - int[] widths = header.Select(p => p.Length).ToArray(); - string[][] rows = data - .Select(item => - { - string[] fields = getRow(item); - if (fields.Length != widths.Length) - throw new InvalidOperationException($"Expected {widths.Length} columns, but found {fields.Length}: {string.Join(", ", fields)}"); - - for (int i = 0; i < fields.Length; i++) - widths[i] = Math.Max(widths[i], fields[i].Length); - - return fields; - }) - .ToArray(); - - // render fields - List<string[]> lines = new List<string[]>(rows.Length + 2) - { - header, - header.Select((value, i) => "".PadRight(widths[i], '-')).ToArray() - }; - lines.AddRange(rows); - - return string.Join( - Environment.NewLine, - lines.Select(line => string.Join(" | ", line.Select((field, i) => field.PadLeft(widths[i], ' ')).ToArray()) - ) - ); - } - - private void DisplayPerformanceCounters(IList<string> arguments) - { - bool showSummary = true; - bool showSummaryOnlyImportant = true; - string filterByName = null; - - if (arguments.Any()) - { - switch (arguments[0]) - { - case "summary": - case "sum": - showSummary = true; - - if (arguments.Count > 1) - { - switch (arguments[1].ToLower()) - { - case "all": - showSummaryOnlyImportant = false; - break; - case "important": - showSummaryOnlyImportant = true; - break; - default: - filterByName = arguments[1]; - break; - } - } - break; - case "reset": - this.PerformanceCounterManager.Reset(); - return; - default: - showSummary = false; - filterByName = arguments[0]; - break; - - } - } - var lastMinute = TimeSpan.FromSeconds(60); - - if (showSummary) - { - this.DisplayPerformanceCounterSummary(showSummaryOnlyImportant, filterByName); - } - else - { - var data = this.PerformanceCounterManager.PerformanceCounterEvents.Where(p => p.Event.GetEventName().ToLowerInvariant().Contains(filterByName.ToLowerInvariant())); - - foreach (var i in data) - { - this.DisplayPerformanceCounter(i, lastMinute); - } - } - - double avgTime = PerformanceCounter.PerformanceCounter.Stopwatch.ElapsedMilliseconds / (double)PerformanceCounter.PerformanceCounter.TotalNumEventsLogged; - this.Monitor.Log($"Logged {PerformanceCounter.PerformanceCounter.TotalNumEventsLogged} events in {PerformanceCounter.PerformanceCounter.Stopwatch.ElapsedMilliseconds}ms (avg {avgTime:F4}ms / event)"); - - } - - private void DisplayPerformanceCounterSummary(bool showOnlyImportant, string eventNameFilter = null) - { - StringBuilder sb = new StringBuilder($"Performance Counter Summary:\n\n"); - - IEnumerable<EventPerformanceCounterCategory> data; - - if (eventNameFilter != null) - { - data = this.PerformanceCounterManager.PerformanceCounterEvents.Where(p => p.Event.GetEventName().ToLowerInvariant().Contains(eventNameFilter.ToLowerInvariant())); - } - else - { - if (showOnlyImportant) - { - data = this.PerformanceCounterManager.PerformanceCounterEvents.Where(p => p.IsImportant); - } - else - { - data = this.PerformanceCounterManager.PerformanceCounterEvents; - } - } - - - sb.AppendLine(this.GetTableString( - data: data, - header: new[] {"Event", "Avg Calls/s", "Avg Execution Time (Game)", "Avg Execution Time (Mods)", "Avg Execution Time (Game+Mods)"}, - getRow: item => new[] - { - item.Event.GetEventName(), - item.Event.GetAverageCallsPerSecond().ToString(), - item.Event.GetGameAverageExecutionTime().ToString("F2") + " ms", - item.Event.GetModsAverageExecutionTime().ToString("F2") + " ms", - item.Event.GetAverageExecutionTime().ToString("F2") + " ms" - } - )); - - this.Monitor.Log(sb.ToString(), LogLevel.Info); - } - - private void DisplayPerformanceCounter (EventPerformanceCounterCategory obj, TimeSpan averageInterval) - { - StringBuilder sb = new StringBuilder($"Performance Counter for {obj.Event.GetEventName()}:\n\n"); - - sb.AppendLine(this.GetTableString( - data: obj.Event.PerformanceCounters, - header: new[] {"Mod", $"Avg Execution Time over {(int)averageInterval.TotalSeconds}s", "Last Execution Time", "Peak Execution Time"}, - getRow: item => new[] - { - item.Key, - item.Value.GetAverage(averageInterval).ToString("F2") + " ms" ?? "-", - item.Value.GetLastEntry()?.Elapsed.TotalMilliseconds.ToString("F2") + " ms" ?? "-", - item.Value.GetPeak()?.Elapsed.TotalMilliseconds.ToString("F2") + " ms" ?? "-", - } - )); - - sb.AppendLine($"Average execution time (Game+Mods): {obj.Event.GetAverageExecutionTime():F2} ms"); - sb.AppendLine($"Average execution time (Game only) : {obj.Event.GetGameAverageExecutionTime():F2} ms"); - sb.AppendLine($"Average execution time (Mods only) : {obj.Event.GetModsAverageExecutionTime():F2} ms"); - - this.Monitor.Log(sb.ToString(), LogLevel.Info); - } - /// <summary>Redirect messages logged directly to the console to the given monitor.</summary> /// <param name="gameMonitor">The monitor with which to log messages as the game.</param> /// <param name="message">The message to log.</param> diff --git a/src/SMAPI/Framework/SGame.cs b/src/SMAPI/Framework/SGame.cs index d6c3b836..8aba9b57 100644 --- a/src/SMAPI/Framework/SGame.cs +++ b/src/SMAPI/Framework/SGame.cs @@ -17,6 +17,7 @@ using StardewModdingAPI.Framework.Content; using StardewModdingAPI.Framework.Events; using StardewModdingAPI.Framework.Input; using StardewModdingAPI.Framework.Networking; +using StardewModdingAPI.Framework.PerformanceCounter; using StardewModdingAPI.Framework.Reflection; using StardewModdingAPI.Framework.StateTracking.Comparers; using StardewModdingAPI.Framework.StateTracking.Snapshots; @@ -58,6 +59,8 @@ namespace StardewModdingAPI.Framework /// <summary>Manages deprecation warnings.</summary> private readonly DeprecationManager DeprecationManager; + private readonly PerformanceCounterManager PerformanceCounterManager; + /// <summary>The maximum number of consecutive attempts SMAPI should make to recover from a draw error.</summary> private readonly Countdown DrawCrashTimer = new Countdown(60); // 60 ticks = roughly one second @@ -152,11 +155,12 @@ namespace StardewModdingAPI.Framework /// <param name="jsonHelper">Encapsulates SMAPI's JSON file parsing.</param> /// <param name="modRegistry">Tracks the installed mods.</param> /// <param name="deprecationManager">Manages deprecation warnings.</param> + /// <param name="performanceCounterManager">Manages performance monitoring.</param> /// <param name="onGameInitialized">A callback to invoke after the game finishes initializing.</param> /// <param name="onGameExiting">A callback to invoke when the game exits.</param> /// <param name="cancellationToken">Propagates notification that SMAPI should exit.</param> /// <param name="logNetworkTraffic">Whether to log network traffic.</param> - internal SGame(Monitor monitor, IMonitor monitorForGame, Reflector reflection, Translator translator, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, DeprecationManager deprecationManager, Action onGameInitialized, Action onGameExiting, CancellationTokenSource cancellationToken, bool logNetworkTraffic) + internal SGame(Monitor monitor, IMonitor monitorForGame, Reflector reflection, Translator translator, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, DeprecationManager deprecationManager, PerformanceCounterManager performanceCounterManager, Action onGameInitialized, Action onGameExiting, CancellationTokenSource cancellationToken, bool logNetworkTraffic) { this.OnLoadingFirstAsset = SGame.ConstructorHack.OnLoadingFirstAsset; SGame.ConstructorHack = null; @@ -176,6 +180,7 @@ namespace StardewModdingAPI.Framework this.Reflection = reflection; this.Translator = translator; this.DeprecationManager = deprecationManager; + this.PerformanceCounterManager = performanceCounterManager; this.OnGameInitialized = onGameInitialized; this.OnGameExiting = onGameExiting; Game1.input = new SInputState(); @@ -307,6 +312,7 @@ namespace StardewModdingAPI.Framework try { this.DeprecationManager.PrintQueued(); + this.PerformanceCounterManager.PrintQueued(); /********* ** First-tick initialization @@ -382,7 +388,7 @@ namespace StardewModdingAPI.Framework // state while mods are running their code. This is risky, because data changes can // conflict (e.g. collection changed during enumeration errors) and data may change // unexpectedly from one mod instruction to the next. - // + // // Therefore we can just run Game1.Update here without raising any SMAPI events. There's // a small chance that the task will finish after we defer but before the game checks, // which means technically events should be raised, but the effects of missing one diff --git a/src/SMAPI/Program.cs b/src/SMAPI/Program.cs index b5e6307a..933590d3 100644 --- a/src/SMAPI/Program.cs +++ b/src/SMAPI/Program.cs @@ -11,7 +11,7 @@ using StardewModdingAPI.Framework; using StardewModdingAPI.Toolkit.Utilities; [assembly: InternalsVisibleTo("SMAPI.Tests")] -[assembly: InternalsVisibleTo("SMAPI.Mods.ConsoleCommands")] +[assembly: InternalsVisibleTo("ConsoleCommands")] [assembly: InternalsVisibleTo("DynamicProxyGenAssembly2")] // Moq for unit testing namespace StardewModdingAPI { |