fix: Removes profiling. Streamlines core tick count. (#1948)

### Summary - Removes `Profiling` - Recommend using Visual Studio Performance Profiler, [dotnet-trace](https://learn.microsoft.com/en-us/dotnet/core/diagnostics/dotnet-trace) or [JetBrains dotTrace](https://www.jetbrains.com/profiler/) - Cleans up the core tick count, sampling, etc.
2024-09-11 00:55:18 -07:00 · 2024-09-11 00:55:18 -07:00 · 2e6ddcd31a
commit 2e6ddcd31a
parent 65bc264402
14 changed files with 80 additions and 949 deletions
--- a/Projects/Server/Diagnostics/BaseProfile.cs
+++ b/Projects/Server/Diagnostics/BaseProfile.cs
@ -1,79 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Diagnostics;
-using System.IO;
-
-namespace Server.Diagnostics;
-
-public abstract class BaseProfile
-{
-    private readonly Stopwatch _stopwatch;
-
-    protected BaseProfile(string name)
-    {
-        Name = name;
-
-        _stopwatch = new Stopwatch();
-    }
-
-    public string Name { get; }
-
-    public long Count { get; private set; }
-
-    public TimeSpan AverageTime => TimeSpan.FromTicks(TotalTime.Ticks / Math.Max(Count, 1));
-
-    public TimeSpan PeakTime { get; private set; }
-
-    public TimeSpan TotalTime { get; private set; }
-
-    public static void WriteAll<T>(TextWriter op, IEnumerable<T> profiles) where T : BaseProfile
-    {
-        var list = new List<T>(profiles);
-
-        list.Sort((a, b) => -a.TotalTime.CompareTo(b.TotalTime));
-
-        foreach (var prof in list)
-        {
-            prof.WriteTo(op);
-            op.WriteLine();
-        }
-    }
-
-    public virtual void Start()
-    {
-        if (_stopwatch.IsRunning)
-        {
-            _stopwatch.Reset();
-        }
-
-        _stopwatch.Start();
-    }
-
-    public virtual void Finish()
-    {
-        var elapsed = _stopwatch.Elapsed;
-
-        TotalTime += elapsed;
-
-        if (elapsed > PeakTime)
-        {
-            PeakTime = elapsed;
-        }
-
-        Count++;
-
-        _stopwatch.Reset();
-    }
-
-    public virtual void WriteTo(TextWriter op)
-    {
-        op.Write(
-            "{0,-100} {1,12:N0} {2,12:F5} {3,-12:F5} {4,12:F5}",
-            Name,
-            Count,
-            AverageTime.TotalSeconds,
-            PeakTime.TotalSeconds,
-            TotalTime.TotalSeconds
-        );
-    }
-}
--- a/Projects/Server/Diagnostics/PacketProfile.cs
+++ b/Projects/Server/Diagnostics/PacketProfile.cs
@ -1,88 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.IO;
-using System.Threading;
-
-namespace Server.Diagnostics;
-
-public abstract class BasePacketProfile : BaseProfile
-{
-    protected BasePacketProfile(string name) : base(name)
-    {
-    }
-
-    public long TotalLength { get; private set; }
-
-    public double AverageLength => (double)TotalLength / Math.Max(Count, 1);
-
-    public void Finish(long length)
-    {
-        Finish();
-
-        TotalLength += length;
-    }
-
-    public override void WriteTo(TextWriter op)
-    {
-        base.WriteTo(op);
-
-        op.Write("\t{0,12:F2} {1,-12:N0}", AverageLength, TotalLength);
-    }
-}
-
-public class PacketSendProfile : BasePacketProfile
-{
-    private static readonly Dictionary<int, PacketSendProfile> _profiles = new();
-
-    private long _created;
-
-    public PacketSendProfile(int packetId) : base($"0x{packetId:X2}")
-    {
-    }
-
-    public static IEnumerable<PacketSendProfile> Profiles => _profiles.Values;
-
-    public static PacketSendProfile Acquire(int packetId)
-    {
-        if (!_profiles.TryGetValue(packetId, out var prof))
-        {
-            _profiles.Add(packetId, prof = new PacketSendProfile(packetId));
-        }
-
-        return prof;
-    }
-
-    public void Increment()
-    {
-        Interlocked.Increment(ref _created);
-    }
-
-    public override void WriteTo(TextWriter op)
-    {
-        base.WriteTo(op);
-
-        op.Write("\t{0,12:N0}", _created);
-    }
-}
-
-public class PacketReceiveProfile : BasePacketProfile
-{
-    private static readonly Dictionary<int, PacketReceiveProfile>
-        _profiles = new();
-
-    public PacketReceiveProfile(int packetId) : base($"0x{packetId:X2}")
-    {
-    }
-
-    public static IEnumerable<PacketReceiveProfile> Profiles => _profiles.Values;
-
-    public static PacketReceiveProfile Acquire(int packetId)
-    {
-        if (!_profiles.TryGetValue(packetId, out var prof))
-        {
-            _profiles.Add(packetId, prof = new PacketReceiveProfile(packetId));
-        }
-
-        return prof;
-    }
-}
--- a/Projects/Server/Diagnostics/TargetProfile.cs
+++ b/Projects/Server/Diagnostics/TargetProfile.cs
@ -1,31 +0,0 @@
-using System;
-using System.Collections.Generic;
-
-namespace Server.Diagnostics;
-
-public class TargetProfile : BaseProfile
-{
-    private static readonly Dictionary<Type, TargetProfile> _profiles = new();
-
-    public TargetProfile(Type type)
-        : base(type.FullName)
-    {
-    }
-
-    public static IEnumerable<TargetProfile> Profiles => _profiles.Values;
-
-    public static TargetProfile Acquire(Type type)
-    {
-        if (!Core.Profiling)
-        {
-            return null;
-        }
-
-        if (!_profiles.TryGetValue(type, out var prof))
-        {
-            _profiles.Add(type, prof = new TargetProfile(type));
-        }
-
-        return prof;
-    }
-}
--- a/Projects/Server/Diagnostics/TimerProfile.cs
+++ b/Projects/Server/Diagnostics/TimerProfile.cs
@ -1,44 +0,0 @@
-using System.Collections.Generic;
-using System.IO;
-
-namespace Server.Diagnostics;
-
-public class TimerProfile : BaseProfile
-{
-    private static readonly Dictionary<string, TimerProfile> _profiles = new();
-
-    public TimerProfile(string name)
-        : base(name)
-    {
-    }
-
-    public static IEnumerable<TimerProfile> Profiles => _profiles.Values;
-
-    public long Created { get; set; }
-
-    public long Started { get; set; }
-
-    public long Stopped { get; set; }
-
-    public static TimerProfile Acquire(string name)
-    {
-        if (!Core.Profiling)
-        {
-            return null;
-        }
-
-        if (!_profiles.TryGetValue(name, out var prof))
-        {
-            _profiles.Add(name, prof = new TimerProfile(name));
-        }
-
-        return prof;
-    }
-
-    public override void WriteTo(TextWriter op)
-    {
-        base.WriteTo(op);
-
-        op.Write("\t{0,12:N0} {1,12:N0} {2,-12:N0}", Created, Started, Stopped);
-    }
-}
--- a/Projects/Server/Main.cs
+++ b/Projects/Server/Main.cs
@ -44,9 +44,6 @@ public static class Core
    private static bool _crashed;
    private static string _baseDirectory;

-    private static bool _profiling;
-    private static long _profileStart;
-    private static long _profileTime;
    private static bool? _isRunningFromXUnit;

    private static int _itemCount;
@ -90,30 +87,6 @@ public static class Core
    }
 #nullable restore

-    public static bool Profiling
-    {
-        get => _profiling;
-        set
-        {
-            if (_profiling == value)
-            {
-                return;
-            }
-
-            _profiling = value;
-
-            if (_profileStart > 0)
-            {
-                _profileTime += Stopwatch.GetTimestamp() - _profileStart;
-            }
-
-            _profileStart = _profiling ? Stopwatch.GetTimestamp() : 0;
-        }
-    }
-
-    public static TimeSpan ProfileTime =>
-        TimeSpan.FromTicks(_profileStart > 0 ? _profileTime + (Stopwatch.GetTimestamp() - _profileStart) : _profileTime);
-
    public static Assembly ApplicationAssembly { get; set; }
    public static Assembly Assembly { get; set; }

@ -126,50 +99,15 @@ public static class Core

    private static long _firstTick;

-    [ThreadStatic]
    private static long _tickCount;

-    // Don't access this from other threads than the game thread.
    private static DateTime _now;

-    // For Unix Stopwatch.Frequency is normalized to 1ns
-    // We don't anticipate needing this for Windows/OSX
-    private const long _maxTickCountBeforePrecisionLoss = long.MaxValue / 1000L;
-    private static readonly long _ticksPerMillisecond = Stopwatch.Frequency / 1000L;
+    public static long TickCount => _tickCount;

-    public static long TickCount
-    {
-        get
-        {
-            if (_tickCount != 0)
-            {
-                return _tickCount;
-            }
+    public static DateTime Now => _now;

-            var timestamp = Stopwatch.GetTimestamp();
-
-            return timestamp > _maxTickCountBeforePrecisionLoss
-                ? timestamp / _ticksPerMillisecond
-                // No precision loss
-                : 1000L * timestamp / Stopwatch.Frequency;
-        }
-        // Setting this to a value lower than the previous is bad. Timers will become delayed
-        // until time catches up.
-        set => _tickCount = value;
-    }
-
-    public static DateTime Now
-    {
-        [MethodImpl(MethodImplOptions.AggressiveInlining)]
-        get
-        {
-            // See notes above for _now and why this is a volatile variable.
-            var now = _now;
-            return now == DateTime.MinValue ? DateTime.UtcNow : now;
-        }
-    }
-
-    public static long Uptime => Thread.CurrentThread != Thread ? 0 : TickCount - _firstTick;
+    public static long Uptime => TickCount - _firstTick;

    private static long _cycleIndex;
    private static readonly double[] _cyclesPerSecond = new double[128];
@ -207,21 +145,6 @@ public static class Core

    public static bool Closing => ClosingTokenSource.IsCancellationRequested;

-    public static string Arguments
-    {
-        get
-        {
-            var sb = new StringBuilder();
-
-            if (_profiling)
-            {
-                Utility.Separate(sb, "-profile", " ");
-            }
-
-            return sb.ToString();
-        }
-    }
-
    public static int GlobalUpdateRange { get; set; } = 18;

    public static int GlobalMaxUpdateRange { get; set; } = 24;
@ -380,7 +303,7 @@ public static class Core
                logger.Information("Restarting");
                if (IsWindows)
                {
-                    using var process = Process.Start("dotnet", $"{ApplicationAssembly.Location} {Arguments}");
+                    using var process = Process.Start("dotnet", $"{ApplicationAssembly.Location}");
                }
                else
                {
@ -388,7 +311,7 @@ public static class Core
                    process.StartInfo = new ProcessStartInfo
                    {
                        FileName = "dotnet",
-                        Arguments = $"{ApplicationAssembly.Location} {Arguments}",
+                        Arguments = $"{ApplicationAssembly.Location}",
                        UseShellExecute = true
                    };

@ -420,7 +343,10 @@ public static class Core
        }
    }

-    public static void Setup(bool profiling, Assembly applicationAssembly, Process process)
+    [MethodImpl(MethodImplOptions.AggressiveInlining)]
+    public static long GetTimestamp() => 1000L * Stopwatch.GetTimestamp() / Stopwatch.Frequency;
+
+    public static void Setup(Assembly applicationAssembly, Process process)
    {
        Process = process;
        ApplicationAssembly = applicationAssembly;
@ -428,7 +354,6 @@ public static class Core
        Thread = Thread.CurrentThread;
        LoopContext = new EventLoopContext();
        SynchronizationContext.SetSynchronizationContext(LoopContext);
-        Profiling = profiling;

        AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException;
        AppDomain.CurrentDomain.ProcessExit += CurrentDomain_ProcessExit;
@ -472,13 +397,6 @@ public static class Core

        logger.Information("Running on {Framework}", RuntimeInformation.FrameworkDescription);

-        var s = Arguments;
-
-        if (s.Length > 0)
-        {
-            logger.Information("Running with arguments: {Args}", s);
-        }
-
        var assemblyPath = Path.Join(BaseDirectory, AssembliesConfiguration);

        // Load UOContent.dll
@ -497,7 +415,10 @@ public static class Core

        VerifySerialization();

-        Timer.Init(TickCount);
+        _now = DateTime.UtcNow;
+        _firstTick = _tickCount = GetTimestamp();
+
+        Timer.Init(_tickCount);

        AssemblyHandler.Invoke("Configure");

@ -511,7 +432,6 @@ public static class Core
        TcpServer.Start();
        PingServer.Start();
        EventSink.InvokeServerStarted();
-        _firstTick = TickCount;
        RunEventLoop();
    }

@ -526,7 +446,7 @@ public static class Core
 #endif

            var cycleCount = _cyclesPerSecond.Length;
-            long last = Stopwatch.GetTimestamp();
+            long last = _tickCount;
            const int interval = 100;
            double frequency = Stopwatch.Frequency * interval;

@ -534,7 +454,7 @@ public static class Core

            while (!Closing)
            {
-                _tickCount = TickCount;
+                _tickCount = GetTimestamp();
                _now = DateTime.UtcNow;

                Mobile.ProcessDeltaQueue();
@ -566,9 +486,10 @@ public static class Core
                _tickCount = 0;
                _now = DateTime.MinValue;

-                if (++sample % interval == 0)
+                if (sample++ == interval)
                {
-                    var now = Stopwatch.GetTimestamp();
+                    sample = 0;
+                    var now = GetTimestamp();

                    var cyclesPerSecond = frequency / (now - last);
                    _cyclesPerSecond[_cycleIndex++] = cyclesPerSecond;
--- a/Projects/Server/Network/NetState/NetState.cs
+++ b/Projects/Server/Network/NetState/NetState.cs
@ -15,7 +15,6 @@

 using Server.Accounting;
 using Server.Collections;
-using Server.Diagnostics;
 using Server.HuePickers;
 using Server.Items;
 using Server.Logging;
@ -455,14 +454,6 @@ public partial class NetState : IComparable<NetState>, IValueLinkListNode<NetSta

        try
        {
-            PacketSendProfile prof = null;
-
-            if (Core.Profiling)
-            {
-                prof = PacketSendProfile.Acquire(span[0]);
-                prof.Start();
-            }
-
            if (_packetEncoder != null)
            {
                length = _packetEncoder(span, buffer);
@ -484,8 +475,6 @@ public partial class NetState : IComparable<NetState>, IValueLinkListNode<NetSta
                _flushPending.Enqueue(this);
                _flushQueued = true;
            }
-
-            prof?.Finish();
        }
        catch (Exception ex)
        {
@ -804,14 +793,6 @@ public partial class NetState : IComparable<NetState>, IValueLinkListNode<NetSta
            SetPacketTime(packetId);
        }

-        PacketReceiveProfile prof = null;
-
-        if (Core.Profiling)
-        {
-            prof = PacketReceiveProfile.Acquire(packetId);
-            prof?.Start();
-        }
-
        UpdatePacketCount(packetId);

        if (PacketLogging)
@ -826,8 +807,6 @@ public partial class NetState : IComparable<NetState>, IValueLinkListNode<NetSta

        handler.OnReceive(this, new SpanReader(packetReader.Buffer.Slice(start, remainingLength)));

-        prof?.Finish(packetLength);
-
        return ParserState.AwaitingNextPacket;
    }

--- a/Projects/Server/Timer/Timer.TimerWheel.cs
+++ b/Projects/Server/Timer/Timer.TimerWheel.cs
@ -136,9 +136,6 @@ public partial class Timer
    {
        var finished = timer.Count != 0 && timer.Index + 1 >= timer.Count;

-        var prof = timer.GetProfile();
-        prof?.Start();
-
        // Stop the timer from running so that way if Start() is called in OnTick, the timer will be started.
        if (finished)
        {
@ -149,7 +146,6 @@ public partial class Timer
        var version = timer.Version;

        timer.OnTick();
-        prof?.Finish();

        // Starting doesn't change the timer version, so we need to check if it's finished and if it's still running.
        if (timer.Version != version || finished && timer.Running)
--- a/Projects/Server/Timer/Timer.cs
+++ b/Projects/Server/Timer/Timer.cs
@ -15,7 +15,6 @@

 using System;
 using System.Diagnostics;
-using Server.Diagnostics;
 using Server.Logging;

 namespace Server;
@ -54,13 +53,6 @@ public partial class Timer
        Next = Core.Now + Delay;
        _ring = -1;
        _slot = -1;
-
-        var prof = GetProfile();
-
-        if (prof != null)
-        {
-            prof.Created++;
-        }
    }

    protected int Version { get; set; } // Used to determine if a timer was altered and we should abandon it.
@ -73,8 +65,6 @@ public partial class Timer
    public int RemainingCount => Count == 0 ? int.MaxValue : Count - Index;
    public bool Running { get; private set; }

-    public TimerProfile GetProfile() => !Core.Profiling ? null : TimerProfile.Acquire(ToString() ?? "null");
-
    public override string ToString() => GetType().FullName;

    public Timer Start()
@ -111,13 +101,6 @@ public partial class Timer
        Running = true;
        AddTimer(this, (long)Delay.TotalMilliseconds);

-        var prof = GetProfile();
-
-        if (prof != null)
-        {
-            prof.Started++;
-        }
-
        return this;
    }

@ -174,12 +157,6 @@ public partial class Timer
        {
            _executingRings[_ring] = _nextTimer;
        }
-
-        var prof = GetProfile();
-        if (prof != null)
-        {
-            prof.Stopped++;
-        }
    }

    protected virtual void OnTick()