Fix TimerAsync.Stop throwing after an early Start, and bring coverage to 100%

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<Task> 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<InvalidOperationException>(() => 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])!;
+}

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<InvalidOperationException>(engine.StopAsync);
 	}
+
+	[Fact]
+	public async Task RestartAsync_WhenStopped_Throws()
+	{
+		var engine = new TestEngine();
+
+		await Assert.ThrowsAsync<InvalidOperationException>(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<InvalidOperationException>(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);
 }

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>(TState state) where TState : notnull => null;
+
+	public bool IsEnabled(LogLevel logLevel) => true;
+
+	public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> 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
+	}
+}