Skip to content

Commit 16852b8

Browse files
committed
Should support concurrency better
Some significant allocation/performance improvements
1 parent b9cd05a commit 16852b8

File tree

8 files changed

+90
-58
lines changed

8 files changed

+90
-58
lines changed

sample/Startup.cs

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,5 @@
11
using Microsoft.AspNetCore.Builder;
22
using Microsoft.Extensions.DependencyInjection;
3-
using Microsoft.Extensions.Logging;
43
using SampleApi.Utils;
54

65
namespace SampleApi;
@@ -21,7 +20,7 @@ public void ConfigureServices(IServiceCollection services)
2120
}
2221

2322
// This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
24-
public void Configure(IApplicationBuilder app, ILogger<Startup> logger)
23+
public void Configure(IApplicationBuilder app)
2524
{
2625
app.UseRouting();
2726

src/Serilog.Sinks.XUnit.Injectable/Extensions/InjectableTestOutputExtension.cs

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -31,11 +31,9 @@ public static class InjectableTestOutputExtension
3131
public static LoggerConfiguration InjectableTestOutput(this LoggerSinkConfiguration sinkConfiguration, IInjectableTestOutputSink sink,
3232
LogEventLevel restrictedToMinimumLevel = LevelAlias.Minimum, LoggingLevelSwitch? levelSwitch = null)
3333
{
34-
if (sinkConfiguration == null)
35-
throw new ArgumentNullException(nameof(sinkConfiguration));
34+
ArgumentNullException.ThrowIfNull(sinkConfiguration, nameof(sinkConfiguration));
3635

37-
if (sink == null)
38-
throw new ArgumentNullException(nameof(sink));
36+
ArgumentNullException.ThrowIfNull(sink, nameof(sink));
3937

4038
return sinkConfiguration.Sink(sink, restrictedToMinimumLevel, levelSwitch);
4139
}
Lines changed: 56 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
using System;
2-
using System.Collections.Generic;
3-
using System.IO;
2+
using System.Collections.Concurrent;
3+
using System.Text;
4+
using System.Threading;
45
using Serilog.Events;
56
using Serilog.Formatting.Display;
67
using Serilog.Sinks.XUnit.Injectable.Abstract;
@@ -10,79 +11,87 @@
1011

1112
namespace Serilog.Sinks.XUnit.Injectable;
1213

13-
/// <inheritdoc cref="IInjectableTestOutputSink"/>
14+
///<inheritdoc cref="IInjectableTestOutputSink"/>
1415
public sealed class InjectableTestOutputSink : IInjectableTestOutputSink
1516
{
16-
private readonly Stack<LogEvent> _cachedLogEvents;
17-
private readonly MessageTemplateTextFormatter _textFormatter;
18-
private IMessageSink? _messageSink;
19-
private ITestOutputHelper? _testOutputHelper;
20-
21-
private const string _defaultConsoleOutputTemplate = "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}";
22-
23-
/// <summary>
24-
/// Use this ctor for injecting into the DI container
25-
/// </summary>
26-
/// <param name="outputTemplate">A message template describing the format used to write to the sink.
27-
/// the default is <code>"[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}"</code>.</param>
28-
/// <param name="formatProvider">Supplies culture-specific formatting information, or null.</param>
29-
/// <returns>Configuration object allowing method chaining.</returns>
30-
public InjectableTestOutputSink(string outputTemplate = _defaultConsoleOutputTemplate, IFormatProvider? formatProvider = null)
31-
{
32-
_cachedLogEvents = new Stack<LogEvent>();
17+
private readonly Lock _lock = new(); // guards flush+write
18+
private readonly ConcurrentQueue<LogEvent> _cache = new();
19+
private readonly MessageTemplateTextFormatter _fmt;
20+
21+
private volatile ITestOutputHelper? _helper; // set once, then read
22+
private volatile IMessageSink? _sink;
23+
24+
private const string _defaultTemplate = "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{Exception}";
25+
26+
[ThreadStatic] private static StringBuilder? _sb;
3327

34-
_textFormatter = new MessageTemplateTextFormatter(outputTemplate, formatProvider);
28+
[ThreadStatic] private static ReusableStringWriter? _sw;
29+
30+
public InjectableTestOutputSink(string outputTemplate = _defaultTemplate, IFormatProvider? formatProvider = null)
31+
{
32+
_fmt = new MessageTemplateTextFormatter(outputTemplate, formatProvider);
3533
}
3634

37-
public void Inject(ITestOutputHelper testOutputHelper, IMessageSink? messageSink = null)
35+
public void Inject(ITestOutputHelper helper, IMessageSink? sink = null)
3836
{
39-
_testOutputHelper = testOutputHelper;
40-
_messageSink = messageSink;
37+
ArgumentNullException.ThrowIfNull(helper);
38+
39+
// one short, guaranteed exit scope
40+
using Lock.Scope _ = _lock.EnterScope();
41+
42+
_helper = helper;
43+
_sink = sink;
44+
FlushLocked();
4145
}
4246

4347
public void Emit(LogEvent logEvent)
4448
{
45-
if (_testOutputHelper == null)
49+
ArgumentNullException.ThrowIfNull(logEvent);
50+
51+
// FAST-PATH: helper not yet available – enqueue without locking
52+
ITestOutputHelper? helperSnapshot = _helper; // direct volatile read
53+
54+
if (helperSnapshot is null)
4655
{
47-
_cachedLogEvents.Push(logEvent);
56+
_cache.Enqueue(logEvent);
4857
return;
4958
}
5059

51-
FlushCachedLogEvents();
52-
Write(logEvent);
60+
61+
using Lock.Scope _ = _lock.EnterScope();
62+
63+
// Flush anything another thread buffered before we obtained the scope
64+
FlushLocked();
65+
WriteLocked(logEvent);
5366
}
5467

55-
private void FlushCachedLogEvents()
68+
private void FlushLocked()
5669
{
57-
while (_cachedLogEvents.Count > 0)
58-
{
59-
Write(_cachedLogEvents.Pop());
60-
}
70+
while (_cache.TryDequeue(out LogEvent? queued))
71+
WriteLocked(queued);
6172
}
6273

63-
/// <summary>
64-
/// Emits the provided log event from a sink
65-
/// </summary>
66-
/// <param name="logEvent">The event being logged</param>
67-
private void Write(LogEvent logEvent)
74+
private void WriteLocked(LogEvent evt)
6875
{
69-
if (logEvent == null)
70-
throw new ArgumentNullException(nameof(logEvent));
76+
// rent / reset thread-local buffers
77+
StringBuilder sb = _sb ??= new StringBuilder(256);
78+
sb.Clear();
7179

72-
var renderSpace = new StringWriter();
73-
_textFormatter.Format(logEvent, renderSpace);
80+
ReusableStringWriter sw = _sw ??= new ReusableStringWriter(sb);
81+
sw.Reset();
7482

75-
string message = renderSpace.ToString().Trim();
83+
_fmt.Format(evt, sw);
84+
var message = sb.ToString(); // single unavoidable alloc
7685

77-
_messageSink?.OnMessage(new DiagnosticMessage(message));
86+
_sink?.OnMessage(new DiagnosticMessage(message));
7887

7988
try
8089
{
81-
_testOutputHelper?.WriteLine(message);
90+
_helper?.WriteLine(message);
8291
}
83-
catch (InvalidOperationException ex)
92+
catch (InvalidOperationException)
8493
{
85-
// Typically no test is active
94+
/* test already finished – swallow */
8695
}
8796
}
8897
}
Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,13 @@
1+
using System.IO;
2+
using System.Text;
3+
4+
namespace Serilog.Sinks.XUnit.Injectable;
5+
6+
internal sealed class ReusableStringWriter : StringWriter
7+
{
8+
public ReusableStringWriter(StringBuilder sb) : base(sb)
9+
{
10+
}
11+
12+
public void Reset() => GetStringBuilder().Clear();
13+
}

src/Serilog.Sinks.XUnit.Injectable/Serilog.Sinks.XUnit.Injectable.csproj

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,9 @@
1-
<?xml version="1.0" encoding="utf-8"?><Project Sdk="Microsoft.NET.Sdk">
1+
<?xml version="1.0" encoding="utf-8"?>
2+
3+
<Project Sdk="Microsoft.NET.Sdk">
24

35
<PropertyGroup>
4-
<TargetFrameworks>net8.0;net9.0</TargetFrameworks>
6+
<TargetFrameworks>net9.0</TargetFrameworks>
57
<Nullable>enable</Nullable>
68
<NoWarn>$(NoWarn);1591</NoWarn>
79
<Platforms>AnyCPU</Platforms>
@@ -30,7 +32,8 @@
3032
<LangVersion>latest</LangVersion>
3133
<PackageReadmeFile>README.md</PackageReadmeFile>
3234
<PackageIcon>icon.png</PackageIcon>
33-
<ContinuousIntegrationBuild>true</ContinuousIntegrationBuild></PropertyGroup>
35+
<ContinuousIntegrationBuild>true</ContinuousIntegrationBuild>
36+
</PropertyGroup>
3437
<ItemGroup>
3538
<None Include="..\..\README.md" Pack="true" PackagePath="\" />
3639
<None Include="..\..\icon.png" Pack="true" PackagePath="\" />

test/Integration/ApiFixture.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,7 @@ namespace Serilog.Sinks.XUnit.Injectable.Tests.Integration;
1111

1212
public class ApiFixture : IAsyncLifetime
1313
{
14-
public WebApplicationFactory<Program> ApiFactory { get; set; } = default!;
14+
public WebApplicationFactory<Program> ApiFactory { get; set; } = null!;
1515

1616
public ValueTask InitializeAsync()
1717
{

test/Integration/ApiTests.cs

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,4 +24,14 @@ public async Task Get_should_have_log_messages_and_be_successful()
2424
HttpResponseMessage response = await _client.GetAsync("/", TestContext.Current.CancellationToken);
2525
response.EnsureSuccessStatusCode();
2626
}
27+
28+
[Fact]
29+
public async Task Get_concurrent()
30+
{
31+
Task<HttpResponseMessage> task1= _client.GetAsync("/", TestContext.Current.CancellationToken);
32+
Task<HttpResponseMessage> task2 = _client.GetAsync("/", TestContext.Current.CancellationToken);
33+
Task<HttpResponseMessage> task3 = _client.GetAsync("/", TestContext.Current.CancellationToken);
34+
35+
await Task.WhenAll(task1, task2, task3);
36+
}
2737
}

test/Unit/UnitFixture.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,7 @@ namespace Serilog.Sinks.XUnit.Injectable.Tests.Unit;
1010

1111
public class UnitFixture : IAsyncLifetime
1212
{
13-
public ServiceProvider ServiceProvider { get; set; } = default!;
13+
public ServiceProvider ServiceProvider { get; set; } = null!;
1414

1515
protected IServiceCollection Services { get; set; }
1616

0 commit comments

Comments
 (0)