From 6f569c579422641d6a56b491795504abd11893e9 Mon Sep 17 00:00:00 2001 From: Jesse Plamondon-Willard Date: Wed, 7 Nov 2018 13:33:56 -0500 Subject: add verbose logging as a monitor feature --- src/SMAPI/Framework/Monitor.cs | 15 +++++++++++++- src/SMAPI/Framework/SCore.cs | 16 ++++----------- src/SMAPI/Framework/SGame.cs | 31 ++++++++++++---------------- src/SMAPI/Framework/SMultiplayer.cs | 41 +++++++++++++------------------------ 4 files changed, 45 insertions(+), 58 deletions(-) (limited to 'src/SMAPI/Framework') diff --git a/src/SMAPI/Framework/Monitor.cs b/src/SMAPI/Framework/Monitor.cs index 2812a9cc..a4d92e4b 100644 --- a/src/SMAPI/Framework/Monitor.cs +++ b/src/SMAPI/Framework/Monitor.cs @@ -37,6 +37,9 @@ namespace StardewModdingAPI.Framework /// Whether SMAPI is aborting. Mods don't need to worry about this unless they have background tasks. public bool IsExiting => this.ExitTokenSource.IsCancellationRequested; + /// Whether verbose logging is enabled. This enables more detailed diagnostic messages than are normally needed. + public bool IsVerbose { get; } + /// Whether to show the full log stamps (with time/level/logger) in the console. If false, shows a simplified stamp with only the logger. internal bool ShowFullStampInConsole { get; set; } @@ -56,7 +59,8 @@ namespace StardewModdingAPI.Framework /// The log file to which to write messages. /// Propagates notification that SMAPI should exit. /// The console color scheme to use. - public Monitor(string source, ConsoleInterceptionManager consoleInterceptor, LogFileManager logFile, CancellationTokenSource exitTokenSource, MonitorColorScheme colorScheme) + /// Whether verbose logging is enabled. This enables more detailed diagnostic messages than are normally needed. + 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; } /// Log a message for the player or developer. @@ -78,6 +83,14 @@ namespace StardewModdingAPI.Framework this.LogImpl(this.Source, message, (ConsoleLogLevel)level); } + /// Log a message that only appears when is enabled. + /// The message to log. + public void VerboseLog(string message) + { + if (this.IsVerbose) + this.Log(message, LogLevel.Trace); + } + /// 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. /// The reason for the shutdown. public void ExitGameImmediately(string reason) diff --git a/src/SMAPI/Framework/SCore.cs b/src/SMAPI/Framework/SCore.cs index ee175a1b..7e5b6e02 100644 --- a/src/SMAPI/Framework/SCore.cs +++ b/src/SMAPI/Framework/SCore.cs @@ -126,7 +126,7 @@ namespace StardewModdingAPI.Framework // init basics this.Settings = JsonConvert.DeserializeObject(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 /// The name of the module which will log messages with this instance. 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 }; } - /// Log a message if verbose mode is enabled. - /// The message to log. - private void VerboseLog(string message) - { - if (this.Settings.VerboseLogging) - this.Monitor.Log(message, LogLevel.Trace); - } - /// Get the absolute path to the next available log file. private string GetLogPath() { diff --git a/src/SMAPI/Framework/SGame.cs b/src/SMAPI/Framework/SGame.cs index 04db9632..3de97aea 100644 --- a/src/SMAPI/Framework/SGame.cs +++ b/src/SMAPI/Framework/SGame.cs @@ -57,9 +57,6 @@ namespace StardewModdingAPI.Framework /// Manages deprecation warnings. private readonly DeprecationManager DeprecationManager; - /// Whether SMAPI should log more information about the game context. - private readonly bool VerboseLogging; - /// The maximum number of consecutive attempts SMAPI should make to recover from a draw error. private readonly Countdown DrawCrashTimer = new Countdown(60); // 60 ticks = roughly one second @@ -143,8 +140,7 @@ namespace StardewModdingAPI.Framework /// Manages deprecation warnings. /// A callback to invoke after the game finishes initialising. /// A callback to invoke when the game exits. - /// Whether SMAPI should log more information about the game context. - 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> 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)); } diff --git a/src/SMAPI/Framework/SMultiplayer.cs b/src/SMAPI/Framework/SMultiplayer.cs index 2d0f8b9b..dc9b8b68 100644 --- a/src/SMAPI/Framework/SMultiplayer.cs +++ b/src/SMAPI/Framework/SMultiplayer.cs @@ -50,9 +50,6 @@ namespace StardewModdingAPI.Framework /// The players who are currently disconnecting. private readonly IList DisconnectingFarmers; - /// Whether SMAPI should log more detailed information. - private readonly bool VerboseLogging; - /// A callback to invoke when a mod message is received. private readonly Action OnModMessageReceived; @@ -76,16 +73,14 @@ namespace StardewModdingAPI.Framework /// Encapsulates SMAPI's JSON file parsing. /// Tracks the installed mods. /// Simplifies access to private code. - /// Whether SMAPI should log more detailed information. /// A callback to invoke when a mod message is received. - public SMultiplayer(IMonitor monitor, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, Reflector reflection, bool verboseLogging, Action onModMessageReceived) + public SMultiplayer(IMonitor monitor, EventManager eventManager, JsonHelper jsonHelper, ModRegistry modRegistry, Reflector reflection, Action 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>(this, "disconnectingFarmers").GetValue(); @@ -140,7 +135,7 @@ namespace StardewModdingAPI.Framework /// Send the underlying message. 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 /// Send the underlying message. 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 /// Process the message using the game's default logic. 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 whether the message was handled. 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(json); HashSet playerIDs = new HashSet(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) }; } - - /// Log a trace message if is enabled. - /// The message to log. - private void VerboseLog(string message) - { - if (this.VerboseLogging) - this.Monitor.Log(message, LogLevel.Trace); - } } } -- cgit