chore(profiling): instrument plugin-load hot paths (v1.4.9 R3)

Bump AutoTranslate-warmup and FilterAllTabs log-level from Debug to
Information so the xllog tail surfaces them without a Debug filter.
Wrap MessageStore.Connect and MessageStore.Migrate in Stopwatches so
the SQLite open and migration-chain costs are visible too.

Sub-Task 3.4 Befund on v1.4.8-baseline (4 reloads, medians):
- MessageStore.Connect: 50.5 ms
- MessageStore.Migrate:    2 ms
- MessageManager.FilterAllTabs: 68.5 ms
- AutoTranslate warmup:  108 ms
- UiBuilder HITCH:       108.9 ms

Outcome D — none of the three dominates the 200 ms threshold. The
ChatTwo "300 ms" comment for AutoTranslate is falsified at ~108 ms;
SQLite is not the bottleneck (52.5 ms total); FilterAllTabs runs on
the worker thread and only competes for CPU slots. The HITCH is left
unexplained by these probes, which keeps Hypothesis c (multi-window
WindowSystem.Draw initial pass) as the main R2 suspect to be
validated by the R1 lazy-window refactor.

Logs stay in as belt-and-suspenders for future plugin-load
regressions.
This commit is contained in:
2026-05-14 23:33:56 +02:00
parent 55120e6572
commit 6051e49307
3 changed files with 25 additions and 2 deletions
+4 -1
View File
@@ -206,7 +206,10 @@ internal class MessageManager : IAsyncDisposable
Plugin.LogProxy.Error(ex, "Error in FilterAllTabs");
}
Plugin.LogProxy.Debug($"FilterAllTabs took {stopwatch.ElapsedMilliseconds}ms");
// v1.4.9 R3 profiling: Information so the xllog tail surfaces this
// without a Debug filter. Belt-and-suspenders for future plugin-load
// regressions; remains in place after Sub-Task 3.4 Befund.
Plugin.LogProxy.Information($"FilterAllTabs took {stopwatch.ElapsedMilliseconds}ms");
});
}
+15
View File
@@ -237,14 +237,26 @@ internal class MessageStore : IDisposable
private SqliteConnection Connect()
{
// v1.4.9 R3 profiling: trace cost of SQLite open + pragma-apply. Paired
// with the Migrate-Stopwatch below — Connect alone is the cheap half
// (Open + a handful of PRAGMAs); the expensive half typically lives in
// Migrate, especially on a large DB after a schema bump.
var connectSw = System.Diagnostics.Stopwatch.StartNew();
var conn = new SqliteConnection(BuildConnectionString(DbPath));
conn.Open();
ApplyPragmas(conn);
connectSw.Stop();
_logger.Information($"MessageStore.Connect took {connectSw.ElapsedMilliseconds}ms");
return conn;
}
private void Migrate()
{
// v1.4.9 R3 profiling: trace cost of the schema-migration chain. On a
// large DB after a fresh schema bump this is the dominant SQLite cost
// at plugin-load, not Connect.
var migrateSw = System.Diagnostics.Stopwatch.StartNew();
using var cmd = Connection.CreateCommand();
cmd.CommandText = "PRAGMA user_version;";
var userVersion = Convert.ToInt32(cmd.ExecuteScalar());
@@ -276,6 +288,9 @@ internal class MessageStore : IDisposable
foreach (var migration in migrationsToDo)
migration();
migrateSw.Stop();
_logger.Information($"MessageStore.Migrate took {migrateSw.ElapsedMilliseconds}ms");
}
private void Migrate0()
+6 -1
View File
@@ -62,7 +62,12 @@ internal static class AutoTranslate
{
var sw = Stopwatch.StartNew();
AllEntries();
Plugin.LogProxy.Debug($"Warming up auto-translate took {sw.ElapsedMilliseconds}ms");
// v1.4.9 R3 profiling: Information so the xllog tail surfaces this
// without a Debug filter. Belt-and-suspenders for future plugin-load
// regressions; remains in place after Sub-Task 3.4 Befund.
Plugin.LogProxy.Information(
$"Warming up auto-translate took {sw.ElapsedMilliseconds}ms"
);
})
{
IsBackground = true,