diff --git a/Dalamud/Game/Framework.cs b/Dalamud/Game/Framework.cs index 98f430d4a..9ba9b2f0e 100644 --- a/Dalamud/Game/Framework.cs +++ b/Dalamud/Game/Framework.cs @@ -9,7 +9,6 @@ using System.Threading.Tasks; using Dalamud.Configuration.Internal; using Dalamud.Game.Gui; using Dalamud.Game.Gui.Toast; -using Dalamud.Game.Network; using Dalamud.Hooking; using Dalamud.IoC; using Dalamud.IoC.Internal; @@ -29,6 +28,7 @@ public sealed class Framework : IDisposable, IServiceType private static Stopwatch statsStopwatch = new(); private readonly Stopwatch updateStopwatch = new(); + private readonly HitchDetector hitchDetector = new("FrameworkUpdate", 20); private readonly Hook updateHook; private readonly Hook destroyHook; @@ -368,18 +368,18 @@ public sealed class Framework : IDisposable, IServiceType ThreadSafety.MarkMainThread(); + this.hitchDetector.Start(); + try { var chatGui = Service.GetNullable(); var toastGui = Service.GetNullable(); - var gameNetwork = Service.GetNullable(); var config = Service.GetNullable(); - if (chatGui == null || toastGui == null || gameNetwork == null) + if (chatGui == null || toastGui == null) goto original; chatGui.UpdateQueue(); toastGui.UpdateQueue(); - gameNetwork.UpdateQueue(); config?.Update(); } @@ -397,7 +397,31 @@ public sealed class Framework : IDisposable, IServiceType this.LastUpdate = DateTime.Now; this.LastUpdateUTC = DateTime.UtcNow; - this.RunPendingTickTasks(); + void AddToStats(string key, double ms) + { + if (!StatsHistory.ContainsKey(key)) + StatsHistory.Add(key, new List()); + + StatsHistory[key].Add(ms); + + if (StatsHistory[key].Count > 1000) + { + StatsHistory[key].RemoveRange(0, StatsHistory[key].Count - 1000); + } + } + + if (StatsEnabled) + { + statsStopwatch.Restart(); + this.RunPendingTickTasks(); + statsStopwatch.Stop(); + + AddToStats(nameof(this.RunPendingTickTasks), statsStopwatch.Elapsed.TotalMilliseconds); + } + else + { + this.RunPendingTickTasks(); + } if (StatsEnabled && this.Update != null) { @@ -424,20 +448,15 @@ public sealed class Framework : IDisposable, IServiceType if (notUpdated.Contains(key)) notUpdated.Remove(key); - if (!StatsHistory.ContainsKey(key)) - StatsHistory.Add(key, new List()); - - StatsHistory[key].Add(statsStopwatch.Elapsed.TotalMilliseconds); - - if (StatsHistory[key].Count > 1000) - { - StatsHistory[key].RemoveRange(0, StatsHistory[key].Count - 1000); - } + AddToStats(key, statsStopwatch.Elapsed.TotalMilliseconds); } // Cleanup handlers that are no longer being called foreach (var key in notUpdated) { + if (key == nameof(this.RunPendingTickTasks)) + continue; + if (StatsHistory[key].Count > 0) { StatsHistory[key].RemoveAt(0); @@ -454,6 +473,8 @@ public sealed class Framework : IDisposable, IServiceType } } + this.hitchDetector.Stop(); + original: return this.updateHook.OriginalDisposeSafe(framework); } diff --git a/Dalamud/Game/Network/GameNetwork.cs b/Dalamud/Game/Network/GameNetwork.cs index 0fab9bf74..f2cd5ecbd 100644 --- a/Dalamud/Game/Network/GameNetwork.cs +++ b/Dalamud/Game/Network/GameNetwork.cs @@ -5,6 +5,7 @@ using System.Runtime.InteropServices; using Dalamud.Hooking; using Dalamud.IoC; using Dalamud.IoC.Internal; +using Dalamud.Utility; using Serilog; namespace Dalamud.Game.Network; @@ -20,7 +21,9 @@ public sealed class GameNetwork : IDisposable, IServiceType private readonly GameNetworkAddressResolver address; private readonly Hook processZonePacketDownHook; private readonly Hook processZonePacketUpHook; - private readonly Queue zoneInjectQueue = new(); + + private readonly HitchDetector hitchDetectorUp = new("GameNetworkUp"); + private readonly HitchDetector hitchDetectorDown = new("GameNetworkDown"); private IntPtr baseAddress; @@ -68,27 +71,6 @@ public sealed class GameNetwork : IDisposable, IServiceType this.processZonePacketUpHook.Dispose(); } - /// - /// Process a chat queue. - /// - internal void UpdateQueue() - { - while (this.zoneInjectQueue.Count > 0) - { - var packetData = this.zoneInjectQueue.Dequeue(); - - var unmanagedPacketData = Marshal.AllocHGlobal(packetData.Length); - Marshal.Copy(packetData, 0, unmanagedPacketData, packetData.Length); - - if (this.baseAddress != IntPtr.Zero) - { - this.processZonePacketDownHook.Original(this.baseAddress, 0, unmanagedPacketData); - } - - Marshal.FreeHGlobal(unmanagedPacketData); - } - } - [ServiceManager.CallWhenServicesReady] private void ContinueConstruction() { @@ -100,6 +82,8 @@ public sealed class GameNetwork : IDisposable, IServiceType { this.baseAddress = a; + this.hitchDetectorDown.Start(); + // Go back 0x10 to get back to the start of the packet header dataPtr -= 0x10; @@ -128,10 +112,14 @@ public sealed class GameNetwork : IDisposable, IServiceType this.processZonePacketDownHook.Original(a, targetId, dataPtr + 0x10); } + + this.hitchDetectorDown.Stop(); } private byte ProcessZonePacketUpDetour(IntPtr a1, IntPtr dataPtr, IntPtr a3, byte a4) { + this.hitchDetectorUp.Start(); + try { // Call events @@ -155,27 +143,8 @@ public sealed class GameNetwork : IDisposable, IServiceType Log.Error(ex, "Exception on ProcessZonePacketUp hook. Header: " + header); } + this.hitchDetectorUp.Stop(); + return this.processZonePacketUpHook.Original(a1, dataPtr, a3, a4); } - - // private void InjectZoneProtoPacket(byte[] data) - // { - // this.zoneInjectQueue.Enqueue(data); - // } - - // private void InjectActorControl(short cat, int param1) - // { - // var packetData = new byte[] - // { - // 0x14, 0x00, 0x8D, 0x00, 0x00, 0x00, 0x0E, 0x00, 0x17, 0x7C, 0xC5, 0x5D, 0x00, 0x00, 0x00, 0x00, - // 0x05, 0x00, 0x48, 0xB2, 0x0C, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, - // 0x00, 0x00, 0x00, 0x00, 0x43, 0x7F, 0x00, 0x00, - // }; - // - // BitConverter.GetBytes((short)cat).CopyTo(packetData, 0x10); - // - // BitConverter.GetBytes((uint)param1).CopyTo(packetData, 0x14); - // - // this.InjectZoneProtoPacket(packetData); - // } } diff --git a/Dalamud/Interface/UiBuilder.cs b/Dalamud/Interface/UiBuilder.cs index 2b0ed2b0d..8b1b7d5c6 100644 --- a/Dalamud/Interface/UiBuilder.cs +++ b/Dalamud/Interface/UiBuilder.cs @@ -26,6 +26,7 @@ namespace Dalamud.Interface; public sealed class UiBuilder : IDisposable { private readonly Stopwatch stopwatch; + private readonly HitchDetector hitchDetector; private readonly string namespaceName; private readonly InterfaceManager interfaceManager = Service.Get(); private readonly GameFontManager gameFontManager = Service.Get(); @@ -41,6 +42,7 @@ public sealed class UiBuilder : IDisposable internal UiBuilder(string namespaceName) { this.stopwatch = new Stopwatch(); + this.hitchDetector = new HitchDetector($"UiBuilder({namespaceName})", 15.0f); this.namespaceName = namespaceName; this.interfaceManager.Draw += this.OnDraw; @@ -415,6 +417,8 @@ public sealed class UiBuilder : IDisposable private void OnDraw() { + this.hitchDetector.Start(); + var configuration = Service.Get(); var gameGui = Service.GetNullable(); if (gameGui == null) @@ -501,6 +505,8 @@ public sealed class UiBuilder : IDisposable } ImGui.PopID(); + + this.hitchDetector.Stop(); } private void OnBuildFonts() diff --git a/Dalamud/Utility/HitchDetector.cs b/Dalamud/Utility/HitchDetector.cs new file mode 100644 index 000000000..d749ec25d --- /dev/null +++ b/Dalamud/Utility/HitchDetector.cs @@ -0,0 +1,56 @@ +using System; +using System.Diagnostics; + +using Serilog; + +namespace Dalamud.Utility; + +/// +/// Utility class to detect hitches. +/// +public class HitchDetector +{ + private readonly TimeSpan cooldownTime = TimeSpan.FromSeconds(30); + + private readonly string name; + private readonly double millisecondsMax; + + private DateTime lastTriggeredTime; + private Stopwatch stopwatch = new(); + + /// + /// Initializes a new instance of the class. + /// + /// Name to log. + /// Milliseconds to print a warning for. + public HitchDetector(string name, double millisecondsMax = 20) + { + this.name = name; + this.millisecondsMax = millisecondsMax; + + this.lastTriggeredTime = DateTime.Now - this.cooldownTime; + } + + /// + /// Start the time tracking. + /// + public void Start() + { + this.stopwatch.Restart(); + } + + /// + /// Stop the time tracking, and print a warning, if applicable. + /// + public void Stop() + { + this.stopwatch.Stop(); + + if (this.stopwatch.Elapsed.TotalMilliseconds > this.millisecondsMax && + DateTime.Now - this.lastTriggeredTime > this.cooldownTime) + { + Log.Warning("[HITCH] Long {Name} detected, {Total}ms > {Max}ms - check in the plugin stats window.", this.name, this.stopwatch.Elapsed.TotalMilliseconds, this.millisecondsMax); + this.lastTriggeredTime = DateTime.Now; + } + } +}