Improved MTStopwatch APIs.

ModTek/Features/Logging/AppenderFile.cs

@@ -1,6 +1,7 @@
 using System;
 using System.Globalization;
 using ModTek.Common.Utils;
+using ModTek.Util.Stopwatch;
 using UnityEngine;
 
 namespace ModTek.Features.Logging;
@@ -41,13 +42,10 @@ private void Write(string text)
         _writer.Append(bytes, 0, bytes.Length);
     }
 
-    internal static readonly MTStopwatch FlushStopWatch = new()
-    {
-        SkipFirstNumberOfMeasurements = 0
-    };
+    internal static readonly MTStopwatch FlushStopWatch = new();
     internal static readonly MTStopwatch FiltersStopWatch = new();
     internal static readonly MTStopwatch FormatterStopWatch = new();
-    internal static readonly MTStopwatch WriteStopwatch = new() { SkipFirstNumberOfMeasurements = 0 };
+    internal static readonly MTStopwatch WriteStopwatch = new();
     internal void Append(ref MTLoggerMessageDto messageDto)
     {
         if (messageDto.FlushToDisk)
@@ -57,16 +55,16 @@ internal void Append(ref MTLoggerMessageDto messageDto)
                 FlushToOS();
             }
 
-            var measurement = FlushStopWatch.StartMeasurement();
+            var measurement = MTStopwatch.GetTimestamp();
             _writer.FlushToDisk();
-            measurement.Stop();
+            FlushStopWatch.EndMeasurement(measurement);
             return;
         }
 
         {
-            var measurement = FiltersStopWatch.StartMeasurement();
+            var measurement = MTStopwatch.GetTimestamp();
             var included = _filters.IsIncluded(ref messageDto);
-            measurement.Stop();
+            FiltersStopWatch.EndMeasurement(measurement);
             if (!included)
             {
                 if (!messageDto.HasMore && _buffer._length > 0)
@@ -78,9 +76,9 @@ internal void Append(ref MTLoggerMessageDto messageDto)
         }
 
         {
-            var measurement = FormatterStopWatch.StartMeasurement();
+            var measurement = MTStopwatch.GetTimestamp();
             _formatter.SerializeMessage(ref messageDto, _buffer);
-            measurement.Stop();
+            FormatterStopWatch.EndMeasurement(measurement);
 
             if (!messageDto.HasMore || _buffer._length >= _bufferFlushThreshold)
             {
@@ -91,11 +89,11 @@ internal void Append(ref MTLoggerMessageDto messageDto)
 
     private void FlushToOS()
     {
-        var measurement = WriteStopwatch.StartMeasurement();
+        var measurement = MTStopwatch.GetTimestamp();
         var length = _buffer.GetBytes(out var threadUnsafeBytes);
         _writer.Append(threadUnsafeBytes, 0, length);
         _buffer.Reset();
-        measurement.Stop();
+        WriteStopwatch.EndMeasurement(measurement);
     }
 
     public void Dispose()

ModTek/Features/Logging/FastBuffer.cs

@@ -2,6 +2,7 @@
 using System.Runtime.CompilerServices;
 using System.Runtime.InteropServices;
 using System.Text;
+using ModTek.Util.Stopwatch;
 
 namespace ModTek.Features.Logging;
 
@@ -154,15 +155,15 @@ internal void Append(string value)
             return;
 
             Utf8Fallback: // this is 10x slower or more (GetBytes has no fast ASCII path and no SIMD in this old .NET)
-            var measurement = UTF8FallbackStopwatch.StartMeasurement();
+            var measurement = MTStopwatch.GetTimestamp();
             var charIndex = value.Length - processingCount;
             const int Utf8MaxBytesPerChar = 4;
             EnsureCapacity(_length + processingCount * Utf8MaxBytesPerChar);
             _length += Encoding.UTF8.GetBytes(value, charIndex, processingCount, _buffer, _length);
-            measurement.Stop();
+            UTF8FallbackStopwatch.EndMeasurement(measurement);
         }
     }
-    internal static readonly MTStopwatch UTF8FallbackStopwatch = new() { SkipFirstNumberOfMeasurements = 0 };
+    internal static readonly MTStopwatch UTF8FallbackStopwatch = new();
 
     [MethodImpl(MethodImplOptions.AggressiveInlining)]
     private void SetAscii(byte* positionIterPtr, char* charsIterPtr, int offset, out bool isUnicodeCompatibleAscii)

ModTek/Features/Logging/LoggingFeature.cs

@@ -1,11 +1,11 @@
 using System;
 using System.Collections.Generic;
-using System.Diagnostics;
 using System.IO;
 using System.Runtime.CompilerServices;
 using System.Threading;
 using HBS.Logging;
 using ModTek.Misc;
+using ModTek.Util.Stopwatch;
 
 namespace ModTek.Features.Logging;
 
@@ -101,12 +101,12 @@ internal static void AddModLogAppender(string logPath, string loggerName)
         _logsAppenders = logsAppenders;
     }
 
-    internal static readonly MTStopwatch DispatchStopWatch = new() { SkipFirstNumberOfMeasurements = 100, Sampling = 100 };
+    internal static readonly MTStopwatchWithSampling DispatchStopWatch = new(100);
     // used for intercepting all logging attempts and to log centrally
     internal static void LogAtLevel(string loggerName, LogLevel logLevel, object message, Exception exception, IStackTrace location)
     {
         // capture timestamp as early as possible, to be as close to the callers intended time
-        var timestamp = Stopwatch.GetTimestamp();
+        var timestamp = MTStopwatch.GetTimestamp();
 
         // convert message to string while still in caller thread
         var messageAsString = message?.ToString(); // do this asap too, as this can throw exceptions
@@ -144,7 +144,7 @@ internal static void LogAtLevel(string loggerName, LogLevel logLevel, object mes
         updateDto.ThreadId = threadId;
         updateDto.Commit();
 
-        DispatchStopWatch.EndMeasurementSampled(timestamp);
+        DispatchStopWatch.EndMeasurement(timestamp);
     }
 
     internal static void Flush()
@@ -158,10 +158,9 @@ internal static void Flush()
             LogMessageThreadSafe(ref messageDto);
             return;
         }
-
-        var measurement = DispatchStopWatch.StartMeasurement();
+        var measurement = MTStopwatch.GetTimestamp();
         ref var updateDto = ref _queue.AcquireUncommitedOrWait();
-        measurement.Stop();
+        DispatchStopWatch.EndMeasurement(measurement);
 
         updateDto.FlushToDiskPostEvent = flushEvent;
         updateDto.Commit();

ModTek/Features/Logging/MTLoggerAsyncQueue.cs

@@ -1,5 +1,6 @@
 using System;
 using System.Threading;
+using ModTek.Util.Stopwatch;
 using UnityEngine;
 using ThreadPriority = System.Threading.ThreadPriority;
 
@@ -24,9 +25,7 @@ internal MTLoggerAsyncQueue()
         LogWriterThreadId = thread.ManagedThreadId;
     }
 
-    private static readonly MTStopwatch s_loggingStopwatch = new()
-    {
-        Callback = stats =>
+    private static readonly MTStopwatchWithCallback s_loggingStopwatch = new(stats =>
         {
             var logger = Log.Main.Trace;
             if (logger is null)
@@ -51,9 +50,8 @@ Async internal processing had an average latency of {latencyStats.AverageNanosec
                     Write (to OS buffers) {AppenderFile.WriteStopwatch.GetStats()}.
                 """
             );
-        },
-        CallbackForEveryNumberOfMeasurements = 50_000
-    };
+        }
+    );
 
     public bool IsShuttingOrShutDown => _queue._shuttingOrShutDown;
 
@@ -79,7 +77,7 @@ private void LoggingLoop()
             {
                 ref var message = ref _queue.AcquireCommittedOrWait();
 
-                var measurement = s_loggingStopwatch.StartMeasurement();
+                var measurement = MTStopwatch.GetTimestamp();
                 try
                 {
                     LoggingFeature.LogMessage(ref message);
@@ -91,7 +89,7 @@ private void LoggingLoop()
                 finally
                 {
                     message.Reset();
-                    measurement.Stop();
+                    s_loggingStopwatch.EndMeasurement(measurement);
                 }
             }
         }

ModTek/Features/Logging/MTLoggerMessageDto.cs

@@ -3,13 +3,14 @@
 using System.Runtime.CompilerServices;
 using System.Threading;
 using HBS.Logging;
+using ModTek.Util.Stopwatch;
 using UnityEngine;
 
 namespace ModTek.Features.Logging;
 
 internal struct MTLoggerMessageDto
 {
-    private static readonly long s_stopwatchTimestamp = Stopwatch.GetTimestamp();
+    private static readonly long s_stopwatchTimestamp = MTStopwatch.GetTimestamp();
     private static readonly DateTime s_dateTime = DateTime.UtcNow;
     private static readonly TimeSpan s_unityStartupTime = TimeSpan.FromSeconds(Time.realtimeSinceStartup);
 

ModTek/Features/Profiler/Patches/JSONSerializationUtility_RehydrateObjectFromDictionary_Patch.cs

@@ -2,7 +2,7 @@
 using System.Collections.Generic;
 using HBS;
 using HBS.Util;
-using ModTek.Features.Logging;
+using ModTek.Util.Stopwatch;
 
 namespace ModTek.Features.Profiler.Patches;
 
@@ -24,31 +24,28 @@ public static bool Prepare()
         return ModTek.Enabled && ModTek.Config.ProfilerEnabled;
     }
 
-    private static readonly MTStopwatch s_stopwatch  = new()
-    {
-        Callback = stats =>
+    private static readonly MTStopwatchWithCallback s_stopwatch  = new(stats =>
         {
             var id = "JSONSerializationUtility.RehydrateObjectFromDictionary";
             Log.Main.Trace?.Log($"{id} was called {stats.Count} times, taking a total of {stats.TotalTime} with an average of {stats.AverageNanoseconds}ns.");
-        },
-        CallbackForEveryNumberOfMeasurements = 1000
-    };
+        }
+    );
 
     [HarmonyPriority(Priority.First)]
-    public static void Prefix(string classStructure, ref MTStopwatch.Tracker __state)
+    public static void Prefix(string classStructure, ref long __state)
     {
         if (string.IsNullOrEmpty(classStructure))
         {
-            __state.Begin();
+            __state = MTStopwatch.GetTimestamp();
         }
     }
 
     [HarmonyPriority(Priority.Last)]
-    public static void Postfix(string classStructure, ref MTStopwatch.Tracker __state)
+    public static void Postfix(string classStructure, ref long __state)
     {
-        if (string.IsNullOrEmpty(classStructure))
+        if (__state > 0)
         {
-            s_stopwatch.AddMeasurement(__state.End());
+            s_stopwatch.EndMeasurement(__state);
         }
     }
 }