using System.Diagnostics; using Microsoft.Data.Sqlite; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Options; namespace ScadaLink.SiteEventLogging.Tests; /// /// Regression tests for SiteEventLogging-005 (synchronous I/O on caller thread) /// and SiteEventLogging-008 (write failures silently swallowed). /// public class SiteEventLoggerAsyncTests : IDisposable { private readonly SiteEventLogger _logger; private readonly string _dbPath; public SiteEventLoggerAsyncTests() { _dbPath = Path.Combine(Path.GetTempPath(), $"test_async_{Guid.NewGuid()}.db"); var options = Options.Create(new SiteEventLogOptions { DatabasePath = _dbPath }); _logger = new SiteEventLogger(options, NullLogger.Instance); } public void Dispose() { _logger.Dispose(); if (File.Exists(_dbPath)) File.Delete(_dbPath); } [Fact] public async Task LogEventAsync_DoesNotBlockCaller_WhenWriteIsSlow() { // SiteEventLogging-005: LogEventAsync must not perform the SQLite write // inline on the caller's thread. We hold the recorder busy on a long // database operation from one thread, then time how long it takes the // caller of LogEventAsync to get control back. If recording is offloaded // to a background writer, the caller returns essentially immediately even // though the database is busy. If recording is synchronous (the bug), the // caller blocks on the write lock for the full busy period. var busyStarted = new ManualResetEventSlim(false); var releaseBusy = new ManualResetEventSlim(false); var busyThread = new Thread(() => { _logger.WithConnection(_ => { busyStarted.Set(); // Hold the connection lock until the test releases it. releaseBusy.Wait(TimeSpan.FromSeconds(10)); }); }); busyThread.Start(); Assert.True(busyStarted.Wait(TimeSpan.FromSeconds(5)), "Busy thread did not start."); var sw = Stopwatch.StartNew(); var recordTask = _logger.LogEventAsync("script", "Info", null, "Caller", "Should not block"); sw.Stop(); // The CALL must return quickly even though the database is busy for ~1s. Assert.True(sw.ElapsedMilliseconds < 500, $"LogEventAsync blocked the caller for {sw.ElapsedMilliseconds} ms — recording is not offloaded."); // Release the busy thread; the record must still complete successfully. releaseBusy.Set(); busyThread.Join(TimeSpan.FromSeconds(10)); await recordTask.WaitAsync(TimeSpan.FromSeconds(10)); } [Fact] public async Task LogEventAsync_TaskCompletes_AfterEventIsPersisted() { // Awaiting the returned Task must guarantee the row is durably written. await _logger.LogEventAsync("script", "Info", "inst-1", "Source", "Persisted event"); var count = _logger.WithConnection(connection => { using var cmd = connection.CreateCommand(); cmd.CommandText = "SELECT COUNT(*) FROM site_events"; return (long)cmd.ExecuteScalar()!; }); Assert.Equal(1, count); } [Fact] public async Task LogEventAsync_FaultsTask_AndCountsFailure_OnWriteError() { // SiteEventLogging-008: a write failure must not be silently swallowed. // The returned Task must fault and the failure counter must increment so // Health Monitoring can surface a logging outage. using var failingConnection = new SqliteConnection("Data Source=:memory:"); failingConnection.Open(); var options = Options.Create(new SiteEventLogOptions { DatabasePath = Path.Combine(Path.GetTempPath(), $"test_fail_{Guid.NewGuid()}.db") }); var logger = new SiteEventLogger(options, NullLogger.Instance); // Drop the table so every write fails with "no such table". logger.WithConnection(connection => { using var cmd = connection.CreateCommand(); cmd.CommandText = "DROP TABLE site_events"; cmd.ExecuteNonQuery(); }); await Assert.ThrowsAnyAsync(() => logger.LogEventAsync("script", "Error", null, "Source", "Failing write")); Assert.True(logger.FailedWriteCount > 0, "FailedWriteCount must increment when an event write fails."); logger.Dispose(); } }