Skip to content
Open
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
34 changes: 30 additions & 4 deletions src/SharpFM/AvaloniaNLogSink.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using System;
using System.Collections.Concurrent;
using System.Diagnostics.CodeAnalysis;
using Avalonia;
using Avalonia.Logging;
Expand All @@ -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)
{
Expand All @@ -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);
}
Expand Down
Loading