From 510db8d0461de5d863b6b08598a622f353fc300b Mon Sep 17 00:00:00 2001 From: Ruben Bartelink Date: Sun, 22 Apr 2018 02:46:19 +0100 Subject: [PATCH] Address nblumhardt review comments --- README.md | 14 ++++----- .../LoggerConfigurationAsyncExtensions.cs | 29 ++----------------- .../Sinks/Async/BackgroundWorkerSink.cs | 8 ++--- .../Sinks/Async/IAsyncLogEventSinkState.cs | 25 ++++++++++++++++ .../BackgroundWorkerSinkSpec.cs | 8 ++--- 5 files changed, 43 insertions(+), 41 deletions(-) create mode 100644 src/Serilog.Sinks.Async/Sinks/Async/IAsyncLogEventSinkState.cs diff --git a/README.md b/README.md index 234ce46..25f13bf 100644 --- a/README.md +++ b/README.md @@ -32,18 +32,18 @@ Because the memory buffer may contain events that have not yet been written to t ### Buffering & Dropping -The default memory buffer feeding the worker thread is capped to 10,000 items, after which arriving events will be dropped. To increase or decrease this limit, specify it when configuring the async sink. One can determine whether events have been dropped via `IQueueState.DroppedMessagesCount` (see Buffer Inspection interface below). +The default memory buffer feeding the worker thread is capped to 10,000 items, after which arriving events will be dropped. To increase or decrease this limit, specify it when configuring the async sink. One can determine whether events have been dropped via `Serilog.Async.IAsyncLogEventSinkState.DroppedMessagesCount` (see Sink State Inspection interface below). ```csharp // Reduce the buffer to 500 events .WriteTo.Async(a => a.File("logs/myapp.log"), bufferSize: 500) ``` -### Health Monitoring via the Buffer Inspection interface +### Health Monitoring via the Sink State Inspection interface -The Async wrapper is primarily intended to allow one to achieve minimal logging latency at all times, even when writing to sinks that may momentarily block during the course of their processing (e.g., a File sink might block for a low number of ms while flushing). The dropping behavior is an important failsafe in that it avoids having an unbounded buffering behaviour should logging frequency overwhelm the sink, or the sink ingestion throughput degrades to a major degree. +The `Async` wrapper is primarily intended to allow one to achieve minimal logging latency at all times, even when writing to sinks that may momentarily block during the course of their processing (e.g., a `File` Sink might block for a low number of ms while flushing). The dropping behavior is an important failsafe; it avoids having an unbounded buffering behaviour should logging frequency overwhelm the sink, or the sink ingestion throughput degrade to a major degree. -In practice, this configuration (assuming one provisions an adequate `bufferSize`) achieves an efficient and resilient logging configuration that can handle load gracefully. The key risk is of course that events may be dropped when the buffer threshold gets breached. The `inspector` allows one to arrange for your Application's health monitoring mechanism to actively validate that the buffer allocation is not being exceeded in practice. +In practice, this configuration (assuming one provisions an adequate `bufferSize`) achieves an efficient and resilient logging configuration that can handle load safely. The key risk is of course that events get be dropped when the buffer threshold gets breached. The `inspector` allows one to arrange for your Application's health monitoring mechanism to actively validate that the buffer allocation is not being exceeded in practice. ```csharp // Example check: log message to an out of band alarm channel if logging is showing signs of getting overwhelmed @@ -54,10 +54,10 @@ In practice, this configuration (assuming one provisions an adequate `bufferSize } // Allow a backlog of up to 10,000 items to be maintained (dropping extras if full) - .WriteTo.Async(a => a.File("logs/myapp.log"), inspector: out IQueueState inspector) ... + .WriteTo.Async(a => a.File("logs/myapp.log"), inspector: out Async.IAsyncLogEventSinkState inspector) ... - // Wire the inspector through to health monitoring and/or metrics in order to periodically emit a metric, raise an alarm, etc. - ... healthMonitoring.RegisterCheck(() => new PeriodicMonitorCheck(inspector)); + // Wire the inspector through to application health monitoring and/or metrics in order to periodically emit a metric, raise an alarm, etc. + ... HealthMonitor.RegisterAsyncLogSink(inspector); ``` ### Blocking diff --git a/src/Serilog.Sinks.Async/LoggerConfigurationAsyncExtensions.cs b/src/Serilog.Sinks.Async/LoggerConfigurationAsyncExtensions.cs index 2adeee4..ea53e0b 100644 --- a/src/Serilog.Sinks.Async/LoggerConfigurationAsyncExtensions.cs +++ b/src/Serilog.Sinks.Async/LoggerConfigurationAsyncExtensions.cs @@ -67,12 +67,12 @@ public static LoggerConfiguration Async( public static LoggerConfiguration Async( this LoggerSinkConfiguration loggerSinkConfiguration, Action configure, - out IQueueState inspector, + out IAsyncLogEventSinkState inspector, int bufferSize = 10000, bool blockWhenFull = false) { // Cannot assign directly to the out param from within the lambda, so we need a temp - IQueueState stateLens = null; + IAsyncLogEventSinkState stateLens = null; var result = LoggerSinkConfiguration.Wrap( loggerSinkConfiguration, wrappedSink => @@ -86,27 +86,4 @@ public static LoggerConfiguration Async( return result; } } - - /// - /// Provides a way to inspect the current state of Async wrapper's ingestion queue. - /// - public interface IQueueState - { - /// - /// Count of items currently awaiting ingestion. - /// - /// The Sink has been disposed. - int Count { get; } - - /// - /// Accumulated number of messages dropped due to attempted submission having breached limit. - /// - long DroppedMessagesCount { get; } - - /// - /// Maximum number of items permitted to be held in the buffer awaiting ingestion. - /// - /// The Sink has been disposed. - int BufferSize { get; } - } -} +} \ No newline at end of file diff --git a/src/Serilog.Sinks.Async/Sinks/Async/BackgroundWorkerSink.cs b/src/Serilog.Sinks.Async/Sinks/Async/BackgroundWorkerSink.cs index b7a741b..75239f5 100644 --- a/src/Serilog.Sinks.Async/Sinks/Async/BackgroundWorkerSink.cs +++ b/src/Serilog.Sinks.Async/Sinks/Async/BackgroundWorkerSink.cs @@ -8,7 +8,7 @@ namespace Serilog.Sinks.Async { - sealed class BackgroundWorkerSink : ILogEventSink, IQueueState, IDisposable + sealed class BackgroundWorkerSink : ILogEventSink, IAsyncLogEventSinkState, IDisposable { readonly ILogEventSink _pipeline; readonly bool _blockWhenFull; @@ -79,10 +79,10 @@ void Pump() } } - int IQueueState.Count => _queue.Count; + int IAsyncLogEventSinkState.BufferSize => _queue.BoundedCapacity; - int IQueueState.BufferSize => _queue.BoundedCapacity; + int IAsyncLogEventSinkState.Count => _queue.Count; - long IQueueState.DroppedMessagesCount => _droppedMessages; + long IAsyncLogEventSinkState.DroppedMessagesCount => _droppedMessages; } } diff --git a/src/Serilog.Sinks.Async/Sinks/Async/IAsyncLogEventSinkState.cs b/src/Serilog.Sinks.Async/Sinks/Async/IAsyncLogEventSinkState.cs new file mode 100644 index 0000000..f4ce960 --- /dev/null +++ b/src/Serilog.Sinks.Async/Sinks/Async/IAsyncLogEventSinkState.cs @@ -0,0 +1,25 @@ +namespace Serilog.Sinks.Async +{ + /// + /// Provides a way to monitor the state of Async wrapper's ingestion queue. + /// + public interface IAsyncLogEventSinkState + { + /// + /// Configured maximum number of items permitted to be held in the buffer awaiting ingestion. + /// + /// The Sink has been disposed. + int BufferSize { get; } + + /// + /// Current moment-in-time Count of items currently awaiting ingestion. + /// + /// The Sink has been disposed. + int Count { get; } + + /// + /// Accumulated number of messages dropped due to breach of limit. + /// + long DroppedMessagesCount { get; } + } +} \ No newline at end of file diff --git a/test/Serilog.Sinks.Async.Tests/BackgroundWorkerSinkSpec.cs b/test/Serilog.Sinks.Async.Tests/BackgroundWorkerSinkSpec.cs index 7071e79..9a0e572 100644 --- a/test/Serilog.Sinks.Async.Tests/BackgroundWorkerSinkSpec.cs +++ b/test/Serilog.Sinks.Async.Tests/BackgroundWorkerSinkSpec.cs @@ -106,7 +106,7 @@ public async Task GivenDefaultConfig_WhenRequestsExceedCapacity_DoesNotBlock() // Allow at least one to propagate await Task.Delay(TimeSpan.FromSeconds(1)).ConfigureAwait(false); - Assert.NotEqual(0, ((IQueueState)sink).DroppedMessagesCount); + Assert.NotEqual(0, ((IAsyncLogEventSinkState)sink).DroppedMessagesCount); } // Sanity check the overall timing batchTiming.Stop(); @@ -145,7 +145,7 @@ from e in _innerSink.Events Assert.InRange(2, 2 * 3 / 2 - 1, propagatedExcludingFinal.Count()); // Final event should have made it through Assert.Contains(_innerSink.Events, x => Object.ReferenceEquals(finalEvent, x)); - Assert.NotEqual(0, ((IQueueState)sink).DroppedMessagesCount); + Assert.NotEqual(0, ((IAsyncLogEventSinkState)sink).DroppedMessagesCount); } } @@ -184,7 +184,7 @@ public async Task GivenConfiguredToBlock_WhenQueueFilled_ThenBlocks() // No events should be dropped Assert.Equal(3, _innerSink.Events.Count); - Assert.Equal(0, ((IQueueState)sink).DroppedMessagesCount); + Assert.Equal(0, ((IAsyncLogEventSinkState)sink).DroppedMessagesCount); } } @@ -195,7 +195,7 @@ public void InspectorOutParameterAffordsHealthMonitoringHook() // 2 spaces in queue; 1 would make the second log entry eligible for dropping if consumer does not activate instantaneously var bufferSize = 2; using (var logger = new LoggerConfiguration() - .WriteTo.Async(w => w.Sink(collector), bufferSize: 2, inspector: out IQueueState inspector) + .WriteTo.Async(w => w.Sink(collector), bufferSize: 2, inspector: out IAsyncLogEventSinkState inspector) .CreateLogger()) { Assert.Equal(bufferSize, inspector.BufferSize);