Added FastLogging support.

ModTek/Features/Logging/AppenderSettings.cs

@@ -63,4 +63,9 @@ internal class AppenderSettings
     internal const string StartupTimeFormat_Description = "Runs through `TimeSpan.ToString`.";
     [JsonProperty]
     internal string StartupTimeFormat = "hh':'mm':'ss'.'fffffff";
+
+    [JsonProperty]
+    internal const string FastLoggingEnabled_Description = "If enabled, hardcodes formats and disables many settings to achieve high performance.";
+    [JsonProperty]
+    internal bool FastLoggingEnabled = false;
 }

ModTek/Features/Logging/Formatter.cs

@@ -1,6 +1,5 @@
 using System;
 using System.Globalization;
-using System.Linq;
 using System.Text;
 using System.Text.RegularExpressions;
 using HBS.Logging;
@@ -23,21 +22,39 @@ internal Formatter(AppenderSettings settings)
 
     internal string GetFormattedLogLine(MTLoggerMessageDto messageDto)
     {
+        // only improving TRACE level already brings all the benefits
+        // but we would have 2 different formats in the same log file
+        //!LogLevelExtension.IsLogLevelGreaterThan(LogLevel.Log, messageDto.LogLevel);
+        var fastLogging = _settings.FastLoggingEnabled;
+
         var sb = new StringBuilder();
 
-        if (_settings.AbsoluteTimeEnabled)
+        if (fastLogging)
         {
-            var dtoUtc = messageDto.GetDateTimeOffsetUtc();
-            var dto = _settings.AbsoluteTimeUseUtc ? dtoUtc : dtoUtc.ToLocalTime();
-            sb.Append(dto.ToString(_settings.AbsoluteFormat, CultureInfo.InvariantCulture));
-            sb.Append(" ");
+            if (_settings.AbsoluteTimeEnabled || _settings.StartupTimeEnabled)
+            {
+                var ts = messageDto.StartupTime();
+                var secondsWithFraction = ts.Ticks * 1E-07m;
+                sb.Append(secondsWithFraction);
+                sb.Append(" ");
+            }
         }
-
-        if (_settings.StartupTimeEnabled)
+        else
         {
-            var ts = messageDto.StartupTime();
-            sb.Append(ts.ToString(_settings.StartupTimeFormat));
-            sb.Append(" ");
+            if (_settings.AbsoluteTimeEnabled)
+            {
+                var dt = messageDto.GetDateTime();
+                var dts = _settings.AbsoluteTimeUseUtc ? dt : dt.ToLocalTime();
+                sb.Append(dts.ToString(_settings.AbsoluteFormat, CultureInfo.InvariantCulture));
+                sb.Append(" ");
+            }
+
+            if (_settings.StartupTimeEnabled)
+            {
+                var ts = messageDto.StartupTime();
+                sb.Append(ts.ToString(_settings.StartupTimeFormat));
+                sb.Append(" ");
+            }
         }
 
         if (messageDto.ThreadId != s_unityMainThreadId)
@@ -58,13 +75,13 @@ internal string GetFormattedLogLine(MTLoggerMessageDto messageDto)
         if (!string.IsNullOrEmpty(messageDto.Message))
         {
             sb.Append(prefix);
-            if (_sanitizerRegex == null)
+            if (!fastLogging && _sanitizerRegex != null)
             {
-                sb.Append(messageDto.Message);
+                sb.Append(_sanitizerRegex.Replace(messageDto.Message, string.Empty));
             }
             else
             {
-                sb.Append(_sanitizerRegex.Replace(messageDto.Message, string.Empty));
+                sb.Append(messageDto.Message);
             }
             prefix = Environment.NewLine;
         }
@@ -84,15 +101,18 @@ internal string GetFormattedLogLine(MTLoggerMessageDto messageDto)
             sb.Append(GetLocationString(messageDto.Location));
         }
 
-        if (_settings.NormalizeNewLines)
+        if (!fastLogging)
         {
-            sb.Replace("\r", "");
-            sb.Replace("\n", Environment.NewLine);
-        }
+            if (_settings.NormalizeNewLines)
+            {
+                sb.Replace("\r", "");
+                sb.Replace("\n", Environment.NewLine);
+            }
 
-        if (_settings.IndentNewLines)
-        {
-            sb.Replace("\n", "\n\t");
+            if (_settings.IndentNewLines)
+            {
+                sb.Replace("\n", "\n\t");
+            }
         }
 
         sb.Append(Environment.NewLine);

ModTek/Features/Logging/LogLevelExtension.cs

@@ -21,7 +21,7 @@ internal static string LogToString(LogLevel level)
         };
     }
 
-    internal static bool IsLogLevelEnabled(LogLevel loggerLevel, LogLevel messageLevel)
+    internal static bool IsLogLevelGreaterThan(LogLevel loggerLevel, LogLevel messageLevel)
     {
         return Convert(messageLevel) >= Convert(loggerLevel);
     }

ModTek/Features/Logging/MTLoggerAsyncQueue.cs

@@ -1,4 +1,5 @@
 using System;
+using System.Text;
 using System.Threading;
 using UnityEngine;
 using ThreadPriority = System.Threading.ThreadPriority;
@@ -30,29 +31,37 @@ internal MTLoggerAsyncQueue(Action<MTLoggerMessageDto> processor)
     {
         Callback = stats =>
         {
-            var dispatchStats = LoggingFeature.DispatchStopWatch.GetStats(); // fetch the overhead introduced by async logging
-            var offloadedTime = stats.TotalTime.Subtract(dispatchStats.TotalTime);
-            Log.Main.Debug?.Log($"Asynchronous logging offloaded {offloadedTime} from the main thread.");
-
-            var trace = Log.Main.Trace;
-            if (trace is not null)
+            var debug = Log.Main.Debug;
+            if (debug is not null)
             {
-                var dtoStats = LoggingFeature.MessageDtoStopWatch.GetStats();
-                trace.Log($"DTO setup took a total of {dtoStats.TotalTime} with an average of {dtoStats.AverageNanoseconds}ns.");
+                var dispatchStats = LoggingFeature.DispatchStopWatch.GetStats(); // fetch the overhead introduced by async logging
+                var offloadedTime = stats.TotalTime.Subtract(dispatchStats.TotalTime);
+                debug.Log($"Asynchronous logging offloaded {offloadedTime} from the main thread.");
+
+                var trace = Log.Main.Trace;
+                if (trace is not null)
+                {
+                    var sb = new StringBuilder();
+
+                    var dtoStats = LoggingFeature.MessageDtoStopWatch.GetStats();
+                    sb.Append($"\nDTO setup took a total of {dtoStats.TotalTime} with an average of {dtoStats.AverageNanoseconds}ns.");
+
+                    sb.Append($"\nDispatched {dispatchStats.Count} times, taking a total of {dispatchStats.TotalTime} with an average of {dispatchStats.AverageNanoseconds}ns.");
 
-                trace.Log($"Dispatched {dispatchStats.Count} times, taking a total of {dispatchStats.TotalTime} with an average of {dispatchStats.AverageNanoseconds}ns.");
+                    var filterStats = AppenderFile.FiltersStopWatch.GetStats();
+                    sb.Append($"\nFilters took a total of {filterStats.TotalTime} with an average of {filterStats.AverageNanoseconds}ns.");
 
-                var filterStats = AppenderFile.FiltersStopWatch.GetStats();
-                trace.Log($"Filters took a total of {filterStats.TotalTime} with an average of {filterStats.AverageNanoseconds}ns.");
+                    var formatterStats = AppenderFile.FormatterStopWatch.GetStats();
+                    sb.Append($"\nFormatter took a total of {formatterStats.TotalTime} with an average of {formatterStats.AverageNanoseconds}ns.");
 
-                var formatterStats = AppenderFile.FormatterStopWatch.GetStats();
-                trace.Log($"Formatter took a total of {formatterStats.TotalTime} with an average of {formatterStats.AverageNanoseconds}ns.");
+                    var bytesStats = AppenderFile.GetBytesStopwatch.GetStats();
+                    sb.Append($"\nGetBytes took a total of {bytesStats.TotalTime} with an average of {bytesStats.AverageNanoseconds}ns.");
 
-                var bytesStats = AppenderFile.GetBytesStopwatch.GetStats();
-                trace.Log($"GetBytes took a total of {bytesStats.TotalTime} with an average of {bytesStats.AverageNanoseconds}ns.");
+                    var writeStats = AppenderFile.WriteStopwatch.GetStats();
+                    sb.Append($"\nWrite called {writeStats.Count} times, taking a total of {writeStats.TotalTime} with an average of {writeStats.AverageNanoseconds}ns.");
 
-                var writeStats = AppenderFile.WriteStopwatch.GetStats();
-                trace.Log($"Write called {writeStats.Count} times, taking a total of {writeStats.TotalTime} with an average of {writeStats.AverageNanoseconds}ns.");
+                    trace.Log(sb.ToString());
+                }
             }
         },
         CallbackForEveryNumberOfMeasurements = 50_000

ModTek/Features/Logging/MTLoggerMessageDto.cs

@@ -9,13 +9,13 @@ internal struct MTLoggerMessageDto
 {
     internal static readonly TimeSpan InitialUnityStartupTime;
     internal static readonly long InitialStopwatchTimestamp;
-    internal static readonly DateTimeOffset InitialDatTimeOffsetUtc;
+    internal static readonly DateTime InitialDateTime;
 
     static MTLoggerMessageDto()
     {
         InitialUnityStartupTime = TimeSpan.FromSeconds(Time.realtimeSinceStartup);
         InitialStopwatchTimestamp = Stopwatch.GetTimestamp();
-        InitialDatTimeOffsetUtc = DateTimeOffset.UtcNow;
+        InitialDateTime = DateTime.UtcNow;
     }
 
     internal volatile bool CommittedToQueue;
@@ -54,9 +54,9 @@ internal TimeSpan StartupTime()
         return InitialUnityStartupTime.Add(GetElapsedSinceInitial());
     }
 
-    internal DateTimeOffset GetDateTimeOffsetUtc()
+    internal DateTime GetDateTime()
     {
-        return InitialDatTimeOffsetUtc.Add(GetElapsedSinceInitial());
+        return InitialDateTime.Add(GetElapsedSinceInitial());
     }
 
     private TimeSpan GetElapsedSinceInitial()

ModTek/Features/Logging/Patches/LogImpl_IsEnabledFor_Patch.cs

@@ -13,7 +13,7 @@ public static bool Prepare()
     [HarmonyPriority(Priority.High)]
     public static bool Prefix(Logger.LogImpl __instance, LogLevel level, ref bool __result)
     {
-        __result = LogLevelExtension.IsLogLevelEnabled(__instance.EffectiveLevel, level);
+        __result = LogLevelExtension.IsLogLevelGreaterThan(__instance.EffectiveLevel, level);
         return false;
     }
 }