Skip to content

Commit 4711543

Browse files
committed
perf: gate AvaloniaNLogSink at Warning, cache loggers
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.
1 parent 6786308 commit 4711543

1 file changed

Lines changed: 30 additions & 4 deletions

File tree

src/SharpFM/AvaloniaNLogSink.cs

Lines changed: 30 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
using System;
2+
using System.Collections.Concurrent;
23
using System.Diagnostics.CodeAnalysis;
34
using Avalonia;
45
using Avalonia.Logging;
@@ -8,14 +9,38 @@ namespace SharpFM;
89

910
/// <summary>
1011
/// Avalonia Log Sink that writes to NLog Loggers.
12+
///
13+
/// <para>Hot path note: Avalonia's framework code emits high-volume
14+
/// Verbose/Debug/Info events during layout, input, and rendering. The
15+
/// app's <c>nlog.config</c> blackholes <c>Avalonia*</c> events at those
16+
/// levels via a <c>final="true"</c> rule, so they have nowhere to go —
17+
/// but if <see cref="IsEnabled"/> says <c>true</c>, Avalonia still
18+
/// formats arguments and calls <see cref="Log"/>, which then walks NLog's
19+
/// rule engine before discarding. Profiling on a small script during
20+
/// typing showed this sink consuming ~318ms of inclusive CPU over a 30s
21+
/// trace — more than any other SharpFM-attributed path.</para>
22+
///
23+
/// <para>Two-part fix: gate <see cref="IsEnabled"/> at Warning so Avalonia
24+
/// short-circuits before the formatting work, and cache the per-source
25+
/// <see cref="ILogger"/> so the surviving events skip
26+
/// <see cref="LogManager.GetLogger(string)"/> on every call.</para>
1127
/// </summary>
1228
[ExcludeFromCodeCoverage]
1329
public class AvaloniaNLogSink : ILogSink
1430
{
31+
private static readonly ILogger DefaultLogger =
32+
LogManager.GetLogger(typeof(AvaloniaNLogSink).ToString());
33+
34+
private static readonly ConcurrentDictionary<Type, ILogger> LoggerCache = new();
35+
1536
/// <summary>
16-
/// AvaloniaNLogSink is always enabled.
37+
/// Gate at Warning to match the intent of <c>nlog.config</c>'s
38+
/// <c>Avalonia*</c> blackhole rule. Avalonia framework code routinely
39+
/// emits hundreds of Verbose/Debug/Info events per second during
40+
/// typing — none of which would reach a target anyway.
1741
/// </summary>
18-
public bool IsEnabled(LogEventLevel level, string area) => true;
42+
public bool IsEnabled(LogEventLevel level, string area) =>
43+
level >= LogEventLevel.Warning;
1944

2045
public void Log(LogEventLevel level, string area, object? source, string messageTemplate)
2146
{
@@ -24,8 +49,9 @@ public void Log(LogEventLevel level, string area, object? source, string message
2449

2550
public void Log(LogEventLevel level, string area, object? source, string messageTemplate, params object?[] propertyValues)
2651
{
27-
ILogger? logger = source is not null ? LogManager.GetLogger(source.GetType().ToString())
28-
: LogManager.GetLogger(typeof(AvaloniaNLogSink).ToString());
52+
ILogger logger = source is null
53+
? DefaultLogger
54+
: LoggerCache.GetOrAdd(source.GetType(), static t => LogManager.GetLogger(t.ToString()));
2955

3056
logger.Log(LogLevelToNLogLevel(level), $"{area}: {messageTemplate}", propertyValues);
3157
}

0 commit comments

Comments
 (0)