From e693d3ded7f1113c95a058eca9b71d49aeb13094 Mon Sep 17 00:00:00 2001 From: Tyler Young Date: Wed, 24 Jun 2020 19:43:09 -0400 Subject: [PATCH] Buffered VT ANSI Logging, Server Off Console Thread, Log Unhandled Errors (#1152) --- Robust.Client/GameController.cs | 30 +++++ Robust.Server/Program.cs | 56 ++++++++- Robust.Shared/Log/ConsoleLogHandler.cs | 114 ++++++++++++++++-- .../Serialization/RobustSerializer.cs | 1 - 4 files changed, 184 insertions(+), 17 deletions(-) diff --git a/Robust.Client/GameController.cs b/Robust.Client/GameController.cs index 7b476194d..8dd7f6d6a 100644 --- a/Robust.Client/GameController.cs +++ b/Robust.Client/GameController.cs @@ -2,6 +2,7 @@ using System.Globalization; using System.IO; using System.Net; +using System.Threading.Tasks; using Robust.Client.Console; using Robust.Client.Interfaces; using Robust.Client.Interfaces.GameObjects; @@ -300,6 +301,35 @@ namespace Robust.Client logManager.GetSawmill("gdparse").Level = LogLevel.Error; logManager.GetSawmill("discord").Level = LogLevel.Warning; logManager.GetSawmill("net.predict").Level = LogLevel.Info; + +#if DEBUG_ONLY_FCE_INFO +#if DEBUG_ONLY_FCE_LOG + var fce = logManager.GetSawmill("fce"); +#endif + AppDomain.CurrentDomain.FirstChanceException += (sender, args) => + { + // TODO: record FCE stats +#if DEBUG_ONLY_FCE_LOG + fce.Fatal(message); +#endif + } +#endif + + var uh = logManager.GetSawmill("unhandled"); + AppDomain.CurrentDomain.UnhandledException += (sender, args) => + { + var message = ((Exception) args.ExceptionObject).ToString(); + uh.Log(args.IsTerminating ? LogLevel.Fatal : LogLevel.Error, message); + }; + + var uo = logManager.GetSawmill("unobserved"); + TaskScheduler.UnobservedTaskException += (sender, args) => + { + uo.Error(args.Exception!.ToString()); +#if EXCEPTION_TOLERANCE + args.SetObserved(); // don't crash +#endif + }; } private string GetUserDataDir() diff --git a/Robust.Server/Program.cs b/Robust.Server/Program.cs index af8262f54..ae138da4b 100644 --- a/Robust.Server/Program.cs +++ b/Robust.Server/Program.cs @@ -1,6 +1,9 @@ using System; using System.Collections.Generic; +using System.Globalization; using System.Reflection; +using System.Threading; +using System.Threading.Tasks; using Robust.Server.Interfaces; using Robust.Shared.ContentPack; using Robust.Shared.Interfaces.Log; @@ -11,8 +14,10 @@ using Robust.Shared; namespace Robust.Server { + internal static class Program { + private static bool _hasStarted; internal static void Main(string[] args) @@ -20,7 +25,9 @@ namespace Robust.Server Start(args); } - internal static void Start(string[] args, bool contentStart=false) + private static Thread? _offMainThread; + + internal static void Start(string[] args, bool contentStart = false) { if (_hasStarted) { @@ -29,10 +36,22 @@ namespace Robust.Server _hasStarted = true; - if (CommandLineArgs.TryParse(args, out var parsed)) + if (!CommandLineArgs.TryParse(args, out var parsed)) { - ParsedMain(parsed, contentStart); + return; } + + _offMainThread = new Thread(() => ParsedMain(parsed, contentStart)) + { + IsBackground = false, + Name = "Server", + Priority = ThreadPriority.Highest, + CurrentCulture = CultureInfo.InvariantCulture, + CurrentUICulture = CultureInfo.InvariantCulture + }; + + _offMainThread.Start(); + //_offMainThread.Join(); } private static void ParsedMain(CommandLineArgs args, bool contentStart) @@ -91,6 +110,37 @@ namespace Robust.Server mgr.RootSawmill.AddHandler(handler); mgr.GetSawmill("res.typecheck").Level = LogLevel.Info; mgr.GetSawmill("go.sys").Level = LogLevel.Info; + +#if DEBUG_ONLY_FCE_INFO +#if DEBUG_ONLY_FCE_LOG + var fce = mgr.GetSawmill("fce"); +#endif + AppDomain.CurrentDomain.FirstChanceException += (sender, args) => + { + // TODO: record FCE stats +#if DEBUG_ONLY_FCE_LOG + fce.Fatal(message); +#endif + } +#endif + + var uh = mgr.GetSawmill("unhandled"); + AppDomain.CurrentDomain.UnhandledException += (sender, args) => + { + var message = ((Exception) args.ExceptionObject).ToString(); + uh.Log(args.IsTerminating ? LogLevel.Fatal : LogLevel.Error, message); + }; + + var uo = mgr.GetSawmill("unobserved"); + TaskScheduler.UnobservedTaskException += (sender, args) => + { + uo.Error(args.Exception!.ToString()); +#if EXCEPTION_TOLERANCE + args.SetObserved(); // don't crash +#endif + }; } + } + } diff --git a/Robust.Shared/Log/ConsoleLogHandler.cs b/Robust.Shared/Log/ConsoleLogHandler.cs index affe526ce..c95dc4a31 100644 --- a/Robust.Shared/Log/ConsoleLogHandler.cs +++ b/Robust.Shared/Log/ConsoleLogHandler.cs @@ -1,50 +1,138 @@ using Robust.Shared.Interfaces.Log; using System; +using System.IO; +using System.Runtime.InteropServices; +using System.Text; +using System.Timers; +using Robust.Shared.Maths; namespace Robust.Shared.Log { + /// /// Log handler that prints to console. /// public sealed class ConsoleLogHandler : ILogHandler { - private readonly object locker = new object(); + + private object locker => _writer; + + private readonly Stream _writer = new BufferedStream(System.Console.OpenStandardOutput(), 2 * 1024 * 1024); + + private readonly StringBuilder _line = new StringBuilder(4096); + + private readonly Timer _timer = new Timer(0.1); + + public ConsoleLogHandler() + { + _timer.Start(); + _timer.Elapsed += (sender, args) => _writer.Flush(); + + if (RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) + { + WindowsConsole.TryEnableVirtualTerminalProcessing(); + } + } public void Log(in LogMessage message) { var name = LogMessage.LogLevelToName(message.Level); var color = LogLevelToConsoleColor(message.Level); - lock (locker) { - System.Console.Write('['); - System.Console.ForegroundColor = color; - System.Console.Write(name); - System.Console.ResetColor(); - System.Console.WriteLine("] {0}: {1}", message.SawmillName, message.Message); + _line + .Clear() + .Append("\x1B[39m") + .Append("[") + .Append("\x1B[38;2;") + .Append(color.RByte) + .Append(';') + .Append(color.GByte) + .Append(';') + .Append(color.BByte) + .Append('m') + .Append(name) + .Append("\x1B[39m") + .Append("] ") + .Append(message.SawmillName) + .Append(": ") + .Append(message.Message) + .AppendLine(); + foreach (var chunk in _line.GetChunks()) + { + _writer.Write(MemoryMarshal.AsBytes(chunk.Span)); + } + + if (message.Level >= LogLevel.Error) + { + _writer.Flush(); + } } } - private static ConsoleColor LogLevelToConsoleColor(LogLevel level) + private static Color LogLevelToConsoleColor(LogLevel level) { switch (level) { case LogLevel.Debug: - return ConsoleColor.DarkBlue; + return Color.Navy; case LogLevel.Info: - return ConsoleColor.Cyan; + return Color.Cyan; case LogLevel.Warning: - return ConsoleColor.Yellow; + return Color.Yellow; case LogLevel.Error: + return Color.DarkRed; + case LogLevel.Fatal: - return ConsoleColor.Red; + return Color.Magenta; default: - return ConsoleColor.White; + return Color.White; } } + } + + public static class WindowsConsole + { + + public static bool TryEnableVirtualTerminalProcessing() + { + try + { + var stdHandle = NativeMethods.GetStdHandle(-11); + NativeMethods.GetConsoleMode(stdHandle, out var mode); + NativeMethods.SetConsoleMode(stdHandle, mode | 4); + NativeMethods.GetConsoleMode(stdHandle, out mode); + return (mode & 4) == 4; + } + catch (DllNotFoundException) + { + return false; + } + catch (EntryPointNotFoundException) + { + return false; + } + } + + internal static class NativeMethods + { + + [DllImport("kernel32", SetLastError = true)] + internal static extern bool SetConsoleMode(IntPtr hConsoleHandle, int mode); + + [DllImport("kernel32", SetLastError = true)] + internal static extern bool GetConsoleMode(IntPtr handle, out int mode); + + [DllImport("kernel32", SetLastError = true)] + internal static extern IntPtr GetStdHandle(int handle); + + } + + } + } diff --git a/Robust.Shared/Serialization/RobustSerializer.cs b/Robust.Shared/Serialization/RobustSerializer.cs index 1dd62dcdc..d50990be5 100644 --- a/Robust.Shared/Serialization/RobustSerializer.cs +++ b/Robust.Shared/Serialization/RobustSerializer.cs @@ -19,7 +19,6 @@ namespace Robust.Shared.Serialization { [Dependency] private readonly IReflectionManager _reflectionManager = default!; - [Dependency] private readonly ILogManager _logManager = default!; [Dependency] private readonly INetManager _netManager = default!; private readonly Lazy _lazyLogSzr = new Lazy(() => Logger.GetSawmill("szr"));