Enabling console logger queue length and mode to be configurable

src/libraries/Microsoft.Extensions.Logging.Console/ref/Microsoft.Extensions.Logging.Console.cs

@@ -62,6 +62,8 @@ public ConsoleLoggerOptions() { }
  [System.ObsoleteAttribute("ConsoleLoggerOptions.IncludeScopes has been deprecated. Use ConsoleFormatterOptions.IncludeScopes instead.")]
  public bool IncludeScopes { get { throw null; } set { } }
  public Microsoft.Extensions.Logging.LogLevel LogToStandardErrorThreshold { get { throw null; } set { } }
+ public int MaxQueueLength { get { throw null; } set { } }
+ public Microsoft.Extensions.Logging.Console.ConsoleLoggerQueueFullMode QueueFullMode { get { throw null; } set { } }
  [System.ObsoleteAttribute("ConsoleLoggerOptions.TimestampFormat has been deprecated. Use ConsoleFormatterOptions.TimestampFormat instead.")]
  public string? TimestampFormat { get { throw null; } set { } }
  [System.ObsoleteAttribute("ConsoleLoggerOptions.UseUtcTimestamp has been deprecated. Use ConsoleFormatterOptions.UseUtcTimestamp instead.")]
@@ -77,6 +79,11 @@ public ConsoleLoggerProvider(Microsoft.Extensions.Options.IOptionsMonitor<Micros
  public void Dispose() { }
  public void SetScopeProvider(Microsoft.Extensions.Logging.IExternalScopeProvider scopeProvider) { }
  }
+ public enum ConsoleLoggerQueueFullMode
+ {
+ Wait = 0,
+ DropWrite = 1,
+ }
  public partial class JsonConsoleFormatterOptions : Microsoft.Extensions.Logging.Console.ConsoleFormatterOptions
  {
  public JsonConsoleFormatterOptions() { }

src/libraries/Microsoft.Extensions.Logging.Console/src/ConsoleLoggerOptions.cs

@@ -63,5 +63,42 @@ public ConsoleLoggerFormat Format
  /// </summary>
  [System.ObsoleteAttribute("ConsoleLoggerOptions.UseUtcTimestamp has been deprecated. Use ConsoleFormatterOptions.UseUtcTimestamp instead.")]
  public bool UseUtcTimestamp { get; set; }
+
+ private ConsoleLoggerQueueFullMode _queueFullMode = ConsoleLoggerQueueFullMode.Wait;
+ /// <summary>
+ /// Gets or sets the desired console logger behavior when the queue becomes full. Defaults to <c>Wait</c>.
+ /// </summary>
+ public ConsoleLoggerQueueFullMode QueueFullMode
+ {
+ get => _queueFullMode;
+ set
+ {
+ if (value != ConsoleLoggerQueueFullMode.Wait && value != ConsoleLoggerQueueFullMode.DropWrite)
+ {
+ throw new ArgumentOutOfRangeException(SR.Format(SR.QueueModeNotSupported, nameof(value)));
+ }
+ _queueFullMode = value;
+ }
+ }
+
+ internal const int DefaultMaxQueueLengthValue = 2500;
+ private int _maxQueuedMessages = DefaultMaxQueueLengthValue;
+
+ /// <summary>
+ /// Gets or sets the maximum number of enqueued messages. Defaults to 2500.
+ /// </summary>
+ public int MaxQueueLength
+ {
+ get => _maxQueuedMessages;
+ set
+ {
+ if (value <= 0)
+ {
+ throw new ArgumentOutOfRangeException(SR.Format(SR.MaxQueueLengthBadValue, nameof(value)));
+ }
+
+ _maxQueuedMessages = value;
+ }
+ }
  }
 }

src/libraries/Microsoft.Extensions.Logging.Console/src/ConsoleLoggerProcessor.cs

@@ -2,8 +2,10 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System;
-using System.Collections.Concurrent;
+using System.Collections.Generic;
+using System.Diagnostics;
 using System.Diagnostics.CodeAnalysis;
+using System.Diagnostics.Metrics;
 using System.Runtime.Versioning;
 using System.Threading;
 
@@ -12,16 +14,56 @@ namespace Microsoft.Extensions.Logging.Console
  [UnsupportedOSPlatform("browser")]
  internal class ConsoleLoggerProcessor : IDisposable
  {
- private const int _maxQueuedMessages = 1024;
+ private readonly Queue<LogMessageEntry> _messageQueue;
+ private volatile int _messagesDropped;
+ private bool _isAddingCompleted;
+ private int _maxQueuedMessages = ConsoleLoggerOptions.DefaultMaxQueueLengthValue;
+ public int MaxQueueLength
+ {
+ get => _maxQueuedMessages;
+ set
+ {
+ if (value <= 0)
+ {
+ throw new ArgumentOutOfRangeException(SR.Format(SR.MaxQueueLengthBadValue, nameof(value)));
+ }
 
- private readonly BlockingCollection<LogMessageEntry> _messageQueue = new BlockingCollection<LogMessageEntry>(_maxQueuedMessages);
+ lock (_messageQueue)
+ {
+ _maxQueuedMessages = value;
+ Monitor.PulseAll(_messageQueue);
+ }
+ }
+ }
+ private ConsoleLoggerQueueFullMode _fullMode = ConsoleLoggerQueueFullMode.Wait;
+ public ConsoleLoggerQueueFullMode FullMode
+ {
+ get => _fullMode;
+ set
+ {
+ if (value != ConsoleLoggerQueueFullMode.Wait && value != ConsoleLoggerQueueFullMode.DropWrite)
+ {
+ throw new ArgumentOutOfRangeException(SR.Format(SR.QueueModeNotSupported, nameof(value)));
+ }
+
+ lock (_messageQueue)
+ {
+ // _fullMode is used inside the lock and is safer to guard setter with lock as well
+ // this set is not expected to happen frequently
+ _fullMode = value;
+ }
+ }
+ }
  private readonly Thread _outputThread;
 
  public IConsole Console { get; }
  public IConsole ErrorConsole { get; }
 
- public ConsoleLoggerProcessor(IConsole console, IConsole errorConsole)
+ public ConsoleLoggerProcessor(IConsole console, IConsole errorConsole, ConsoleLoggerQueueFullMode fullMode, int maxQueueLength)
  {
+ _messageQueue = new Queue<LogMessageEntry>();
+ FullMode = fullMode;
+ MaxQueueLength = maxQueueLength;
  Console = console;
  ErrorConsole = errorConsole;
  // Start Console message queue processor
@@ -35,59 +77,128 @@ public ConsoleLoggerProcessor(IConsole console, IConsole errorConsole)
 
  public virtual void EnqueueMessage(LogMessageEntry message)
  {
- if (!_messageQueue.IsAddingCompleted)
+ // cannot enqueue when adding is completed
+ if (!Enqueue(message))
  {
- try
- {
- _messageQueue.Add(message);
- return;
- }
- catch (InvalidOperationException) { }
+ WriteMessage(message);
  }
+ }
 
- // Adding is completed so just log the message
+ // internal for testing
+ internal void WriteMessage(LogMessageEntry entry)
+ {
  try
  {
- WriteMessage(message);
+ IConsole console = entry.LogAsError ? ErrorConsole : Console;
+ console.Write(entry.Message);
+ }
+ catch
+ {
+ CompleteAdding();
  }
- catch (Exception) { }
  }
 
- // for testing
- internal void WriteMessage(LogMessageEntry entry)
+ private void ProcessLogQueue()
  {
- IConsole console = entry.LogAsError ? ErrorConsole : Console;
- console.Write(entry.Message);
+ while (TryDequeue(out LogMessageEntry message))
+ {
+ WriteMessage(message);
+ }
  }
 
- private void ProcessLogQueue()
+ public bool Enqueue(LogMessageEntry item)
  {
- try
+ lock (_messageQueue)
  {
- foreach (LogMessageEntry message in _messageQueue.GetConsumingEnumerable())
+ while (_messageQueue.Count >= MaxQueueLength && !_isAddingCompleted)
+ {
+ if (FullMode == ConsoleLoggerQueueFullMode.DropWrite)
+ {
+ _messagesDropped++;
+ return true;
+ }
+
+ Debug.Assert(FullMode == ConsoleLoggerQueueFullMode.Wait);
+ Monitor.Wait(_messageQueue);
+ }
+
+ if (!_isAddingCompleted)
  {
- WriteMessage(message);
+ Debug.Assert(_messageQueue.Count < MaxQueueLength);
+ bool startedEmpty = _messageQueue.Count == 0;
+ if (_messagesDropped > 0)
+ {
+ _messageQueue.Enqueue(new LogMessageEntry(
+ message: SR.Format(SR.WarningMessageOnDrop + Environment.NewLine, _messagesDropped),
+ logAsError: true
+ ));
+
+ _messagesDropped = 0;
+ }
+
+ // if we just logged the dropped message warning this could push the queue size to
+ // MaxLength + 1, that shouldn't be a problem. It won't grow any further until it is less than
+ // MaxLength once again.
+ _messageQueue.Enqueue(item);
+
+ // if the queue started empty it could be at 1 or 2 now
+ if (startedEmpty)
+ {
+ // pulse for wait in Dequeue
+ Monitor.PulseAll(_messageQueue);
+ }
+
+ return true;
  }
  }
- catch
+
+ return false;
+ }
+
+ public bool TryDequeue(out LogMessageEntry item)
+ {
+ lock (_messageQueue)
  {
- try
+ while (_messageQueue.Count == 0 && !_isAddingCompleted)
+ {
+ Monitor.Wait(_messageQueue);
+ }
+
+ if (_messageQueue.Count > 0 && !_isAddingCompleted)
  {
- _messageQueue.CompleteAdding();
+ item = _messageQueue.Dequeue();
+ if (_messageQueue.Count == MaxQueueLength - 1)
+ {
+ // pulse for wait in Enqueue
+ Monitor.PulseAll(_messageQueue);
+ }
+
+ return true;
  }
- catch { }
+
+ item = default;
+ return false;
  }
  }
 
  public void Dispose()
  {
- _messageQueue.CompleteAdding();
+ CompleteAdding();
 
  try
  {
  _outputThread.Join(1500); // with timeout in-case Console is locked by user input
  }
  catch (ThreadStateException) { }
  }
+
+ private void CompleteAdding()
+ {
+ lock (_messageQueue)
+ {
+ Monitor.PulseAll(_messageQueue);
+ _isAddingCompleted = true;
+ }
+ }
  }
 }

src/libraries/Microsoft.Extensions.Logging.Console/src/ConsoleLoggerProvider.cs

@@ -43,10 +43,6 @@ public ConsoleLoggerProvider(IOptionsMonitor<ConsoleLoggerOptions> options, IEnu
  _options = options;
  _loggers = new ConcurrentDictionary<string, ConsoleLogger>();
  SetFormatters(formatters);
-
- ReloadLoggerOptions(options.CurrentValue);
- _optionsReloadToken = _options.OnChange(ReloadLoggerOptions);
-
  IConsole? console;
  IConsole? errorConsole;
  if (DoesConsoleSupportAnsi())
@@ -59,7 +55,14 @@ public ConsoleLoggerProvider(IOptionsMonitor<ConsoleLoggerOptions> options, IEnu
  console = new AnsiParsingLogConsole();
  errorConsole = new AnsiParsingLogConsole(stdErr: true);
  }
- _messageQueue = new ConsoleLoggerProcessor(console, errorConsole);
+ _messageQueue = new ConsoleLoggerProcessor(
+ console,
+ errorConsole,
+ options.CurrentValue.QueueFullMode,
+ options.CurrentValue.MaxQueueLength);
+
+ ReloadLoggerOptions(options.CurrentValue);
+ _optionsReloadToken = _options.OnChange(ReloadLoggerOptions);
  }
 
  [UnsupportedOSPlatformGuard("windows")]
@@ -123,6 +126,9 @@ private void ReloadLoggerOptions(ConsoleLoggerOptions options)
 #pragma warning restore CS0618
  }
 
+ _messageQueue.FullMode = options.QueueFullMode;
+ _messageQueue.MaxQueueLength = options.MaxQueueLength;
+
  foreach (KeyValuePair<string, ConsoleLogger> logger in _loggers)
  {
  logger.Value.Options = options;

src/libraries/Microsoft.Extensions.Logging.Console/src/ConsoleLoggerQueueFullMode.cs

@@ -0,0 +1,20 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+
+namespace Microsoft.Extensions.Logging.Console
+{
+ /// <summary>
+ /// Determines the console logger behavior when the queue becomes full.
+ /// </summary>
+ public enum ConsoleLoggerQueueFullMode
+ {
+ /// <summary>
+ /// Blocks the logging threads once the queue limit is reached.
+ /// </summary>
+ Wait,
+ /// <summary>
+ /// Drops new log messages when the queue is full.
+ /// </summary>
+ DropWrite
+ }
+}

src/libraries/Microsoft.Extensions.Logging.Console/src/Resources/Strings.resx

@@ -120,4 +120,13 @@
  <data name="BufferMaximumSizeExceeded" xml:space="preserve">
  <value>Cannot allocate a buffer of size {0}.</value>
  </data>
+ <data name="QueueModeNotSupported" xml:space="preserve">
+ <value>{0} is not a supported queue mode value.</value>
+ </data>
+ <data name="MaxQueueLengthBadValue" xml:space="preserve">
+ <value>{0} must be larger than zero.</value>
+ </data>
+ <data name="WarningMessageOnDrop" xml:space="preserve">
+ <value>{0} message(s) dropped because of queue size limit. Increase the queue size or decrease logging verbosity to avoid this. You may change `ConsoleLoggerQueueFullMode` to stop dropping messages.</value>
+ </data>
 </root>

src/libraries/Microsoft.Extensions.Logging.Console/tests/Microsoft.Extensions.Logging.Console.Tests/ConsoleFormatterTests.cs

@@ -38,7 +38,9 @@ internal static (ConsoleLogger Logger, ConsoleSink Sink, ConsoleSink ErrorSink,
  var errorSink = new ConsoleSink();
  var console = new TestConsole(sink);
  var errorConsole = new TestConsole(errorSink);
- var consoleLoggerProcessor = new TestLoggerProcessor(console, errorConsole);
+ var bufferMode = options == null ? ConsoleLoggerQueueFullMode.Wait : options.QueueFullMode;
+ var maxQueueLength = options == null ? ConsoleLoggerOptions.DefaultMaxQueueLengthValue : options.MaxQueueLength;
+ var consoleLoggerProcessor = new TestLoggerProcessor(console, errorConsole, bufferMode, maxQueueLength);
 
  var formatters = new ConcurrentDictionary<string, ConsoleFormatter>(ConsoleLoggerTest.GetFormatters(simpleOptions, systemdOptions, jsonOptions).ToDictionary(f => f.Name));