test(auditlog): audit failures never abort user-facing actions (#23 M4)

This commit is contained in:
Joseph Doherty
2026-05-20 16:50:48 -04:00
parent a7eea0a795
commit 065c8259ae

View File

@@ -0,0 +1,472 @@
using Akka.Actor;
using Akka.TestKit.Xunit2;
using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Hosting;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.TestHost;
using Microsoft.Data.Sqlite;
using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;
using Microsoft.Extensions.Logging.Abstractions;
using Microsoft.Extensions.Options;
using NSubstitute;
using ScadaLink.Commons.Entities.Audit;
using ScadaLink.Commons.Entities.Notifications;
using ScadaLink.Commons.Interfaces.Repositories;
using ScadaLink.Commons.Interfaces.Services;
using ScadaLink.Commons.Messages.Integration;
using ScadaLink.Commons.Types;
using ScadaLink.Commons.Types.Enums;
using ScadaLink.ConfigurationDatabase;
using ScadaLink.ConfigurationDatabase.Repositories;
using ScadaLink.ConfigurationDatabase.Tests.Migrations;
using ScadaLink.InboundAPI.Middleware;
using ScadaLink.NotificationOutbox;
using ScadaLink.NotificationOutbox.Delivery;
using ScadaLink.NotificationOutbox.Messages;
using ScadaLink.SiteRuntime.Scripts;
using System.Net;
using System.Security.Claims;
using System.Text;
using System.Text.Encodings.Web;
namespace ScadaLink.AuditLog.Tests.Integration;
/// <summary>
/// Audit Log #23 — M4 Bundle E (Task E4) cross-boundary safety suite verifying
/// the alog.md §13 contract: an always-throwing audit writer NEVER aborts the
/// user-facing action. Exercises every boundary that emits audit rows in M2,
/// M3, and M4:
///
/// <list type="bullet">
/// <item><description>External system sync call (M2 Bundle F).</description></item>
/// <item><description>External system cached call (M3 Bundle E).</description></item>
/// <item><description>Database sync write (M4 Bundle A).</description></item>
/// <item><description>Inbound API request (M4 Bundle D).</description></item>
/// <item><description>Notification dispatcher (M4 Bundle B).</description></item>
/// </list>
///
/// <para>
/// The site-local boundaries (ESG sync/cached, DB sync) take the always-throw
/// <see cref="ThrowingAuditWriter"/> in place of the production
/// <see cref="IAuditWriter"/>; the central boundaries (Inbound API,
/// Notification dispatcher) take the always-throw
/// <see cref="ThrowingCentralAuditWriter"/> in place of
/// <see cref="ICentralAuditWriter"/>. In each case the wrapped action's
/// original return value (or original exception) must still flow back to the
/// caller untouched.
/// </para>
/// </remarks>
public class AuditWriteFailureSafetyTests : TestKit, IClassFixture<MsSqlMigrationFixture>
{
private readonly MsSqlMigrationFixture _fixture;
public AuditWriteFailureSafetyTests(MsSqlMigrationFixture fixture)
{
_fixture = fixture;
}
// ---------------------------------------------------------------------
// Always-throwing writer test doubles
// ---------------------------------------------------------------------
/// <summary>
/// Site-side <see cref="IAuditWriter"/> that ALWAYS throws on
/// <see cref="WriteAsync"/>. Used to verify that ESG / DB script-side
/// helpers swallow the throw and return their normal result to the script.
/// </summary>
private sealed class ThrowingAuditWriter : IAuditWriter
{
private int _attempts;
public int Attempts => Volatile.Read(ref _attempts);
public Task WriteAsync(AuditEvent evt, CancellationToken ct = default)
{
Interlocked.Increment(ref _attempts);
return Task.FromException(new InvalidOperationException(
"test-only ThrowingAuditWriter — audit pipeline unavailable"));
}
}
/// <summary>
/// Central-side <see cref="ICentralAuditWriter"/> that ALWAYS throws on
/// <see cref="WriteAsync"/>. Used to verify Inbound API + Notification
/// dispatcher absorb audit-write failures rather than propagating them
/// into the response / state transition.
/// </summary>
private sealed class ThrowingCentralAuditWriter : ICentralAuditWriter
{
private int _attempts;
public int Attempts => Volatile.Read(ref _attempts);
public Task WriteAsync(AuditEvent evt, CancellationToken ct = default)
{
Interlocked.Increment(ref _attempts);
throw new InvalidOperationException(
"test-only ThrowingCentralAuditWriter — audit subsystem unavailable");
}
}
/// <summary>
/// Site-side <see cref="ICachedCallTelemetryForwarder"/> that ALWAYS
/// throws on <see cref="ForwardAsync"/>. The cached-call helpers absorb
/// the throw and still return a valid <see cref="TrackedOperationId"/>.
/// </summary>
private sealed class ThrowingCachedForwarder : ICachedCallTelemetryForwarder
{
private int _attempts;
public int Attempts => Volatile.Read(ref _attempts);
public Task ForwardAsync(CachedCallTelemetry telemetry, CancellationToken ct = default)
{
Interlocked.Increment(ref _attempts);
return Task.FromException(new InvalidOperationException(
"test-only ThrowingCachedForwarder — telemetry pipeline unavailable"));
}
}
// ---------------------------------------------------------------------
// Test 1 — ESG sync call still returns the original ExternalCallResult.
// ---------------------------------------------------------------------
[Fact]
public async Task EsgSyncCall_BrokenAuditWriter_StillReturnsResult()
{
var client = Substitute.For<IExternalSystemClient>();
var expected = new ExternalCallResult(
Success: true,
ResponseJson: "{\"orderId\":42}",
ErrorMessage: null,
WasBuffered: false);
client.CallAsync(
"ERP", "GetOrder",
Arg.Any<IReadOnlyDictionary<string, object?>?>(),
Arg.Any<CancellationToken>())
.Returns(expected);
var writer = new ThrowingAuditWriter();
var helper = new ScriptRuntimeContext.ExternalSystemHelper(
client,
instanceName: "Plant.Pump42",
NullLogger.Instance,
auditWriter: writer,
siteId: "site-77",
sourceScript: "ScriptActor:Sync",
cachedForwarder: null);
var result = await helper.Call("ERP", "GetOrder");
Assert.Same(expected, result);
// Proof the audit writer was attempted — otherwise the test wouldn't
// actually exercise the safety contract.
Assert.True(writer.Attempts >= 1,
$"Expected audit writer to be invoked at least once; saw {writer.Attempts}.");
}
// ---------------------------------------------------------------------
// Test 2 — ESG cached call still returns a TrackedOperationId.
// ---------------------------------------------------------------------
[Fact]
public async Task EsgCachedCall_BrokenAuditWriter_StillReturnsTrackedOperationId()
{
var client = Substitute.For<IExternalSystemClient>();
// CachedCallAsync returns WasBuffered=true so the helper takes the
// S&F-deferred path — no immediate-terminal telemetry, which keeps the
// forwarder attempt count at exactly one (the CachedSubmit emission).
client.CachedCallAsync(
"ERP", "GetOrder",
Arg.Any<IReadOnlyDictionary<string, object?>?>(),
Arg.Any<string?>(),
Arg.Any<CancellationToken>(),
Arg.Any<TrackedOperationId?>())
.Returns(new ExternalCallResult(true, null, null, WasBuffered: true));
// BOTH the audit writer AND the cached forwarder throw — the
// CachedSubmit emission goes through the forwarder in production, so
// breaking only the writer wouldn't actually exercise the cached
// path's safety contract.
var writer = new ThrowingAuditWriter();
var forwarder = new ThrowingCachedForwarder();
var helper = new ScriptRuntimeContext.ExternalSystemHelper(
client,
instanceName: "Plant.Pump42",
NullLogger.Instance,
auditWriter: writer,
siteId: "site-77",
sourceScript: "ScriptActor:Cached",
cachedForwarder: forwarder);
var trackedId = await helper.CachedCall("ERP", "GetOrder");
// Non-default id materialised despite the forwarder failing.
Assert.NotEqual(default, trackedId);
Assert.True(forwarder.Attempts >= 1,
$"Expected cached forwarder to be invoked at least once; saw {forwarder.Attempts}.");
}
// ---------------------------------------------------------------------
// Test 3 — DB sync write still returns the rows-affected count.
// ---------------------------------------------------------------------
[Fact]
public async Task DbSyncWrite_BrokenAuditWriter_StillReturnsRowsAffected()
{
const string connectionName = "machineData";
const string instanceName = "Plant.Pump42";
using var keepAlive = new SqliteConnection(
"Data Source=k-safety-db;Mode=Memory;Cache=Shared");
keepAlive.Open();
// Schema + seed inside a unique in-memory DB.
var dbName = $"db-{Guid.NewGuid():N}";
var connStr = $"Data Source={dbName};Mode=Memory;Cache=Shared";
using var dbKeepAlive = new SqliteConnection(connStr);
dbKeepAlive.Open();
using (var seed = dbKeepAlive.CreateCommand())
{
seed.CommandText =
"CREATE TABLE t (id INTEGER PRIMARY KEY, name TEXT NOT NULL);";
seed.ExecuteNonQuery();
}
var inner = new SqliteConnection(connStr);
inner.Open();
var gateway = Substitute.For<IDatabaseGateway>();
gateway.GetConnectionAsync(connectionName, Arg.Any<CancellationToken>())
.Returns(inner);
var writer = new ThrowingAuditWriter();
var helper = new ScriptRuntimeContext.DatabaseHelper(
gateway,
instanceName,
NullLogger.Instance,
auditWriter: writer,
siteId: "site-77",
sourceScript: "ScriptActor:Db",
cachedForwarder: null);
await using (var conn = await helper.Connection(connectionName))
await using (var cmd = conn.CreateCommand())
{
cmd.CommandText = "INSERT INTO t (id, name) VALUES (1, 'safety')";
var rows = await cmd.ExecuteNonQueryAsync();
Assert.Equal(1, rows);
}
Assert.True(writer.Attempts >= 1,
$"Expected audit writer to be invoked at least once; saw {writer.Attempts}.");
}
// ---------------------------------------------------------------------
// Test 4 — Inbound API request still returns HTTP 200.
// ---------------------------------------------------------------------
[Fact]
public async Task InboundApi_BrokenAuditWriter_StillReturns200()
{
var writer = new ThrowingCentralAuditWriter();
using var host = await BuildInboundApiHostAsync(writer, endpointStatus: 200);
var client = host.GetTestClient();
var resp = await client.PostAsync(
"/api/echo",
new StringContent("{\"x\":1}", Encoding.UTF8, "application/json"));
Assert.Equal(HttpStatusCode.OK, resp.StatusCode);
Assert.True(writer.Attempts >= 1,
$"Expected central audit writer to be invoked at least once; saw {writer.Attempts}.");
}
// ---------------------------------------------------------------------
// Test 5 — Notification dispatcher still transitions to Delivered.
// ---------------------------------------------------------------------
[SkippableFact]
public async Task NotificationDispatch_BrokenAuditWriter_StillTransitionsToDelivered()
{
Skip.IfNot(_fixture.Available, _fixture.SkipReason);
var siteId = "test-e4-safety-" + Guid.NewGuid().ToString("N").Substring(0, 8);
var notificationId = Guid.NewGuid();
await SeedSmtpConfigAsync();
await SeedNotificationAsync(notificationId, siteId);
var adapter = new SingleOutcomeAdapter(DeliveryOutcome.Success("ops@example.com"));
var serviceProvider = BuildNotificationDispatcherProvider(adapter);
var throwingWriter = new ThrowingCentralAuditWriter();
var actor = Sys.ActorOf(Props.Create(() => new NotificationOutboxActor(
serviceProvider,
new NotificationOutboxOptions
{
DispatchInterval = TimeSpan.FromHours(1),
PurgeInterval = TimeSpan.FromDays(1),
},
(ICentralAuditWriter)throwingWriter,
NullLogger<NotificationOutboxActor>.Instance)));
actor.Tell(InternalMessages.DispatchTick.Instance);
// Notifications table reflects the successful delivery even though
// every audit write threw — the central direct-write writer
// catches/logs internally and the dispatcher catches defensively too
// (alog.md §13).
await AwaitAssertAsync(async () =>
{
await using var ctx = CreateContext();
var row = await ctx.Notifications.SingleAsync(
n => n.NotificationId == notificationId.ToString("D"));
Assert.Equal(NotificationStatus.Delivered, row.Status);
Assert.NotNull(row.DeliveredAt);
}, TimeSpan.FromSeconds(15));
Assert.True(throwingWriter.Attempts >= 1,
$"Expected dispatcher to attempt audit write at least once; saw {throwingWriter.Attempts}.");
}
// ---------------------------------------------------------------------
// Test infrastructure
// ---------------------------------------------------------------------
private ScadaLinkDbContext CreateContext()
{
var options = new DbContextOptionsBuilder<ScadaLinkDbContext>()
.UseSqlServer(_fixture.ConnectionString)
.ConfigureWarnings(w => w.Ignore(
Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning))
.Options;
return new ScadaLinkDbContext(options);
}
private IServiceProvider BuildNotificationDispatcherProvider(
INotificationDeliveryAdapter adapter)
{
var services = new ServiceCollection();
services.AddDbContext<ScadaLinkDbContext>(opts =>
opts.UseSqlServer(_fixture.ConnectionString)
.ConfigureWarnings(w => w.Ignore(
Microsoft.EntityFrameworkCore.Diagnostics.RelationalEventId.PendingModelChangesWarning)));
services.AddScoped<INotificationOutboxRepository>(sp =>
new NotificationOutboxRepository(sp.GetRequiredService<ScadaLinkDbContext>()));
services.AddScoped<INotificationRepository>(sp =>
new NotificationRepository(sp.GetRequiredService<ScadaLinkDbContext>()));
services.AddScoped<INotificationDeliveryAdapter>(_ => adapter);
return services.BuildServiceProvider();
}
private async Task SeedSmtpConfigAsync()
{
await using var ctx = CreateContext();
ctx.SmtpConfigurations.Add(new SmtpConfiguration(
"smtp.example.com", "Basic", "noreply@example.com")
{
MaxRetries = 5,
RetryDelay = TimeSpan.Zero,
});
await ctx.SaveChangesAsync();
}
private async Task SeedNotificationAsync(Guid notificationId, string siteId)
{
await using var ctx = CreateContext();
ctx.Notifications.Add(new Notification(
notificationId.ToString("D"),
NotificationType.Email,
"ops-team",
"Safety subject",
"Safety body",
siteId)
{
SourceInstanceId = "Plant.Pump42",
SourceScript = "AlarmScript",
CreatedAt = DateTimeOffset.UtcNow.AddMinutes(-1),
});
await ctx.SaveChangesAsync();
}
/// <summary>
/// Single-outcome adapter — returns the same <see cref="DeliveryOutcome"/>
/// for every call. Used by the dispatcher safety test where we only need
/// one happy-path delivery.
/// </summary>
private sealed class SingleOutcomeAdapter : INotificationDeliveryAdapter
{
private readonly DeliveryOutcome _outcome;
public SingleOutcomeAdapter(DeliveryOutcome outcome) { _outcome = outcome; }
public NotificationType Type => NotificationType.Email;
public Task<DeliveryOutcome> DeliverAsync(
Notification notification, CancellationToken cancellationToken = default)
=> Task.FromResult(_outcome);
}
/// <summary>
/// Builds an in-memory TestHost mirroring the production inbound-API
/// pipeline order. The supplied <paramref name="writer"/> stands in for
/// the production <see cref="ICentralAuditWriter"/> so the safety test can
/// install the always-throwing variant without standing up any DB.
/// </summary>
private static async Task<IHost> BuildInboundApiHostAsync(
ICentralAuditWriter writer, int endpointStatus)
{
var hostBuilder = new HostBuilder()
.ConfigureWebHost(webBuilder =>
{
webBuilder
.UseTestServer()
.ConfigureServices(services =>
{
services.AddSingleton(writer);
services.AddRouting();
services.AddAuthorization();
services.AddAuthentication("TestScheme")
.AddScheme<Microsoft.AspNetCore.Authentication.AuthenticationSchemeOptions,
AlwaysAuthenticatedHandler>("TestScheme", _ => { });
})
.Configure(app =>
{
app.UseRouting();
app.UseAuthentication();
app.UseAuthorization();
app.UseAuditWriteMiddleware();
app.UseEndpoints(endpoints =>
{
endpoints.MapPost("/api/{methodName}", async ctx =>
{
ctx.Items[AuditWriteMiddleware.AuditActorItemKey] = "safety-actor";
ctx.Response.StatusCode = endpointStatus;
await ctx.Response.WriteAsync("ok");
});
});
});
});
return await hostBuilder.StartAsync();
}
private sealed class AlwaysAuthenticatedHandler
: Microsoft.AspNetCore.Authentication.AuthenticationHandler<
Microsoft.AspNetCore.Authentication.AuthenticationSchemeOptions>
{
public AlwaysAuthenticatedHandler(
IOptionsMonitor<Microsoft.AspNetCore.Authentication.AuthenticationSchemeOptions> options,
Microsoft.Extensions.Logging.ILoggerFactory logger,
UrlEncoder encoder)
: base(options, logger, encoder) { }
protected override Task<Microsoft.AspNetCore.Authentication.AuthenticateResult>
HandleAuthenticateAsync()
{
var identity = new ClaimsIdentity(
new[] { new Claim(ClaimTypes.Name, "framework-user") }, "TestScheme");
var principal = new ClaimsPrincipal(identity);
var ticket = new Microsoft.AspNetCore.Authentication.AuthenticationTicket(
principal, "TestScheme");
return Task.FromResult(
Microsoft.AspNetCore.Authentication.AuthenticateResult.Success(ticket));
}
}
}