From d47251c34ba74d9c48a8f177f425ff6cad0a3e75 Mon Sep 17 00:00:00 2001 From: GA Date: Sun, 25 Oct 2026 15:33:41 +0100 Subject: [PATCH] perf: warm up plugins at startup and log startup timings Pay the first-use costs (JIT, static constructors, dependent assemblies) when QuickLook starts instead of on the first preview: - App: start a ProfileOptimization profile so the methods used by the previous run's startup are compiled on spare cores, in parallel. - PluginManager.WarmUp(): run every plugin's CanHandle once on the UI thread at idle priority, one plugin per dispatcher operation so a key press is never held up; then precompile every plugin assembly (RuntimeHelpers.PrepareMethod) on a lowest-priority background thread, which also covers Prepare and View. - Log how long plugin loading, plugin Init and the viewer window take at startup (and plugins that are slow to load or initialise) to QuickLook.Keyboard.log. KeyboardLog.cs (the QuickLook.Keyboard.log writer) is included because the timings are written there; it is identical to the copy added by the Raw Input keyboard change. Co-Authored-By: Claude Haiku 5.5 --- QuickLook/App.xaml.cs | 17 +++++ QuickLook/Helpers/KeyboardLog.cs | 102 ++++++++++++++++++++++++++++ QuickLook/PluginManager.cs | 111 +++++++++++++++++++++++++++++++ 3 files changed, 230 insertions(+) create mode 100644 QuickLook/Helpers/KeyboardLog.cs diff --git a/QuickLook/App.xaml.cs b/QuickLook/App.xaml.cs index 838e774e7..6e618d197 100644 --- a/QuickLook/App.xaml.cs +++ b/QuickLook/App.xaml.cs @@ -54,6 +54,17 @@ public partial class App : Application static App() { + // Compile what the previous run used at startup on spare cores, in parallel with the startup itself + try + { + System.Runtime.ProfileOptimization.SetProfileRoot(SettingHelper.LocalDataPath); + System.Runtime.ProfileOptimization.StartProfile("QuickLook.Startup.jitprofile"); + } + catch + { + // data folder not writable yet: EnsureFolderWritable reports it + } + // Set the process render mode based on the user setting var processRenderMode = SettingHelper.Get("ProcessRenderMode", failsafe: (int)RenderMode.Default, "QuickLook"); if (processRenderMode == (int)RenderMode.SoftwareOnly) @@ -359,9 +370,15 @@ private void RunListener(StartupEventArgs e) NativeMethods.QuickLook.Init(); + var sw = Stopwatch.StartNew(); PluginManager.GetInstance(); + var pluginsMs = sw.ElapsedMilliseconds; + sw.Restart(); ViewWindowManager.GetInstance(); + KeyboardLog.Write($"Startup: plugins {pluginsMs} ms, viewer window {sw.ElapsedMilliseconds} ms, since process start {(DateTime.Now - Process.GetCurrentProcess().StartTime).TotalMilliseconds:F0} ms"); KeystrokeDispatcher.GetInstance(); PipeServerManager.GetInstance(); + + PluginManager.GetInstance().WarmUp(); } } diff --git a/QuickLook/Helpers/KeyboardLog.cs b/QuickLook/Helpers/KeyboardLog.cs new file mode 100644 index 000000000..b92d2d510 --- /dev/null +++ b/QuickLook/Helpers/KeyboardLog.cs @@ -0,0 +1,102 @@ +// Copyright © 2017-2026 QL-Win Contributors +// +// This file is part of QuickLook program. +// +// This program is free software: you can redistribute it and/or modify +// it under the terms of the GNU General Public License as published by +// the Free Software Foundation, either version 3 of the License, or +// (at your option) any later version. +// +// This program is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU General Public License for more details. +// +// You should have received a copy of the GNU General Public License +// along with this program. If not, see . + +using QuickLook.Common.Helpers; +using System; +using System.Collections.Concurrent; +using System.IO; +using System.Text; +using System.Threading; + +namespace QuickLook.Helpers; + +/// +/// Diagnostic log for the keyboard pipeline, written to QuickLook.Keyboard.log in the data folder. +/// Only QuickLook's own keys and anomalies are logged, never other keystrokes. +/// +internal static class KeyboardLog +{ + private const long MAX_SIZE = 512 * 1024; + + /// Preview phases slower than this block switching to the next file and get logged. + private const long SLOW_PREVIEW_PHASE_MS = 100; + + private static readonly string LogPath = Path.Combine(SettingHelper.LocalDataPath, "QuickLook.Keyboard.log"); + + // Bounded so that a stuck disk can never make the keyboard hook wait or grow memory. + private static readonly BlockingCollection Queue = new(new ConcurrentQueue(), 1000); + + static KeyboardLog() + { + new Thread(WriteLoop) + { + IsBackground = true, + Name = "QuickLook.KeyboardLog", + Priority = ThreadPriority.BelowNormal, + }.Start(); + } + + /// + /// Never blocks; safe to call from inside the low-level keyboard hook. + /// + public static void Write(string message) + { + Queue.TryAdd($"{DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} [T{Thread.CurrentThread.ManagedThreadId}] {message}"); + } + + /// + /// Logs a preview phase that ran on the UI thread only when it was slow enough to delay + /// the next selection change, naming the plugin and file type, never the file name. + /// + public static void WriteIfSlow(string phase, long elapsedMs) + { + if (elapsedMs >= SLOW_PREVIEW_PHASE_MS) + Write($"Slow preview {phase}: {elapsedMs} ms"); + } + + private static void WriteLoop() + { + var batch = new StringBuilder(); + + foreach (var line in Queue.GetConsumingEnumerable()) + { + batch.AppendLine(line); + while (Queue.TryTake(out var more)) + batch.AppendLine(more); + + try + { + Directory.CreateDirectory(Path.GetDirectoryName(LogPath)!); + + var file = new FileInfo(LogPath); + if (file.Exists && file.Length > MAX_SIZE) + { + File.Delete(LogPath + ".old"); + File.Move(LogPath, LogPath + ".old"); + } + + File.AppendAllText(LogPath, batch.ToString()); + } + catch + { + // logging must never take QuickLook down + } + + batch.Clear(); + } + } +} diff --git a/QuickLook/PluginManager.cs b/QuickLook/PluginManager.cs index 7560dcc6e..db8c0bbe8 100644 --- a/QuickLook/PluginManager.cs +++ b/QuickLook/PluginManager.cs @@ -18,13 +18,18 @@ using QuickLook.Common.ExtensionMethods; using QuickLook.Common.Helpers; using QuickLook.Common.Plugin; +using QuickLook.Helpers; using System; using System.Collections.Generic; using System.Diagnostics; using System.IO; using System.Linq; using System.Reflection; +using System.Runtime.CompilerServices; +using System.Threading; +using System.Threading.Tasks; using System.Windows; +using System.Windows.Threading; using UnblockZoneIdentifier; namespace QuickLook; @@ -35,9 +40,13 @@ public sealed class PluginManager private PluginManager() { + var sw = Stopwatch.StartNew(); LoadPlugins(App.UserPluginPath); LoadPlugins(Path.Combine(App.AppPath, @"QuickLook.Plugin\")); + var loadMs = sw.ElapsedMilliseconds; + sw.Restart(); InitLoadedPlugins(); + KeyboardLog.Write($"Startup: plugins loaded in {loadMs} ms, initialized in {sw.ElapsedMilliseconds} ms"); } internal IViewer DefaultPlugin { get; } = new Plugin.InfoPanel.Plugin(); @@ -79,6 +88,104 @@ internal IViewer FindMatch(string path) return (matched ?? DefaultPlugin).GetType().CreateInstance(); } + /// + /// Pays the first-use costs (JIT, static constructors, dependent assemblies) at startup instead of + /// on the first preview. Each plugin's CanHandle runs once on the UI thread at idle priority, one plugin + /// per dispatcher operation so a key press is never held up; then every plugin assembly is compiled + /// ahead on a low-priority background thread, which also covers Prepare and View. + /// + internal void WarmUp() + { + var sw = Stopwatch.StartNew(); + var probe = Path.Combine(Path.GetTempPath(), "QuickLook.WarmUp.nonexistent.txt"); + + foreach (var plugin in LoadedPlugins) + { + Application.Current.Dispatcher.BeginInvoke(() => + { + try + { + plugin.CanHandle(probe); + } + catch + { + // ignored + } + }, DispatcherPriority.ApplicationIdle); + } + + Application.Current.Dispatcher.BeginInvoke(() => + { + KeyboardLog.Write($"Startup: CanHandle warm-up done in {sw.ElapsedMilliseconds} ms"); + + var assemblies = LoadedPlugins.Select(p => p.GetType().Assembly).Distinct().ToArray(); + new Thread(() => PrepareAssemblies(assemblies)) + { + IsBackground = true, + Name = "QuickLook.WarmUp", + Priority = ThreadPriority.Lowest, + }.Start(); + }, DispatcherPriority.ApplicationIdle); + } + + private static void PrepareAssemblies(Assembly[] assemblies) + { + var sw = Stopwatch.StartNew(); + var count = 0; + + foreach (var assembly in assemblies) + { + Type[] types; + try + { + types = assembly.GetTypes(); + } + catch (ReflectionTypeLoadException e) + { + types = [.. e.Types.Where(t => t != null)]; + } + + foreach (var type in types) + { + if (type.IsGenericTypeDefinition || type.IsInterface) + continue; + + const BindingFlags flags = BindingFlags.DeclaredOnly | BindingFlags.Instance | BindingFlags.Static + | BindingFlags.Public | BindingFlags.NonPublic; + + MethodBase[] methods; + try + { + methods = [.. type.GetMethods(flags), .. type.GetConstructors(flags)]; + } + catch + { + continue; + } + + foreach (var method in methods) + { + if (method.IsAbstract || method.ContainsGenericParameters + || (method.MethodImplementationFlags & MethodImplAttributes.InternalCall) != 0 + || method.GetMethodBody() == null) + continue; + + try + { + RuntimeHelpers.PrepareMethod(method.MethodHandle); + count++; + } + catch + { + // a missing optional dependency, etc.: that method is simply compiled on first use + } + } + } + } + + KeyboardLog.Write($"Startup: precompiled {count} plugin methods in {sw.ElapsedMilliseconds} ms"); + } + private void LoadPlugins(string folder) { if (!Directory.Exists(folder)) @@ -90,6 +197,7 @@ private void LoadPlugins(string folder) .ToList() .ForEach(lib => { + var sw = Stopwatch.StartNew(); try { Assembly.LoadFrom(lib) @@ -110,6 +218,7 @@ private void LoadPlugins(string folder) ProcessHelper.WriteLog($"Failed to load plugin {Path.GetFileName(lib)}: {ex}"); failedPlugins.Add((Path.GetFileName(lib), ex)); } + KeyboardLog.WriteIfSlow($"startup load {Path.GetFileNameWithoutExtension(lib)}", sw.ElapsedMilliseconds); }); LoadedPlugins = [.. LoadedPlugins.OrderByDescending(i => i.Priority)]; @@ -132,6 +241,7 @@ private void InitLoadedPlugins() { LoadedPlugins.ForEach(i => { + var sw = Stopwatch.StartNew(); try { i.Init(); @@ -140,6 +250,7 @@ private void InitLoadedPlugins() { ProcessHelper.WriteLog(e.ToString()); } + KeyboardLog.WriteIfSlow($"startup init {i.GetType().Namespace}", sw.ElapsedMilliseconds); }); }