more tests

samples/PicoSampleApp/PicoSampleApp.sln

@@ -9,6 +9,8 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "PicoProfiler.Logging", "..\
 EndProject
 Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "PicoProfiler", "..\..\src\PicoProfiler\PicoProfiler.csproj", "{F56EF65C-0B2B-4364-9ADB-092FD1BDF715}"
 EndProject
+Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "PicoProfiler.Tests", "..\..\src\PicoProfiler.Tests\PicoProfiler.Tests.csproj", "{FC17C1B7-D16A-44DD-A791-401E86B08402}"
+EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
 		Debug|Any CPU = Debug|Any CPU
@@ -27,6 +29,10 @@ Global
 		{F56EF65C-0B2B-4364-9ADB-092FD1BDF715}.Debug|Any CPU.Build.0 = Debug|Any CPU
 		{F56EF65C-0B2B-4364-9ADB-092FD1BDF715}.Release|Any CPU.ActiveCfg = Release|Any CPU
 		{F56EF65C-0B2B-4364-9ADB-092FD1BDF715}.Release|Any CPU.Build.0 = Release|Any CPU
+		{FC17C1B7-D16A-44DD-A791-401E86B08402}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+		{FC17C1B7-D16A-44DD-A791-401E86B08402}.Debug|Any CPU.Build.0 = Debug|Any CPU
+		{FC17C1B7-D16A-44DD-A791-401E86B08402}.Release|Any CPU.ActiveCfg = Release|Any CPU
+		{FC17C1B7-D16A-44DD-A791-401E86B08402}.Release|Any CPU.Build.0 = Release|Any CPU
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE

src/PicoProfiler.Tests/PicoProfiler.Tests.csproj

@@ -11,6 +11,7 @@
 
   <ItemGroup>
     <PackageReference Include="FluentAssertions" Version="6.12.0" />
+    <PackageReference Include="Microsoft.Extensions.Logging" Version="6.0.0" />
     <PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.5.0" />
     <PackageReference Include="xunit" Version="2.4.2" />
     <PackageReference Include="xunit.runner.visualstudio" Version="2.4.5">
@@ -24,6 +25,7 @@
   </ItemGroup>
 
   <ItemGroup>
+    <ProjectReference Include="..\PicoProfiler.Logging\PicoProfiler.Logging.csproj" />
     <ProjectReference Include="..\PicoProfiler\PicoProfiler.csproj" />
   </ItemGroup>
 

src/PicoProfiler.Tests/PicoProfilerTests.cs → src/PicoProfiler.Tests/PicoProfilerCoreTests.cs

@@ -3,7 +3,7 @@
 
 namespace PicoProfiler.Tests;
 
-public class PicoProfilerTests
+public class PicoProfilerCoreTests
 {
     private static readonly TimeSpan DelayTime = TimeSpan.FromMilliseconds(50);
 

src/PicoProfiler.Tests/PicoProfilerLoggerTests.cs

@@ -0,0 +1,115 @@
+using Microsoft.Extensions.Logging;
+using PicoProfiler.Logging;
+using PicoProfiler.Tests.TestLogger;
+
+namespace PicoProfiler.Tests;
+
+public class PicoProfilerLoggerTests
+{
+    [Fact]
+    public void Outputs_To_Log()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler())
+        {
+        }
+
+        Assert.Equal(1, fixture.LogEntries.Count);
+    }
+
+    [Fact]
+    public void Uses_Provided_LogLevel()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler(logLevel: LogLevel.Debug))
+        {
+        }
+
+        Assert.Equal(LogLevel.Debug, fixture.LogEntries.Single().Level);
+    }
+
+    [Fact]
+    public void Uses_Default_ActionName()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler())
+        {
+        }
+
+        Assert.Contains(nameof(Uses_Default_ActionName), fixture.LogEntries.Single().Message);
+    }
+
+    [Fact]
+    public void Uses_Provided_ActionName()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler("fetching"))
+        {
+        }
+
+        Assert.Contains("fetching", fixture.LogEntries.Single().Message);
+    }
+
+    [Fact]
+    public void Uses_Configured_ActionName()
+    {
+        var fixture = new TestLoggerFixture();
+        LoggerOutputConfiguration.Instance.DefaultLogLevel = LogLevel.Critical;
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler())
+        {
+        }
+
+        Assert.Equal(LogLevel.Critical, fixture.LogEntries.Single().Level);
+    }
+
+    [Fact]
+    public void Uses_Default_Message()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler())
+        {
+        }
+
+        Assert.StartsWith($"{nameof(Uses_Default_Message)} finished in", fixture.LogEntries.Single().Message);
+    }
+
+    [Fact]
+    public void Uses_Provided_Message()
+    {
+        var fixture = new TestLoggerFixture();
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler(messageFactory: (name, time) => ("action {act} done!", new object[]{name})))
+        {
+        }
+
+        Assert.Equal($"action {nameof(Uses_Provided_Message)} done!", fixture.LogEntries.Single().Message);
+    }
+
+    [Fact]
+    public void Uses_Configured_Message()
+    {
+        var fixture = new TestLoggerFixture();
+        LoggerOutputConfiguration.Instance.DefaultActionMessageFactory =
+            (name, time) => ("action {act} done!", new object[] { name });
+
+        var logger = fixture.CreateLogger();
+        using (logger.StartProfiler())
+        {
+        }
+
+        Assert.Equal($"action {nameof(Uses_Configured_Message)} done!", fixture.LogEntries.Single().Message);
+    }
+}

src/PicoProfiler.Tests/TestLogger/TestLogger.cs

@@ -0,0 +1,22 @@
+using Microsoft.Extensions.Logging;
+
+namespace PicoProfiler.Tests.TestLogger;
+
+internal class TestLogger : ILogger
+{
+    private readonly TestLoggerProvider _provider;
+
+    public TestLogger(TestLoggerProvider provider)
+    {
+        _provider = provider;
+    }
+
+    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
+    {
+        _provider.Add(logLevel, formatter(state, exception));
+    }
+
+    public bool IsEnabled(LogLevel logLevel) => true;
+
+    public IDisposable BeginScope<TState>(TState state) => default;
+}

src/PicoProfiler.Tests/TestLogger/TestLoggerFixture.cs

@@ -0,0 +1,32 @@
+using Microsoft.Extensions.Logging;
+
+namespace PicoProfiler.Tests.TestLogger;
+
+internal class TestLoggerFixture
+{
+    private readonly TestLoggerProvider _provider = new();
+    private ILoggerFactory _factory = null!;
+
+    public IReadOnlyCollection<TestLoggerProvider.LogEntry> LogEntries
+    {
+        get
+        {
+            // disposing of factory is the only way to flush.
+            RecreateFactory();
+            return _provider.LogEntries.AsReadOnly();
+        }
+    }
+
+    public TestLoggerFixture()
+    {
+        RecreateFactory();
+    }
+
+    private void RecreateFactory()
+    {
+        _factory?.Dispose();
+        _factory = LoggerFactory.Create(x => x.SetMinimumLevel(LogLevel.Trace).AddProvider(_provider));
+    }
+
+    public ILogger CreateLogger() => _factory.CreateLogger<TestLoggerFixture>();
+}

src/PicoProfiler.Tests/TestLogger/TestLoggerProvider.cs

@@ -0,0 +1,21 @@
+using Microsoft.Extensions.Logging;
+
+namespace PicoProfiler.Tests.TestLogger;
+
+internal class TestLoggerProvider : ILoggerProvider
+{
+    public record struct LogEntry(LogLevel Level, string Message);
+
+    public List<LogEntry> LogEntries { get; } = new();
+
+    public void Add(LogLevel level, string message) => LogEntries.Add(new LogEntry(level, message));
+
+    public void Dispose()
+    {
+    }
+
+    public ILogger CreateLogger(string categoryName)
+    {
+        return new TestLogger(this);
+    }
+}