Reworked the console implementation, added monitoring. Some internal refactoring.

This commit is contained in:
Drachenkaetzchen 2020-01-11 15:45:45 +01:00
parent 8a77373b18
commit 280dc91183
18 changed files with 1019 additions and 344 deletions

View File

@ -1,6 +1,7 @@
using System; using System;
using System.Collections; using System.Collections;
using System.Collections.Generic; using System.Collections.Generic;
using System.Globalization;
using System.Linq; using System.Linq;
namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands
@ -113,6 +114,51 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands
return true; 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> /// <summary>Returns an enumerator that iterates through the collection.</summary>
/// <returns>An enumerator that can be used to iterate through the collection.</returns> /// <returns>An enumerator that can be used to iterate through the collection.</returns>
public IEnumerator<string> GetEnumerator() public IEnumerator<string> GetEnumerator()
@ -154,5 +200,22 @@ namespace StardewModdingAPI.Mods.ConsoleCommands.Framework.Commands
else else
this.LogError($"Argument {index} ({name}) must be an integer."); 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.");
}
} }
} }

View File

@ -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 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) 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();
} }
} }
} }

View File

@ -67,6 +67,10 @@
</None> </None>
</ItemGroup> </ItemGroup>
<ItemGroup>
<PackageReference Include="System.ValueTuple" Version="4.5.0" />
</ItemGroup>
<Import Project="..\SMAPI.Internal\SMAPI.Internal.projitems" Label="Shared" /> <Import Project="..\SMAPI.Internal\SMAPI.Internal.projitems" Label="Shared" />
<Import Project="..\..\build\common.targets" /> <Import Project="..\..\build\common.targets" />

View File

@ -56,7 +56,7 @@ namespace StardewModdingAPI
internal const string HomePageUrl = "https://smapi.io"; internal const string HomePageUrl = "https://smapi.io";
/// <summary>The URL of the SMAPI home page.</summary> /// <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> /// <summary>The absolute path to the folder containing SMAPI's internal files.</summary>
internal static readonly string InternalFilesPath = Program.DllSearchPath; internal static readonly string InternalFilesPath = Program.DllSearchPath;

View File

@ -1,5 +1,6 @@
using System.Diagnostics.CodeAnalysis; using System.Diagnostics.CodeAnalysis;
using StardewModdingAPI.Events; using StardewModdingAPI.Events;
using StardewModdingAPI.Framework.PerformanceCounter;
namespace StardewModdingAPI.Framework.Events namespace StardewModdingAPI.Framework.Events
{ {
@ -173,10 +174,10 @@ namespace StardewModdingAPI.Framework.Events
/// <summary>Construct an instance.</summary> /// <summary>Construct an instance.</summary>
/// <param name="monitor">Writes messages to the log.</param> /// <param name="monitor">Writes messages to the log.</param>
/// <param name="modRegistry">The mod registry with which to identify mods.</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 // 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) // init events (new)
this.MenuChanged = ManageEventOf<MenuChangedEventArgs>(nameof(IModEvents.Display), nameof(IDisplayEvents.MenuChanged)); this.MenuChanged = ManageEventOf<MenuChangedEventArgs>(nameof(IModEvents.Display), nameof(IDisplayEvents.MenuChanged));

View File

@ -0,0 +1,7 @@
namespace StardewModdingAPI.Framework.Events
{
internal interface IManagedEvent
{
string GetName();
}
}

View File

@ -1,15 +1,13 @@
using System; using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.Diagnostics;
using System.Linq; using System.Linq;
using StardewModdingAPI.Framework.Utilities; using PerformanceCounterManager = StardewModdingAPI.Framework.PerformanceCounter.PerformanceCounterManager;
using PerformanceCounter = StardewModdingAPI.Framework.PerformanceCounter.PerformanceCounter;
namespace StardewModdingAPI.Framework.Events namespace StardewModdingAPI.Framework.Events
{ {
/// <summary>An event wrapper which intercepts and logs errors in handler code.</summary> /// <summary>An event wrapper which intercepts and logs errors in handler code.</summary>
/// <typeparam name="TEventArgs">The event arguments type.</typeparam> /// <typeparam name="TEventArgs">The event arguments type.</typeparam>
internal class ManagedEvent<TEventArgs>: IPerformanceCounterEvent internal class ManagedEvent<TEventArgs>: IManagedEvent
{ {
/********* /*********
** Fields ** Fields
@ -32,38 +30,8 @@ namespace StardewModdingAPI.Framework.Events
/// <summary>The cached invocation list.</summary> /// <summary>The cached invocation list.</summary>
private EventHandler<TEventArgs>[] CachedInvocationList; private EventHandler<TEventArgs>[] CachedInvocationList;
public IDictionary<string, PerformanceCounter.PerformanceCounter> PerformanceCounters { get; } = new Dictionary<string, PerformanceCounter.PerformanceCounter>(); /// <summary>The performance counter manager.</summary>
private readonly PerformanceCounterManager PerformanceCounterManager;
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());
}
/********* /*********
** Public methods ** Public methods
@ -72,11 +40,18 @@ namespace StardewModdingAPI.Framework.Events
/// <param name="eventName">A human-readable name for the event.</param> /// <param name="eventName">A human-readable name for the event.</param>
/// <param name="monitor">Writes messages to the log.</param> /// <param name="monitor">Writes messages to the log.</param>
/// <param name="modRegistry">The mod registry with which to identify mods.</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.EventName = eventName;
this.Monitor = monitor; this.Monitor = monitor;
this.ModRegistry = modRegistry; 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> /// <summary>Get whether anything is listening to the event.</summary>
@ -99,8 +74,6 @@ namespace StardewModdingAPI.Framework.Events
{ {
this.Event += handler; this.Event += handler;
this.AddTracking(mod, handler, this.Event?.GetInvocationList().Cast<EventHandler<TEventArgs>>()); this.AddTracking(mod, handler, this.Event?.GetInvocationList().Cast<EventHandler<TEventArgs>>());
} }
/// <summary>Remove an event handler.</summary> /// <summary>Remove an event handler.</summary>
@ -111,18 +84,6 @@ namespace StardewModdingAPI.Framework.Events
this.RemoveTracking(handler, this.Event?.GetInvocationList().Cast<EventHandler<TEventArgs>>()); 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> /// <summary>Raise the event and notify all handlers.</summary>
/// <param name="args">The event arguments to pass.</param> /// <param name="args">The event arguments to pass.</param>
public void Raise(TEventArgs args) public void Raise(TEventArgs args)
@ -130,37 +91,23 @@ namespace StardewModdingAPI.Framework.Events
if (this.Event == null) if (this.Event == null)
return; return;
this.EventCallCount++;
this.PerformanceCounterManager.BeginTrackInvocation(this.EventName);
foreach (EventHandler<TEventArgs> handler in this.CachedInvocationList) foreach (EventHandler<TEventArgs> handler in this.CachedInvocationList)
{ {
try try
{ {
var performanceCounterEntry = new PerformanceCounterEntry() this.PerformanceCounterManager.Track(this.EventName, this.GetModNameForPerformanceCounters(handler),
{ () => handler.Invoke(null, args));
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);
} }
catch (Exception ex) catch (Exception ex)
{ {
this.LogError(handler, ex); this.LogError(handler, ex);
} }
} }
this.PerformanceCounterManager.EndTrackInvocation(this.EventName);
} }
/// <summary>Raise the event and notify all handlers.</summary> /// <summary>Raise the event and notify all handlers.</summary>
@ -191,6 +138,20 @@ namespace StardewModdingAPI.Framework.Events
/********* /*********
** Private methods ** 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> /// <summary>Track an event handler.</summary>
/// <param name="mod">The mod which added the handler.</param> /// <param name="mod">The mod which added the handler.</param>
/// <param name="handler">The event handler.</param> /// <param name="handler">The event handler.</param>

View File

@ -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;
}
}
}

View File

@ -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;
}
}
}

View File

@ -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;
}
}
}

View File

@ -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)
{
}
}
}

View File

@ -7,7 +7,6 @@ namespace StardewModdingAPI.Framework.Utilities
{ {
string GetEventName(); string GetEventName();
long GetAverageCallsPerSecond(); long GetAverageCallsPerSecond();
IDictionary<string, PerformanceCounter.PerformanceCounter> PerformanceCounters { get; }
double GetGameAverageExecutionTime(); double GetGameAverageExecutionTime();
double GetModsAverageExecutionTime(); double GetModsAverageExecutionTime();

View File

@ -6,22 +6,25 @@ using StardewModdingAPI.Framework.Utilities;
namespace StardewModdingAPI.Framework.PerformanceCounter namespace StardewModdingAPI.Framework.PerformanceCounter
{ {
public class PerformanceCounter internal class PerformanceCounter
{ {
private const int MAX_ENTRIES = 16384; private const int MAX_ENTRIES = 16384;
public string Name { get; } public string Source { get; }
public static Stopwatch Stopwatch = new Stopwatch(); public static Stopwatch Stopwatch = new Stopwatch();
public static long TotalNumEventsLogged; public static long TotalNumEventsLogged;
public double MonitorThresholdMilliseconds { get; set; }
public bool Monitor { get; set; }
private readonly PerformanceCounterCollection ParentCollection;
private readonly CircularBuffer<PerformanceCounterEntry> _counter; private readonly CircularBuffer<PerformanceCounterEntry> _counter;
private PerformanceCounterEntry? PeakPerformanceCounterEntry; 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); this._counter = new CircularBuffer<PerformanceCounterEntry>(PerformanceCounter.MAX_ENTRIES);
} }
@ -47,6 +50,11 @@ namespace StardewModdingAPI.Framework.PerformanceCounter
PerformanceCounter.Stopwatch.Start(); PerformanceCounter.Stopwatch.Start();
this._counter.Put(entry); 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) if (this.PeakPerformanceCounterEntry == null)
{ {
this.PeakPerformanceCounterEntry = entry; this.PeakPerformanceCounterEntry = entry;

View File

@ -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;
}
}
}

View File

@ -1,4 +1,8 @@
using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Text;
using StardewModdingAPI.Framework.Events; using StardewModdingAPI.Framework.Events;
using StardewModdingAPI.Framework.Utilities; using StardewModdingAPI.Framework.Utilities;
@ -6,92 +10,187 @@ namespace StardewModdingAPI.Framework.PerformanceCounter
{ {
internal class PerformanceCounterManager 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(IMonitor monitor)
public PerformanceCounterManager(EventManager eventManager)
{ {
this.EventManager = eventManager; this.Monitor = monitor;
this.InitializePerformanceCounterEvents();
} }
public void Reset() 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)
{ {
eventPerformanceCounter.Value.Reset(); return;
}
StringBuilder sb = new StringBuilder();
foreach (var alert in this.Alerts)
{
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();
}
public void Track(string collectionName, string modName, Action action)
{
DateTime eventTime = DateTime.UtcNow;
this.Stopwatch.Reset();
this.Stopwatch.Start();
try
{
action();
}
finally
{
this.Stopwatch.Stop();
this.GetOrCreateCollectionByName(collectionName).Track(modName, new PerformanceCounterEntry
{
EventTime = eventTime,
Elapsed = this.Stopwatch.Elapsed
});
} }
} }
private void InitializePerformanceCounterEvents() public PerformanceCounterCollection GetCollectionByName(string name)
{ {
this.PerformanceCounterEvents = new HashSet<EventPerformanceCounterCategory>() return this.PerformanceCounterCollections.FirstOrDefault(collection => collection.Name == name);
}
public PerformanceCounterCollection GetOrCreateCollectionByName(string name)
{
PerformanceCounterCollection collection = this.GetCollectionByName(name);
if (collection == null)
{ {
new EventPerformanceCounterCategory(this.EventManager.MenuChanged, false), 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 // Rendering Events
new EventPerformanceCounterCategory(this.EventManager.Rendering, true), new EventPerformanceCounterCollection(this, eventManager.Rendering, true),
new EventPerformanceCounterCategory(this.EventManager.Rendered, true), new EventPerformanceCounterCollection(this, eventManager.Rendered, true),
new EventPerformanceCounterCategory(this.EventManager.RenderingWorld, true), new EventPerformanceCounterCollection(this, eventManager.RenderingWorld, true),
new EventPerformanceCounterCategory(this.EventManager.RenderedWorld, true), new EventPerformanceCounterCollection(this, eventManager.RenderedWorld, true),
new EventPerformanceCounterCategory(this.EventManager.RenderingActiveMenu, true), new EventPerformanceCounterCollection(this, eventManager.RenderingActiveMenu, true),
new EventPerformanceCounterCategory(this.EventManager.RenderedActiveMenu, true), new EventPerformanceCounterCollection(this, eventManager.RenderedActiveMenu, true),
new EventPerformanceCounterCategory(this.EventManager.RenderingHud, true), new EventPerformanceCounterCollection(this, eventManager.RenderingHud, true),
new EventPerformanceCounterCategory(this.EventManager.RenderedHud, true), new EventPerformanceCounterCollection(this, eventManager.RenderedHud, true),
new EventPerformanceCounterCategory(this.EventManager.WindowResized, false), new EventPerformanceCounterCollection(this, eventManager.WindowResized, false),
new EventPerformanceCounterCategory(this.EventManager.GameLaunched, false), new EventPerformanceCounterCollection(this, eventManager.GameLaunched, false),
new EventPerformanceCounterCategory(this.EventManager.UpdateTicking, true), new EventPerformanceCounterCollection(this, eventManager.UpdateTicking, true),
new EventPerformanceCounterCategory(this.EventManager.UpdateTicked, true), new EventPerformanceCounterCollection(this, eventManager.UpdateTicked, true),
new EventPerformanceCounterCategory(this.EventManager.OneSecondUpdateTicking, true), new EventPerformanceCounterCollection(this, eventManager.OneSecondUpdateTicking, true),
new EventPerformanceCounterCategory(this.EventManager.OneSecondUpdateTicked, true), new EventPerformanceCounterCollection(this, eventManager.OneSecondUpdateTicked, true),
new EventPerformanceCounterCategory(this.EventManager.SaveCreating, false), new EventPerformanceCounterCollection(this, eventManager.SaveCreating, false),
new EventPerformanceCounterCategory(this.EventManager.SaveCreated, false), new EventPerformanceCounterCollection(this, eventManager.SaveCreated, false),
new EventPerformanceCounterCategory(this.EventManager.Saving, false), new EventPerformanceCounterCollection(this, eventManager.Saving, false),
new EventPerformanceCounterCategory(this.EventManager.Saved, false), new EventPerformanceCounterCollection(this, eventManager.Saved, false),
new EventPerformanceCounterCategory(this.EventManager.DayStarted, false), new EventPerformanceCounterCollection(this, eventManager.DayStarted, false),
new EventPerformanceCounterCategory(this.EventManager.DayEnding, false), new EventPerformanceCounterCollection(this, eventManager.DayEnding, false),
new EventPerformanceCounterCategory(this.EventManager.TimeChanged, true), new EventPerformanceCounterCollection(this, eventManager.TimeChanged, true),
new EventPerformanceCounterCategory(this.EventManager.ReturnedToTitle, false), new EventPerformanceCounterCollection(this, eventManager.ReturnedToTitle, false),
new EventPerformanceCounterCategory(this.EventManager.ButtonPressed, true), new EventPerformanceCounterCollection(this, eventManager.ButtonPressed, true),
new EventPerformanceCounterCategory(this.EventManager.ButtonReleased, true), new EventPerformanceCounterCollection(this, eventManager.ButtonReleased, true),
new EventPerformanceCounterCategory(this.EventManager.CursorMoved, true), new EventPerformanceCounterCollection(this, eventManager.CursorMoved, true),
new EventPerformanceCounterCategory(this.EventManager.MouseWheelScrolled, true), new EventPerformanceCounterCollection(this, eventManager.MouseWheelScrolled, true),
new EventPerformanceCounterCategory(this.EventManager.PeerContextReceived, true), new EventPerformanceCounterCollection(this, eventManager.PeerContextReceived, true),
new EventPerformanceCounterCategory(this.EventManager.ModMessageReceived, true), new EventPerformanceCounterCollection(this, eventManager.ModMessageReceived, true),
new EventPerformanceCounterCategory(this.EventManager.PeerDisconnected, true), new EventPerformanceCounterCollection(this, eventManager.PeerDisconnected, true),
new EventPerformanceCounterCategory(this.EventManager.InventoryChanged, true), new EventPerformanceCounterCollection(this, eventManager.InventoryChanged, true),
new EventPerformanceCounterCategory(this.EventManager.LevelChanged, true), new EventPerformanceCounterCollection(this, eventManager.LevelChanged, true),
new EventPerformanceCounterCategory(this.EventManager.Warped, true), new EventPerformanceCounterCollection(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),
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),
}; };
} }
} }

View File

@ -25,7 +25,6 @@ using StardewModdingAPI.Framework.ModLoading;
using StardewModdingAPI.Framework.Patching; using StardewModdingAPI.Framework.Patching;
using StardewModdingAPI.Framework.Reflection; using StardewModdingAPI.Framework.Reflection;
using StardewModdingAPI.Framework.Serialization; using StardewModdingAPI.Framework.Serialization;
using StardewModdingAPI.Framework.Utilities;
using StardewModdingAPI.Patches; using StardewModdingAPI.Patches;
using StardewModdingAPI.Toolkit; using StardewModdingAPI.Toolkit;
using StardewModdingAPI.Toolkit.Framework.Clients.WebApi; using StardewModdingAPI.Toolkit.Framework.Clients.WebApi;
@ -82,8 +81,6 @@ namespace StardewModdingAPI.Framework
/// <summary>Manages SMAPI events for mods.</summary> /// <summary>Manages SMAPI events for mods.</summary>
private readonly EventManager EventManager; private readonly EventManager EventManager;
private readonly PerformanceCounterManager PerformanceCounterManager;
/// <summary>Whether the game is currently running.</summary> /// <summary>Whether the game is currently running.</summary>
private bool IsGameRunning; 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> /// <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; } 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 ** Public methods
@ -165,8 +166,10 @@ namespace StardewModdingAPI.Framework
ShowFullStampInConsole = this.Settings.DeveloperMode ShowFullStampInConsole = this.Settings.DeveloperMode
}; };
this.MonitorForGame = this.GetSecondaryMonitor("game"); 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); SCore.DeprecationManager = new DeprecationManager(this.Monitor, this.ModRegistry);
@ -245,6 +248,7 @@ namespace StardewModdingAPI.Framework
jsonHelper: this.Toolkit.JsonHelper, jsonHelper: this.Toolkit.JsonHelper,
modRegistry: this.ModRegistry, modRegistry: this.ModRegistry,
deprecationManager: SCore.DeprecationManager, deprecationManager: SCore.DeprecationManager,
performanceCounterManager: SCore.PerformanceCounterManager,
onGameInitialized: this.InitializeAfterGameStart, onGameInitialized: this.InitializeAfterGameStart,
onGameExiting: this.Dispose, onGameExiting: this.Dispose,
cancellationToken: this.CancellationToken, 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.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, "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, "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 // start handling command line input
Thread inputThread = new Thread(() => Thread inputThread = new Thread(() =>
@ -1317,176 +1307,11 @@ namespace StardewModdingAPI.Framework
this.ReloadTranslations(this.ModRegistry.GetAll(contentPacks: false)); 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); 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; break;
case "performance_counters":
case "pc":
this.DisplayPerformanceCounters(arguments.ToList());
break;
default: default:
throw new NotSupportedException($"Unrecognized core SMAPI command '{name}'."); 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> /// <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="gameMonitor">The monitor with which to log messages as the game.</param>
/// <param name="message">The message to log.</param> /// <param name="message">The message to log.</param>

View File

@ -17,6 +17,7 @@ using StardewModdingAPI.Framework.Content;
using StardewModdingAPI.Framework.Events; using StardewModdingAPI.Framework.Events;
using StardewModdingAPI.Framework.Input; using StardewModdingAPI.Framework.Input;
using StardewModdingAPI.Framework.Networking; using StardewModdingAPI.Framework.Networking;
using StardewModdingAPI.Framework.PerformanceCounter;
using StardewModdingAPI.Framework.Reflection; using StardewModdingAPI.Framework.Reflection;
using StardewModdingAPI.Framework.StateTracking.Comparers; using StardewModdingAPI.Framework.StateTracking.Comparers;
using StardewModdingAPI.Framework.StateTracking.Snapshots; using StardewModdingAPI.Framework.StateTracking.Snapshots;
@ -58,6 +59,8 @@ namespace StardewModdingAPI.Framework
/// <summary>Manages deprecation warnings.</summary> /// <summary>Manages deprecation warnings.</summary>
private readonly DeprecationManager DeprecationManager; 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> /// <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 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="jsonHelper">Encapsulates SMAPI's JSON file parsing.</param>
/// <param name="modRegistry">Tracks the installed mods.</param> /// <param name="modRegistry">Tracks the installed mods.</param>
/// <param name="deprecationManager">Manages deprecation warnings.</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="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="onGameExiting">A callback to invoke when the game exits.</param>
/// <param name="cancellationToken">Propagates notification that SMAPI should exit.</param> /// <param name="cancellationToken">Propagates notification that SMAPI should exit.</param>
/// <param name="logNetworkTraffic">Whether to log network traffic.</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; this.OnLoadingFirstAsset = SGame.ConstructorHack.OnLoadingFirstAsset;
SGame.ConstructorHack = null; SGame.ConstructorHack = null;
@ -176,6 +180,7 @@ namespace StardewModdingAPI.Framework
this.Reflection = reflection; this.Reflection = reflection;
this.Translator = translator; this.Translator = translator;
this.DeprecationManager = deprecationManager; this.DeprecationManager = deprecationManager;
this.PerformanceCounterManager = performanceCounterManager;
this.OnGameInitialized = onGameInitialized; this.OnGameInitialized = onGameInitialized;
this.OnGameExiting = onGameExiting; this.OnGameExiting = onGameExiting;
Game1.input = new SInputState(); Game1.input = new SInputState();
@ -307,6 +312,7 @@ namespace StardewModdingAPI.Framework
try try
{ {
this.DeprecationManager.PrintQueued(); this.DeprecationManager.PrintQueued();
this.PerformanceCounterManager.PrintQueued();
/********* /*********
** First-tick initialization ** First-tick initialization
@ -382,7 +388,7 @@ namespace StardewModdingAPI.Framework
// state while mods are running their code. This is risky, because data changes can // 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 // conflict (e.g. collection changed during enumeration errors) and data may change
// unexpectedly from one mod instruction to the next. // unexpectedly from one mod instruction to the next.
// //
// Therefore we can just run Game1.Update here without raising any SMAPI events. There's // 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, // 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 // which means technically events should be raised, but the effects of missing one

View File

@ -11,7 +11,7 @@ using StardewModdingAPI.Framework;
using StardewModdingAPI.Toolkit.Utilities; using StardewModdingAPI.Toolkit.Utilities;
[assembly: InternalsVisibleTo("SMAPI.Tests")] [assembly: InternalsVisibleTo("SMAPI.Tests")]
[assembly: InternalsVisibleTo("SMAPI.Mods.ConsoleCommands")] [assembly: InternalsVisibleTo("ConsoleCommands")]
[assembly: InternalsVisibleTo("DynamicProxyGenAssembly2")] // Moq for unit testing [assembly: InternalsVisibleTo("DynamicProxyGenAssembly2")] // Moq for unit testing
namespace StardewModdingAPI namespace StardewModdingAPI
{ {