Skip to content

Commit

Permalink
test: replace Serilog with Microsoft.Extensions.Diagnostics.Testing (#…
Browse files Browse the repository at this point in the history
  • Loading branch information
skwasjer authored Dec 15, 2024
1 parent 88d329e commit 1b3d679
Show file tree
Hide file tree
Showing 11 changed files with 229 additions and 192 deletions.
2 changes: 1 addition & 1 deletion src/Correlate.Core/Extensions/LoggerExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ internal static class LoggerExtensions
return logger.BeginScope(new CorrelatedLogScope(scopeKey, correlationId));
}

private sealed class CorrelatedLogScope : IReadOnlyList<KeyValuePair<string, object>>
internal sealed class CorrelatedLogScope : IReadOnlyList<KeyValuePair<string, object>>
{
private readonly string _scopeKey;
private readonly string _correlationId;
Expand Down
70 changes: 38 additions & 32 deletions test/Correlate.AspNetCore.Tests/AspNetCore/CorrelateFeatureTests.cs
Original file line number Diff line number Diff line change
@@ -1,12 +1,9 @@
using Correlate.Http;
using Correlate.Testing;
using Microsoft.AspNetCore.Http.Features;
using Microsoft.Extensions.Logging.Testing;
using Microsoft.Extensions.Options;
using Microsoft.Extensions.Primitives;
using Serilog;
using Serilog.Core;
using Serilog.Events;
using Serilog.Extensions.Logging;
using Serilog.Sinks.TestCorrelator;

namespace Correlate.AspNetCore;

Expand All @@ -19,19 +16,24 @@ public sealed class CorrelateFeatureTests : IDisposable
private readonly IActivityFactory _activityFactoryMock;
private readonly CorrelateOptions _options;
private readonly ICorrelationIdFactory _correlationIdFactory;
private readonly ServiceProvider _services;
private readonly FakeLogCollector _logCollector;

private static readonly string CorrelationId = Guid.NewGuid().ToString("D");

public CorrelateFeatureTests()
{
_httpContext = new DefaultHttpContext();
_httpContext.Features.Set<IHttpResponseFeature>(_responseFeature = new TestResponseFeature());
_responseFeature = new TestResponseFeature();
_httpContext.Features.Set<IHttpResponseFeature>(_responseFeature);

Logger serilog = new LoggerConfiguration()
.MinimumLevel.Verbose()
.WriteTo.TestCorrelator()
.CreateLogger();
var loggerFactory = new LoggerFactory(new[] { new SerilogLoggerProvider(serilog) });
_services = new ServiceCollection()
.AddLogging(
builder => builder
.SetMinimumLevel(LogLevel.Trace)
.AddFakeLogging()
.AddDebug())
.BuildServiceProvider();

_activityMock = Substitute.For<IActivity>();
_activityFactoryMock = Substitute.For<IActivityFactory>();
Expand All @@ -41,11 +43,18 @@ public CorrelateFeatureTests()
_correlationIdFactory.Create().Returns(CorrelationId);

_options = new CorrelateOptions();
_sut = new CorrelateFeature(loggerFactory, _correlationIdFactory, _activityFactoryMock, Options.Create(_options));
_sut = new CorrelateFeature(
_services.GetRequiredService<ILoggerFactory>(),
_correlationIdFactory,
_activityFactoryMock,
Options.Create(_options));

_logCollector = _services.GetFakeLogCollector();
}

public void Dispose()
{
_services.Dispose();
_responseFeature.Dispose();
}

Expand Down Expand Up @@ -219,27 +228,24 @@ public async Task When_correlating_has_started_it_should_create_logScope_with_co
_options.RequestHeaders.Should().NotBeNullOrEmpty();
const string expectedLogProperty = CorrelateConstants.CorrelationIdKey;

_logCollector.Clear();
using FakeLogContext context = _services.CreateLoggerContext();

// Act
using (TestCorrelator.CreateContext())
{
_sut.StartCorrelating(_httpContext);
await _responseFeature.FireOnSendingHeadersAsync();

// Assert
TestCorrelator.GetLogEventsFromCurrentContext()
.Should()
.ContainSingle(le => le.MessageTemplate.Text.StartsWith("Setting response header"))
.Which.Properties
.Should()
// this tests the {CorrelationId} from log message template in CorrelateFeature.LogRequestHeaderFound, not the one from log scope added by IActivityFactory.CreateActivity
.ContainSingle(p => p.Key == expectedLogProperty)
.Which.Value
.Should()
.BeOfType<ScalarValue>()
.Which.Value
.Should()
.Be(CorrelationId);
}
_sut.StartCorrelating(_httpContext);
await _responseFeature.FireOnSendingHeadersAsync();

// Assert
IReadOnlyList<FakeLogRecord> logEvents = _logCollector.GetSnapshot(context, true);
logEvents
.Should()
.ContainSingle(le => le.Message.StartsWith("Setting response header"))
.Which.StructuredState
.Should()
// this tests the {CorrelationId} from log message template in CorrelateFeature.LogRequestHeaderFound, not the one from log scope added by IActivityFactory.CreateActivity
.ContainKey(expectedLogProperty)
.WhoseValue.Should()
.Be(CorrelationId);

_correlationIdFactory.Received(1).Create();
_activityFactoryMock.Received(1).CreateActivity();
Expand Down
21 changes: 16 additions & 5 deletions test/Correlate.AspNetCore.Tests/AspNetCore/Fixtures/Startup.cs
Original file line number Diff line number Diff line change
@@ -1,16 +1,17 @@
using System.Diagnostics;
using System.Runtime.CompilerServices;
using Correlate.AspNetCore.Diagnostics;
using Correlate.DependencyInjection;
using Correlate.Testing;
using MockHttp;
using Serilog.Sinks.TestCorrelator;

namespace Correlate.AspNetCore.Fixtures;

public class Startup
{
private static readonly TestCorrelatorObserver Observer = new();

public static ITestCorrelatorContext? LastRequestContext => Observer.Current;
public static FakeLogContext? LastRequestContext { get => Observer.Current; }

public void ConfigureServices(IServiceCollection services)
{
Expand Down Expand Up @@ -45,7 +46,7 @@ private sealed class TestCorrelatorObserver
: IObserver<KeyValuePair<string, object?>>,
IDisposable
{
public ITestCorrelatorContext? Current { get; private set; }
public FakeLogContext? Current { get; private set; }

public void Dispose()
{
Expand All @@ -62,8 +63,18 @@ public void OnError(Exception error)

public void OnNext(KeyValuePair<string, object?> value)
{
Current?.Dispose();
Current ??= TestCorrelator.CreateContext();
if (value.Key == HttpRequestInDiagnosticsObserver.ActivityStartKey)
{
HttpContext? httpContext = Unsafe.As<HttpContext>(value.Value);
if (httpContext is not null)
{
Current = httpContext.RequestServices.CreateLoggerContext();
}
}
else if (value.Key == HttpRequestInDiagnosticsObserver.ActivityStopKey)
{
Current?.Dispose();
}
}

public static bool IsEnabled(string operationName)
Expand Down
Original file line number Diff line number Diff line change
@@ -1,33 +1,30 @@
using Microsoft.AspNetCore.Mvc.Testing;
using Serilog;
using Serilog.Core;
using Serilog.Events;

namespace Correlate.AspNetCore.Fixtures;

public class TestAppFactory<TStartup> : WebApplicationFactory<TStartup>
where TStartup : class
{
private readonly LoggingLevelSwitch _logLevelSwitch = new();
private LogEventLevel _lastLevel = LogEventLevel.Information;
private readonly DynamicLevelFilter _logLevelSwitch = new();
private LogLevel? _lastLevel = LogLevel.Information;

public bool LoggingEnabled
{
get => (int)_logLevelSwitch.MinimumLevel <= (int)LogEventLevel.Fatal;
get => (int?)_logLevelSwitch.LogLevel <= (int)LogLevel.Critical;
set
{
if (value)
{
_logLevelSwitch.MinimumLevel = _lastLevel;
_logLevelSwitch.LogLevel = _lastLevel;
}
else
{
if ((int)_lastLevel <= (int)LogEventLevel.Fatal)
if ((int?)_lastLevel <= (int)LogLevel.Critical)
{
_lastLevel = _logLevelSwitch.MinimumLevel;
_lastLevel = _logLevelSwitch.LogLevel;
}

_logLevelSwitch.MinimumLevel = (LogEventLevel)10 + (int)LogEventLevel.Fatal;
_logLevelSwitch.LogLevel = LogLevel.None;
}
}
}
Expand All @@ -36,13 +33,13 @@ protected override IHostBuilder CreateHostBuilder()
{
return Host.CreateDefaultBuilder()
.UseEnvironment(Environments.Development)
.UseSerilog((_, configuration) =>
{
configuration
.MinimumLevel.ControlledBy(_logLevelSwitch)
.WriteTo.TestCorrelator();
},
true)
.ConfigureLogging(builder => builder
.ClearProviders()
.SetMinimumLevel(LogLevel.Trace)
.AddFakeLogging()
.AddDebug()
.Services.Configure<LoggerFilterOptions>(opts => opts.Rules.Add(_logLevelSwitch))
)
.ConfigureWebHost(webHostBuilder => webHostBuilder
.UseStartup<TStartup>()
);
Expand All @@ -53,4 +50,26 @@ protected override void ConfigureWebHost(IWebHostBuilder builder)
builder.UseContentRoot(".");
base.ConfigureWebHost(builder);
}

private class DynamicLevelFilter : LoggerFilterRule
{
public static LogLevel? _level;

public DynamicLevelFilter() : base(
null,
null,
null,
(s, s1, arg3) =>
{
return arg3 >= _level;
})
{
}

public new LogLevel? LogLevel
{
get => _level;
set => _level = value;
}
}
}
34 changes: 18 additions & 16 deletions test/Correlate.AspNetCore.Tests/AspNetCore/IntegrationTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,14 @@
using System.Net.Http.Headers;
using Correlate.AspNetCore.Fixtures;
using Correlate.Http;
using Correlate.Testing;
using Correlate.Testing.FluentAssertions;
using Microsoft.AspNetCore.Mvc.Testing;
using Microsoft.AspNetCore.TestHost;
using Microsoft.Extensions.Logging.Testing;
using Microsoft.Extensions.Options;
using MockHttp;
using Serilog.Events;
using Serilog.Sinks.TestCorrelator;
using LoggerExtensions = Correlate.Extensions.LoggerExtensions;

namespace Correlate.AspNetCore;

Expand All @@ -19,6 +20,7 @@ public sealed class IntegrationTests : IClassFixture<TestAppFactory<Startup>>, I
private readonly TestAppFactory<Startup> _rootFactory;
private readonly CorrelateOptions _options;
private readonly MockHttpHandler _mockHttp;
private readonly FakeLogCollector _logCollector;

public IntegrationTests(TestAppFactory<Startup> factory)
{
Expand All @@ -35,6 +37,8 @@ public IntegrationTests(TestAppFactory<Startup> factory)
services.AddSingleton(Options.Create(_options));
})
);

_logCollector = _factory.Services.GetFakeLogCollector();
}

public void Dispose()
Expand Down Expand Up @@ -198,7 +202,7 @@ public async Task When_executing_multiple_requests_the_response_should_contain_n
}

[Fact]
public async Task When_logging_and_diagnostics_is_disabled_should_not_throw_in_controller()
public async Task When_logging_and_diagnostics_is_disabled_should_not_throw_in_controller_and_not_create_logScope()
{
_rootFactory.LoggingEnabled = false;

Expand All @@ -208,6 +212,9 @@ public async Task When_logging_and_diagnostics_is_disabled_should_not_throw_in_c

// Assert
await act.Should().NotThrowAsync<Exception>();

IReadOnlyList<FakeLogRecord> logEvents = _logCollector.GetSnapshot(true);
logEvents.Should().BeEmpty();
}

[Fact]
Expand All @@ -219,24 +226,19 @@ public async Task When_logging_should_have_correlationId_for_all_logged_events()
var request = new HttpRequestMessage();
request.Headers.Add(headerName, correlationId);

_logCollector.Clear();

// Act
HttpClient client = _factory.CreateClient();
await client.SendAsync(request);

// Assert
// ReSharper disable once SuggestVarOrType_Elsewhere
var logEvents = TestCorrelator.GetLogEventsFromContextGuid(Startup.LastRequestContext!.Guid).ToList();
logEvents.Should().HaveCountGreaterThan(2);

logEvents
.ToList()
.ForEach(le => le.Properties
.ToDictionary(kvp => kvp.Key, kvp => kvp.Value)
IReadOnlyList<FakeLogRecord> logEvents = _logCollector.GetSnapshot(Startup.LastRequestContext!.Id, true);
logEvents.Should()
.HaveCountGreaterThan(2)
.And.AllSatisfy(ev => ev.Scopes
.Should()
.ContainKey(CorrelateConstants.CorrelationIdKey)
.WhoseValue.Should()
.BeOfType<ScalarValue>()
.Which.Value.Should()
.Be(correlationId));
.ContainEquivalentOf(new LoggerExtensions.CorrelatedLogScope(CorrelateConstants.CorrelationIdKey, correlationId))
);
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -9,17 +9,14 @@

<PropertyGroup>
<Microsoft_AspNetCore_Mvc_Testing>9.0.0</Microsoft_AspNetCore_Mvc_Testing>
<Serilog_AspNetCore>9.0.0</Serilog_AspNetCore>
</PropertyGroup>

<PropertyGroup Condition="'$(TargetFramework)'=='net8.0'">
<Microsoft_AspNetCore_Mvc_Testing>8.0.8</Microsoft_AspNetCore_Mvc_Testing>
<Serilog_AspNetCore>8.0.0</Serilog_AspNetCore>
<Microsoft_AspNetCore_Mvc_Testing>8.0.11</Microsoft_AspNetCore_Mvc_Testing>
</PropertyGroup>

<ItemGroup>
<PackageReference Include="Microsoft.AspNetCore.Mvc.Testing" Version="$(Microsoft_AspNetCore_Mvc_Testing)" />
<PackageReference Include="Serilog.AspNetCore" Version="$(Serilog_AspNetCore)" />
</ItemGroup>

<ItemGroup>
Expand Down
Loading

0 comments on commit 1b3d679

Please sign in to comment.