diff --git a/.gitignore b/.gitignore index f65f7a1c6..1a35d8862 100644 --- a/.gitignore +++ b/.gitignore @@ -9,11 +9,9 @@ /Distribution/Backups /Distribution/Saves /Distribution/docs -/Distribution/zlib.dll -/Distribution/libz.dylib -/Distribution/libz.so -/Distribution/ZLib.Bindings.dll -/Distribution/Microsoft.Toolkit.HighPerformance.dll +/Distribution/*.dylib +/Distribution/*.so +/Distribution/*.dll /Distribution/runtimes /Distribution/nohup.out /Distribution/ref diff --git a/Projects/Benchmarks/Benchmarks.csproj b/Projects/Benchmarks/Benchmarks.csproj index e0ab71eea..291c5811d 100644 --- a/Projects/Benchmarks/Benchmarks.csproj +++ b/Projects/Benchmarks/Benchmarks.csproj @@ -10,6 +10,9 @@ + + + diff --git a/Projects/Benchmarks/Benchmarks/Logging/BenchmarkConsoleLogging.cs b/Projects/Benchmarks/Benchmarks/Logging/BenchmarkConsoleLogging.cs new file mode 100644 index 000000000..f95b139df --- /dev/null +++ b/Projects/Benchmarks/Benchmarks/Logging/BenchmarkConsoleLogging.cs @@ -0,0 +1,63 @@ +using System; +using BenchmarkDotNet.Attributes; +using BenchmarkDotNet.Jobs; +using Serilog; +using Serilog.Core; + +namespace Benchmarks +{ + [SimpleJob(RuntimeMoniker.NetCoreApp50)] + public class BenchmarkConsoleLogging + { + private const string text = "Sample message"; + + private Logger logger; + private Logger asyncLogger; + + [IterationSetup] + public void IterationSetup() + { + logger = new LoggerConfiguration() + .WriteTo.Console() + .CreateLogger(); + + asyncLogger = new LoggerConfiguration() + .WriteTo.Async(a => a.Console()) + .CreateLogger(); + } + + [IterationCleanup] + public void IterationCleanup() + { + logger = null; + asyncLogger = null; + } + + [Benchmark] + public void TestConsoleWriteLine() + { + for (int i = 0; i < 100; i++) + { + Console.WriteLine(text); + } + } + + [Benchmark] + public void TestSerilogConsoleSink() + { + for (int i = 0; i < 100; i++) + { + logger.Information(text); + } + } + + [Benchmark] + public void TestSerilogAsyncConsoleSink() + { + for (int i = 0; i < 100; i++) + { + asyncLogger.Information(text); + } + } + } +} diff --git a/Projects/Benchmarks/Program.cs b/Projects/Benchmarks/Program.cs index 19eab94b6..6ad1f5623 100644 --- a/Projects/Benchmarks/Program.cs +++ b/Projects/Benchmarks/Program.cs @@ -1,5 +1,4 @@ using BenchmarkDotNet.Running; -using Benchmarks.BenchmarkText; namespace Benchmarks { @@ -12,7 +11,8 @@ namespace Benchmarks // var broadcast = BenchmarkRunner.Run(); // var stringHelpers = BenchmarkRunner.Run(); // var indexList = BenchmarkRunner.Run(); - var textEncoding = BenchmarkRunner.Run(); + // var textEncoding = BenchmarkRunner.Run(); + var logging = BenchmarkRunner.Run(); } } } diff --git a/Projects/Server/Configuration/ServerConfiguration.cs b/Projects/Server/Configuration/ServerConfiguration.cs index 9948c5999..9d5619ec2 100644 --- a/Projects/Server/Configuration/ServerConfiguration.cs +++ b/Projects/Server/Configuration/ServerConfiguration.cs @@ -19,11 +19,14 @@ using System.Globalization; using System.IO; using System.Net; using Server.Json; +using Server.Logging; namespace Server { public static class ServerConfiguration { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(ServerConfiguration)); + private const string m_RelPath = "Configuration/modernuo.json"; private static readonly string m_FilePath = Path.Join(Core.BaseDirectory, m_RelPath); private static ServerSettings m_Settings; @@ -178,20 +181,16 @@ namespace Server if (File.Exists(m_FilePath)) { - Core.WriteConsole($"Reading server configuration from {m_RelPath}..."); + logger.Information($"Reading server configuration from {m_RelPath}..."); m_Settings = JsonConfig.Deserialize(m_FilePath); if (m_Settings == null) { - Utility.PushColor(ConsoleColor.Red); - Console.WriteLine("failed"); - Utility.PopColor(); + logger.Error($"Reading server configuration failed"); throw new FileNotFoundException($"Failed to deserialize {m_FilePath}."); } - Utility.PushColor(ConsoleColor.Green); - Console.WriteLine("done"); - Utility.PopColor(); + logger.Information($"Reading server configuration done"); } else { @@ -237,9 +236,7 @@ namespace Server if (updated) { Save(); - Utility.PushColor(ConsoleColor.Green); - Core.WriteConsoleLine($"Server configuration saved to {m_RelPath}."); - Utility.PopColor(); + logger.Information($"Server configuration saved to {m_RelPath}."); } } @@ -263,7 +260,7 @@ namespace Server return; } - Core.WriteConsoleLine($"Invalid option. ({input})"); + logger.Information($"Invalid option. ({input})"); } while (true); } @@ -301,7 +298,7 @@ namespace Server return expansion; } - Core.WriteConsoleLine($"Invalid expansion. ({input})"); + logger.Information($"Invalid expansion. ({input})"); } while (true); } @@ -323,11 +320,11 @@ namespace Server if (Directory.Exists(directory)) { directories.Add(directory); - Core.WriteConsoleLine($"Path {directory} added."); + logger.Information($"Path {directory} added."); } else { - Core.WriteConsoleLine($"Path does not exist. ({directory})"); + logger.Information($"Path does not exist. ({directory})"); } } while (true); @@ -360,11 +357,11 @@ namespace Server if (IPEndPoint.TryParse(ipStr, out var ip)) { ips.Add(ip); - Core.WriteConsoleLine($"Core: {ipStr} added."); + logger.Information($"Core: {ipStr} added."); } else { - Core.WriteConsoleLine($"{ipStr} is not a valid IP or port"); + logger.Information($"{ipStr} is not a valid IP or port"); } } while (true); diff --git a/Projects/Server/Logging/ILogger.cs b/Projects/Server/Logging/ILogger.cs new file mode 100644 index 000000000..d1c6f8b7a --- /dev/null +++ b/Projects/Server/Logging/ILogger.cs @@ -0,0 +1,37 @@ +/************************************************************************* + * ModernUO * + * Copyright 2019-2021 - ModernUO Development Team * + * Email: hi@modernuo.com * + * File: ILogger.cs * + * * + * This program is free software: you can redistribute it and/or modify * + * it under the terms of the GNU General Public License as published by * + * the Free Software Foundation, either version 3 of the License, or * + * (at your option) any later version. * + * * + * You should have received a copy of the GNU General Public License * + * along with this program. If not, see . * + *************************************************************************/ + +using System; + +namespace Server.Logging +{ + public interface ILogger + { + void Debug(string message, params object[] args); + void Debug(Exception exception, string message, params object[] args); + + void Information(string message, params object[] args); + void Information(Exception exception, string message, params object[] args); + + void Warning(string message, params object[] args); + void Warning(Exception exception, string message, params object[] args); + + void Error(string message, params object[] args); + void Error(Exception exception, string message, params object[] args); + + void Fatal(string message, params object[] args); + void Fatal(Exception exception, string message, params object[] args); + } +} diff --git a/Projects/Server/Logging/LogFactory.cs b/Projects/Server/Logging/LogFactory.cs new file mode 100644 index 000000000..2bf93a57d --- /dev/null +++ b/Projects/Server/Logging/LogFactory.cs @@ -0,0 +1,31 @@ +/************************************************************************* + * ModernUO * + * Copyright 2019-2021 - ModernUO Development Team * + * Email: hi@modernuo.com * + * File: LogFactory.cs * + * * + * This program is free software: you can redistribute it and/or modify * + * it under the terms of the GNU General Public License as published by * + * the Free Software Foundation, either version 3 of the License, or * + * (at your option) any later version. * + * * + * You should have received a copy of the GNU General Public License * + * along with this program. If not, see . * + *************************************************************************/ + +using System; +using Serilog; + +namespace Server.Logging +{ + public static class LogFactory + { + private static readonly Serilog.ILogger serilogLogger = new LoggerConfiguration() + .WriteTo.Async(a => a.Console( + outputTemplate: "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj} {NewLine}{Exception}" + )) + .CreateLogger(); + + public static ILogger GetLogger(Type declaringType) => new SerilogLogger(serilogLogger.ForContext(declaringType)); + } +} diff --git a/Projects/Server/Logging/SerilogLogger.cs b/Projects/Server/Logging/SerilogLogger.cs new file mode 100644 index 000000000..c4df66f29 --- /dev/null +++ b/Projects/Server/Logging/SerilogLogger.cs @@ -0,0 +1,57 @@ +/************************************************************************* + * ModernUO * + * Copyright 2019-2021 - ModernUO Development Team * + * Email: hi@modernuo.com * + * File: SerilogLogger.cs * + * * + * This program is free software: you can redistribute it and/or modify * + * it under the terms of the GNU General Public License as published by * + * the Free Software Foundation, either version 3 of the License, or * + * (at your option) any later version. * + * * + * You should have received a copy of the GNU General Public License * + * along with this program. If not, see . * + *************************************************************************/ + +using System; + +namespace Server.Logging +{ + public class SerilogLogger : ILogger + { + private readonly Serilog.ILogger serilogLogger; + + public SerilogLogger(Serilog.ILogger serilogLogger) => + this.serilogLogger = serilogLogger; + + public void Debug(string message, params object[] args) => + serilogLogger.Debug(message, args); + + public void Debug(Exception exception, string message, params object[] args) => + serilogLogger.Debug(exception, message, args); + + public void Information(string message, params object[] args) => + serilogLogger.Information(message, args); + + public void Information(Exception exception, string message, params object[] args) => + serilogLogger.Information(exception, message, args); + + public void Warning(string message, params object[] args) => + serilogLogger.Warning(message, args); + + public void Warning(Exception exception, string message, params object[] args) => + serilogLogger.Information(exception, message, args); + + public void Error(string message, params object[] args) => + serilogLogger.Error(message, args); + + public void Error(Exception exception, string message, params object[] args) => + serilogLogger.Error(exception, message, args); + + public void Fatal(string message, params object[] args) => + serilogLogger.Fatal(message, args); + + public void Fatal(Exception exception, string message, params object[] args) => + serilogLogger.Fatal(exception, message, args); + } +} diff --git a/Projects/Server/Main.cs b/Projects/Server/Main.cs index b61dad707..e3736e8ed 100644 --- a/Projects/Server/Main.cs +++ b/Projects/Server/Main.cs @@ -26,12 +26,15 @@ using System.Text.Json; using System.Threading; using System.Threading.Tasks; using Server.Json; +using Server.Logging; using Server.Network; namespace Server { public static class Core { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(Core)); + private static bool _crashed; private static Thread _timerThread; private static string _baseDirectory; @@ -297,7 +300,7 @@ namespace Server _ => "CTRL+C" }; - WriteConsoleLine($"Detected {keypress} pressed."); + logger.Information($"Detected {keypress} pressed."); e.Cancel = true; Kill(); } @@ -410,7 +413,7 @@ namespace Server ".TrimMultiline()); Utility.PopColor(); - WriteConsoleLine($"Running on {RuntimeInformation.FrameworkDescription}"); + logger.Information($"Running on {RuntimeInformation.FrameworkDescription}"); var ttObj = new Timer.TimerThread(); _timerThread = new Thread(ttObj.TimerMain) @@ -422,7 +425,7 @@ namespace Server if (s.Length > 0) { - WriteConsoleLine($"Running with arguments: {s}"); + logger.Information($"Running with arguments: {s}"); } ProcessorCount = Environment.ProcessorCount; @@ -434,17 +437,17 @@ namespace Server if (MultiProcessor) { - WriteConsoleLine($"Optimizing for {ProcessorCount} processor{(ProcessorCount == 1 ? "" : "s")}"); + logger.Information($"Optimizing for {ProcessorCount} processor{(ProcessorCount == 1 ? "" : "s")}"); } Console.CancelKeyPress += Console_CancelKeyPressed; if (GCSettings.IsServerGC) { - WriteConsoleLine(": Server garbage collection mode enabled"); + logger.Information("Server garbage collection mode enabled"); } - WriteConsoleLine($"High resolution timing ({(Stopwatch.IsHighResolution ? "Supported" : "Unsupported")})"); + logger.Information($"High resolution timing ({(Stopwatch.IsHighResolution ? "Supported" : "Unsupported")})"); ServerConfiguration.Load(); @@ -605,17 +608,5 @@ namespace Server Parallel.ForEach(assembly.GetTypes(), VerifyType); } } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - internal static void WriteConsole(string message) - { - Console.Write("Core: {0}", message); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - internal static void WriteConsoleLine(string message) - { - Console.WriteLine("Core: {0}", message); - } } } diff --git a/Projects/Server/Maps/MapLoader.cs b/Projects/Server/Maps/MapLoader.cs index 5e3ab0667..d07382443 100644 --- a/Projects/Server/Maps/MapLoader.cs +++ b/Projects/Server/Maps/MapLoader.cs @@ -20,11 +20,14 @@ using System.IO; using System.Text.Json; using System.Text.Json.Serialization; using Server.Json; +using Server.Logging; namespace Server { public static class MapLoader { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(MapLoader)); + /* Here we configure all maps. Some notes: * * 1) The first 32 maps are reserved for core use. @@ -52,7 +55,7 @@ namespace Server var path = Path.Combine(Core.BaseDirectory, "Data/map-definitions.json"); - Console.Write("Map Definitions: Loading..."); + logger.Information("Loading Map Definitions"); var stopwatch = Stopwatch.StartNew(); var maps = JsonConfig.Deserialize>(path); @@ -85,21 +88,25 @@ namespace Server stopwatch.Stop(); - Utility.PushColor(failures.Count > 0 ? ConsoleColor.Yellow : ConsoleColor.Green); - Console.Write(failures.Count > 0 ? "done with failures" : "done"); - Utility.PopColor(); - Console.WriteLine( - " ({0} maps, {1} failures) ({2:F2} seconds)", - count, - failures.Count, - stopwatch.Elapsed.TotalSeconds - ); - if (failures.Count > 0) { - Utility.PushColor(ConsoleColor.Red); - Console.WriteLine(string.Join(Environment.NewLine, failures)); - Utility.PopColor(); + logger.Warning( + "Map Definitions loaded with failures ({0} maps, {1} failures) ({2:F2} seconds)", + count, + failures.Count, + stopwatch.Elapsed.TotalSeconds + ); + + logger.Warning(string.Join(Environment.NewLine, failures)); + } + else + { + logger.Information( + "Map Definitions loaded successfully ({0} maps, {1} failures) ({2:F2} seconds)", + count, + failures.Count, + stopwatch.Elapsed.TotalSeconds + ); } } diff --git a/Projects/Server/Network/NetState/NetState.cs b/Projects/Server/Network/NetState/NetState.cs index af5d86e72..7b6170f22 100644 --- a/Projects/Server/Network/NetState/NetState.cs +++ b/Projects/Server/Network/NetState/NetState.cs @@ -17,7 +17,6 @@ using System; using System.Buffers; using System.Collections.Concurrent; using System.Collections.Generic; -using System.Diagnostics; using System.IO; using System.Net; using System.Net.Sockets; @@ -28,6 +27,7 @@ using Server.Diagnostics; using Server.Gumps; using Server.HuePickers; using Server.Items; +using Server.Logging; using Server.Menus; namespace Server.Network @@ -39,6 +39,8 @@ namespace Server.Network public partial class NetState : IComparable { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(NetState)); + private const int RecvPipeSize = 1024 * 64; private const int SendPipeSize = 1024 * 256; private static int GumpCap = 512; @@ -343,15 +345,15 @@ namespace Server.Network } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void WriteConsole(string text) + public void LogInfo(string text) { - Console.WriteLine("Client: {0}: {1}", this, text); + logger.Information("Client: {0}: {1}", this, text); } [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void WriteConsole(string format, params object[] args) + public void LogInfo(string format, params object[] args) { - WriteConsole(string.Format(format, args)); + LogInfo(string.Format(format, args)); } public void AddMenu(IMenu menu) @@ -364,7 +366,7 @@ namespace Server.Network } else { - WriteConsole("Exceeded menu cap, disconnecting..."); + LogInfo("Exceeded menu cap, disconnecting..."); Disconnect("Exceeded menu cap."); } } @@ -394,7 +396,7 @@ namespace Server.Network } else { - WriteConsole("Exceeded hue picker cap, disconnecting..."); + LogInfo("Exceeded hue picker cap, disconnecting..."); Disconnect("Exceeded hue picker cap."); } } @@ -424,7 +426,7 @@ namespace Server.Network } else { - WriteConsole("Exceeded gump cap, disconnecting..."); + LogInfo("Exceeded gump cap, disconnecting..."); Disconnect("Exceeded gump cap."); } } @@ -622,7 +624,7 @@ namespace Server.Network { if (packetId != 0xCF && packetId != 0x80) { - WriteConsole("Possible encrypted client detected, disconnecting..."); + LogInfo("Possible encrypted client detected, disconnecting..."); HandleError(packetId, packetLength); return true; } @@ -740,7 +742,7 @@ namespace Server.Network PacketHandler handler = GetHandler(packetId); if (handler == null) { - WriteConsole($"received unknown packet 0x{packetId:X2} while in state {_protocolState}"); + LogInfo($"received unknown packet 0x{packetId:X2} while in state {_protocolState}"); packetLength = length; return ParserState.Error; } @@ -771,7 +773,7 @@ namespace Server.Network { if (Mobile == null) { - WriteConsole($"received packet 0x{packetId:X2} before having been attached to a mobile"); + LogInfo($"received packet 0x{packetId:X2} before having been attached to a mobile"); return ParserState.Error; } @@ -1015,7 +1017,7 @@ namespace Server.Network { if (Connection != null && _nextActivityCheck - curTicks < 0) { - WriteConsole("Disconnecting due to inactivity..."); + LogInfo("Disconnecting due to inactivity..."); Disconnect("Disconnecting due to inactivity."); } } @@ -1147,11 +1149,11 @@ namespace Server.Network if (a != null) { - WriteConsole("Disconnected. [{0} Online] [{1}]", count, a); + LogInfo("Disconnected. [{0} Online] [{1}]", count, a); } else { - WriteConsole("Disconnected. [{0} Online]", count); + LogInfo("Disconnected. [{0} Online]", count); } } } diff --git a/Projects/Server/Network/Packets/IncomingAccountPackets.cs b/Projects/Server/Network/Packets/IncomingAccountPackets.cs index fab4bdffd..ad4af8ca8 100644 --- a/Projects/Server/Network/Packets/IncomingAccountPackets.cs +++ b/Projects/Server/Network/Packets/IncomingAccountPackets.cs @@ -157,7 +157,7 @@ namespace Server.Network if (check != null && check.Map != Map.Internal) { - state.WriteConsole("Account in use"); + state.LogInfo("Account in use"); state.SendPopupMessage(PMMessage.CharInWorld); return; } @@ -274,7 +274,7 @@ namespace Server.Network if (check != null && check.Map != Map.Internal && check != m) { - state.WriteConsole("Account in use"); + state.LogInfo("Account in use"); state.SendPopupMessage(PMMessage.CharInWorld); return; } @@ -395,13 +395,13 @@ namespace Server.Network if (!m_AuthIDWindow.TryGetValue(authID, out var ap)) { - state.WriteConsole("Invalid client detected, disconnecting..."); + state.LogInfo("Invalid client detected, disconnecting..."); state.Disconnect("Unable to find auth id."); } if (state._authId != 0 && authID != state._authId || state._authId == 0 && authID != state._seed) { - state.WriteConsole("Invalid client detected, disconnecting..."); + state.LogInfo("Invalid client detected, disconnecting..."); state.Disconnect("Invalid auth id in game login packet."); return; } @@ -461,7 +461,7 @@ namespace Server.Network if (state._seed == 0) { - state.WriteConsole("Invalid client detected, disconnecting"); + state.LogInfo("Invalid client detected, disconnecting"); state.Disconnect("Duplicate seed sent."); return; } diff --git a/Projects/Server/Network/Packets/IncomingExtendedCommandPackets.cs b/Projects/Server/Network/Packets/IncomingExtendedCommandPackets.cs index 9a4921fc8..fe8f01177 100644 --- a/Projects/Server/Network/Packets/IncomingExtendedCommandPackets.cs +++ b/Projects/Server/Network/Packets/IncomingExtendedCommandPackets.cs @@ -120,7 +120,7 @@ namespace Server.Network { if (state.Mobile == null) { - state.WriteConsole( + state.LogInfo( "Sent in-game packet (0xBFx{0:X2}) before having been attached to a mobile", packetId ); diff --git a/Projects/Server/Network/Packets/IncomingPlayerPackets.cs b/Projects/Server/Network/Packets/IncomingPlayerPackets.cs index 7d34ed171..cab618b2e 100644 --- a/Projects/Server/Network/Packets/IncomingPlayerPackets.cs +++ b/Projects/Server/Network/Packets/IncomingPlayerPackets.cs @@ -203,7 +203,7 @@ namespace Server.Network } default: { - state.WriteConsole("Unknown text-command type 0x{0:X2}: {1}", state, type, command); + state.LogInfo("Unknown text-command type 0x{0:X2}: {1}", state, type, command); break; } } @@ -373,7 +373,7 @@ namespace Server.Network if (!buttonExists) { - state.WriteConsole("Invalid gump response, disconnecting..."); + state.LogInfo("Invalid gump response, disconnecting..."); var exception = new InvalidGumpResponseException($"Button {buttonID} doesn't exist"); exception.SetStackTrace(new StackTrace()); NetState.TraceException(exception); @@ -387,7 +387,7 @@ namespace Server.Network if (switchCount < 0 || switchCount > gump.m_Switches) { - state.WriteConsole("Invalid gump response, disconnecting..."); + state.LogInfo("Invalid gump response, disconnecting..."); var exception = new InvalidGumpResponseException($"Bad switch count {switchCount}"); exception.SetStackTrace(new StackTrace()); NetState.TraceException(exception); @@ -408,7 +408,7 @@ namespace Server.Network if (textCount < 0 || textCount > gump.m_TextEntries) { - state.WriteConsole("Invalid gump response, disconnecting..."); + state.LogInfo("Invalid gump response, disconnecting..."); var exception = new InvalidGumpResponseException($"Bad text entry count {textCount}"); exception.SetStackTrace(new StackTrace()); NetState.TraceException(exception); @@ -427,7 +427,7 @@ namespace Server.Network if (textLength > 239) { - state.WriteConsole("Invalid gump response, disconnecting..."); + state.LogInfo("Invalid gump response, disconnecting..."); var exception = new InvalidGumpResponseException($"Text entry {i} is too long ({textLength})"); exception.SetStackTrace(new StackTrace()); NetState.TraceException(exception); @@ -614,7 +614,7 @@ namespace Server.Network if (ph.Ingame && state.Mobile == null) { - state.WriteConsole( + state.LogInfo( "Sent in-game packet (0xD7x{0:X2}) before being attached to a mobile", packetId ); diff --git a/Projects/Server/Network/Packets/OutgoingGumpPackets.cs b/Projects/Server/Network/Packets/OutgoingGumpPackets.cs index 12052e35c..d8eefbd26 100644 --- a/Projects/Server/Network/Packets/OutgoingGumpPackets.cs +++ b/Projects/Server/Network/Packets/OutgoingGumpPackets.cs @@ -20,11 +20,14 @@ using System.IO.Compression; using System.Runtime.CompilerServices; using Server.Collections; using Server.Gumps; +using Server.Logging; namespace Server.Network { public static class OutgoingGumpPackets { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(OutgoingGumpPackets)); + public static void SendCloseGump(this NetState ns, int typeId, int buttonId) { if (ns == null) @@ -73,9 +76,7 @@ namespace Server.Network if (error != ZlibError.Okay) { - Utility.PushColor(ConsoleColor.Red); - Core.WriteConsoleLine($"Gump compression failed {error}"); - Utility.PopColor(); + logger.Warning($"Gump compression failed {error}"); writer.Write(4); writer.Write(0); diff --git a/Projects/Server/Network/TcpServer.cs b/Projects/Server/Network/TcpServer.cs index dc44702d5..b5ddcf165 100644 --- a/Projects/Server/Network/TcpServer.cs +++ b/Projects/Server/Network/TcpServer.cs @@ -20,11 +20,14 @@ using System.Linq; using System.Net; using System.Net.NetworkInformation; using System.Net.Sockets; +using Server.Logging; namespace Server.Network { public static class TcpServer { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(TcpServer)); + private const int MaxConnectionsPerLoop = 250; // Sanity. 256 * 1024 * 4096 = ~1.3GB of ram @@ -75,7 +78,7 @@ namespace Server.Network foreach (var ipep in listeningAddresses) { - Console.WriteLine("Listening: {0}:{1}", ipep.Address, ipep.Port); + logger.Information("Listening: {0}:{1}", ipep.Address, ipep.Port); } ListeningAddresses = listeningAddresses.ToArray(); @@ -104,17 +107,16 @@ namespace Server.Network // WSAEADDRINUSE if (se.ErrorCode == 10048) { - Console.WriteLine("Listener: {0}:{1}: Failed (In Use)", ipep.Address, ipep.Port); + logger.Warning("Listener: {0}:{1}: Failed (In Use)", ipep.Address, ipep.Port); } // WSAEADDRNOTAVAIL else if (se.ErrorCode == 10049) { - Console.WriteLine("Listener {0}:{1}: Failed (Unavailable)", ipep.Address, ipep.Port); + logger.Warning("Listener {0}:{1}: Failed (Unavailable)", ipep.Address, ipep.Port); } else { - Console.WriteLine("Listener Exception:"); - Console.WriteLine(se); + logger.Warning(se, "Listener Exception:"); } } @@ -128,7 +130,7 @@ namespace Server.Network while (++count <= MaxConnectionsPerLoop && _connectedQueue.TryDequeue(out var ns)) { Instances.Add(ns); - ns.WriteConsole("Connected. [{0} Online]", Instances.Count); + ns.LogInfo("Connected. [{0} Online]", Instances.Count); ns.Start(); } @@ -154,7 +156,7 @@ namespace Server.Network if (socket.RemoteEndPoint is IPEndPoint ipep) { var ip = ipep.Address.ToString(); - Console.WriteLine("Listener {0}: Failed (Maximum connections reached)", ip); + logger.Warning("Listener {0}: Failed (Maximum connections reached)", ip); NetState.TraceDisconnect("Maximum connections reached.", ip); } diff --git a/Projects/Server/Regions/RegionLoader.cs b/Projects/Server/Regions/RegionLoader.cs index ae9251f84..73ec7a3c9 100644 --- a/Projects/Server/Regions/RegionLoader.cs +++ b/Projects/Server/Regions/RegionLoader.cs @@ -19,12 +19,15 @@ using System.Diagnostics; using System.IO; using System.Text.Json; using Server.Json; +using Server.Logging; using Server.Utilities; namespace Server { internal static class RegionLoader { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(RegionLoader)); + internal static void LoadRegions() { var path = Path.Join(Core.BaseDirectory, "Data/regions.json"); @@ -32,7 +35,7 @@ namespace Server var failures = new List(); var count = 0; - Console.Write("Regions: Loading..."); + logger.Information("Loading regions"); var stopwatch = Stopwatch.StartNew(); var regions = JsonConfig.Deserialize>(path); @@ -58,21 +61,25 @@ namespace Server stopwatch.Stop(); - Utility.PushColor(failures.Count > 0 ? ConsoleColor.Yellow : ConsoleColor.Green); - Console.Write(failures.Count > 0 ? "done with failures" : "done"); - Utility.PopColor(); - Console.WriteLine( - " ({0} regions, {1} failures) ({2:F2} seconds)", - count, - failures.Count, - stopwatch.Elapsed.TotalSeconds - ); - - if (failures.Count > 0) + if (failures.Count == 0) { - Utility.PushColor(ConsoleColor.Red); - Console.WriteLine(string.Join(Environment.NewLine, failures)); - Utility.PopColor(); + logger.Information( + "Regions loaded ({0} regions, {1} failures) ({2:F2} seconds)", + count, + failures.Count, + stopwatch.Elapsed.TotalSeconds + ); + } + else + { + logger.Warning( + "Failed loading regions ({0} regions, {1} failures) ({2:F2} seconds)", + count, + failures.Count, + stopwatch.Elapsed.TotalSeconds + ); + + logger.Warning(string.Join(Environment.NewLine, failures)); } } } diff --git a/Projects/Server/Serialization/GenericPersistence.cs b/Projects/Server/Serialization/GenericPersistence.cs index b15926b0a..ec5087403 100644 --- a/Projects/Server/Serialization/GenericPersistence.cs +++ b/Projects/Server/Serialization/GenericPersistence.cs @@ -73,8 +73,8 @@ namespace Server catch (Exception e) { Utility.PushColor(ConsoleColor.Red); - Persistence.WriteConsoleLine($"***** Bad deserialize of {name} *****"); - Persistence.WriteConsoleLine(e.ToString()); + Console.WriteLine($"***** Bad deserialize of {name} *****"); + Console.WriteLine(e.ToString()); Utility.PopColor(); } } diff --git a/Projects/Server/Serialization/Persistence.cs b/Projects/Server/Serialization/Persistence.cs index 86b5e3e13..c4abd1458 100644 --- a/Projects/Server/Serialization/Persistence.cs +++ b/Projects/Server/Serialization/Persistence.cs @@ -16,12 +16,11 @@ using System; using System.Collections.Generic; using System.IO; -using System.Runtime.CompilerServices; using System.Threading.Tasks; namespace Server { - public static class Persistence + public class Persistence { public const int DefaultPriority = 100; @@ -105,20 +104,6 @@ namespace Server } } - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static void WriteConsole(string message) - { - var now = Core.Now; - Console.Write("[{0} {1}] Persistence: {2}", now.ToShortDateString(), now.ToLongTimeString(), message); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public static void WriteConsoleLine(string message) - { - var now = Core.Now; - Console.WriteLine("[{0} {1}] Persistence: {2}", now.ToShortDateString(), now.ToLongTimeString(), message); - } - public static void TraceException(Exception ex) { try diff --git a/Projects/Server/Server.csproj b/Projects/Server/Server.csproj index 226e8eb82..1dc311dad 100644 --- a/Projects/Server/Server.csproj +++ b/Projects/Server/Server.csproj @@ -29,6 +29,9 @@ + + + diff --git a/Projects/Server/TileMatrix/TileMatrixLoader.cs b/Projects/Server/TileMatrix/TileMatrixLoader.cs index 773cfc2d1..0d2e2563e 100644 --- a/Projects/Server/TileMatrix/TileMatrixLoader.cs +++ b/Projects/Server/TileMatrix/TileMatrixLoader.cs @@ -15,14 +15,17 @@ using System; using System.Diagnostics; +using Server.Logging; namespace Server { internal static class TileMatrixLoader { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(TileMatrixLoader)); + internal static void LoadTileMatrix() { - Console.Write("Maps: Loading..."); + logger.Information("Loading maps"); var stopwatch = Stopwatch.StartNew(); Exception exception = null; @@ -41,14 +44,13 @@ namespace Server stopwatch.Stop(); - Utility.PushColor(exception != null ? ConsoleColor.Yellow : ConsoleColor.Green); - Console.Write(exception != null ? "failed" : "done"); - Utility.PopColor(); - Console.WriteLine(" ({0:F2} seconds)", stopwatch.Elapsed.TotalSeconds); - - if (exception != null) + if (exception == null) { - Console.WriteLine(exception); + logger.Information("Maps loaded ({0:F2} seconds)", stopwatch.Elapsed.TotalSeconds); + } + else + { + logger.Error(exception, "Loading maps failed ({0:F2} seconds)", stopwatch.Elapsed.TotalSeconds); throw exception; } } diff --git a/Projects/Server/World/EntityPersistence.cs b/Projects/Server/World/EntityPersistence.cs index ed7717791..d16c63f21 100644 --- a/Projects/Server/World/EntityPersistence.cs +++ b/Projects/Server/World/EntityPersistence.cs @@ -19,6 +19,7 @@ using System.IO; using System.Reflection; using System.Runtime.CompilerServices; using System.Threading.Tasks; +using Server.Logging; namespace Server { @@ -210,12 +211,10 @@ namespace Server } else { - Utility.PushColor(ConsoleColor.Red); - Persistence.WriteConsoleLine($"***** Bad deserialize of {t.GetType()} *****"); - Persistence.WriteConsoleLine(error); - Utility.PopColor(); + Console.WriteLine($"***** Bad deserialize of {t.GetType()} *****"); + Console.WriteLine(error); - Persistence.WriteConsoleLine("Delete the object and continue? (y/n)"); + Console.WriteLine("Delete the object and continue? (y/n)"); if (Console.ReadKey(true).Key != ConsoleKey.Y) { @@ -245,20 +244,20 @@ namespace Server if (t?.IsAbstract != false) { - Persistence.WriteConsoleLine("failed"); + Console.WriteLine("failed"); var issue = t?.IsAbstract == true ? "marked abstract" : "not found"; - Persistence.WriteConsoleLine($"Error: Type '{typeName}' was {issue}. Delete all of those types? (y/n)"); + Console.WriteLine($"Error: Type '{typeName}' was {issue}. Delete all of those types? (y/n)"); if (Console.ReadKey(true).Key == ConsoleKey.Y) { types.Add(null); - Persistence.WriteConsole("Loading..."); + Console.WriteLine("Loading..."); continue; } - Persistence.WriteConsoleLine("Types will not be deleted. An exception will be thrown."); + Console.WriteLine("Types will not be deleted. An exception will be thrown."); throw new Exception($"Bad type '{typeName}'"); } diff --git a/Projects/Server/World/World.cs b/Projects/Server/World/World.cs index fb1adf203..ade65d8fd 100644 --- a/Projects/Server/World/World.cs +++ b/Projects/Server/World/World.cs @@ -22,6 +22,7 @@ using System.Linq; using System.Runtime.CompilerServices; using System.Threading; using Server.Guilds; +using Server.Logging; using Server.Network; namespace Server @@ -37,6 +38,8 @@ namespace Server public static class World { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(World)); + private static readonly ManualResetEvent m_DiskWriteHandle = new(true); private static readonly Dictionary _pendingAdd = new(); private static readonly Dictionary _pendingDelete = new(); @@ -154,7 +157,7 @@ namespace Server { if (WorldState != WorldState.Saving) { - WriteConsoleLine($"Attempting to queue {item} for decay but the world is not saving"); + logger.Warning($"Attempting to queue {item} for decay but the world is not saving"); return; } @@ -245,7 +248,7 @@ namespace Server WorldState = WorldState.Loading; - WriteConsole("Loading..."); + logger.Information("Loading world"); var watch = Stopwatch.StartNew(); Persistence.Load(_savePath); @@ -273,15 +276,11 @@ namespace Server watch.Stop(); - Utility.PushColor(ConsoleColor.Green); - Console.Write("done"); - Utility.PopColor(); - Console.WriteLine( - " ({1} items, {2} mobiles) ({0:F2} seconds)", + logger.Information(string.Format("World loaded ({1} items, {2} mobiles) ({0:F2} seconds)", watch.Elapsed.TotalSeconds, Items.Count, Mobiles.Count - ); + )); WorldState = WorldState.Running; } @@ -309,7 +308,7 @@ namespace Server var message = $"Warning: Attempted to {action} {entity} during world save.{Environment.NewLine}This action could cause inconsistent state.{Environment.NewLine}It is strongly advised that the offending scripts be corrected."; - WriteConsoleLine(message); + logger.Information(message); try { @@ -383,7 +382,7 @@ namespace Server try { var watch = Stopwatch.StartNew(); - WriteConsole("Writing snapshot..."); + logger.Information("Writing snapshot..."); Persistence.WriteSnapshot(tempPath); @@ -475,7 +474,7 @@ namespace Server var now = DateTime.UtcNow; - WriteConsole("Saving..."); + logger.Information("Saving world"); var watch = Stopwatch.StartNew(); @@ -592,9 +591,7 @@ namespace Server { if (_pendingDelete.Remove(entity.Serial)) { - Utility.PushColor(ConsoleColor.Red); - WriteConsoleLine($"Deleted then added {entity.GetType().Name} during {WorldState.ToString()} state."); - Utility.PopColor(); + logger.Warning($"Deleted then added {entity.GetType().Name} during {WorldState.ToString()} state."); } _pendingAdd[entity.Serial] = entity; break; @@ -656,19 +653,5 @@ namespace Server [MethodImpl(MethodImplOptions.AggressiveInlining)] public static void RemoveGuild(BaseGuild guild) => Guilds.Remove(guild.Serial); - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - private static void WriteConsole(string message) - { - var now = DateTime.UtcNow; - Console.Write("[{0} {1}] World: {2}", now.ToShortDateString(), now.ToLongTimeString(), message); - } - - [MethodImpl(MethodImplOptions.AggressiveInlining)] - private static void WriteConsoleLine(string message) - { - var now = DateTime.UtcNow; - Console.WriteLine("[{0} {1}] World: {2}", now.ToShortDateString(), now.ToLongTimeString(), message); - } } } diff --git a/Projects/UOContent/Accounting/AccountHandler.cs b/Projects/UOContent/Accounting/AccountHandler.cs index cf07e57d1..22d01df7a 100644 --- a/Projects/UOContent/Accounting/AccountHandler.cs +++ b/Projects/UOContent/Accounting/AccountHandler.cs @@ -250,7 +250,7 @@ namespace Server.Misc } else { - state.WriteConsole("Deleting character {0} (0x{1:X})", index, m.Serial.Value); + state.LogInfo("Deleting character {0} (0x{1:X})", index, m.Serial.Value); acct.Comments.Add(new AccountComment("System", $"Character #{index + 1} {m} deleted by {state}")); diff --git a/Projects/UOContent/Engines/Chat/ChatPackets.cs b/Projects/UOContent/Engines/Chat/ChatPackets.cs index 9f19817fe..30ad48adc 100644 --- a/Projects/UOContent/Engines/Chat/ChatPackets.cs +++ b/Projects/UOContent/Engines/Chat/ChatPackets.cs @@ -73,7 +73,7 @@ namespace Server.Engines.Chat if (handler == null) { - state.WriteConsole("Unknown chat action 0x{0:X}: {1}", actionID, param); + state.LogInfo("Unknown chat action 0x{0:X}: {1}", actionID, param); return; } diff --git a/Projects/UOContent/Misc/AutoSave.cs b/Projects/UOContent/Misc/AutoSave.cs index c455706e8..8c71c1981 100644 --- a/Projects/UOContent/Misc/AutoSave.cs +++ b/Projects/UOContent/Misc/AutoSave.cs @@ -1,10 +1,13 @@ using System; using System.IO; +using Server.Logging; namespace Server.Misc { public class AutoSave : Timer { + private static readonly ILogger logger = LogFactory.GetLogger(typeof(Persistence)); + public static TimeSpan Delay { get; private set; } public static TimeSpan Warning { get; private set; } public static string BackupPath { get; private set; } @@ -103,7 +106,7 @@ namespace Server.Misc AssemblyHandler.EnsureDirectory(BackupPath); Directory.Move(args.OldSavePath, backupPath); - Persistence.WriteConsoleLine($"Created backup at {backupPath}"); + logger.Information($"Created backup at {backupPath}"); } } } diff --git a/Projects/UOContent/Misc/ClientVerification.cs b/Projects/UOContent/Misc/ClientVerification.cs index ac0e830a2..981031e31 100644 --- a/Projects/UOContent/Misc/ClientVerification.cs +++ b/Projects/UOContent/Misc/ClientVerification.cs @@ -171,7 +171,7 @@ namespace Server.Misc { if (ns.Connection != null) { - ns.WriteConsole("Disconnecting, bad version"); + ns.LogInfo("Disconnecting, bad version"); ns.Disconnect($"Invalid client version {ns.Version}."); } } diff --git a/Projects/UOContent/Network/ConnectUO.cs b/Projects/UOContent/Network/ConnectUO.cs index a2bb977d9..82b9db03a 100644 --- a/Projects/UOContent/Network/ConnectUO.cs +++ b/Projects/UOContent/Network/ConnectUO.cs @@ -89,11 +89,11 @@ namespace Server.Network } } - ns.WriteConsole($"ConnectUO (v{version}) is requesting stats."); + ns.LogInfo($"ConnectUO (v{version}) is requesting stats."); if (version > ConnectUOProtocolVersion) { Utility.PushColor(ConsoleColor.Yellow); - ns.WriteConsole("Warning! ConnectUO (v{version}) is newer than what is supported."); + ns.LogInfo("Warning! ConnectUO (v{version}) is newer than what is supported."); Utility.PopColor(); } diff --git a/Projects/UOContent/Network/ProtocolExtensions.cs b/Projects/UOContent/Network/ProtocolExtensions.cs index abdc6681b..c012bdb11 100644 --- a/Projects/UOContent/Network/ProtocolExtensions.cs +++ b/Projects/UOContent/Network/ProtocolExtensions.cs @@ -34,7 +34,7 @@ namespace Server.Network if (ph.Ingame && state.Mobile == null) { - state.WriteConsole("Sent in-game packet (0x{0:X2}x{1:X2}) before having been attached to a mobile", packetId, cmd); + state.LogInfo("Sent in-game packet (0x{0:X2}x{1:X2}) before having been attached to a mobile", packetId, cmd); state.Disconnect("Sent in-game packet before being attached to a mobile."); } else if (ph.Ingame && state.Mobile.Deleted)