0d8a80aa27
Completes Task 5a of the LocalDb Phase 1 adoption plan. The GUID-id half landed
with Task 2 (727fa48c) because leaving it out would have committed a writer that
could not satisfy site_events.id NOT NULL; this is the connection half, which
was blocked on Task 3.
SiteEventLogger owned a SqliteConnection built from SiteEventLogOptions
.DatabasePath. It now takes ILocalDb and gets that connection from
CreateConnection() - already open, pragma-configured, and carrying the
zb_hlc_next() UDF that site_events' capture triggers call. It still owns and
disposes the connection; WithConnection's signature and locking semantics are
untouched, so EventLogQueryService and EventLogPurgeService are unaffected.
The connectionStringOverride seam is deleted rather than preserved. site_events
is a replicated table, so a raw connection lacks the UDF and fails closed on
every insert - an override could only produce a logger that cannot write. It had
no callers outside this class (the connectionStringOverride hits elsewhere in the
tree belong to SqliteAuditWriter, a different type).
Tests: a shared TestLocalDb helper gives each fixture a real ILocalDb over a temp
file. Real rather than stubbed on purpose - a stub handing back a bare
SqliteConnection would pass today and fail closed the moment the table is
registered, which is exactly the silent-wiring failure mode this family has hit
three times. ServiceWiringTests' DI path also needed AddZbLocalDb, mirroring
SiteServiceRegistration.
Verified: build 0 warnings; SiteEventLogging 70/70, Host 294/294,
SiteRuntime 530/530.
Claude-Session: https://claude.ai/code/session_01BL2Vu1ESDQ9SCN4gVKkdts
121 lines
4.8 KiB
C#
121 lines
4.8 KiB
C#
using System.Diagnostics;
|
|
using Microsoft.Data.Sqlite;
|
|
using Microsoft.Extensions.Logging.Abstractions;
|
|
using Microsoft.Extensions.Options;
|
|
|
|
namespace ZB.MOM.WW.ScadaBridge.SiteEventLogging.Tests;
|
|
|
|
/// <summary>
|
|
/// Regression tests for SiteEventLogging-005 (synchronous I/O on caller thread)
|
|
/// and SiteEventLogging-008 (write failures silently swallowed).
|
|
/// </summary>
|
|
public class SiteEventLoggerAsyncTests : IDisposable
|
|
{
|
|
private readonly SiteEventLogger _logger;
|
|
private readonly string _dbPath;
|
|
private readonly TestLocalDb _localDb;
|
|
|
|
public SiteEventLoggerAsyncTests()
|
|
{
|
|
_dbPath = Path.Combine(Path.GetTempPath(), $"test_async_{Guid.NewGuid()}.db");
|
|
var options = Options.Create(new SiteEventLogOptions { DatabasePath = _dbPath });
|
|
_localDb = TestLocalDb.Create(_dbPath);
|
|
_logger = new SiteEventLogger(options, NullLogger<SiteEventLogger>.Instance, _localDb.Db);
|
|
}
|
|
|
|
public void Dispose()
|
|
{
|
|
_logger.Dispose();
|
|
_localDb.Dispose();
|
|
TestLocalDb.DeleteFiles(_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 failDbPath = Path.Combine(Path.GetTempPath(), $"test_fail_{Guid.NewGuid()}.db");
|
|
var options = Options.Create(new SiteEventLogOptions { DatabasePath = failDbPath });
|
|
using var failLocalDb = TestLocalDb.Create(failDbPath);
|
|
var logger = new SiteEventLogger(options, NullLogger<SiteEventLogger>.Instance, failLocalDb.Db);
|
|
|
|
// 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<SqliteException>(() =>
|
|
logger.LogEventAsync("script", "Error", null, "Source", "Failing write"));
|
|
|
|
Assert.True(logger.FailedWriteCount > 0,
|
|
"FailedWriteCount must increment when an event write fails.");
|
|
|
|
logger.Dispose();
|
|
failLocalDb.Dispose();
|
|
TestLocalDb.DeleteFiles(failDbPath);
|
|
}
|
|
}
|