add verbose logging as a monitor feature

This commit is contained in:
Jesse Plamondon-Willard 2018-11-07 13:33:56 -05:00
parent a379726ad9
commit 6f569c5794
No known key found for this signature in database
GPG Key ID: 7D7C8097B62033CE
6 changed files with 54 additions and 59 deletions

View File

@ -34,6 +34,7 @@
* For modders:
* Added [data API](https://stardewvalleywiki.com/Modding:Modder_Guide/APIs/Data).
* Added [multiplayer API](https://stardewvalleywiki.com/Modding:Modder_Guide/APIs/Multiplayer) and [events](https://stardewvalleywiki.com/Modding:Modder_Guide/Apis/Events#Multiplayer_2) to send/receive messages and get connected player info.
* Added [verbose logging](https://stardewvalleywiki.com/Modding:Modder_Guide/APIs/Logging#Verbose_logging) feature.
* Added `IContentPack.WriteJsonFile` method.
* Added IntelliSense documentation for the non-developers version of SMAPI.
* Added more events to the prototype `helper.Events` for SMAPI 3.0.

View File

@ -37,6 +37,9 @@ namespace StardewModdingAPI.Framework
/// <summary>Whether SMAPI is aborting. Mods don't need to worry about this unless they have background tasks.</summary>
public bool IsExiting => this.ExitTokenSource.IsCancellationRequested;
/// <summary>Whether verbose logging is enabled. This enables more detailed diagnostic messages than are normally needed.</summary>
public bool IsVerbose { get; }
/// <summary>Whether to show the full log stamps (with time/level/logger) in the console. If false, shows a simplified stamp with only the logger.</summary>
internal bool ShowFullStampInConsole { get; set; }
@ -56,7 +59,8 @@ namespace StardewModdingAPI.Framework
/// <param name="logFile">The log file to which to write messages.</param>
/// <param name="exitTokenSource">Propagates notification that SMAPI should exit.</param>
/// <param name="colorScheme">The console color scheme to use.</param>
public Monitor(string source, ConsoleInterceptionManager consoleInterceptor, LogFileManager logFile, CancellationTokenSource exitTokenSource, MonitorColorScheme colorScheme)
/// <param name="isVerbose">Whether verbose logging is enabled. This enables more detailed diagnostic messages than are normally needed.</param>
public Monitor(string source, ConsoleInterceptionManager consoleInterceptor, LogFileManager logFile, CancellationTokenSource exitTokenSource, MonitorColorScheme colorScheme, bool isVerbose)
{
// validate
if (string.IsNullOrWhiteSpace(source))
@ -68,6 +72,7 @@ namespace StardewModdingAPI.Framework
this.ConsoleWriter = new ColorfulConsoleWriter(Constants.Platform, colorScheme);
this.ConsoleInterceptor = consoleInterceptor;
this.ExitTokenSource = exitTokenSource;
this.IsVerbose = isVerbose;
}
/// <summary>Log a message for the player or developer.</summary>
@ -78,6 +83,14 @@ namespace StardewModdingAPI.Framework
this.LogImpl(this.Source, message, (ConsoleLogLevel)level);
}
/// <summary>Log a message that only appears when <see cref="IMonitor.IsVerbose"/> is enabled.</summary>
/// <param name="message">The message to log.</param>
public void VerboseLog(string message)
{
if (this.IsVerbose)
this.Log(message, LogLevel.Trace);
}
/// <summary>Immediately exit the game without saving. This should only be invoked when an irrecoverable fatal error happens that risks save corruption or game-breaking bugs.</summary>
/// <param name="reason">The reason for the shutdown.</param>
public void ExitGameImmediately(string reason)

View File

@ -126,7 +126,7 @@ namespace StardewModdingAPI.Framework
// init basics
this.Settings = JsonConvert.DeserializeObject<SConfig>(File.ReadAllText(Constants.ApiConfigPath));
this.LogFile = new LogFileManager(logPath);
this.Monitor = new Monitor("SMAPI", this.ConsoleManager, this.LogFile, this.CancellationTokenSource, this.Settings.ColorScheme)
this.Monitor = new Monitor("SMAPI", this.ConsoleManager, this.LogFile, this.CancellationTokenSource, this.Settings.ColorScheme, this.Settings.VerboseLogging)
{
WriteToConsole = writeToConsole,
ShowTraceInConsole = this.Settings.DeveloperMode,
@ -213,7 +213,7 @@ namespace StardewModdingAPI.Framework
// override game
SGame.ConstructorHack = new SGameConstructorHack(this.Monitor, this.Reflection, this.Toolkit.JsonHelper);
this.GameInstance = new SGame(this.Monitor, this.MonitorForGame, this.Reflection, this.EventManager, this.Toolkit.JsonHelper, this.ModRegistry, this.DeprecationManager, this.InitialiseAfterGameStart, this.Dispose, this.Settings.VerboseLogging);
this.GameInstance = new SGame(this.Monitor, this.MonitorForGame, this.Reflection, this.EventManager, this.Toolkit.JsonHelper, this.ModRegistry, this.DeprecationManager, this.InitialiseAfterGameStart, this.Dispose);
StardewValley.Program.gamePtr = this.GameInstance;
// add exit handler
@ -355,7 +355,7 @@ namespace StardewModdingAPI.Framework
this.Monitor.Log($"You configured SMAPI to not check for updates. Running an old version of SMAPI is not recommended. You can enable update checks by reinstalling SMAPI or editing {Constants.ApiConfigPath}.", LogLevel.Warn);
if (!this.Monitor.WriteToConsole)
this.Monitor.Log("Writing to the terminal is disabled because the --no-terminal argument was received. This usually means launching the terminal failed.", LogLevel.Warn);
this.VerboseLog("Verbose logging enabled.");
this.Monitor.VerboseLog("Verbose logging enabled.");
// validate XNB integrity
if (!this.ValidateContentIntegrity())
@ -1298,7 +1298,7 @@ namespace StardewModdingAPI.Framework
/// <param name="name">The name of the module which will log messages with this instance.</param>
private Monitor GetSecondaryMonitor(string name)
{
return new Monitor(name, this.ConsoleManager, this.LogFile, this.CancellationTokenSource, this.Settings.ColorScheme)
return new Monitor(name, this.ConsoleManager, this.LogFile, this.CancellationTokenSource, this.Settings.ColorScheme, this.Settings.VerboseLogging)
{
WriteToConsole = this.Monitor.WriteToConsole,
ShowTraceInConsole = this.Settings.DeveloperMode,
@ -1306,14 +1306,6 @@ namespace StardewModdingAPI.Framework
};
}
/// <summary>Log a message if verbose mode is enabled.</summary>
/// <param name="message">The message to log.</param>
private void VerboseLog(string message)
{
if (this.Settings.VerboseLogging)
this.Monitor.Log(message, LogLevel.Trace);
}
/// <summary>Get the absolute path to the next available log file.</summary>
private string GetLogPath()
{

View File

@ -57,9 +57,6 @@ namespace StardewModdingAPI.Framework
/// <summary>Manages deprecation warnings.</summary>
private readonly DeprecationManager DeprecationManager;
/// <summary>Whether SMAPI should log more information about the game context.</summary>
private readonly bool VerboseLogging;
/// <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
@ -143,8 +140,7 @@ namespace StardewModdingAPI.Framework
/// <param name="deprecationManager">Manages deprecation warnings.</param>
/// <param name="onGameInitialised">A callback to invoke after the game finishes initialising.</param>
/// <param name="onGameExiting">A callback to invoke when the game exits.</param>
/// <param name="verboseLogging">Whether SMAPI should log more information about the game context.</param>
internal SGame(IMonitor monitor, IMonitor monitorForGame, Reflector reflection, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, DeprecationManager deprecationManager, Action onGameInitialised, Action onGameExiting, bool verboseLogging)
internal SGame(IMonitor monitor, IMonitor monitorForGame, Reflector reflection, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, DeprecationManager deprecationManager, Action onGameInitialised, Action onGameExiting)
{
SGame.ConstructorHack = null;
@ -164,9 +160,8 @@ namespace StardewModdingAPI.Framework
this.DeprecationManager = deprecationManager;
this.OnGameInitialised = onGameInitialised;
this.OnGameExiting = onGameExiting;
this.VerboseLogging = verboseLogging;
Game1.input = new SInputState();
Game1.multiplayer = new SMultiplayer(monitor, eventManager, jsonHelper, modRegistry, reflection, this.VerboseLogging, this.OnModMessageReceived);
Game1.multiplayer = new SMultiplayer(monitor, eventManager, jsonHelper, modRegistry, reflection, this.OnModMessageReceived);
Game1.hooks = new SModHooks(this.OnNewDayAfterFade);
// init observables
@ -468,7 +463,7 @@ namespace StardewModdingAPI.Framework
// since the game adds & removes its own handler on the fly.
if (this.Watchers.WindowSizeWatcher.IsChanged)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: window size changed to {this.Watchers.WindowSizeWatcher.CurrentValue}.", LogLevel.Trace);
Point oldSize = this.Watchers.WindowSizeWatcher.PreviousValue;
@ -507,7 +502,7 @@ namespace StardewModdingAPI.Framework
int now = this.Watchers.MouseWheelScrollWatcher.CurrentValue;
this.Watchers.MouseWheelScrollWatcher.Reset();
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: mouse wheel scrolled to {now}.", LogLevel.Trace);
this.Events.MouseWheelScrolled.Raise(new MouseWheelScrolledEventArgs(cursor, was, now));
}
@ -520,7 +515,7 @@ namespace StardewModdingAPI.Framework
if (status == InputStatus.Pressed)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: button {button} pressed.", LogLevel.Trace);
this.Events.ButtonPressed.Raise(new ButtonPressedEventArgs(button, cursor, inputState));
@ -542,7 +537,7 @@ namespace StardewModdingAPI.Framework
}
else if (status == InputStatus.Released)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: button {button} released.", LogLevel.Trace);
this.Events.ButtonReleased.Raise(new ButtonReleasedEventArgs(button, cursor, inputState));
@ -581,7 +576,7 @@ namespace StardewModdingAPI.Framework
IClickableMenu now = this.Watchers.ActiveMenuWatcher.CurrentValue;
this.Watchers.ActiveMenuWatcher.Reset(); // reset here so a mod changing the menu will be raised as a new event afterwards
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Context: menu changed from {was?.GetType().FullName ?? "none"} to {now?.GetType().FullName ?? "none"}.", LogLevel.Trace);
// raise menu events
@ -609,7 +604,7 @@ namespace StardewModdingAPI.Framework
GameLocation[] removed = this.Watchers.LocationsWatcher.Removed.ToArray();
this.Watchers.LocationsWatcher.ResetLocationList();
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
{
string addedText = this.Watchers.LocationsWatcher.Added.Any() ? string.Join(", ", added.Select(p => p.Name)) : "none";
string removedText = this.Watchers.LocationsWatcher.Removed.Any() ? string.Join(", ", removed.Select(p => p.Name)) : "none";
@ -705,7 +700,7 @@ namespace StardewModdingAPI.Framework
int now = this.Watchers.TimeWatcher.CurrentValue;
this.Watchers.TimeWatcher.Reset();
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: time changed from {was} to {now}.", LogLevel.Trace);
this.Events.TimeChanged.Raise(new TimeChangedEventArgs(was, now));
@ -722,7 +717,7 @@ namespace StardewModdingAPI.Framework
// raise current location changed
if (playerTracker.TryGetNewLocation(out GameLocation newLocation))
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Context: set location to {newLocation.Name}.", LogLevel.Trace);
GameLocation oldLocation = playerTracker.LocationWatcher.PreviousValue;
@ -733,7 +728,7 @@ namespace StardewModdingAPI.Framework
// raise player leveled up a skill
foreach (KeyValuePair<SkillType, IValueWatcher<int>> pair in playerTracker.GetChangedSkills())
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Events: player skill '{pair.Key}' changed from {pair.Value.PreviousValue} to {pair.Value.CurrentValue}.", LogLevel.Trace);
this.Events.LevelChanged.Raise(new LevelChangedEventArgs(playerTracker.Player, pair.Key, pair.Value.PreviousValue, pair.Value.CurrentValue));
@ -744,7 +739,7 @@ namespace StardewModdingAPI.Framework
ItemStackChange[] changedItems = playerTracker.GetInventoryChanges().ToArray();
if (changedItems.Any())
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log("Events: player inventory changed.", LogLevel.Trace);
this.Events.InventoryChanged.Raise(new InventoryChangedEventArgs(playerTracker.Player, changedItems));
this.Events.Legacy_InventoryChanged.Raise(new EventArgsInventoryChanged(Game1.player.Items, changedItems));
@ -753,7 +748,7 @@ namespace StardewModdingAPI.Framework
// raise mine level changed
if (playerTracker.TryGetNewMineLevel(out int mineLevel))
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Context: mine level changed to {mineLevel}.", LogLevel.Trace);
this.Events.Legacy_MineLevelChanged.Raise(new EventArgsMineLevelChanged(playerTracker.MineLevelWatcher.PreviousValue, mineLevel));
}

View File

@ -50,9 +50,6 @@ namespace StardewModdingAPI.Framework
/// <summary>The players who are currently disconnecting.</summary>
private readonly IList<long> DisconnectingFarmers;
/// <summary>Whether SMAPI should log more detailed information.</summary>
private readonly bool VerboseLogging;
/// <summary>A callback to invoke when a mod message is received.</summary>
private readonly Action<ModMessageModel> OnModMessageReceived;
@ -76,16 +73,14 @@ namespace StardewModdingAPI.Framework
/// <param name="jsonHelper">Encapsulates SMAPI's JSON file parsing.</param>
/// <param name="modRegistry">Tracks the installed mods.</param>
/// <param name="reflection">Simplifies access to private code.</param>
/// <param name="verboseLogging">Whether SMAPI should log more detailed information.</param>
/// <param name="onModMessageReceived">A callback to invoke when a mod message is received.</param>
public SMultiplayer(IMonitor monitor, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, Reflector reflection, bool verboseLogging, Action<ModMessageModel> onModMessageReceived)
public SMultiplayer(IMonitor monitor, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, Reflector reflection, Action<ModMessageModel> onModMessageReceived)
{
this.Monitor = monitor;
this.EventManager = eventManager;
this.JsonHelper = jsonHelper;
this.ModRegistry = modRegistry;
this.Reflection = reflection;
this.VerboseLogging = verboseLogging;
this.OnModMessageReceived = onModMessageReceived;
this.DisconnectingFarmers = reflection.GetField<List<long>>(this, "disconnectingFarmers").GetValue();
@ -140,7 +135,7 @@ namespace StardewModdingAPI.Framework
/// <param name="resume">Send the underlying message.</param>
protected void OnServerSendingMessage(SLidgrenServer server, NetConnection connection, OutgoingMessage message, Action resume)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"SERVER SEND {(MessageType)message.MessageType} {message.FarmerID}", LogLevel.Trace);
resume();
@ -152,7 +147,7 @@ namespace StardewModdingAPI.Framework
/// <param name="resume">Send the underlying message.</param>
protected void OnClientSendingMessage(SLidgrenClient client, OutgoingMessage message, Action resume)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"CLIENT SEND {(MessageType)message.MessageType} {message.FarmerID}", LogLevel.Trace);
switch (message.MessageType)
@ -177,7 +172,7 @@ namespace StardewModdingAPI.Framework
/// <param name="resume">Process the message using the game's default logic.</param>
public void OnServerProcessingMessage(SLidgrenServer server, NetIncomingMessage rawMessage, IncomingMessage message, Action resume)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"SERVER RECV {(MessageType)message.MessageType} {message.FarmerID}", LogLevel.Trace);
switch (message.MessageType)
@ -199,13 +194,13 @@ namespace StardewModdingAPI.Framework
this.AddPeer(newPeer, canBeHost: false, raiseEvent: false);
// reply with own context
this.VerboseLog(" Replying with host context...");
this.Monitor.VerboseLog(" Replying with host context...");
newPeer.SendMessage(new OutgoingMessage((byte)MessageType.ModContext, Game1.player.UniqueMultiplayerID, this.GetContextSyncMessageFields()));
// reply with other players' context
foreach (MultiplayerPeer otherPeer in this.Peers.Values.Where(p => p.PlayerID != newPeer.PlayerID))
{
this.VerboseLog($" Replying with context for player {otherPeer.PlayerID}...");
this.Monitor.VerboseLog($" Replying with context for player {otherPeer.PlayerID}...");
newPeer.SendMessage(new OutgoingMessage((byte)MessageType.ModContext, otherPeer.PlayerID, this.GetContextSyncMessageFields(otherPeer)));
}
@ -215,7 +210,7 @@ namespace StardewModdingAPI.Framework
object[] fields = this.GetContextSyncMessageFields(newPeer);
foreach (MultiplayerPeer otherPeer in this.Peers.Values.Where(p => p.PlayerID != newPeer.PlayerID))
{
this.VerboseLog($" Forwarding context to player {otherPeer.PlayerID}...");
this.Monitor.VerboseLog($" Forwarding context to player {otherPeer.PlayerID}...");
otherPeer.SendMessage(new OutgoingMessage((byte)MessageType.ModContext, newPeer.PlayerID, fields));
}
}
@ -256,7 +251,7 @@ namespace StardewModdingAPI.Framework
/// <returns>Returns whether the message was handled.</returns>
public void OnClientProcessingMessage(SLidgrenClient client, IncomingMessage message, Action resume)
{
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"CLIENT RECV {(MessageType)message.MessageType} {message.FarmerID}", LogLevel.Trace);
switch (message.MessageType)
@ -351,7 +346,7 @@ namespace StardewModdingAPI.Framework
throw new ArgumentNullException(nameof(fromModID));
if (!this.Peers.Any())
{
this.VerboseLog($"Ignored '{messageType}' broadcast from mod {fromModID}: not connected to any players.");
this.Monitor.VerboseLog($"Ignored '{messageType}' broadcast from mod {fromModID}: not connected to any players.");
return;
}
@ -363,7 +358,7 @@ namespace StardewModdingAPI.Framework
playerIDs.RemoveWhere(id => !this.Peers.ContainsKey(id));
if (!playerIDs.Any())
{
this.VerboseLog($"Ignored '{messageType}' broadcast from mod {fromModID}: none of the specified player IDs are connected.");
this.Monitor.VerboseLog($"Ignored '{messageType}' broadcast from mod {fromModID}: none of the specified player IDs are connected.");
return;
}
}
@ -380,7 +375,7 @@ namespace StardewModdingAPI.Framework
string data = JsonConvert.SerializeObject(model, Formatting.None);
// log message
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Broadcasting '{messageType}' message: {data}.", LogLevel.Trace);
// send message
@ -398,7 +393,7 @@ namespace StardewModdingAPI.Framework
else if (this.HostPeer != null && this.HostPeer.HasSmapi)
this.HostPeer.SendMessage(new OutgoingMessage((byte)MessageType.ModMessage, this.HostPeer.PlayerID, data));
else
this.VerboseLog(" Can't send message because no valid connections were found.");
this.Monitor.VerboseLog(" Can't send message because no valid connections were found.");
}
@ -441,7 +436,7 @@ namespace StardewModdingAPI.Framework
string json = message.Reader.ReadString();
ModMessageModel model = this.JsonHelper.Deserialise<ModMessageModel>(json);
HashSet<long> playerIDs = new HashSet<long>(model.ToPlayerIDs ?? this.GetKnownPlayerIDs());
if (this.VerboseLogging)
if (this.Monitor.IsVerbose)
this.Monitor.Log($"Received message: {json}.");
// notify local mods
@ -457,7 +452,7 @@ namespace StardewModdingAPI.Framework
if (playerID != Game1.player.UniqueMultiplayerID && playerID != model.FromPlayerID && this.Peers.TryGetValue(playerID, out MultiplayerPeer peer))
{
newModel.ToPlayerIDs = new[] { peer.PlayerID };
this.VerboseLog($" Forwarding message to player {peer.PlayerID}.");
this.Monitor.VerboseLog($" Forwarding message to player {peer.PlayerID}.");
peer.SendMessage(new OutgoingMessage((byte)MessageType.ModMessage, peer.PlayerID, this.JsonHelper.Serialise(newModel, Formatting.None)));
}
}
@ -520,13 +515,5 @@ namespace StardewModdingAPI.Framework
return new object[] { this.JsonHelper.Serialise(model, Formatting.None) };
}
/// <summary>Log a trace message if <see cref="VerboseLogging"/> is enabled.</summary>
/// <param name="message">The message to log.</param>
private void VerboseLog(string message)
{
if (this.VerboseLogging)
this.Monitor.Log(message, LogLevel.Trace);
}
}
}

View File

@ -1,4 +1,4 @@
namespace StardewModdingAPI
namespace StardewModdingAPI
{
/// <summary>Encapsulates monitoring and logging for a given module.</summary>
public interface IMonitor
@ -9,6 +9,9 @@
/// <summary>Whether SMAPI is aborting. Mods don't need to worry about this unless they have background tasks.</summary>
bool IsExiting { get; }
/// <summary>Whether verbose logging is enabled. This enables more detailed diagnostic messages than are normally needed.</summary>
bool IsVerbose { get; }
/*********
** Methods
@ -18,6 +21,10 @@
/// <param name="level">The log severity level.</param>
void Log(string message, LogLevel level = LogLevel.Debug);
/// <summary>Log a message that only appears when <see cref="IsVerbose"/> is enabled.</summary>
/// <param name="message">The message to log.</param>
void VerboseLog(string message);
/// <summary>Immediately exit the game without saving. This should only be invoked when an irrecoverable fatal error happens that risks save corruption or game-breaking bugs.</summary>
/// <param name="reason">The reason for the shutdown.</param>
void ExitGameImmediately(string reason);