From 47115437cd0f957bb7c21fa89525b5d3c5fc56e2 Mon Sep 17 00:00:00 2001
From: Nate Bross <nate@brosstribe.com>
Date: Sat, 25 Apr 2026 14:12:50 -0500
Subject: [PATCH] perf: gate AvaloniaNLogSink at Warning, cache loggers
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Avalonia framework code emits high-volume Verbose/Debug/Info events
during layout, input, and rendering. nlog.config blackholes
Avalonia* events at those levels with a final="true" rule, so
they have nowhere to go — but IsEnabled returning true unconditionally
made Avalonia format arguments and call Log() before NLog discarded
them. dotnet-trace on a script-editor typing session showed the
sink consuming ~318ms of inclusive CPU over 30s, more than any
other app-attributed path.

Two changes:

1. IsEnabled now returns false below Warning. Avalonia short-circuits
   before formatting arguments, matching the intent of the existing
   nlog.config Avalonia* blackhole rule.
2. Per-source ILogger lookups go through a ConcurrentDictionary
   keyed by Type instead of LogManager.GetLogger(string) on each
   call. Smaller win after #1 since most calls don't reach Log
   anymore, but cheap enough to land together.

Surviving Warning/Error/Fatal events flow through unchanged.
---
 src/SharpFM/AvaloniaNLogSink.cs | 34 +++++++++++++++++++++++++++++----
 1 file changed, 30 insertions(+), 4 deletions(-)

diff --git a/src/SharpFM/AvaloniaNLogSink.cs b/src/SharpFM/AvaloniaNLogSink.cs
index cf42171..15224a8 100644
--- a/src/SharpFM/AvaloniaNLogSink.cs
+++ b/src/SharpFM/AvaloniaNLogSink.cs
@@ -1,4 +1,5 @@
 using System;
+using System.Collections.Concurrent;
 using System.Diagnostics.CodeAnalysis;
 using Avalonia;
 using Avalonia.Logging;
@@ -8,14 +9,38 @@ namespace SharpFM;
 
 /// <summary>
 /// Avalonia Log Sink that writes to NLog Loggers.
+///
+/// <para>Hot path note: Avalonia's framework code emits high-volume
+/// Verbose/Debug/Info events during layout, input, and rendering. The
+/// app's <c>nlog.config</c> blackholes <c>Avalonia*</c> events at those
+/// levels via a <c>final="true"</c> rule, so they have nowhere to go —
+/// but if <see cref="IsEnabled"/> says <c>true</c>, Avalonia still
+/// formats arguments and calls <see cref="Log"/>, which then walks NLog's
+/// rule engine before discarding. Profiling on a small script during
+/// typing showed this sink consuming ~318ms of inclusive CPU over a 30s
+/// trace — more than any other SharpFM-attributed path.</para>
+///
+/// <para>Two-part fix: gate <see cref="IsEnabled"/> at Warning so Avalonia
+/// short-circuits before the formatting work, and cache the per-source
+/// <see cref="ILogger"/> so the surviving events skip
+/// <see cref="LogManager.GetLogger(string)"/> on every call.</para>
 /// </summary>
 [ExcludeFromCodeCoverage]
 public class AvaloniaNLogSink : ILogSink
 {
+    private static readonly ILogger DefaultLogger =
+        LogManager.GetLogger(typeof(AvaloniaNLogSink).ToString());
+
+    private static readonly ConcurrentDictionary<Type, ILogger> LoggerCache = new();
+
     /// <summary>
-    /// AvaloniaNLogSink is always enabled.
+    /// Gate at Warning to match the intent of <c>nlog.config</c>'s
+    /// <c>Avalonia*</c> blackhole rule. Avalonia framework code routinely
+    /// emits hundreds of Verbose/Debug/Info events per second during
+    /// typing — none of which would reach a target anyway.
     /// </summary>
-    public bool IsEnabled(LogEventLevel level, string area) => true;
+    public bool IsEnabled(LogEventLevel level, string area) =>
+        level >= LogEventLevel.Warning;
 
     public void Log(LogEventLevel level, string area, object? source, string messageTemplate)
     {
@@ -24,8 +49,9 @@ public void Log(LogEventLevel level, string area, object? source, string message
 
     public void Log(LogEventLevel level, string area, object? source, string messageTemplate, params object?[] propertyValues)
     {
-        ILogger? logger = source is not null ? LogManager.GetLogger(source.GetType().ToString())
-            : LogManager.GetLogger(typeof(AvaloniaNLogSink).ToString());
+        ILogger logger = source is null
+            ? DefaultLogger
+            : LoggerCache.GetOrAdd(source.GetType(), static t => LogManager.GetLogger(t.ToString()));
 
         logger.Log(LogLevelToNLogLevel(level), $"{area}: {messageTemplate}", propertyValues);
     }