From c7dc8c81f427e390689611e31bffca4cf50b6690 Mon Sep 17 00:00:00 2001 From: kizer Date: Sun, 26 Jun 2022 02:34:40 +0900 Subject: [PATCH] Fix async plugin load and show full profiler (#898) --- Dalamud/Dalamud.cs | 15 +- Dalamud/Game/Gui/Dtr/DtrBar.cs | 4 +- Dalamud/Game/Gui/GameGui.cs | 10 +- Dalamud/Game/SigScanner.cs | 34 ----- Dalamud/Hooking/Internal/HookManager.cs | 4 +- .../Interface/GameFonts/GameFontManager.cs | 2 +- Dalamud/Interface/Internal/DalamudCommands.cs | 2 +- .../Interface/Internal/DalamudInterface.cs | 4 +- .../Internal/Windows/PluginImageCache.cs | 2 - .../PluginInstaller/PluginInstallerWindow.cs | 2 +- .../Internal/Windows/ProfilerWindow.cs | 128 +++++++++++++---- Dalamud/IoC/Internal/ServiceContainer.cs | 3 +- Dalamud/Plugin/Internal/PluginManager.cs | 63 +++----- .../Plugin/Internal/Types/LocalDevPlugin.cs | 4 +- Dalamud/Plugin/Internal/Types/LocalPlugin.cs | 14 +- Dalamud/ServiceManager.cs | 136 +++++++++++++----- Dalamud/Service{T}.cs | 46 +++--- Dalamud/Utility/Timing/TimingEvent.cs | 13 +- Dalamud/Utility/Timing/TimingHandle.cs | 91 +++++++----- Dalamud/Utility/Timing/Timings.cs | 75 ++++++++-- 20 files changed, 404 insertions(+), 248 deletions(-) diff --git a/Dalamud/Dalamud.cs b/Dalamud/Dalamud.cs index 7584861e4..182cfb6b1 100644 --- a/Dalamud/Dalamud.cs +++ b/Dalamud/Dalamud.cs @@ -1,7 +1,5 @@ using System; -using System.Diagnostics; using System.IO; -using System.Reflection; using System.Runtime.CompilerServices; using System.Threading; using System.Threading.Tasks; @@ -9,24 +7,15 @@ using Dalamud.Configuration.Internal; using Dalamud.Data; using Dalamud.Game; using Dalamud.Game.ClientState; -using Dalamud.Game.Command; -using Dalamud.Game.Gui; using Dalamud.Game.Gui.Internal; using Dalamud.Game.Internal; -using Dalamud.Game.Network; using Dalamud.Game.Network.Internal; -using Dalamud.Game.Text.SeStringHandling; using Dalamud.Hooking.Internal; -using Dalamud.Interface; -using Dalamud.Interface.GameFonts; using Dalamud.Interface.Internal; -using Dalamud.IoC.Internal; using Dalamud.Logging.Internal; using Dalamud.Plugin.Internal; -using Dalamud.Plugin.Ipc.Internal; using Dalamud.Support; using Dalamud.Utility; -using Dalamud.Utility.Timing; using Serilog; using Serilog.Core; using Serilog.Events; @@ -74,9 +63,7 @@ namespace Dalamud SerilogEventSink.Instance.LogLine += SerilogOnLogLine; - Service.Provide(this); - Service.Provide(info); - Service.Provide(configuration); + ServiceManager.InitializeProvidedServicesAndClientStructs(this, info, configuration); if (!configuration.IsResumeGameAfterPluginLoad) { diff --git a/Dalamud/Game/Gui/Dtr/DtrBar.cs b/Dalamud/Game/Gui/Dtr/DtrBar.cs index 13c9c3324..e4a75071c 100644 --- a/Dalamud/Game/Gui/Dtr/DtrBar.cs +++ b/Dalamud/Game/Gui/Dtr/DtrBar.cs @@ -26,9 +26,9 @@ namespace Dalamud.Game.Gui.Dtr private uint runningNodeIds = BaseNodeId; [ServiceManager.ServiceConstructor] - private DtrBar(DalamudConfiguration configuration) + private DtrBar(DalamudConfiguration configuration, Framework framework) { - Service.Get().Update += this.Update; + framework.Update += this.Update; configuration.DtrOrder ??= new List(); configuration.DtrIgnore ??= new List(); diff --git a/Dalamud/Game/Gui/GameGui.cs b/Dalamud/Game/Gui/GameGui.cs index 1d7a09861..53ab50255 100644 --- a/Dalamud/Game/Gui/GameGui.cs +++ b/Dalamud/Game/Gui/GameGui.cs @@ -423,13 +423,13 @@ namespace Dalamud.Game.Gui /// public void Enable() { - Service.Get().Enable(); - Service.Get().Enable(); - Service.Get().Enable(); - Service.Get().Enable(); + Service.GetAsync().ContinueWith(x => x.Result.Enable()); + Service.GetAsync().ContinueWith(x => x.Result.Enable()); + Service.GetAsync().ContinueWith(x => x.Result.Enable()); + Service.GetAsync().ContinueWith(x => x.Result.Enable()); if (EnvironmentConfiguration.DalamudDoContextMenu) - Service.Get().Enable(); + Service.GetAsync().ContinueWith(x => x.Result.Enable()); this.setGlobalBgmHook.Enable(); this.handleItemHoverHook.Enable(); diff --git a/Dalamud/Game/SigScanner.cs b/Dalamud/Game/SigScanner.cs index 46418384e..832066ee5 100644 --- a/Dalamud/Game/SigScanner.cs +++ b/Dalamud/Game/SigScanner.cs @@ -9,7 +9,6 @@ using System.Runtime.InteropServices; using Dalamud.IoC; using Dalamud.IoC.Internal; -using Dalamud.Utility.Timing; using Newtonsoft.Json; using Serilog; @@ -20,7 +19,6 @@ namespace Dalamud.Game /// [PluginInterface] [InterfaceVersion("1.0")] - [ServiceManager.BlockingEarlyLoadedService] public class SigScanner : IDisposable { private readonly FileInfo? cacheFile; @@ -30,38 +28,6 @@ namespace Dalamud.Game private ConcurrentDictionary? textCache; - [ServiceManager.ServiceConstructor] - private SigScanner(DalamudStartInfo startInfo) - { - // Initialize the process information. - var cacheDir = new DirectoryInfo(Path.Combine(startInfo.WorkingDirectory!, "cachedSigs")); - if (!cacheDir.Exists) - cacheDir.Create(); - - this.cacheFile = new FileInfo(Path.Combine(cacheDir.FullName, $"{startInfo.GameVersion}.json")); - this.Module = Process.GetCurrentProcess().MainModule!; - this.Is32BitProcess = !Environment.Is64BitProcess; - this.IsCopy = true; - - // Limit the search space to .text section. - this.SetupSearchSpace(this.Module); - - if (this.IsCopy) - this.SetupCopiedSegments(); - - Log.Verbose($"Module base: 0x{this.TextSectionBase.ToInt64():X}"); - Log.Verbose($"Module size: 0x{this.TextSectionSize:X}"); - - if (this.cacheFile != null) - this.Load(); - - // Initialize FFXIVClientStructs function resolver - using (Timings.Start("CS Resolver Init")) - { - FFXIVClientStructs.Resolver.InitializeParallel(new FileInfo(Path.Combine(cacheDir.FullName, $"{startInfo.GameVersion}_cs.json"))); - } - } - /// /// Initializes a new instance of the class using the main module of the current process. /// diff --git a/Dalamud/Hooking/Internal/HookManager.cs b/Dalamud/Hooking/Internal/HookManager.cs index 989425949..b9c0d270c 100644 --- a/Dalamud/Hooking/Internal/HookManager.cs +++ b/Dalamud/Hooking/Internal/HookManager.cs @@ -31,12 +31,12 @@ namespace Dalamud.Hooking.Internal /// /// Gets a static dictionary of original code for a hooked address. /// - internal static Dictionary Originals { get; } = new(); + internal static ConcurrentDictionary Originals { get; } = new(); /// /// Gets a static dictionary of the number of hooks on a given address. /// - internal static Dictionary> MultiHookTracker { get; } = new(); + internal static ConcurrentDictionary> MultiHookTracker { get; } = new(); /// public void Dispose() diff --git a/Dalamud/Interface/GameFonts/GameFontManager.cs b/Dalamud/Interface/GameFonts/GameFontManager.cs index 544b15123..ce4460257 100644 --- a/Dalamud/Interface/GameFonts/GameFontManager.cs +++ b/Dalamud/Interface/GameFonts/GameFontManager.cs @@ -57,7 +57,7 @@ namespace Dalamud.Interface.GameFonts .Select(x => x.Glyphs.Select(y => y.TextureFileIndex).Max()) .Max()) .Select(x => dataManager.GetFile($"common/font/font{x}.tex")!) - .Select(x => new Task(() => x.ImageData!)) + .Select(x => new Task(Timings.AttachTimingHandle(() => x.ImageData!))) .ToArray(); foreach (var task in texTasks) task.Start(); diff --git a/Dalamud/Interface/Internal/DalamudCommands.cs b/Dalamud/Interface/Internal/DalamudCommands.cs index 86132eecb..a9fc47995 100644 --- a/Dalamud/Interface/Internal/DalamudCommands.cs +++ b/Dalamud/Interface/Internal/DalamudCommands.cs @@ -166,7 +166,7 @@ namespace Dalamud.Interface.Internal try { - Service.Get().ReloadAllPlugins(); + Service.Get().ReloadAllPluginsAsync().Wait(); chatGui.Print("OK"); } catch (Exception ex) diff --git a/Dalamud/Interface/Internal/DalamudInterface.cs b/Dalamud/Interface/Internal/DalamudInterface.cs index afe106367..d5a34d34e 100644 --- a/Dalamud/Interface/Internal/DalamudInterface.cs +++ b/Dalamud/Interface/Internal/DalamudInterface.cs @@ -35,7 +35,7 @@ namespace Dalamud.Interface.Internal /// /// This plugin implements all of the Dalamud interface separately, to allow for reloading of the interface and rapid prototyping. /// - [ServiceManager.EarlyLoadedService] + [ServiceManager.AfterDrawingEarlyLoadedService] internal class DalamudInterface : IDisposable { private static readonly ModuleLog Log = new("DUI"); @@ -714,7 +714,7 @@ namespace Dalamud.Interface.Internal { try { - pluginManager.ReloadAllPlugins(); + pluginManager.ReloadAllPluginsAsync().Wait(); } catch (Exception ex) { diff --git a/Dalamud/Interface/Internal/Windows/PluginImageCache.cs b/Dalamud/Interface/Internal/Windows/PluginImageCache.cs index d1081600c..2e714a8c8 100644 --- a/Dalamud/Interface/Internal/Windows/PluginImageCache.cs +++ b/Dalamud/Interface/Internal/Windows/PluginImageCache.cs @@ -60,8 +60,6 @@ namespace Dalamud.Interface.Internal.Windows var dalamud = Service.Get(); var interfaceManager = Service.Get(); - interfaceManager.SceneInitializeTask.Wait(); - this.DefaultIcon = interfaceManager.LoadImage(Path.Combine(dalamud.AssetDirectory.FullName, "UIRes", "defaultIcon.png"))!; this.TroubleIcon = interfaceManager.LoadImage(Path.Combine(dalamud.AssetDirectory.FullName, "UIRes", "troubleIcon.png"))!; this.UpdateIcon = interfaceManager.LoadImage(Path.Combine(dalamud.AssetDirectory.FullName, "UIRes", "updateIcon.png"))!; diff --git a/Dalamud/Interface/Internal/Windows/PluginInstaller/PluginInstallerWindow.cs b/Dalamud/Interface/Internal/Windows/PluginInstaller/PluginInstallerWindow.cs index aaedb9d28..7f02781a5 100644 --- a/Dalamud/Interface/Internal/Windows/PluginInstaller/PluginInstallerWindow.cs +++ b/Dalamud/Interface/Internal/Windows/PluginInstaller/PluginInstallerWindow.cs @@ -1735,7 +1735,7 @@ namespace Dalamud.Interface.Internal.Windows.PluginInstaller if (!enableTask.Result) return; - var loadTask = Task.Run(() => plugin.Load(PluginLoadReason.Installer)) + var loadTask = Task.Run(() => plugin.LoadAsync(PluginLoadReason.Installer)) .ContinueWith(this.DisplayErrorContinuation, Locs.ErrorModal_LoadFail(plugin.Name)); loadTask.Wait(); diff --git a/Dalamud/Interface/Internal/Windows/ProfilerWindow.cs b/Dalamud/Interface/Internal/Windows/ProfilerWindow.cs index ddaa26756..91c53efe5 100644 --- a/Dalamud/Interface/Internal/Windows/ProfilerWindow.cs +++ b/Dalamud/Interface/Internal/Windows/ProfilerWindow.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Generic; using System.Linq; using System.Numerics; using Dalamud.Interface.Colors; @@ -13,25 +14,35 @@ public class ProfilerWindow : Window { private double min; private double max; + private List>> occupied = new(); public ProfilerWindow() : base("Profiler", forceMainWindow: true) { } public override void OnOpen() { - this.min = Timings.AllTimings.Min(x => x.StartTime); - this.max = Timings.AllTimings.Max(x => x.EndTime); + this.min = Timings.AllTimings.Keys.Min(x => x.StartTime); + this.max = Timings.AllTimings.Keys.Max(x => x.EndTime); + } + + private class RectInfo + { + internal TimingHandle Timing; + internal Vector2 MinPos; + internal Vector2 MaxPos; + internal Vector4 RectColor; + internal bool Hover; } /// public override void Draw() { var width = ImGui.GetWindowWidth(); - var actualMin = Timings.AllTimings.Min(x => x.StartTime); - var actualMax = Timings.AllTimings.Max(x => x.EndTime); + var actualMin = Timings.AllTimings.Keys.Min(x => x.StartTime); + var actualMax = Timings.AllTimings.Keys.Max(x => x.EndTime); ImGui.Text("Timings"); - const int childHeight = 300; + var childHeight = Math.Max(300, 20 * (2 + this.occupied.Count)); if (ImGui.BeginChild("Timings", new Vector2(0, childHeight), true)) { @@ -68,48 +79,113 @@ public class ProfilerWindow : Window uint maxRectDept = 0; - foreach (var timingHandle in Timings.AllTimings) + foreach (var l in this.occupied) + l.Clear(); + + var parentDepthDict = new Dictionary(); + var rects = new Dictionary(); + var mousePos = ImGui.GetMousePos(); + foreach (var timingHandle in Timings.AllTimings.Keys) { var startX = (timingHandle.StartTime - this.min) / (this.max - this.min) * width; var endX = (timingHandle.EndTime - this.min) / (this.max - this.min) * width; + var depth = timingHandle.IdChain.Length < 2 ? 0 : parentDepthDict.GetValueOrDefault(timingHandle.IdChain[^2]); + for (; depth < this.occupied.Count; depth++) + { + var acceptable = true; + foreach (var (x1, x2) in this.occupied[depth]) + { + if (x2 <= timingHandle.StartTime || x1 >= timingHandle.EndTime) + continue; + acceptable = false; + break; + } + + if (acceptable) + break; + } + + if (depth == this.occupied.Count) + this.occupied.Add(new()); + this.occupied[depth].Add(Tuple.Create(timingHandle.StartTime, timingHandle.EndTime)); + parentDepthDict[timingHandle.Id] = depth; startX = Math.Max(startX, 0); endX = Math.Max(endX, 0); - var rectColor = timingHandle.IsMainThread ? ImGuiColors.ParsedBlue : ImGuiColors.ParsedPurple; - rectColor.X -= timingHandle.Depth * 0.12f; - rectColor.Y -= timingHandle.Depth * 0.12f; - rectColor.Z -= timingHandle.Depth * 0.12f; + Vector4 rectColor; + if (this.occupied[depth].Count % 2 == 0) + rectColor = timingHandle.IsMainThread ? ImGuiColors.ParsedBlue : ImGuiColors.ParsedOrange; + else + rectColor = timingHandle.IsMainThread ? ImGuiColors.ParsedPurple : ImGuiColors.ParsedGold; + rectColor.X -= timingHandle.IdChain.Length * 0.12f; + rectColor.Y -= timingHandle.IdChain.Length * 0.12f; + rectColor.Z -= timingHandle.IdChain.Length * 0.12f; - if (maxRectDept < timingHandle.Depth) - maxRectDept = timingHandle.Depth; + if (maxRectDept < depth) + maxRectDept = (uint)depth; if (startX == endX) { continue; } - var minPos = pos + new Vector2((uint)startX, 20 * timingHandle.Depth); - var maxPos = pos + new Vector2((uint)endX, 20 * (timingHandle.Depth + 1)); + var minPos = pos + new Vector2((uint)startX, 20 * depth); + var maxPos = pos + new Vector2((uint)endX, 20 * (depth + 1)); + rects[timingHandle.Id] = new RectInfo + { + Hover = mousePos.X >= minPos.X && mousePos.X < maxPos.X && + mousePos.Y >= minPos.Y && mousePos.Y < maxPos.Y, + Timing = timingHandle, + MinPos = minPos, + MaxPos = maxPos, + RectColor = rectColor, + }; + } + + foreach (var hoveredItem in rects.Values.Where(x => x.Hover)) + { + foreach (var rectInfo in rects.Values) + { + if (rectInfo == hoveredItem) + rectInfo.RectColor = new Vector4(255, 255, 255, 255); + else if (rectInfo.Timing.IdChain.Contains(hoveredItem.Timing.Id)) + rectInfo.RectColor = ImGuiColors.ParsedGreen; + else if (hoveredItem.Timing.IdChain.Contains(rectInfo.Timing.Id)) + rectInfo.RectColor = ImGuiColors.ParsedPink; + } + } + + foreach (var rectInfo in rects.Values) + { ImGui.GetWindowDrawList().AddRectFilled( - minPos, - maxPos, - ImGui.GetColorU32(rectColor)); + rectInfo.MinPos, + rectInfo.MaxPos, + ImGui.GetColorU32(rectInfo.RectColor)); - ImGui.GetWindowDrawList().AddTextClippedEx(minPos, maxPos, timingHandle.Name, null, Vector2.Zero, null); + if (rectInfo.Hover) + ImGui.PushStyleColor(ImGuiCol.Text, new Vector4(0, 0, 0, 255)); + ImGui.GetWindowDrawList().AddTextClippedEx( + rectInfo.MinPos, + rectInfo.MaxPos, + rectInfo.Timing.Name, + null, + Vector2.Zero, + null); + if (rectInfo.Hover) + ImGui.PopStyleColor(); // Show tooltip when hovered - var mousePos = ImGui.GetMousePos(); - if (mousePos.X > pos.X + startX && mousePos.X < pos.X + endX && - mousePos.Y > pos.Y + (20 * timingHandle.Depth) && - mousePos.Y < pos.Y + (20 * (timingHandle.Depth + 1))) + if (rectInfo.Hover) { ImGui.BeginTooltip(); - ImGui.Text(timingHandle.Name); - ImGui.Text(timingHandle.MemberName); - ImGui.Text($"{timingHandle.FileName}:{timingHandle.LineNumber}"); - ImGui.Text($"Duration: {timingHandle.Duration}ms"); + ImGui.TextUnformatted(rectInfo.Timing.Name); + ImGui.TextUnformatted(rectInfo.Timing.MemberName); + ImGui.TextUnformatted($"{rectInfo.Timing.FileName}:{rectInfo.Timing.LineNumber}"); + ImGui.TextUnformatted($"Duration: {rectInfo.Timing.Duration}ms"); + if (rectInfo.Timing.Parent != null) + ImGui.TextUnformatted($"Parent: {rectInfo.Timing.Parent.Name}"); ImGui.EndTooltip(); } } diff --git a/Dalamud/IoC/Internal/ServiceContainer.cs b/Dalamud/IoC/Internal/ServiceContainer.cs index 4a9d57dde..5369f3c67 100644 --- a/Dalamud/IoC/Internal/ServiceContainer.cs +++ b/Dalamud/IoC/Internal/ServiceContainer.cs @@ -5,6 +5,7 @@ using System.Reflection; using System.Runtime.Serialization; using System.Threading.Tasks; using Dalamud.Logging.Internal; +using Dalamud.Utility.Timing; namespace Dalamud.IoC.Internal { @@ -60,7 +61,7 @@ namespace Dalamud.IoC.Internal var parameterType = p.ParameterType; var requiredVersion = p.GetCustomAttribute(typeof(RequiredVersionAttribute)) as RequiredVersionAttribute; return (parameterType, requiredVersion); - }); + }).ToList(); var versionCheck = parameters.All(p => CheckInterfaceVersion(p.requiredVersion, p.parameterType)); diff --git a/Dalamud/Plugin/Internal/PluginManager.cs b/Dalamud/Plugin/Internal/PluginManager.cs index 859edd2f7..d88e82236 100644 --- a/Dalamud/Plugin/Internal/PluginManager.cs +++ b/Dalamud/Plugin/Internal/PluginManager.cs @@ -314,13 +314,13 @@ internal partial class PluginManager : IDisposable // Dev plugins should load first. pluginDefs.InsertRange(0, devPluginDefs); - Task LoadPluginOnBoot(string logPrefix, PluginDef pluginDef) + async Task LoadPluginOnBoot(string logPrefix, PluginDef pluginDef) { using (Timings.Start($"{pluginDef.DllFile.Name}: {logPrefix}Boot")) { try { - return this.LoadPluginAsync( + await this.LoadPluginAsync( pluginDef.DllFile, pluginDef.Manifest, PluginLoadReason.Boot, @@ -336,8 +336,6 @@ internal partial class PluginManager : IDisposable Log.Error(ex, "{0}: During boot plugin load, an unexpected error occurred", logPrefix); } } - - return Task.CompletedTask; } void LoadPluginsSync(string logPrefix, IEnumerable pluginDefsList) @@ -350,7 +348,8 @@ internal partial class PluginManager : IDisposable { return Task.WhenAll( pluginDefsList - .Select(pluginDef => LoadPluginOnBoot(logPrefix, pluginDef)) + .Select(pluginDef => Task.Run(Timings.AttachTimingHandle( + () => LoadPluginOnBoot(logPrefix, pluginDef)))) .ToArray()); } @@ -394,15 +393,15 @@ internal partial class PluginManager : IDisposable TaskContinuationOptions.RunContinuationsAsynchronously) .Unwrap() .ContinueWith( - _ => Service.Get().RunOnTick(() => - { - LoadPluginsSync( + _ => Service.Get().RunOnTick( + () => LoadPluginsSync( "DrawAvailableSync", - syncPlugins.Where(def => def.Manifest?.LoadRequiredState is 0 or null)); - return LoadPluginsAsync( - "DrawAvailableAsync", - asyncPlugins.Where(def => def.Manifest?.LoadRequiredState is 0 or null)); - })) + syncPlugins.Where(def => def.Manifest?.LoadRequiredState is 0 or null)))) + .Unwrap() + .ContinueWith( + _ => LoadPluginsAsync( + "DrawAvailableAsync", + asyncPlugins.Where(def => def.Manifest?.LoadRequiredState is 0 or null))) .Unwrap()); // Save signatures when all plugins are done loading, successful or not. @@ -427,33 +426,16 @@ internal partial class PluginManager : IDisposable /// /// Reload all loaded plugins. /// - public void ReloadAllPlugins() + /// A task. + public Task ReloadAllPluginsAsync() { - var aggregate = new List(); - lock (this.pluginListLock) { - foreach (var plugin in this.InstalledPlugins) - { - if (plugin.IsLoaded) - { - try - { - plugin.Reload(); - } - catch (Exception ex) - { - Log.Error(ex, "Error during reload all"); - - aggregate.Add(ex); - } - } - } - } - - if (aggregate.Any()) - { - throw new AggregateException(aggregate); + return Task.WhenAll(this.InstalledPlugins + .Where(x => x.IsLoaded) + .ToList() + .Select(x => Task.Run(async () => await x.ReloadAsync())) + .ToList()); } } @@ -706,10 +688,7 @@ internal partial class PluginManager : IDisposable if (plugin.IsDisabled) plugin.Enable(); - // Await for things that plugin just require - _ = await Service.GetAsync(); - - plugin.Load(reason); + await plugin.LoadAsync(reason); } catch (InvalidPluginException) { @@ -1004,7 +983,7 @@ internal partial class PluginManager : IDisposable Thread.Sleep(500); // Let's indicate "installer" here since this is supposed to be a fresh install - plugin.Load(PluginLoadReason.Installer); + plugin.LoadAsync(PluginLoadReason.Installer).Wait(); } /// diff --git a/Dalamud/Plugin/Internal/Types/LocalDevPlugin.cs b/Dalamud/Plugin/Internal/Types/LocalDevPlugin.cs index eb0877227..2043b8c6b 100644 --- a/Dalamud/Plugin/Internal/Types/LocalDevPlugin.cs +++ b/Dalamud/Plugin/Internal/Types/LocalDevPlugin.cs @@ -124,7 +124,7 @@ internal class LocalDevPlugin : LocalPlugin, IDisposable var current = Interlocked.Increment(ref this.reloadCounter); Task.Delay(500).ContinueWith( - _ => + async _ => { if (this.fileWatcherTokenSource.IsCancellationRequested) { @@ -148,7 +148,7 @@ internal class LocalDevPlugin : LocalPlugin, IDisposable try { - this.Reload(); + await this.ReloadAsync(); notificationManager.AddNotification($"The DevPlugin '{this.Name} was reloaded successfully.", "Plugin reloaded!", NotificationType.Success); } catch (Exception ex) diff --git a/Dalamud/Plugin/Internal/Types/LocalPlugin.cs b/Dalamud/Plugin/Internal/Types/LocalPlugin.cs index 885f783e0..e10081d3a 100644 --- a/Dalamud/Plugin/Internal/Types/LocalPlugin.cs +++ b/Dalamud/Plugin/Internal/Types/LocalPlugin.cs @@ -2,7 +2,7 @@ using System; using System.IO; using System.Linq; using System.Reflection; - +using System.Threading.Tasks; using Dalamud.Configuration.Internal; using Dalamud.Game; using Dalamud.Game.Gui.Dtr; @@ -160,7 +160,7 @@ internal class LocalPlugin : IDisposable public PluginState State { get; protected set; } /// - /// Gets the AssemblyName plugin, populated during . + /// Gets the AssemblyName plugin, populated during . /// /// Plugin type. public AssemblyName? AssemblyName { get; private set; } @@ -225,7 +225,8 @@ internal class LocalPlugin : IDisposable /// /// The reason why this plugin is being loaded. /// Load while reloading. - public void Load(PluginLoadReason reason, bool reloading = false) + /// A task. + public async Task LoadAsync(PluginLoadReason reason, bool reloading = false) { var startInfo = Service.Get(); var configuration = Service.Get(); @@ -334,7 +335,7 @@ internal class LocalPlugin : IDisposable this.DalamudInterface = new DalamudPluginInterface(this.pluginAssembly.GetName().Name!, this.DllFile, reason, this.IsDev); var ioc = Service.Get(); - this.instance = ioc.CreateAsync(this.pluginType, this.DalamudInterface).GetAwaiter().GetResult() as IDalamudPlugin; + this.instance = await ioc.CreateAsync(this.pluginType, this.DalamudInterface) as IDalamudPlugin; if (this.instance == null) { this.State = PluginState.LoadError; @@ -423,7 +424,8 @@ internal class LocalPlugin : IDisposable /// /// Reload this plugin. /// - public void Reload() + /// A task. + public async Task ReloadAsync() { this.Unload(true); @@ -431,7 +433,7 @@ internal class LocalPlugin : IDisposable var dtr = Service.Get(); dtr.HandleRemovedNodes(); - this.Load(PluginLoadReason.Reload, true); + await this.LoadAsync(PluginLoadReason.Reload, true); } /// diff --git a/Dalamud/ServiceManager.cs b/Dalamud/ServiceManager.cs index 8a2303d5d..00ee3790e 100644 --- a/Dalamud/ServiceManager.cs +++ b/Dalamud/ServiceManager.cs @@ -1,10 +1,15 @@ using System; using System.Collections.Generic; +using System.IO; using System.Linq; using System.Reflection; using System.Threading.Tasks; +using Dalamud.Configuration.Internal; +using Dalamud.Game; +using Dalamud.Interface.Internal; using Dalamud.IoC.Internal; using Dalamud.Logging.Internal; +using Dalamud.Utility.Timing; using JetBrains.Annotations; namespace Dalamud @@ -26,16 +31,43 @@ namespace Dalamud /// public static Task BlockingResolved { get; } = BlockingServicesLoadedTaskCompletionSource.Task; + /// + /// Initializes Provided Services and FFXIVClientStructs. + /// + /// Instance of . + /// Instance of . + /// Instance of . + public static void InitializeProvidedServicesAndClientStructs(Dalamud dalamud, DalamudStartInfo startInfo, DalamudConfiguration configuration) + { + Service.Provide(dalamud); + Service.Provide(startInfo); + Service.Provide(configuration); + Service.Provide(new ServiceContainer()); + + // Initialize the process information. + var cacheDir = new DirectoryInfo(Path.Combine(startInfo.WorkingDirectory!, "cachedSigs")); + if (!cacheDir.Exists) + cacheDir.Create(); + Service.Provide(new SigScanner(true, new FileInfo(Path.Combine(cacheDir.FullName, $"{startInfo.GameVersion}.json")))); + + using (Timings.Start("CS Resolver Init")) + { + FFXIVClientStructs.Resolver.InitializeParallel(new FileInfo(Path.Combine(cacheDir.FullName, $"{startInfo.GameVersion}_cs.json"))); + } + } + /// /// Kicks off construction of services that can handle early loading. /// /// Task for initializing all services. public static async Task InitializeEarlyLoadableServices() { - Service.Provide(new ServiceContainer()); - + using var serviceInitializeTimings = Timings.Start("Services Init"); var service = typeof(Service<>); - var blockingEarlyLoadingServices = new List(); + + var earlyLoadingServices = new HashSet(); + var blockingEarlyLoadingServices = new HashSet(); + var afterDrawingEarlyLoadedServices = new HashSet(); var dependencyServicesMap = new Dictionary>(); var getAsyncTaskMap = new Dictionary(); @@ -52,10 +84,19 @@ namespace Dalamud null, null, null); + if (attr.IsAssignableTo(typeof(BlockingEarlyLoadedService))) { getAsyncTaskMap[serviceType] = getTask; - blockingEarlyLoadingServices.Add(getTask); + blockingEarlyLoadingServices.Add(serviceType); + } + else if (attr.IsAssignableTo(typeof(AfterDrawingEarlyLoadedService))) + { + afterDrawingEarlyLoadedServices.Add(serviceType); + } + else + { + earlyLoadingServices.Add(serviceType); } dependencyServicesMap[serviceType] = @@ -69,50 +110,70 @@ namespace Dalamud null); } - _ = Task.WhenAll(blockingEarlyLoadingServices).ContinueWith(x => + _ = Task.Run(async () => { try { - if (x.IsFaulted) - BlockingServicesLoadedTaskCompletionSource.SetException(x.Exception!); - else - BlockingServicesLoadedTaskCompletionSource.SetResult(); + using var blockingServiceInitializeTimings = Timings.Start("BlockingServices Init"); + await Task.WhenAll(blockingEarlyLoadingServices.Select(x => getAsyncTaskMap[x])); + BlockingServicesLoadedTaskCompletionSource.SetResult(); } - catch (Exception) + catch (Exception e) { - // don't care, as this means task result/exception has already been set + BlockingServicesLoadedTaskCompletionSource.SetException(e); } }).ConfigureAwait(false); try { - var tasks = new List(); - while (dependencyServicesMap.Any()) + for (var i = 0; i < 2; i++) { - tasks.Clear(); - foreach (var (serviceType, dependencies) in dependencyServicesMap.ToList()) + var tasks = new List(); + var servicesToLoad = new HashSet(); + if (i == 0) { - if (!dependencies.All( - x => !getAsyncTaskMap.ContainsKey(x) || getAsyncTaskMap[x].IsCompleted)) - continue; - - tasks.Add((Task)service.MakeGenericType(serviceType).InvokeMember( - "StartLoader", - BindingFlags.InvokeMethod | BindingFlags.Static | BindingFlags.Public, - null, - null, - null)); - dependencyServicesMap.Remove(serviceType); + servicesToLoad.UnionWith(earlyLoadingServices); + servicesToLoad.UnionWith(blockingEarlyLoadingServices); + } + else + { + servicesToLoad.UnionWith(afterDrawingEarlyLoadedServices); + await (await Service.GetAsync()).SceneInitializeTask; } - if (!tasks.Any()) - throw new InvalidOperationException("Unresolvable dependency cycle detected"); - - await Task.WhenAll(tasks); - foreach (var task in tasks) + while (servicesToLoad.Any()) { - if (task.IsFaulted) - throw task.Exception!; + foreach (var serviceType in servicesToLoad) + { + if (dependencyServicesMap[serviceType].Any( + x => getAsyncTaskMap.GetValueOrDefault(x)?.IsCompleted == false)) + continue; + + tasks.Add((Task)service.MakeGenericType(serviceType).InvokeMember( + "StartLoader", + BindingFlags.InvokeMethod | BindingFlags.Static | BindingFlags.Public, + null, + null, + null)); + servicesToLoad.Remove(serviceType); + } + + if (!tasks.Any()) + throw new InvalidOperationException("Unresolvable dependency cycle detected"); + + if (servicesToLoad.Any()) + { + await Task.WhenAny(tasks); + var faultedTasks = tasks.Where(x => x.IsFaulted).Select(x => (Exception)x.Exception!).ToArray(); + if (faultedTasks.Any()) + throw new AggregateException(faultedTasks); + } + else + { + await Task.WhenAll(tasks); + } + + tasks.RemoveAll(x => x.IsCompleted); } } } @@ -173,5 +234,14 @@ namespace Dalamud public class BlockingEarlyLoadedService : EarlyLoadedService { } + + /// + /// Indicates that the class is a service, and will be instantiated automatically on startup, + /// when drawing becomes available. + /// + [AttributeUsage(AttributeTargets.Class)] + public class AfterDrawingEarlyLoadedService : EarlyLoadedService + { + } } } diff --git a/Dalamud/Service{T}.cs b/Dalamud/Service{T}.cs index 99dacc993..7079fe17f 100644 --- a/Dalamud/Service{T}.cs +++ b/Dalamud/Service{T}.cs @@ -23,9 +23,6 @@ namespace Dalamud // ReSharper disable once StaticMemberInGenericType private static readonly TaskCompletionSource InstanceTcs = new(); - // ReSharper disable once StaticMemberInGenericType - private static bool startLoaderInvoked = false; - static Service() { var exposeToPlugins = typeof(T).GetCustomAttribute() != null; @@ -45,37 +42,29 @@ namespace Dalamud [UsedImplicitly] public static Task StartLoader() { - if (startLoaderInvoked) - throw new InvalidOperationException("StartLoader has already been called."); - var attr = typeof(T).GetCustomAttribute(true)?.GetType(); if (attr?.IsAssignableTo(typeof(ServiceManager.EarlyLoadedService)) != true) throw new InvalidOperationException($"{typeof(T).Name} is not an EarlyLoadedService"); - startLoaderInvoked = true; - return Task.Run(async () => + return Task.Run(Timings.AttachTimingHandle(async () => { - using (Timings.Start($"{typeof(T).Namespace} Enable")) + ServiceManager.Log.Debug("Service<{0}>: Begin construction", typeof(T).Name); + try { + var x = await ConstructObject(); if (attr?.IsAssignableTo(typeof(ServiceManager.BlockingEarlyLoadedService)) == true) - ServiceManager.Log.Debug("Service<{0}>: Begin construction", typeof(T).Name); - try - { - var x = await ConstructObject(); - if (attr?.IsAssignableTo(typeof(ServiceManager.BlockingEarlyLoadedService)) == true) - ServiceManager.Log.Debug("Service<{0}>: Construction complete", typeof(T).Name); - InstanceTcs.SetResult(x); - return x; - } - catch (Exception e) - { - InstanceTcs.SetException(e); - if (attr?.IsAssignableTo(typeof(ServiceManager.BlockingEarlyLoadedService)) == true) - ServiceManager.Log.Error(e, "Service<{0}>: Construction failure", typeof(T).Name); - throw; - } + ServiceManager.Log.Debug("Service<{0}>: Construction complete", typeof(T).Name); + InstanceTcs.SetResult(x); + return x; } - }); + catch (Exception e) + { + InstanceTcs.SetException(e); + if (attr?.IsAssignableTo(typeof(ServiceManager.BlockingEarlyLoadedService)) == true) + ServiceManager.Log.Error(e, "Service<{0}>: Construction failure", typeof(T).Name); + throw; + } + })); } /// @@ -165,7 +154,10 @@ namespace Dalamud var ctor = GetServiceConstructor(); var args = await Task.WhenAll( ctor.GetParameters().Select(x => GetServiceObjectConstructArgument(x.ParameterType))); - return (T)ctor.Invoke(args)!; + using (Timings.Start($"{typeof(T).Name} Construct")) + { + return (T)ctor.Invoke(args)!; + } } } } diff --git a/Dalamud/Utility/Timing/TimingEvent.cs b/Dalamud/Utility/Timing/TimingEvent.cs index 8067c8a68..2fa7e72c0 100644 --- a/Dalamud/Utility/Timing/TimingEvent.cs +++ b/Dalamud/Utility/Timing/TimingEvent.cs @@ -1,18 +1,27 @@ +using System.Threading; + namespace Dalamud.Utility.Timing; public class TimingEvent { + private static long IdCounter = 0; + + /// + /// Id of this timing event. + /// + public readonly long Id = Interlocked.Increment(ref IdCounter); + internal TimingEvent(string name) { this.Name = name; this.StartTime = Timings.Stopwatch.Elapsed.TotalMilliseconds; } - + /// /// Gets the time this timing started. /// public double StartTime { get; private set; } - + /// /// Gets the name of the timing. /// diff --git a/Dalamud/Utility/Timing/TimingHandle.cs b/Dalamud/Utility/Timing/TimingHandle.cs index a0b55b30f..dbc6e8ef1 100644 --- a/Dalamud/Utility/Timing/TimingHandle.cs +++ b/Dalamud/Utility/Timing/TimingHandle.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Generic; using System.Diagnostics; using System.Linq; @@ -8,7 +9,7 @@ namespace Dalamud.Utility.Timing; /// Class used for tracking a time interval taken. /// [DebuggerDisplay("{Name} - {Duration}")] -public sealed class TimingHandle : TimingEvent, IDisposable +public sealed class TimingHandle : TimingEvent, IDisposable, IComparable { /// /// Initializes a new instance of the class. @@ -16,28 +17,33 @@ public sealed class TimingHandle : TimingEvent, IDisposable /// The name of this timing. internal TimingHandle(string name) : base(name) { - this.Parent = Timings.Current.Value; - Timings.Current.Value = this; + this.Stack = Timings.TaskTimingHandles; - lock (Timings.AllTimings) + this.Parent = this.Stack.LastOrDefault(); + + if (this.Parent != null) { - if (this.Parent != null) - { - this.ChildCount++; - } - - this.EndTime = this.StartTime; - this.IsMainThread = ThreadSafety.IsMainThread; - - if (Timings.ActiveTimings.Count > 0) - { - this.Depth = Timings.ActiveTimings.Max(x => x.Depth) + 1; - } - - Timings.ActiveTimings.Add(this); + this.Parent.ChildCount++; + this.IdChain = new long[this.Parent.IdChain.Length + 1]; + Array.Copy(this.Parent.IdChain, this.IdChain, this.Parent.IdChain.Length); } + else + { + this.IdChain = new long[1]; + } + + this.IdChain[^1] = this.Id; + this.EndTime = this.StartTime; + this.IsMainThread = ThreadSafety.IsMainThread; + + this.Stack.Add(this); } + /// + /// Gets the id chain. + /// + public long[] IdChain { get; init; } + /// /// Gets the time this timing ended. /// @@ -48,16 +54,16 @@ public sealed class TimingHandle : TimingEvent, IDisposable /// public double Duration => Math.Floor(this.EndTime - this.StartTime); + /// + /// Gets the attached timing handle stack. + /// + public List Stack { get; private set; } + /// /// Gets the parent timing. /// public TimingHandle? Parent { get; private set; } - /// - /// Gets a value indicating whether or not this timing has already returned to its parent. - /// - public bool Returned { get; private set; } - /// /// Gets a value indicating whether or not this timing was started on the main thread. /// @@ -68,26 +74,39 @@ public sealed class TimingHandle : TimingEvent, IDisposable /// public uint ChildCount { get; private set; } - /// - /// Gets the depth of this timing. - /// - public uint Depth { get; private set; } - /// public void Dispose() { this.EndTime = Timings.Stopwatch.Elapsed.TotalMilliseconds; - Timings.Current.Value = this.Parent; - - lock (Timings.AllTimings) + this.Stack.Remove(this); + if (this.Duration > 1 || this.ChildCount > 0) { - if (this.Duration > 1 || this.ChildCount > 0) + lock (Timings.AllTimings) { - Timings.AllTimings.Add(this); - this.Returned = this.Parent != null && Timings.ActiveTimings.Contains(this.Parent); + Timings.AllTimings.Add(this, this); } - - Timings.ActiveTimings.Remove(this); } } + + /// + public int CompareTo(TimingHandle? other) + { + if (other == null) + return -1; + + var i = 0; + for (; i < this.IdChain.Length && i < other.IdChain.Length; i++) + { + if (this.IdChain[i] < other.IdChain[i]) + return -1; + if (this.IdChain[i] > other.IdChain[i]) + return 1; + } + + if (this.IdChain.Length < other.IdChain.Length) + return -1; + if (this.IdChain.Length > other.IdChain.Length) + return 1; + return 0; + } } diff --git a/Dalamud/Utility/Timing/Timings.cs b/Dalamud/Utility/Timing/Timings.cs index c644156f5..c35edf1ce 100644 --- a/Dalamud/Utility/Timing/Timings.cs +++ b/Dalamud/Utility/Timing/Timings.cs @@ -3,6 +3,7 @@ using System.Collections.Generic; using System.Diagnostics; using System.Runtime.CompilerServices; using System.Threading; +using System.Threading.Tasks; namespace Dalamud.Utility.Timing; @@ -19,19 +20,75 @@ public static class Timings /// /// All concluded timings. /// - internal static readonly List AllTimings = new(); + internal static readonly SortedList AllTimings = new(); - /// - /// All active timings. - /// - internal static readonly List ActiveTimings = new(); - internal static readonly List Events = new(); + private static readonly AsyncLocal>> taskTimingHandleStorage = new(); + /// - /// Current active timing entry. + /// Gets or sets all active timings of current thread. /// - internal static readonly AsyncLocal Current = new(); + internal static List TaskTimingHandles + { + get + { + if (taskTimingHandleStorage.Value == null || taskTimingHandleStorage.Value.Item1 != Task.CurrentId) + taskTimingHandleStorage.Value = Tuple.Create>(Task.CurrentId, new()); + return taskTimingHandleStorage.Value!.Item2!; + } + set => taskTimingHandleStorage.Value = Tuple.Create(Task.CurrentId, value); + } + + /// + /// Attaches timing handle to a Func{T}. + /// + /// Task to attach. + /// Return type. + /// Attached task. + public static Func AttachTimingHandle(Func task) + { + var outerTimingHandle = TaskTimingHandles; + return () => + { + T res = default(T); + var prev = TaskTimingHandles; + TaskTimingHandles = outerTimingHandle; + try + { + res = task(); + } + finally + { + TaskTimingHandles = prev; + } + + return res; + }; + } + + /// + /// Attaches timing handle to an Action. + /// + /// Task to attach. + /// Attached task. + public static Action AttachTimingHandle(Action task) + { + var outerTimingHandle = TaskTimingHandles; + return () => + { + var prev = TaskTimingHandles; + TaskTimingHandles = outerTimingHandle; + try + { + task(); + } + finally + { + TaskTimingHandles = prev; + } + }; + } /// /// Start a new timing. @@ -50,7 +107,7 @@ public static class Timings LineNumber = sourceLineNumber, }; } - + /// /// Record a one-time event. ///