⛲ log sink: refactor to improve efficiency

- Store formatted log messages instead of raw log events in queue.
- Avoid allocating strings when formatting timestamp and log level.

Author: database64128

YoutubeDl.Wpf/Models/QueuedTextBoxSink.cs

@@ -4,7 +4,6 @@
 using Serilog.Events;
 using System;
 using System.Collections.Generic;
-using System.Linq;
 using System.Reactive.Concurrency;
 
 namespace YoutubeDl.Wpf.Models;
@@ -13,61 +12,80 @@ public class QueuedTextBoxSink : ReactiveObject, ILogEventSink
 {
     private readonly object _locker = new();
     private readonly ObservableSettings _settings;
-    private readonly Queue<LogEvent> _queuedLogEvents;
+    private readonly Queue<string> _queuedLogMessages;
     private readonly IFormatProvider? _formatProvider;
+    private int _contentLength;
 
     [Reactive]
     public string Content { get; set; } = "";
 
     public QueuedTextBoxSink(ObservableSettings settings, IFormatProvider? formatProvider = null)
     {
         _settings = settings;
-        _queuedLogEvents = new(settings.LoggingMaxEntries);
+        _queuedLogMessages = new(settings.LoggingMaxEntries);
         _formatProvider = formatProvider;
     }
 
     public void Emit(LogEvent logEvent)
     {
         // Workaround for https://github.com/reactiveui/ReactiveUI/issues/3415 before upstream has a fix.
-        if (logEvent.MessageTemplate.Text.EndsWith(" is a POCO type and won't send change notifications, WhenAny will only return a single value!"))
+        if (logEvent.MessageTemplate.Text.EndsWith(" is a POCO type and won't send change notifications, WhenAny will only return a single value!", StringComparison.Ordinal))
         {
             return;
         }
 
+        var renderedMessage = logEvent.RenderMessage(_formatProvider);
+
+        // 2023-04-24T10:24:00.000+00:00 [I] Hi!
+        var length = 29 + 1 + 3 + 1 + renderedMessage.Length + Environment.NewLine.Length;
+        var message = string.Create(length, logEvent, (buf, logEvent) =>
+        {
+            if (!logEvent.Timestamp.TryFormat(buf, out var charsWritten, "yyyy-MM-ddTHH:mm:ss.fffzzz"))
+                throw new Exception("Failed to format timestamp for log message.");
+            if (charsWritten != 29)
+                throw new Exception($"Unexpected formatted timestamp length {charsWritten}.");
+
+            buf[29] = ' ';
+            buf[30] = '[';
+            buf[31] = logEvent.Level switch
+            {
+                LogEventLevel.Verbose => 'V',
+                LogEventLevel.Debug => 'D',
+                LogEventLevel.Information => 'I',
+                LogEventLevel.Warning => 'W',
+                LogEventLevel.Error => 'E',
+                LogEventLevel.Fatal => 'F',
+                _ => '?',
+            };
+            buf[32] = ']';
+            buf[33] = ' ';
+            renderedMessage.CopyTo(buf[34..]);
+            Environment.NewLine.CopyTo(buf[(34 + renderedMessage.Length)..]);
+        });
+
         lock (_locker)
         {
-            if (_queuedLogEvents.Count >= _settings.LoggingMaxEntries)
+            while (_queuedLogMessages.Count >= _settings.LoggingMaxEntries)
             {
-                _queuedLogEvents.Dequeue();
+                var dequeuedMessage = _queuedLogMessages.Dequeue();
+                _contentLength -= dequeuedMessage.Length;
             }
 
-            _queuedLogEvents.Enqueue(logEvent);
+            _queuedLogMessages.Enqueue(message);
+            _contentLength += message.Length;
 
-            var messages = _queuedLogEvents.Select(x => (x.Timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffzzz"), x.Level, x.RenderMessage(_formatProvider)));
-            var length = messages.Sum(x => x.Item1.Length + 1 + 3 + 1 + x.Item3.Length + Environment.NewLine.Length);
-            var text = string.Create(length, messages, (buf, msgs) =>
+            var content = string.Create(_contentLength, _queuedLogMessages, (buf, msgs) =>
             {
                 foreach (var msg in msgs)
                 {
-                    msg.Item1.CopyTo(buf);
-                    buf[msg.Item1.Length] = ' ';
-                    buf = buf[(msg.Item1.Length + 1)..];
-
-                    buf[0] = '[';
-                    buf[1] = msg.Level.ToString()[0];
-                    buf[2] = ']';
-                    buf[3] = ' ';
-                    buf = buf[4..];
-
-                    msg.Item3.CopyTo(buf);
-                    Environment.NewLine.CopyTo(buf[msg.Item3.Length..]);
-                    buf = buf[(msg.Item3.Length + Environment.NewLine.Length)..];
+                    msg.CopyTo(buf);
+                    buf = buf[msg.Length..];
                 }
             });
 
             RxApp.MainThreadScheduler.Schedule(() =>
             {
-                Content = text;
+                Content = content;
             });
         }
     }