diff --git a/src/Foundatio.TestHarness/Queue/QueueTestBase.cs b/src/Foundatio.TestHarness/Queue/QueueTestBase.cs index 1bf7a243..05416721 100644 --- a/src/Foundatio.TestHarness/Queue/QueueTestBase.cs +++ b/src/Foundatio.TestHarness/Queue/QueueTestBase.cs @@ -631,7 +631,7 @@ public virtual async Task WillNotWaitForItemAsync() public virtual async Task WillWaitForItemAsync() { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; var queue = GetQueue(); if (queue == null) return; @@ -792,7 +792,7 @@ await queue.StartWorkingAsync(w => public virtual async Task WorkItemsWillTimeoutAsync() { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; Log.SetLogLevel("Foundatio.Queues.RedisQueue", LogLevel.Trace); var queue = GetQueue(retryDelay: TimeSpan.Zero, workItemTimeout: TimeSpan.FromMilliseconds(50)); if (queue == null) @@ -1313,7 +1313,7 @@ protected async Task CanDequeueWithLockingImpAsync(CacheLockProvider distributed await queue.DeleteQueueAsync(); await AssertEmptyQueueAsync(queue); - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; using var metrics = new InMemoryMetricsClient(new InMemoryMetricsClientOptions { Buffered = false, LoggerFactory = Log }); queue.AttachBehavior(new MetricsQueueBehavior(metrics, loggerFactory: Log)); diff --git a/src/Foundatio.Xunit/Foundatio.Xunit.csproj b/src/Foundatio.Xunit/Foundatio.Xunit.csproj index f881eaee..f9db1e39 100644 --- a/src/Foundatio.Xunit/Foundatio.Xunit.csproj +++ b/src/Foundatio.Xunit/Foundatio.Xunit.csproj @@ -7,7 +7,8 @@ - - + + + diff --git a/src/Foundatio.Xunit/Logging/LogEntry.cs b/src/Foundatio.Xunit/Logging/LogEntry.cs index 6f68b732..85f51762 100644 --- a/src/Foundatio.Xunit/Logging/LogEntry.cs +++ b/src/Foundatio.Xunit/Logging/LogEntry.cs @@ -6,7 +6,7 @@ namespace Foundatio.Xunit; public class LogEntry { - public DateTime Date { get; set; } + public DateTimeOffset Date { get; set; } public string CategoryName { get; set; } public LogLevel LogLevel { get; set; } public object[] Scopes { get; set; } diff --git a/src/Foundatio.Xunit/Logging/LoggingExtensions.cs b/src/Foundatio.Xunit/Logging/LoggingExtensions.cs new file mode 100644 index 00000000..001bf79c --- /dev/null +++ b/src/Foundatio.Xunit/Logging/LoggingExtensions.cs @@ -0,0 +1,84 @@ +using System; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; +using Microsoft.Extensions.Logging; +using Xunit.Abstractions; + +namespace Foundatio.Xunit; + +public static class LoggingExtensions +{ + public static TestLogger GetTestLogger(this IServiceProvider serviceProvider) + { + return serviceProvider.GetRequiredService(); + } + + public static ILoggingBuilder AddXUnit(this ILoggingBuilder builder, ITestOutputHelper outputHelper, + Action configure = null) + { + + var options = new TestLoggerOptions { + WriteLogEntryFunc = logEntry => + { + outputHelper.WriteLine(logEntry.ToString(false)); + } + }; + + configure?.Invoke(options); + + return builder.AddXUnit(options); + } + + public static ILoggingBuilder AddXUnit(this ILoggingBuilder builder, Action configure) + { + var options = new TestLoggerOptions(); + configure?.Invoke(options); + return builder.AddXUnit(options); + } + + public static ILoggingBuilder AddXUnit(this ILoggingBuilder builder, TestLoggerOptions options = null) + { + if (builder == null) + throw new ArgumentNullException(nameof(builder)); + + var loggerProvider = new TestLoggerProvider(options); + builder.AddProvider(loggerProvider); + builder.Services.TryAddSingleton(loggerProvider.Log); + + return builder; + } + + public static ILoggerFactory AddXUnit(this ILoggerFactory factory, Action configure = null) + { + if (factory == null) + throw new ArgumentNullException(nameof(factory)); + + var options = new TestLoggerOptions(); + configure?.Invoke(options); + + factory.AddProvider(new TestLoggerProvider(options)); + + return factory; + } + + public static TestLogger ToTestLogger(this ITestOutputHelper outputHelper, Action configure = null) + { + if (outputHelper == null) + throw new ArgumentNullException(nameof(outputHelper)); + + var options = new TestLoggerOptions(); + options.WriteLogEntryFunc = logEntry => + { + outputHelper.WriteLine(logEntry.ToString()); + }; + + configure?.Invoke(options); + + var testLogger = new TestLogger(options); + + return testLogger; + } + + public static ILogger ToLogger(this ITestOutputHelper outputHelper, Action configure = null) + => outputHelper.ToTestLogger(configure).CreateLogger(); +} diff --git a/src/Foundatio.Xunit/Logging/TestLogger.cs b/src/Foundatio.Xunit/Logging/TestLogger.cs index 2d525cad..065551f5 100644 --- a/src/Foundatio.Xunit/Logging/TestLogger.cs +++ b/src/Foundatio.Xunit/Logging/TestLogger.cs @@ -1,112 +1,81 @@ -using System; +using System; using System.Collections.Generic; -using System.Collections.Immutable; -using System.Linq; using System.Threading; using Foundatio.Utility; using Microsoft.Extensions.Logging; namespace Foundatio.Xunit; -internal class TestLogger : ILogger +public class TestLogger : ILoggerFactory { - private readonly TestLoggerFactory _loggerFactory; - private readonly string _categoryName; + private readonly Dictionary _logLevels = new(); + private readonly Queue _logEntries = new(); - public TestLogger(string categoryName, TestLoggerFactory loggerFactory) + public TestLogger() { - _loggerFactory = loggerFactory; - _categoryName = categoryName; + Options = new TestLoggerOptions(); } - public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) + public TestLogger(TestLoggerOptions options) { - if (!_loggerFactory.IsEnabled(_categoryName, logLevel)) - return; + Options = options ?? new TestLoggerOptions(); + } - object[] scopes = CurrentScopeStack.Reverse().ToArray(); - var logEntry = new LogEntry - { - Date = SystemClock.UtcNow, - LogLevel = logLevel, - EventId = eventId, - State = state, - Exception = exception, - Formatter = (s, e) => formatter((TState)s, e), - CategoryName = _categoryName, - Scopes = scopes - }; - - switch (state) - { - //case LogData logData: - // logEntry.Properties["CallerMemberName"] = logData.MemberName; - // logEntry.Properties["CallerFilePath"] = logData.FilePath; - // logEntry.Properties["CallerLineNumber"] = logData.LineNumber; - - // foreach (var property in logData.Properties) - // logEntry.Properties[property.Key] = property.Value; - // break; - case IDictionary logDictionary: - foreach (var property in logDictionary) - logEntry.Properties[property.Key] = property.Value; - break; - } + public TestLoggerOptions Options { get; } + public IReadOnlyList LogEntries => _logEntries.ToArray(); + + public void Clear() => _logEntries.Clear(); - foreach (object scope in scopes) + internal void AddLogEntry(LogEntry logEntry) + { + lock (_logEntries) { - if (!(scope is IDictionary scopeData)) - continue; + _logEntries.Enqueue(logEntry); - foreach (var property in scopeData) - logEntry.Properties[property.Key] = property.Value; + if (_logEntries.Count > Options.MaxLogEntriesToStore) + _logEntries.Dequeue(); } - _loggerFactory.AddLogEntry(logEntry); - } + if (Options.WriteLogEntryFunc == null || _logEntriesWritten >= Options.MaxLogEntriesToWrite) + return; - public bool IsEnabled(LogLevel logLevel) - { - return _loggerFactory.IsEnabled(_categoryName, logLevel); + try + { + Options.WriteLogEntry(logEntry); + Interlocked.Increment(ref _logEntriesWritten); + } + catch (Exception) + { + // ignored + } } - public IDisposable BeginScope(TState state) - { - if (state == null) - throw new ArgumentNullException(nameof(state)); - - return Push(state); - } + private int _logEntriesWritten = 0; - public IDisposable BeginScope(Func scopeFactory, TState state) + public ILogger CreateLogger(string categoryName) { - if (state == null) - throw new ArgumentNullException(nameof(state)); - - return Push(scopeFactory(state)); + return new TestLoggerLogger(categoryName, this); } - private static readonly AsyncLocal _currentScopeStack = new(); + public void AddProvider(ILoggerProvider loggerProvider) { } - private sealed class Wrapper + public bool IsEnabled(string category, LogLevel logLevel) { - public ImmutableStack Value { get; set; } - } + if (_logLevels.TryGetValue(category, out var categoryLevel)) + return logLevel >= categoryLevel; - private static ImmutableStack CurrentScopeStack - { - get => _currentScopeStack.Value?.Value ?? ImmutableStack.Create(); - set => _currentScopeStack.Value = new Wrapper { Value = value }; + return logLevel >= Options.DefaultMinimumLevel; } - private static IDisposable Push(object state) + public void SetLogLevel(string category, LogLevel minLogLevel) { - CurrentScopeStack = CurrentScopeStack.Push(state); - return new DisposableAction(Pop); + _logLevels[category] = minLogLevel; } - private static void Pop() + public void SetLogLevel(LogLevel minLogLevel) { - CurrentScopeStack = CurrentScopeStack.Pop(); + SetLogLevel(TypeHelper.GetTypeDisplayName(typeof(T)), minLogLevel); } + + public void Dispose() { } } diff --git a/src/Foundatio.Xunit/Logging/TestLoggerFactory.cs b/src/Foundatio.Xunit/Logging/TestLoggerFactory.cs deleted file mode 100644 index 7379a3f6..00000000 --- a/src/Foundatio.Xunit/Logging/TestLoggerFactory.cs +++ /dev/null @@ -1,82 +0,0 @@ -using System; -using System.Collections.Generic; -using System.Threading; -using Foundatio.Utility; -using Microsoft.Extensions.Logging; -using Xunit.Abstractions; - -namespace Foundatio.Xunit; - -public class TestLoggerFactory : ILoggerFactory -{ - private readonly Dictionary _logLevels = new(); - private readonly Queue _logEntries = new(); - private readonly Action _writeLogEntryFunc; - - public TestLoggerFactory() - { - _writeLogEntryFunc = e => { }; - } - - public TestLoggerFactory(Action writeLogEntryFunc) - { - _writeLogEntryFunc = writeLogEntryFunc; - } - - public TestLoggerFactory(ITestOutputHelper output) : this(e => output.WriteLine(e.ToString(false))) { } - - public LogLevel MinimumLevel { get; set; } = LogLevel.Information; - public IReadOnlyList LogEntries => _logEntries.ToArray(); - public int MaxLogEntriesToStore = 100; - public int MaxLogEntriesToWrite = 1000; - - internal void AddLogEntry(LogEntry logEntry) - { - lock (_logEntries) - { - _logEntries.Enqueue(logEntry); - - if (_logEntries.Count > MaxLogEntriesToStore) - _logEntries.Dequeue(); - } - - if (_writeLogEntryFunc == null || _logEntriesWritten >= MaxLogEntriesToWrite) - return; - - try - { - _writeLogEntryFunc(logEntry); - Interlocked.Increment(ref _logEntriesWritten); - } - catch (Exception) { } - } - - private int _logEntriesWritten = 0; - - public ILogger CreateLogger(string categoryName) - { - return new TestLogger(categoryName, this); - } - - public void AddProvider(ILoggerProvider loggerProvider) { } - - public bool IsEnabled(string category, LogLevel logLevel) - { - if (_logLevels.TryGetValue(category, out var categoryLevel)) - return logLevel >= categoryLevel; - - return logLevel >= MinimumLevel; - } - - public void SetLogLevel(string category, LogLevel minLogLevel) - { - _logLevels[category] = minLogLevel; - } - - public void SetLogLevel(LogLevel minLogLevel) - { - SetLogLevel(TypeHelper.GetTypeDisplayName(typeof(T)), minLogLevel); - } - - public void Dispose() { } -} diff --git a/src/Foundatio.Xunit/Logging/TestLoggerLogger.cs b/src/Foundatio.Xunit/Logging/TestLoggerLogger.cs new file mode 100644 index 00000000..d7cff822 --- /dev/null +++ b/src/Foundatio.Xunit/Logging/TestLoggerLogger.cs @@ -0,0 +1,112 @@ +using System; +using System.Collections.Generic; +using System.Collections.Immutable; +using System.Linq; +using System.Threading; +using Foundatio.Utility; +using Microsoft.Extensions.Logging; + +namespace Foundatio.Xunit; + +internal class TestLoggerLogger : ILogger +{ + private readonly TestLogger _logger; + private readonly string _categoryName; + + public TestLoggerLogger(string categoryName, TestLogger logger) + { + _logger = logger; + _categoryName = categoryName; + } + + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) + { + if (!_logger.IsEnabled(_categoryName, logLevel)) + return; + + object[] scopes = _logger.Options.IncludeScopes ? CurrentScopeStack.Reverse().ToArray() : Array.Empty(); + var logEntry = new LogEntry + { + Date = _logger.Options.GetNow(), + LogLevel = logLevel, + EventId = eventId, + State = state, + Exception = exception, + Formatter = (s, e) => formatter((TState)s, e), + CategoryName = _categoryName, + Scopes = scopes + }; + + switch (state) + { + //case LogData logData: + // logEntry.Properties["CallerMemberName"] = logData.MemberName; + // logEntry.Properties["CallerFilePath"] = logData.FilePath; + // logEntry.Properties["CallerLineNumber"] = logData.LineNumber; + + // foreach (var property in logData.Properties) + // logEntry.Properties[property.Key] = property.Value; + // break; + case IDictionary logDictionary: + foreach (var property in logDictionary) + logEntry.Properties[property.Key] = property.Value; + break; + } + + foreach (object scope in scopes) + { + if (!(scope is IDictionary scopeData)) + continue; + + foreach (var property in scopeData) + logEntry.Properties[property.Key] = property.Value; + } + + _logger.AddLogEntry(logEntry); + } + + public bool IsEnabled(LogLevel logLevel) + { + return _logger.IsEnabled(_categoryName, logLevel); + } + + public IDisposable BeginScope(TState state) + { + if (state == null) + throw new ArgumentNullException(nameof(state)); + + return Push(state); + } + + public IDisposable BeginScope(Func scopeFactory, TState state) + { + if (state == null) + throw new ArgumentNullException(nameof(state)); + + return Push(scopeFactory(state)); + } + + private static readonly AsyncLocal _currentScopeStack = new(); + + private sealed class Wrapper + { + public ImmutableStack Value { get; set; } + } + + private static ImmutableStack CurrentScopeStack + { + get => _currentScopeStack.Value?.Value ?? ImmutableStack.Create(); + set => _currentScopeStack.Value = new Wrapper { Value = value }; + } + + private static IDisposable Push(object state) + { + CurrentScopeStack = CurrentScopeStack.Push(state); + return new DisposableAction(Pop); + } + + private static void Pop() + { + CurrentScopeStack = CurrentScopeStack.Pop(); + } +} diff --git a/src/Foundatio.Xunit/Logging/TestLoggerOptions.cs b/src/Foundatio.Xunit/Logging/TestLoggerOptions.cs new file mode 100644 index 00000000..f8489c66 --- /dev/null +++ b/src/Foundatio.Xunit/Logging/TestLoggerOptions.cs @@ -0,0 +1,19 @@ +using System; +using Foundatio.Utility; +using Microsoft.Extensions.Logging; + +namespace Foundatio.Xunit; + +public class TestLoggerOptions +{ + public LogLevel DefaultMinimumLevel { get; set; } = LogLevel.Information; + public int MaxLogEntriesToStore { get; set; } = 100; + public int MaxLogEntriesToWrite { get; set; } = 1000; + public bool IncludeScopes { get; set; } = true; + + public Action WriteLogEntryFunc { get; set; } + internal void WriteLogEntry(LogEntry logEntry) => WriteLogEntryFunc?.Invoke(logEntry); + + public Func NowFunc { get; set; } + internal DateTimeOffset GetNow() => NowFunc?.Invoke() ?? SystemClock.OffsetNow; +} diff --git a/src/Foundatio.Xunit/Logging/TestLoggerProvider.cs b/src/Foundatio.Xunit/Logging/TestLoggerProvider.cs new file mode 100644 index 00000000..41335a5f --- /dev/null +++ b/src/Foundatio.Xunit/Logging/TestLoggerProvider.cs @@ -0,0 +1,35 @@ +using System; +using Microsoft.Extensions.Logging; + +namespace Foundatio.Xunit; + +[ProviderAlias("Test")] +public class TestLoggerProvider : ILoggerProvider +{ + public TestLoggerProvider(TestLoggerOptions options) + { + Log = new TestLogger(options); + } + + public TestLogger Log { get; } + + public virtual ILogger CreateLogger(string categoryName) + { + return Log.CreateLogger(categoryName); + } + + public void Dispose() + { + Dispose(true); + GC.SuppressFinalize(this); + } + + protected virtual void Dispose(bool disposing) + { + } + + ~TestLoggerProvider() + { + Dispose(false); + } +} diff --git a/src/Foundatio.Xunit/Logging/TestWithLoggingBase.cs b/src/Foundatio.Xunit/Logging/TestWithLoggingBase.cs index a3e91ba7..5de2cdba 100644 --- a/src/Foundatio.Xunit/Logging/TestWithLoggingBase.cs +++ b/src/Foundatio.Xunit/Logging/TestWithLoggingBase.cs @@ -9,9 +9,9 @@ public abstract class TestWithLoggingBase protected TestWithLoggingBase(ITestOutputHelper output) { - Log = new TestLoggerFactory(output); + Log = output.ToTestLogger(); _logger = Log.CreateLogger(GetType()); } - protected TestLoggerFactory Log { get; } + protected TestLogger Log { get; } } diff --git a/tests/Foundatio.Tests/Caching/InMemoryCacheClientTests.cs b/tests/Foundatio.Tests/Caching/InMemoryCacheClientTests.cs index 7dc699eb..6bcf9aa2 100644 --- a/tests/Foundatio.Tests/Caching/InMemoryCacheClientTests.cs +++ b/tests/Foundatio.Tests/Caching/InMemoryCacheClientTests.cs @@ -155,7 +155,7 @@ public override Task CanManageListsAsync() [Fact] public async Task CanSetMaxItems() { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; // run in tight loop so that the code is warmed up and we can catch timing issues for (int x = 0; x < 5; x++) diff --git a/tests/Foundatio.Tests/Caching/InMemoryHybridCacheClientTests.cs b/tests/Foundatio.Tests/Caching/InMemoryHybridCacheClientTests.cs index d2e9b197..7a1e56ea 100644 --- a/tests/Foundatio.Tests/Caching/InMemoryHybridCacheClientTests.cs +++ b/tests/Foundatio.Tests/Caching/InMemoryHybridCacheClientTests.cs @@ -81,7 +81,7 @@ public override Task WillExpireRemoteItems() [Fact(Skip = "Skip because cache invalidation loops on this with 2 in memory cache client instances")] public override Task WillWorkWithSets() { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; return base.WillWorkWithSets(); } diff --git a/tests/Foundatio.Tests/Locks/InMemoryLockTests.cs b/tests/Foundatio.Tests/Locks/InMemoryLockTests.cs index af162c2a..3f010eaa 100644 --- a/tests/Foundatio.Tests/Locks/InMemoryLockTests.cs +++ b/tests/Foundatio.Tests/Locks/InMemoryLockTests.cs @@ -59,7 +59,7 @@ public override Task CanAcquireMultipleResources() return base.CanAcquireMultipleResources(); } - [Fact] + [RetryFact] public override Task CanAcquireLocksInParallel() { return base.CanAcquireLocksInParallel(); diff --git a/tests/Foundatio.Tests/Metrics/DiagnosticsMetricsTests.cs b/tests/Foundatio.Tests/Metrics/DiagnosticsMetricsTests.cs index b0f9012d..d70c416b 100644 --- a/tests/Foundatio.Tests/Metrics/DiagnosticsMetricsTests.cs +++ b/tests/Foundatio.Tests/Metrics/DiagnosticsMetricsTests.cs @@ -16,7 +16,7 @@ public class DiagnosticsMetricsTests : TestWithLoggingBase, IDisposable public DiagnosticsMetricsTests(ITestOutputHelper output) : base(output) { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; _client = new DiagnosticsMetricsClient(o => o.MeterName("Test")); } diff --git a/tests/Foundatio.Tests/Queue/InMemoryQueueTests.cs b/tests/Foundatio.Tests/Queue/InMemoryQueueTests.cs index 969ece92..4e14d983 100644 --- a/tests/Foundatio.Tests/Queue/InMemoryQueueTests.cs +++ b/tests/Foundatio.Tests/Queue/InMemoryQueueTests.cs @@ -290,7 +290,7 @@ public override Task VerifyDelayedRetryAttemptsAsync() [Fact] public override Task CanHandleAutoAbandonInWorker() { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; return base.CanHandleAutoAbandonInWorker(); } diff --git a/tests/Foundatio.Tests/Utility/ScheduledTimerTests.cs b/tests/Foundatio.Tests/Utility/ScheduledTimerTests.cs index 09d7b0ec..b7d25114 100644 --- a/tests/Foundatio.Tests/Utility/ScheduledTimerTests.cs +++ b/tests/Foundatio.Tests/Utility/ScheduledTimerTests.cs @@ -47,7 +47,7 @@ public Task CanRunWithMinimumInterval() private async Task CanRunConcurrentlyAsync(TimeSpan? minimumIntervalTime = null) { - Log.MinimumLevel = LogLevel.Trace; + Log.Options.DefaultMinimumLevel = LogLevel.Trace; const int iterations = 2; var countdown = new AsyncCountdownEvent(iterations); diff --git a/tests/Foundatio.Tests/Utility/TestLoggerTests.cs b/tests/Foundatio.Tests/Utility/TestLoggerTests.cs new file mode 100644 index 00000000..390df56a --- /dev/null +++ b/tests/Foundatio.Tests/Utility/TestLoggerTests.cs @@ -0,0 +1,61 @@ +using System; +using System.Collections.Generic; +using Foundatio.Serializer; +using Foundatio.Utility; +using Foundatio.Xunit; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; +using Newtonsoft.Json.Linq; +using Xunit; +using Xunit.Abstractions; + +namespace Foundatio.Tests.Utility; + +public class TestLoggerTests +{ + private readonly ITestOutputHelper _output; + + public TestLoggerTests(ITestOutputHelper output) + { + _output = output; + } + + [Fact] + public void CanUseTestLogger() + { + var services = new ServiceCollection() + .AddLogging(b => b.AddDebug().AddXUnit(_output)) + .AddSingleton(); + + IServiceProvider provider = services.BuildServiceProvider(); + + var someClass = provider.GetRequiredService(); + + someClass.DoSomething(); + + var testLogger = provider.GetTestLogger(); + Assert.Single(testLogger.LogEntries); + Assert.Contains("Doing something", testLogger.LogEntries[0].Message); + + testLogger.Clear(); + testLogger.SetLogLevel(LogLevel.Error); + + someClass.DoSomething(); + Assert.Empty(testLogger.LogEntries); + } +} + +public class SomeClass +{ + private readonly ILogger _logger; + + public SomeClass(ILogger logger) + { + _logger = logger; + } + + public void DoSomething() + { + _logger.LogInformation("Doing something"); + } +}