public async Task GivenDefaultConfig_WhenRequestsExceedCapacity_DoesNotBlock()
{
var batchTiming = Stopwatch.StartNew();
using (var sink = new BackgroundWorkerSink(_logger, 1, blockWhenFull: false /*default*/))
{
// Cause a delay when emitting to the inner sink, allowing us to easily fill the queue to capacity
// while the first event is being propagated
var acceptInterval = TimeSpan.FromMilliseconds(500);
_innerSink.DelayEmit = acceptInterval;
var tenSecondsWorth = 10_000 / acceptInterval.TotalMilliseconds + 1;
for (int i = 0; i < tenSecondsWorth; i++)
{
var emissionTiming = Stopwatch.StartNew();
sink.Emit(CreateEvent());
emissionTiming.Stop();
// Should not block the caller when the queue is full
Assert.InRange(emissionTiming.ElapsedMilliseconds, 0, 200);
}
// Allow at least one to propagate
await Task.Delay(TimeSpan.FromSeconds(1)).ConfigureAwait(false);
Assert.NotEqual(0, ((IAsyncLogEventSinkInspector)sink).DroppedMessagesCount);
}
// Sanity check the overall timing
batchTiming.Stop();
// Need to add a significant fudge factor as AppVeyor build can result in `await` taking quite some time
Assert.InRange(batchTiming.ElapsedMilliseconds, 950, 2050);
}
public async Task GivenDefaultConfig_WhenRequestsExceedCapacity_ThenDropsEventsAndRecovers()
{
using (var sink = new BackgroundWorkerSink(_logger, 1, blockWhenFull: false /*default*/))
{
var acceptInterval = TimeSpan.FromMilliseconds(200);
_innerSink.DelayEmit = acceptInterval;
for (int i = 0; i < 2; i++)
{
sink.Emit(CreateEvent());
sink.Emit(CreateEvent());
await Task.Delay(acceptInterval);
sink.Emit(CreateEvent());
}
// Wait for the buffer and propagation to complete
await Task.Delay(TimeSpan.FromSeconds(1));
// Now verify things are back to normal; emit an event...
var finalEvent = CreateEvent();
sink.Emit(finalEvent);
// ... give adequate time for it to be guaranteed to have percolated through
await Task.Delay(TimeSpan.FromSeconds(1));
// At least one of the preceding events should not have made it through
var propagatedExcludingFinal =
from e in _innerSink.Events
where !Object.ReferenceEquals(finalEvent, e)
select e;
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, ((IAsyncLogEventSinkInspector)sink).DroppedMessagesCount);
}
}
public BackgroundWorkerSinkSpec()
{
_innerSink = new MemorySink();
var logger = new LoggerConfiguration().WriteTo.Sink(_innerSink).CreateLogger();
_sink = new BackgroundWorkerSink(logger, 10000);
}
/// <summary>
/// Configure a sink to be invoked asynchronously, on a background worker thread.
/// </summary>
/// <param name="loggerSinkConfiguration">The <see cref="LoggerSinkConfiguration"/> being configured.</param>
/// <param name="configure">An action that configures the wrapped sink.</param>
/// <param name="bufferSize">The size of the concurrent queue used to feed the background worker thread. If
/// the thread is unable to process events quickly enough and the queue is filled, subsequent events will be
/// dropped until room is made in the queue.</param>
/// <returns>A <see cref="LoggerConfiguration"/> allowing configuration to continue.</returns>
public static LoggerConfiguration Async(
this LoggerSinkConfiguration loggerSinkConfiguration,
Action <LoggerSinkConfiguration> configure,
int bufferSize = 10000)
{
var sublogger = new LoggerConfiguration();
sublogger.MinimumLevel.Is(LevelAlias.Minimum);
configure(sublogger.WriteTo);
var wrapper = new BackgroundWorkerSink(sublogger.CreateLogger(), bufferSize);
return(loggerSinkConfiguration.Sink(wrapper));
}
public async Task GivenConfiguredToBlock_WhenQueueFilled_ThenBlocks()
{
using (var sink = new BackgroundWorkerSink(_logger, 1, blockWhenFull: true))
{
// Cause a delay when emmitting to the inner sink, allowing us to fill the queue to capacity
// after the first event is popped
_innerSink.DelayEmit = TimeSpan.FromMilliseconds(300);
var events = new List <LogEvent>
{
CreateEvent(),
CreateEvent(),
CreateEvent()
};
int i = 0;
events.ForEach(e =>
{
var sw = Stopwatch.StartNew();
sink.Emit(e);
sw.Stop();
// Emit should return immediately the first time, since the queue is not yet full. On
// subsequent calls, the queue should be full, so we should be blocked
if (i > 0)
{
Assert.True(sw.ElapsedMilliseconds > 200, "Should block the caller when the queue is full");
}
});
await Task.Delay(TimeSpan.FromSeconds(2));
// No events should be dropped
Assert.Equal(3, _innerSink.Events.Count);
Assert.Equal(0, ((IAsyncLogEventSinkInspector)sink).DroppedMessagesCount);
}
}
