diff --git a/PanoramicData.Engines.Test/AsyncTimerEngineTests.cs b/PanoramicData.Engines.Test/AsyncTimerEngineTests.cs new file mode 100644 index 0000000..4402cb7 --- /dev/null +++ b/PanoramicData.Engines.Test/AsyncTimerEngineTests.cs @@ -0,0 +1,231 @@ +using Microsoft.Extensions.Logging; +using System.Reflection; +using Xunit; + +namespace PanoramicData.Engines.Test; + +public class TestTimerEngine : AsyncTimerEngine +{ + public TestTimerEngine(TimeSpan interval, ILoggerFactory? loggerFactory) + : base("TestTimerEngine", interval, loggerFactory) + { + } + + public TestTimerEngine(TimeSpan interval) : base("TestTimerEngine", interval) + { + } + + public Func OnTick { get; set; } = () => Task.CompletedTask; + public int PreStartupCount { get; private set; } + public int PostShutdownCount { get; private set; } + public long ElapsedMs => ProcessingElapsedTimeMs; + + public void DisposeManaged(bool disposing) => Dispose(disposing); + + protected override Task TimerEngineMethod() => OnTick(); + + protected override Task PreStartup() + { + PreStartupCount++; + return Task.CompletedTask; + } + + protected override Task PostShutdown() + { + PostShutdownCount++; + return Task.CompletedTask; + } +} + +public class AsyncTimerEngineTests +{ + private static readonly TimeSpan Fast = TimeSpan.FromMilliseconds(10); + + private static Task WaitForExecutions(TestTimerEngine engine, int count) + => TimerAsyncTests.WaitUntil(() => engine.ExecutionCount >= count); + + [Fact] + public async Task StartAndStop_RunsHooksAndExecutesTimerMethod() + { + using var engine = new TestTimerEngine(Fast); + + await engine.StartAsync(); + await WaitForExecutions(engine, 2); + await engine.StopAsync(); + + Assert.Equal(1, engine.PreStartupCount); + Assert.Equal(1, engine.PostShutdownCount); + Assert.True(engine.ExecutionCount >= 2); + Assert.Equal(EngineState.Stopped, engine.EngineState); + } + + [Fact] + public async Task Restart_ResetsExecutionCount() + { + using var engine = new TestTimerEngine(Fast); + await engine.StartAsync(); + await WaitForExecutions(engine, 1); + + await engine.RestartAsync(); + + Assert.Equal(2, engine.PreStartupCount); + Assert.Equal(1, engine.PostShutdownCount); + await engine.StopAsync(); + } + + [Fact] + public async Task TimerMethod_ThrowsWithoutLogger_IsSwallowed() + { + using var engine = new TestTimerEngine(Fast) + { + OnTick = () => throw new InvalidOperationException("boom") + }; + + await engine.StartAsync(); + await WaitForExecutions(engine, 2); + await engine.StopAsync(); + + Assert.Equal(EngineState.Stopped, engine.EngineState); + } + + [Fact] + public async Task TimerMethod_Throws_LogsWarningAndKeepsRunning() + { + var factory = new RecordingLoggerFactory(); + using var engine = new TestTimerEngine(Fast, factory) + { + OnTick = () => throw new InvalidOperationException("boom") + }; + + await engine.StartAsync(); + await WaitForExecutions(engine, 2); + await engine.StopAsync(); + + Assert.True(factory.Logger.Contains(LogLevel.Warning, "InvalidOperationException")); + Assert.True(factory.Logger.Contains(LogLevel.Warning, "boom")); + } + + [Fact] + public async Task TimerMethod_ThrowsAggregateExceptionWithLogger_LogsEachInnerException() + { + var factory = new RecordingLoggerFactory(); + using var engine = new TestTimerEngine(Fast, factory) + { + OnTick = () => throw new AggregateException(new ArgumentException("first"), new InvalidOperationException("second")) + }; + + await engine.StartAsync(); + await WaitForExecutions(engine, 1); + await engine.StopAsync(); + + Assert.True(factory.Logger.Contains(LogLevel.Warning, "ArgumentException")); + Assert.True(factory.Logger.Contains(LogLevel.Warning, "second")); + } + + [Fact] + public async Task TimerMethod_ThrowsAggregateExceptionWithoutLogger_IsSwallowed() + { + using var engine = new TestTimerEngine(Fast) + { + OnTick = () => throw new AggregateException(new ArgumentException("first")) + }; + + await engine.StartAsync(); + await WaitForExecutions(engine, 1); + await engine.StopAsync(); + + Assert.Equal(EngineState.Stopped, engine.EngineState); + } + + [Fact] + public async Task TimerMethod_ThrowsCancellationWithoutCancelRequested_IsLogged() + { + var factory = new RecordingLoggerFactory(); + using var engine = new TestTimerEngine(Fast, factory) + { + OnTick = () => throw new OperationCanceledException("not cancelled") + }; + + await engine.StartAsync(); + await WaitForExecutions(engine, 1); + await engine.StopAsync(); + + Assert.True(factory.Logger.Contains(LogLevel.Warning, "OperationCanceledException")); + } + + [Fact] + public async Task StopWhileTimerMethodCancelled_DoesNotLogOrRestartTimer() + { + var factory = new RecordingLoggerFactory(); + var entered = new TaskCompletionSource(); + var release = new TaskCompletionSource(); + using var engine = new TestTimerEngine(TimeSpan.FromMilliseconds(10), factory) + { + OnTick = async () => + { + entered.TrySetResult(); + await release.Task; + throw new OperationCanceledException(); + } + }; + await engine.StartAsync(); + await entered.Task.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + + var stopping = engine.StopAsync(); + await TimerAsyncTests.WaitUntil(() => engine.EngineState == EngineState.Stopping); + await Task.Delay(100, TestContext.Current.CancellationToken); + release.SetResult(); + await stopping.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + + Assert.Equal(EngineState.Stopped, engine.EngineState); + Assert.False(factory.Logger.Contains(LogLevel.Warning, "OperationCanceledException")); + } + + [Fact] + public async Task TimerMethod_WhenAlreadyExecuting_Throws() + { + using var engine = new TestTimerEngine(Fast); + SetExecuting(engine, true); + + var exception = await Assert.ThrowsAsync(() => InvokeTimerMethod(engine)); + + Assert.Contains("already executing", exception.Message, StringComparison.Ordinal); + } + + [Fact] + public async Task Shutdown_WaitsForTimerMethodFlagToClear() + { + using var engine = new TestTimerEngine(TimeSpan.FromMinutes(5)); + await engine.StartAsync(); + SetExecuting(engine, true); + + var stopping = engine.StopAsync(); + await Task.Delay(100, TestContext.Current.CancellationToken); + Assert.False(stopping.IsCompleted); + SetExecuting(engine, false); + await stopping.WaitAsync(TimeSpan.FromSeconds(10), TestContext.Current.CancellationToken); + + Assert.Equal(EngineState.Stopped, engine.EngineState); + Assert.Equal(1, engine.PostShutdownCount); + } + + [Fact] + public void Dispose_CanBeCalledRepeatedly_AndWithoutDisposing() + { + var engine = new TestTimerEngine(Fast); + + engine.DisposeManaged(false); + engine.Dispose(); + engine.Dispose(); + } + + private static void SetExecuting(AsyncTimerEngine engine, bool value) + => typeof(AsyncTimerEngine) + .GetProperty("IsTimerEngineMethodExecuting", BindingFlags.Instance | BindingFlags.NonPublic)! + .SetValue(engine, value); + + private static Task InvokeTimerMethod(AsyncTimerEngine engine) + => (Task)typeof(AsyncTimerEngine) + .GetMethod("TimerMethod", BindingFlags.Instance | BindingFlags.NonPublic)! + .Invoke(engine, [CancellationToken.None])!; +} diff --git a/PanoramicData.Engines.Test/EngineTests.cs b/PanoramicData.Engines.Test/EngineTests.cs index 61e42dd..1353530 100644 --- a/PanoramicData.Engines.Test/EngineTests.cs +++ b/PanoramicData.Engines.Test/EngineTests.cs @@ -8,6 +8,10 @@ public TestEngine() : base("TestEngine") { } + public TestEngine(Microsoft.Extensions.Logging.ILoggerFactory? loggerFactory) : base("TestEngine", loggerFactory) + { + } + public int StartCount { get; private set; } public int StopCount { get; private set; } @@ -79,4 +83,96 @@ public async Task StopAsync_WhenAlreadyStopped_Throws() await Assert.ThrowsAsync(engine.StopAsync); } + + [Fact] + public async Task RestartAsync_WhenStopped_Throws() + { + var engine = new TestEngine(); + + await Assert.ThrowsAsync(engine.RestartAsync); + } + + [Fact] + public async Task StartAsync_WithNullLoggerFactory_Works() + { + var engine = new TestEngine(null); + + await engine.StartAsync(); + await engine.RestartAsync(); + await engine.StopAsync(); + + Assert.Equal(EngineState.Stopped, engine.EngineState); + } + + [Fact] + public async Task Lifecycle_WithLogger_LogsStateChangesAndRestart() + { + var factory = new RecordingLoggerFactory(); + var engine = new TestEngine(factory); + + await engine.StartAsync(); + await engine.RestartAsync(); + await engine.StopAsync(); + + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Starting")); + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Started")); + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Stopping")); + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Stopped")); + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Restarting")); + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Information, "TestEngine: Restart complete")); + } + + [Fact] + public async Task StopAsync_WhenStoppedWithLogger_LogsError() + { + var factory = new RecordingLoggerFactory(); + var engine = new TestEngine(factory); + + await Assert.ThrowsAsync(engine.StopAsync); + + Assert.True(factory.Logger.Contains(Microsoft.Extensions.Logging.LogLevel.Error, "Cannot stop the engine when it is Stopped")); + } +} + +public class EngineExceptionTests +{ + [Fact] + public void DefaultConstructor_CreatesException() + { + var exception = new EngineException(); + + Assert.NotNull(exception.Message); + Assert.Null(exception.InnerException); + } + + [Fact] + public void MessageConstructor_SetsMessage() + { + var exception = new EngineException("boom"); + + Assert.Equal("boom", exception.Message); + } + + [Fact] + public void MessageAndInnerConstructor_SetsBoth() + { + var inner = new InvalidOperationException("inner"); + + var exception = new EngineException("boom", inner); + + Assert.Equal("boom", exception.Message); + Assert.Same(inner, exception.InnerException); + } +} + +public class EngineStateTests +{ + [Theory] + [InlineData(EngineState.Unknown, 0)] + [InlineData(EngineState.Starting, 1)] + [InlineData(EngineState.Started, 2)] + [InlineData(EngineState.Stopping, 3)] + [InlineData(EngineState.Stopped, 4)] + public void Values_HaveStableNumbers(EngineState state, int expected) + => Assert.Equal(expected, (int)state); } diff --git a/PanoramicData.Engines.Test/RecordingLogger.cs b/PanoramicData.Engines.Test/RecordingLogger.cs new file mode 100644 index 0000000..6ed5360 --- /dev/null +++ b/PanoramicData.Engines.Test/RecordingLogger.cs @@ -0,0 +1,45 @@ +using Microsoft.Extensions.Logging; + +namespace PanoramicData.Engines.Test; + +public sealed class RecordingLogger : ILogger +{ + public List<(LogLevel Level, string Message)> Entries { get; } = []; + + public IDisposable? BeginScope(TState state) where TState : notnull => null; + + public bool IsEnabled(LogLevel logLevel) => true; + + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func formatter) + { + lock (Entries) + { + Entries.Add((logLevel, formatter(state, exception))); + } + } + + public bool Contains(LogLevel level, string text) + { + lock (Entries) + { + return Entries.Any(e => e.Level == level && e.Message.Contains(text, StringComparison.Ordinal)); + } + } +} + +public sealed class RecordingLoggerFactory : ILoggerFactory +{ + public RecordingLogger Logger { get; } = new(); + + public void AddProvider(ILoggerProvider provider) + { + // Providers are not used + } + + public ILogger CreateLogger(string categoryName) => Logger; + + public void Dispose() + { + // Nothing to release + } +} diff --git a/PanoramicData.Engines.Test/TimerAsyncTests.cs b/PanoramicData.Engines.Test/TimerAsyncTests.cs new file mode 100644 index 0000000..4542873 --- /dev/null +++ b/PanoramicData.Engines.Test/TimerAsyncTests.cs @@ -0,0 +1,255 @@ +using Xunit; + +namespace PanoramicData.Engines.Test; + +public class TimerAsyncTests +{ + private static readonly TimeSpan Fast = TimeSpan.FromMilliseconds(10); + private static readonly TimeSpan Timeout = TimeSpan.FromSeconds(10); + + [Fact] + public void Constructor_NullAction_Throws() + => Assert.Throws(() => new TimerAsync(null!, Fast, Fast)); + + [Fact] + public void Constructor_NegativeDueTime_Throws() + => Assert.Throws(() => new TimerAsync(_ => Task.CompletedTask, TimeSpan.FromSeconds(-1), Fast)); + + [Fact] + public void Constructor_NegativePeriod_Throws() + => Assert.Throws(() => new TimerAsync(_ => Task.CompletedTask, Fast, TimeSpan.FromSeconds(-1))); + + [Fact] + public void ErrorEventArgs_ExposesException() + { + var exception = new InvalidOperationException("x"); + + Assert.Same(exception, new TimerAsyncErrorEventArgs(exception).Exception); + } + + [Fact] + public async Task StartAndStop_RunsActionRepeatedly() + { + var count = 0; + var reached = new TaskCompletionSource(); + using var timer = new TimerAsync(_ => + { + if (Interlocked.Increment(ref count) >= 3) + { + reached.TrySetResult(); + } + + return Task.CompletedTask; + }, TimeSpan.Zero, Fast); + Assert.False(timer.IsRunning); + + timer.Start(); + Assert.True(timer.IsRunning); + await reached.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await timer.Stop(); + + Assert.False(timer.IsRunning); + } + + [Fact] + public async Task Start_WhenAlreadyRunning_IsNoOp() + { + using var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + + timer.Start(); + timer.Start(); + + Assert.True(timer.IsRunning); + await timer.Stop(); + } + + [Fact] + public async Task Stop_WhenNotRunning_IsNoOp() + { + using var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + + await timer.Stop(); + + Assert.False(timer.IsRunning); + } + + [Fact] + public async Task CanStartNextActionBeforePreviousIsCompleted_RunsActionsOverlapping() + { + var running = 0; + var maxConcurrent = 0; + var overlapped = new TaskCompletionSource(); + using var timer = new TimerAsync(async ct => + { + var now = Interlocked.Increment(ref running); + InterlockedMax(ref maxConcurrent, now); + if (now >= 2) + { + overlapped.TrySetResult(); + } + + try + { + await Task.Delay(TimeSpan.FromMilliseconds(500), ct); + } + catch (OperationCanceledException) + { + // Timer stopped + } + finally + { + Interlocked.Decrement(ref running); + } + }, TimeSpan.Zero, Fast, canStartNextActionBeforePreviousIsCompleted: true); + + timer.Start(); + await overlapped.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await timer.Stop(); + + Assert.True(maxConcurrent >= 2); + } + + [Fact] + public async Task ActionThrows_RaisesOnErrorAndStopsRunning() + { + var raised = new TaskCompletionSource(); + using var timer = new TimerAsync(_ => throw new InvalidOperationException("boom"), TimeSpan.Zero, Fast); + timer.OnError += (_, e) => raised.TrySetResult(e.Exception); + + timer.Start(); + var exception = await raised.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await WaitUntil(() => !timer.IsRunning); + + Assert.Equal("boom", exception.Message); + await timer.Stop(); + } + + [Fact] + public async Task ActionThrows_WithNoSubscriber_IsSwallowed() + { + var invoked = new TaskCompletionSource(); + using var timer = new TimerAsync(_ => + { + invoked.TrySetResult(); + throw new InvalidOperationException("boom"); + }, TimeSpan.Zero, Fast); + + timer.Start(); + await invoked.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await WaitUntil(() => !timer.IsRunning); + + Assert.False(timer.IsRunning); + } + + [Fact] + public async Task OnErrorHandlerThrows_IsSwallowed() + { + var handlerCalled = new TaskCompletionSource(); + using var timer = new TimerAsync(_ => throw new InvalidOperationException("boom"), TimeSpan.Zero, Fast); + timer.OnError += (_, _) => + { + handlerCalled.TrySetResult(); + throw new InvalidOperationException("handler"); + }; + + timer.Start(); + await handlerCalled.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await WaitUntil(() => !timer.IsRunning); + + Assert.False(timer.IsRunning); + } + + [Fact] + public async Task Stop_DuringDueTimeDelay_CancelsWithoutError() + { + var errored = false; + using var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.FromMinutes(5), Fast); + timer.OnError += (_, _) => errored = true; + + timer.Start(); + await timer.Stop(); + + Assert.False(errored); + Assert.False(timer.IsRunning); + } + + [Fact] + public async Task Stop_WhileActionAwaitingToken_CancelsWithoutError() + { + var errored = false; + var started = new TaskCompletionSource(); + using var timer = new TimerAsync(async ct => + { + started.TrySetResult(); + await Task.Delay(Timeout, ct); + }, TimeSpan.Zero, Fast); + timer.OnError += (_, _) => errored = true; + + timer.Start(); + await started.Task.WaitAsync(Timeout, TestContext.Current.CancellationToken); + await timer.Stop(); + + Assert.False(errored); + } + + [Fact] + public async Task Dispose_WhenCalledTwice_IsSafe() + { + var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + timer.Start(); + await timer.Stop(); + + timer.Dispose(); + timer.Dispose(); + } + + [Fact] + public void Dispose_WithoutStarting_IsSafe() + { + var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + + timer.Dispose(); + } + + [Fact] + public void Start_AfterDispose_Throws() + { + var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + timer.Dispose(); + + Assert.Throws(timer.Start); + } + + [Fact] + public async Task Stop_AfterDispose_Throws() + { + var timer = new TimerAsync(_ => Task.CompletedTask, TimeSpan.Zero, Fast); + timer.Dispose(); + + await Assert.ThrowsAsync(timer.Stop); + } + + private static void InterlockedMax(ref int location, int value) + { + int current; + do + { + current = Volatile.Read(ref location); + if (value <= current) + { + return; + } + } + while (Interlocked.CompareExchange(ref location, value, current) != current); + } + + internal static async Task WaitUntil(Func condition) + { + var deadline = DateTime.UtcNow + Timeout; + while (!condition()) + { + Assert.True(DateTime.UtcNow < deadline, "Timed out waiting for condition"); + await Task.Delay(10, TestContext.Current.CancellationToken); + } + } +} diff --git a/PanoramicData.Engines/TimerAsync.cs b/PanoramicData.Engines/TimerAsync.cs index 492dd99..4abcd7a 100644 --- a/PanoramicData.Engines/TimerAsync.cs +++ b/PanoramicData.Engines/TimerAsync.cs @@ -148,7 +148,8 @@ public async Task Stop() } } - private Task RunScheduledAction() => Task.Run(RunScheduledActionLoop, _cancellationSource!.Token); + // No token on Task.Run: cancelling before the task starts would make Stop() throw TaskCanceledException. + private Task RunScheduledAction() => Task.Run(RunScheduledActionLoop); private async Task RunScheduledActionLoop() { @@ -207,7 +208,7 @@ private void Dispose(bool disposing) if (disposing) { _cancellationSource?.Dispose(); - _semaphore?.Dispose(); + _semaphore.Dispose(); } _disposed = true; diff --git a/PanoramicData.Engines/TimerEngine.cs b/PanoramicData.Engines/TimerEngine.cs index b7067ba..fe50dd2 100644 --- a/PanoramicData.Engines/TimerEngine.cs +++ b/PanoramicData.Engines/TimerEngine.cs @@ -162,7 +162,7 @@ protected virtual void Dispose(bool disposing) return; } - _timer?.Dispose(); + _timer.Dispose(); } [LoggerMessage(Level = LogLevel.Warning, Message = "{EngineName}: Exception of type {ExceptionType} thrown in timer method: {ExceptionDetails}")]