From b76d906c59d8aed3a98ca707d1c6fbfe8478f8ef Mon Sep 17 00:00:00 2001 From: Lucas Nicodemus Date: Tue, 19 May 2020 21:14:06 -0700 Subject: [PATCH 1/2] Overhaul debug logging Debug logging now provides ConsoleDebug and ILog has been updated to support the concept of debug logs. Debug logs are now controlled by config.json instead of by preprocessor debug flag. --- CHANGELOG.md | 3 +++ TShockAPI/ConfigFile.cs | 3 +++ TShockAPI/ILog.cs | 16 ++++++++++++++-- TShockAPI/SqlLog.cs | 30 ++++++++++++++++++++++++------ TShockAPI/TextLog.cs | 30 ++++++++++++++++++++++++------ 5 files changed, 68 insertions(+), 14 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2ef4591b..88c853a3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,9 @@ This is the rolling changelog for TShock for Terraria. Use past tense when adding new entries; sign your name off when you add or change something. This should primarily be things like user changes, not necessarily codebase changes unless it's really relevant or large. +## Upcoming changes +* Debug logging now provides ConsoleDebug and ILog has been updated to support the concept of debug logs. Debug logs are now controlled by `config.json` instead of by preprocessor debug flag. (@hakusaro) + ## TShock 4.4.0 (Pre-release 3) * Fixed `/worldmode` command to correctly target world mode. (@Ristellise) * The following commands have been removed: `tbloodmoon`, `invade`, `dropmeteor`. `fullmoon`, `sandstorm`, `rain`, `eclipse` diff --git a/TShockAPI/ConfigFile.cs b/TShockAPI/ConfigFile.cs index d9a5b559..e440e241 100644 --- a/TShockAPI/ConfigFile.cs +++ b/TShockAPI/ConfigFile.cs @@ -520,6 +520,9 @@ namespace TShockAPI [Description("Whether or not to show backup auto save messages.")] public bool ShowBackupAutosaveMessages = true; + [Description("Whether or not the server should output debug level messages related to system operation.")] + public bool DebugLogs = false; + /// /// Reads a configuration file from a given path /// diff --git a/TShockAPI/ILog.cs b/TShockAPI/ILog.cs index 29a303ad..9fac3789 100644 --- a/TShockAPI/ILog.cs +++ b/TShockAPI/ILog.cs @@ -123,13 +123,25 @@ namespace TShockAPI void Write(string message, TraceLevel level); /// - /// Writes a debug string to the log file. Only works if the DEBUG preprocessor conditional is set. + /// Writes a debug string to the log file and console. Only works if the DebugLogs config option is set to true. + /// + /// The message to be written. + void ConsoleDebug(string message); + + /// + /// Writes a debug string to the log file. Only works if the DebugLogs config option is set to true. + /// + /// The message to be written. + void ConsoleDebug(string message, params object[] args); + + /// + /// Writes a debug string to the log file. Only works if the DebugLogs config option is set to true. /// /// The message to be written. void Debug(string message); /// - /// Writes a debug string to the log file. Only works if the DEBUG preprocessor conditional is set. + /// Writes a debug string to the log file. Only works if the DebugLogs config option is set to true. /// /// The format of the message to be written. /// The format arguments. diff --git a/TShockAPI/SqlLog.cs b/TShockAPI/SqlLog.cs index 3b035c81..a0fd4493 100644 --- a/TShockAPI/SqlLog.cs +++ b/TShockAPI/SqlLog.cs @@ -205,15 +205,34 @@ namespace TShockAPI ConsoleInfo(string.Format(format, args)); } + /// + /// Writes a debug string to the log file. Also outputs to the console. Requires config TShock.DebugLogs to be true. + /// + /// The message to be written. + public void ConsoleDebug(string message) + { + Console.WriteLine("Debug: " + message); + Write(message, TraceLevel.Verbose); + } + + /// + /// Writes a debug string to the log file. Also outputs to the console. Requires config TShock.DebugLogs to be true. + /// + /// The format of the message to be written. + /// The format arguments. + public void ConsoleDebug(string format, params object[] args) + { + ConsoleDebug(string.Format(format, args)); + } + /// /// Writes a debug string to the log file. /// /// The message to be written. public void Debug(string message) { -#if DEBUG - Write(message, TraceLevel.Verbose); -#endif + if (TShock.Config.DebugLogs) + Write(message, TraceLevel.Verbose); } /// @@ -223,9 +242,8 @@ namespace TShockAPI /// The format arguments. public void Debug(string format, params object[] args) { -#if DEBUG - Debug(string.Format(format, args)); -#endif + if (TShock.Config.DebugLogs) + Debug(string.Format(format, args)); } public void Write(string message, TraceLevel level) diff --git a/TShockAPI/TextLog.cs b/TShockAPI/TextLog.cs index 532c9ebf..349ceb01 100644 --- a/TShockAPI/TextLog.cs +++ b/TShockAPI/TextLog.cs @@ -172,15 +172,34 @@ namespace TShockAPI ConsoleInfo(string.Format(format, args)); } + /// + /// Writes a debug string to the log file. Also outputs to the console. Requires config TShock.DebugLogs to be true. + /// + /// The message to be written. + public void ConsoleDebug(string message) + { + Console.WriteLine("Debug: " + message); + Write(message, TraceLevel.Verbose); + } + + /// + /// Writes a debug string to the log file. Also outputs to the console. Requires config TShock.DebugLogs to be true. + /// + /// The format of the message to be written. + /// The format arguments. + public void ConsoleDebug(string format, params object[] args) + { + ConsoleDebug(string.Format(format, args)); + } + /// /// Writes a debug string to the log file. /// /// The message to be written. public void Debug(string message) { -#if DEBUG - Write(message, TraceLevel.Verbose); -#endif + if (TShock.Config.DebugLogs) + Write(message, TraceLevel.Verbose); } /// @@ -190,9 +209,8 @@ namespace TShockAPI /// The format arguments. public void Debug(string format, params object[] args) { -#if DEBUG - Debug(string.Format(format, args)); -#endif + if (TShock.Config.DebugLogs) + Debug(string.Format(format, args)); } /// From e9098d0e78e1db97b49f0d17949f0bf617d89ce7 Mon Sep 17 00:00:00 2001 From: Lucas Nicodemus Date: Tue, 19 May 2020 22:04:37 -0700 Subject: [PATCH 2/2] Add verbose debug logs to a variety of checks These are high priority checks we really want to look at. I want to add more of these debug statements to all checks in Bouncer and other parts of GetDataHandlers, but I think this is good enough for now. --- TShockAPI/Bouncer.cs | 26 +++++++++++++++++++++++++- TShockAPI/GetDataHandlers.cs | 1 + TShockAPI/TShock.cs | 2 +- 3 files changed, 27 insertions(+), 2 deletions(-) diff --git a/TShockAPI/Bouncer.cs b/TShockAPI/Bouncer.cs index 11d293f0..1c64448e 100644 --- a/TShockAPI/Bouncer.cs +++ b/TShockAPI/Bouncer.cs @@ -69,11 +69,12 @@ namespace TShockAPI GetDataHandlers.PlayerDamage += OnPlayerDamage; GetDataHandlers.KillMe += OnKillMe; } - + internal void OnGetSection(object sender, GetDataHandlers.GetSectionEventArgs args) { if (args.Player.RequestedSection) { + TShock.Log.ConsoleDebug("Bouncer / OnGetSection rejected GetSection packet from {0}", args.Player.Name); args.Handled = true; return; } @@ -81,6 +82,7 @@ namespace TShockAPI if (String.IsNullOrEmpty(args.Player.Name)) { + TShock.Log.ConsoleDebug("Bouncer / OnGetSection rejected empty player name."); args.Player.Kick("Your client sent a blank character name.", true, true); args.Handled = true; return; @@ -106,18 +108,21 @@ namespace TShockAPI if (pos.X < 0 || pos.Y < 0 || pos.X >= Main.maxTilesX * 16 - 16 || pos.Y >= Main.maxTilesY * 16 - 16) { + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (position check) {0}", args.Player.Name); args.Handled = true; return; } if (item < 0 || item >= args.Player.TPlayer.inventory.Length) { + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (inventory length) {0}", args.Player.Name); args.Handled = true; return; } if (args.Player.LastNetPosition == Vector2.Zero) { + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (last network position) {0}", args.Player.Name); args.Handled = true; return; } @@ -161,9 +166,11 @@ namespace TShockAPI { args.Player.Spawn(); } + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (??) {0}", args.Player.Name); args.Handled = true; return; } + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (below ??) {0}", args.Player.Name); args.Handled = true; return; } @@ -171,6 +178,7 @@ namespace TShockAPI // Corpses don't move if (args.Player.Dead) { + TShock.Log.ConsoleDebug("Bouncer / OnPlayerUpdate rejected from (corpses don't move) {0}", args.Player.Name); args.Handled = true; return; } @@ -196,6 +204,7 @@ namespace TShockAPI { if (editData < 0) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (editData check) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -203,6 +212,7 @@ namespace TShockAPI if (!TShock.Utils.TilePlacementValid(tileX, tileY)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (tile placement valid) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 1); args.Handled = true; return; @@ -210,12 +220,14 @@ namespace TShockAPI if (action == EditAction.KillTile && Main.tile[tileX, tileY].type == TileID.MagicalIceBlock) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit super accepted from (ice block) {0}", args.Player.Name); args.Handled = false; return; } if (args.Player.Dead && TShock.Config.PreventDeadModification) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (pdm) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -229,6 +241,7 @@ namespace TShockAPI { if (TShock.TileBans.TileIsBanned(editData, args.Player)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (tb) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 1); args.Player.SendErrorMessage("You do not have permission to place this tile."); args.Handled = true; @@ -243,6 +256,7 @@ namespace TShockAPI // If the tile is an axe tile and they aren't selecting an axe, they're hacking. if (Main.tileAxe[tile.type] && ((args.Player.TPlayer.mount.Type != 8 && selectedItem.axe == 0) && !ItemID.Sets.Explosives[selectedItem.netID] && args.Player.RecentFuse == 0)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (axe) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -250,6 +264,7 @@ namespace TShockAPI // If the tile is a hammer tile and they aren't selecting a hammer, they're hacking. else if (Main.tileHammer[tile.type] && ((args.Player.TPlayer.mount.Type != 8 && selectedItem.hammer == 0) && !ItemID.Sets.Explosives[selectedItem.netID] && args.Player.RecentFuse == 0)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (hammer) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -259,6 +274,7 @@ namespace TShockAPI else if (tile.type != TileID.ItemFrame && !Main.tileAxe[tile.type] && !Main.tileHammer[tile.type] && tile.wall == 0 && args.Player.TPlayer.mount.Type != 8 && selectedItem.pick == 0 && !ItemID.Sets.Explosives[selectedItem.netID] && args.Player.RecentFuse == 0) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (pick) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -269,6 +285,7 @@ namespace TShockAPI // If they aren't selecting a hammer, they could be hacking. if (selectedItem.hammer == 0 && !ItemID.Sets.Explosives[selectedItem.netID] && args.Player.RecentFuse == 0 && selectedItem.createWall == 0) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (hammer2) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 1); args.Handled = true; return; @@ -284,6 +301,7 @@ namespace TShockAPI (MaxPlaceStyles.ContainsKey(editData) && style > MaxPlaceStyles[editData]) && (ExtraneousPlaceStyles.ContainsKey(editData) && style > ExtraneousPlaceStyles[editData])) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (ms1) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -294,6 +312,8 @@ namespace TShockAPI (editData != (action == EditAction.PlaceTile ? selectedItem.createTile : selectedItem.createWall) && !(ropeCoilPlacements.ContainsKey(selectedItem.netID) && editData == ropeCoilPlacements[selectedItem.netID]))) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (ms2) {0}", args.Player.Name); + args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; @@ -301,12 +321,14 @@ namespace TShockAPI if (editData >= (action == EditAction.PlaceTile ? Main.maxTileSets : Main.maxWallTypes)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (ms3) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 4); args.Handled = true; return; } if (action == EditAction.PlaceTile && (editData == TileID.PiggyBank || editData == TileID.Safes) && Main.ServerSideCharacter) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (sscprotect) {0}", args.Player.Name); args.Player.SendErrorMessage("You cannot place this tile because server side characters are enabled."); args.Player.SendTileSquare(tileX, tileY, 3); args.Handled = true; @@ -316,6 +338,7 @@ namespace TShockAPI { if (TShock.Utils.HasWorldReachedMaxChests()) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (chestcap) {0}", args.Player.Name); args.Player.SendErrorMessage("The world's chest limit has been reached - unable to place more."); args.Player.SendTileSquare(tileX, tileY, 3); args.Handled = true; @@ -324,6 +347,7 @@ namespace TShockAPI if ((TShock.Utils.TilePlacementValid(tileX, tileY + 1) && Main.tile[tileX, tileY + 1].type == TileID.Boulder) || (TShock.Utils.TilePlacementValid(tileX + 1, tileY + 1) && Main.tile[tileX + 1, tileY + 1].type == TileID.Boulder)) { + TShock.Log.ConsoleDebug("Bouncer / OnTileEdit rejected from (validplacement) {0}", args.Player.Name); args.Player.SendTileSquare(tileX, tileY, 3); args.Handled = true; return; diff --git a/TShockAPI/GetDataHandlers.cs b/TShockAPI/GetDataHandlers.cs index 20409603..9984669c 100644 --- a/TShockAPI/GetDataHandlers.cs +++ b/TShockAPI/GetDataHandlers.cs @@ -2101,6 +2101,7 @@ namespace TShockAPI { if (args.Player == null || args.TPlayer == null || args.Data == null) { + TShock.Log.ConsoleDebug("GetDataHandlers / OnPlayerUpdate rejected from null player."); return true; } diff --git a/TShockAPI/TShock.cs b/TShockAPI/TShock.cs index b7543a30..5e9a2c96 100644 --- a/TShockAPI/TShock.cs +++ b/TShockAPI/TShock.cs @@ -1487,7 +1487,7 @@ namespace TShockAPI PacketTypes type = e.MsgID; - Debug.WriteLine("Recv: {0:X}: {2} ({1:XX})", e.Msg.whoAmI, (byte)type, type); + Log.ConsoleDebug("Recv: {0:X}: {2} ({1:XX})", e.Msg.whoAmI, (byte)type, type); var player = Players[e.Msg.whoAmI]; if (player == null || !player.ConnectionAlive)