merge(agent-c): row 82 — cross-process create+migrate throttle (sp_getapplock counting semaphore), honest command timeouts, deterministic actor stops in the two leaking AuditLog test classes

This commit is contained in:
Joseph Doherty
2026-08-17 04:09:36 -04:00
4 changed files with 538 additions and 69 deletions
@@ -14,27 +14,90 @@ namespace ZB.MOM.WW.ScadaBridge.ConfigurationDatabase.Tests.Migrations;
/// so the runner reports them as Skipped (not silently Passed).
/// </summary>
/// <remarks>
/// <para>
/// xunit 2.9.x has no native <c>Assert.Skip</c>/<c>Assert.SkipUnless</c> (those
/// are v3); the project uses the Xunit.SkippableFact package as the canonical
/// equivalent. The fixture attempts connect + create-db + migrate once at
/// construct time. The Connect Timeout=3 in <see cref="DefaultAdminConnectionString"/>
/// makes the fixture fail fast in a no-container environment (under ~5s total)
/// instead of hanging 30s on SqlClient's default. Only connect-failure exceptions
/// (SqlException, plus the InvalidOperationException SqlClient raises from
/// OpenAsync) flip Available to false — every other exception bubbles up so a
/// real bug is not silently swallowed.
/// construct time. Only connect-failure exceptions (SqlException, plus the
/// InvalidOperationException SqlClient raises from OpenAsync) flip Available to
/// false — every other exception bubbles up so a real bug is not silently
/// swallowed.
/// </para>
/// <para>
/// <b>Cross-process throttling (deferred-work register row 82).</b> Database
/// <i>naming</i> was already isolated (a guid per fixture instance), but nothing
/// bounded how many fixtures ran <c>CREATE DATABASE</c> + the full migration
/// chain against the single dev SQL Server at the same time. xunit runs
/// processor-count test collections in parallel <i>per process</i>, and a
/// full-solution run starts several MSSQL-backed test processes at once — so the
/// server saw dozens of concurrent fresh-database migrations. That is pure
/// resource saturation (CPU / log IO / tempdb on one container), not object-level
/// locking, and it pushed individual migration DDL statements past EF's default
/// 30-second command timeout. Every observed failure had the identical
/// fingerprint: <c>MsSqlMigrationFixture..ctor</c> → <c>Migrator.MigrateAsync</c>
/// → <c>SqlException: Execution Timeout Expired</c> (error 258), which xunit
/// reports as "Class fixture type … threw in its constructor" against every test
/// in the class — a false red that vanished on a re-run in isolation.
/// </para>
/// <para>
/// Two changes close it. First, <see cref="MigrationGate"/> bounds the number of
/// simultaneous create+migrate windows <i>across every process on the machine</i>
/// using SQL Server application locks (<c>sp_getapplock</c>) on <c>master</c> as a
/// counting semaphore — an xunit collection attribute cannot do this, because the
/// contention is between separate test processes. Second, the create/migrate
/// commands get timeouts sized for a queued-but-progressing server rather than an
/// idle one, so a slot holder waits instead of failing. The work always completed;
/// it just did not complete within 30 seconds.
/// </para>
/// </remarks>
public sealed class MsSqlMigrationFixture : IDisposable
{
// Same credentials infra/mssql/setup.sql + docker-compose use. Not a committed
// production secret — this is a local dev container connection string.
// Connect Timeout=3 makes the fixture fail fast (~3s) in a no-container
// environment rather than hanging on SqlClient's default 30s connect timeout.
// Connect Timeout=3 makes the connectivity probe fail fast (~3s per attempt) in a
// no-container environment rather than hanging on SqlClient's default 30s.
private const string DefaultAdminConnectionString =
"Server=localhost,1433;User Id=sa;Password=ScadaBridge_Dev1#;TrustServerCertificate=true;Encrypt=false;Connect Timeout=3";
private const string AdminEnvVar = "SCADABRIDGE_MSSQL_TEST_CONN";
/// <summary>
/// Command timeout for the migration chain. Deliberately far above EF's 30s
/// default: under a bounded queue the server is busy but progressing, and the
/// correct response to a slow DDL statement is to wait for it, not to fail the
/// whole class. See the register-row-82 note in the type remarks.
/// </summary>
private const int MigrationCommandTimeoutSeconds = 300;
/// <summary>
/// Command timeout for the CREATE / DROP DATABASE statements. Lower than the
/// migration chain (one statement, not fifty-odd) but still well clear of the
/// 30s default, because CREATE DATABASE zeroes a fresh log file and that is the
/// single most IO-bound step in the fixture.
/// </summary>
private const int DatabaseDdlCommandTimeoutSeconds = 120;
/// <summary>
/// Number of connectivity-probe attempts before declaring MSSQL unavailable.
/// A single 3s attempt is not proof of absence once the server is under load —
/// treating a busy server as an absent one would silently turn every MSSQL test
/// into a Skip, which reads as green and is worse than a red.
/// </summary>
private const int ConnectProbeAttempts = 3;
/// <summary>
/// Databases whose name matches the fixture prefix and that are older than this
/// are assumed to be strays from a crashed run and are dropped at process start.
/// Comfortably longer than any legitimate fixture lifetime, so a live fixture in
/// a concurrently-running process is never targeted.
/// </summary>
private static readonly TimeSpan OrphanDatabaseMaxAge = TimeSpan.FromHours(2);
private const string DatabaseNamePrefix = "ScadaBridgeAuditMigTest_";
/// <summary>Guards the once-per-process orphan sweep.</summary>
private static int _orphanSweepStarted;
public string DatabaseName { get; }
public string ConnectionString { get; }
@@ -58,7 +121,7 @@ public sealed class MsSqlMigrationFixture : IDisposable
{
// Short, lowercase guid suffix keeps the database identifier under SQL Server's
// 128-char limit and safe for raw concatenation (no quoting required).
DatabaseName = $"ScadaBridgeAuditMigTest_{Guid.NewGuid():N}".Substring(0, 38);
DatabaseName = $"{DatabaseNamePrefix}{Guid.NewGuid():N}".Substring(0, 38);
// Env var lets CI / power users override the admin endpoint; absent
// defaults to the local docker dev container's sa connection.
@@ -67,46 +130,50 @@ public sealed class MsSqlMigrationFixture : IDisposable
? DefaultAdminConnectionString
: fromEnv;
// Step 1: open the admin connection. This is the only step that may
// legitimately fail when MSSQL is absent; SqlException + the rare
// InvalidOperationException from OpenAsync are the connect-failure
// surfaces we tolerate. Everything else (CREATE DATABASE, MigrateAsync)
// is treated as a hard fixture failure once we *have* a connection.
// Step 1: probe connectivity. This is the only step that may legitimately
// fail when MSSQL is absent; SqlException + the rare InvalidOperationException
// from Open are the connect-failure surfaces we tolerate. Everything else
// (CREATE DATABASE, MigrateAsync) is treated as a hard fixture failure once we
// *have* a connection.
var probeFailure = ProbeConnectivity(_adminConnectionString);
if (probeFailure is not null)
{
ConnectionString = string.Empty;
Available = false;
SkipReason = probeFailure;
return;
}
// Step 2: best-effort, once per process — drop databases stranded by a run
// that crashed before Dispose. The guid suffix means they never collide, but
// they do accumulate and consume server resources, which feeds the very
// saturation this fixture now throttles against.
SweepOrphanDatabasesOnce(_adminConnectionString);
try
{
using var connection = new SqlConnection(_adminConnectionString);
try
// Step 3: take a create+migrate slot. Held across BOTH the CREATE DATABASE
// and the migration chain, then released — this is the machine-wide bound
// on how much fresh-database DDL the dev server is asked to do at once.
using (MigrationGate.Acquire(_adminConnectionString))
{
connection.Open();
}
catch (SqlException ex)
{
ConnectionString = string.Empty;
Available = false;
SkipReason = $"MSSQL unavailable (connect failed: SqlException {ex.Number}: {ex.Message})";
return;
}
catch (InvalidOperationException ex)
{
ConnectionString = string.Empty;
Available = false;
SkipReason = $"MSSQL unavailable (OpenAsync threw: {ex.Message})";
return;
}
using (var connection = new SqlConnection(_adminConnectionString))
{
connection.Open();
using var createCmd = connection.CreateCommand();
createCmd.CommandTimeout = DatabaseDdlCommandTimeoutSeconds;
createCmd.CommandText = $"CREATE DATABASE [{DatabaseName}];";
createCmd.ExecuteNonQuery();
}
using (var createCmd = connection.CreateCommand())
{
createCmd.CommandText = $"CREATE DATABASE [{DatabaseName}];";
createCmd.ExecuteNonQuery();
ConnectionString = BuildPerDbConnectionString(_adminConnectionString, DatabaseName);
// Apply the EF migrations once at fixture construction so each test
// can read from a fully-migrated database without per-test setup.
// Failures here are real bugs — let them bubble.
ApplyMigrationsCore(ConnectionString, CancellationToken.None).GetAwaiter().GetResult();
}
ConnectionString = BuildPerDbConnectionString(_adminConnectionString, DatabaseName);
// Apply the EF migrations once at fixture construction so each test
// can read from a fully-migrated database without per-test setup.
// Failures here are real bugs — let them bubble.
ApplyMigrationsCore(ConnectionString, CancellationToken.None).GetAwaiter().GetResult();
Available = true;
SkipReason = string.Empty;
}
@@ -119,6 +186,104 @@ public sealed class MsSqlMigrationFixture : IDisposable
}
}
/// <summary>
/// Opens the admin connection up to <see cref="ConnectProbeAttempts"/> times.
/// Returns null when a connection was established, or the skip reason when every
/// attempt failed.
/// </summary>
private static string? ProbeConnectivity(string adminConnectionString)
{
string lastFailure = "MSSQL unavailable (no connect attempt was made)";
for (var attempt = 1; attempt <= ConnectProbeAttempts; attempt++)
{
try
{
using var connection = new SqlConnection(adminConnectionString);
connection.Open();
return null;
}
catch (SqlException ex)
{
lastFailure =
$"MSSQL unavailable (connect failed after {attempt} attempt(s): SqlException {ex.Number}: {ex.Message})";
}
catch (InvalidOperationException ex)
{
lastFailure =
$"MSSQL unavailable (Open threw after {attempt} attempt(s): {ex.Message})";
}
if (attempt < ConnectProbeAttempts)
{
Thread.Sleep(TimeSpan.FromMilliseconds(250 * attempt));
}
}
return lastFailure;
}
/// <summary>
/// Drops fixture databases left behind by a run that died before
/// <see cref="Dispose"/>. Runs at most once per test process and swallows every
/// failure — an uncleaned stray is untidy, not fatal, and must never turn into a
/// fixture error.
/// </summary>
private static void SweepOrphanDatabasesOnce(string adminConnectionString)
{
if (Interlocked.Exchange(ref _orphanSweepStarted, 1) != 0)
{
return;
}
try
{
using var connection = new SqlConnection(adminConnectionString);
connection.Open();
var stale = new List<string>();
using (var listCmd = connection.CreateCommand())
{
listCmd.CommandTimeout = DatabaseDdlCommandTimeoutSeconds;
listCmd.CommandText =
"SELECT name FROM sys.databases " +
"WHERE name LIKE @Prefix + '%' AND create_date < DATEADD(minute, -@AgeMinutes, GETDATE());";
listCmd.Parameters.AddWithValue("@Prefix", DatabaseNamePrefix);
listCmd.Parameters.AddWithValue("@AgeMinutes", (int)OrphanDatabaseMaxAge.TotalMinutes);
using var reader = listCmd.ExecuteReader();
while (reader.Read())
{
stale.Add(reader.GetString(0));
}
}
foreach (var name in stale)
{
try
{
using var dropCmd = connection.CreateCommand();
dropCmd.CommandTimeout = DatabaseDdlCommandTimeoutSeconds;
// Name comes from sys.databases filtered to our own guid-suffixed
// prefix, so it cannot carry an injection payload.
dropCmd.CommandText =
$"ALTER DATABASE [{name}] SET SINGLE_USER WITH ROLLBACK IMMEDIATE; " +
$"DROP DATABASE [{name}];";
dropCmd.ExecuteNonQuery();
}
catch
{
// Another process may be mid-drop, or the database may be in use.
// Best-effort by design.
}
}
}
catch
{
// Best-effort by design.
}
}
private void TryDropOrphanDatabase()
{
if (string.IsNullOrEmpty(ConnectionString))
@@ -126,24 +291,7 @@ public sealed class MsSqlMigrationFixture : IDisposable
return;
}
try
{
SqlConnection.ClearAllPools();
using var connection = new SqlConnection(_adminConnectionString);
connection.Open();
using var cmd = connection.CreateCommand();
cmd.CommandText =
$"IF DB_ID(N'{DatabaseName}') IS NOT NULL " +
$"BEGIN " +
$" ALTER DATABASE [{DatabaseName}] SET SINGLE_USER WITH ROLLBACK IMMEDIATE; " +
$" DROP DATABASE [{DatabaseName}]; " +
$"END";
cmd.ExecuteNonQuery();
}
catch
{
// Best-effort — orphan databases carry a random guid suffix.
}
DropSelf();
}
/// <summary>
@@ -156,7 +304,10 @@ public sealed class MsSqlMigrationFixture : IDisposable
private static async Task ApplyMigrationsCore(string connectionString, CancellationToken cancellationToken)
{
var options = new DbContextOptionsBuilder<ScadaBridgeDbContext>()
.UseSqlServer(connectionString)
// The explicit command timeout is the register-row-82 fix: EF's 30s default
// is what actually failed under cross-process load, and every migration
// statement in the chain inherits this value.
.UseSqlServer(connectionString, sql => sql.CommandTimeout(MigrationCommandTimeoutSeconds))
.Options;
await using var context = new ScadaBridgeDbContext(options);
@@ -183,9 +334,18 @@ public sealed class MsSqlMigrationFixture : IDisposable
return;
}
// Best-effort drop — never let a teardown failure pollute later runs.
// SINGLE_USER WITH ROLLBACK IMMEDIATE detaches lingering pooled connections
// so the DROP DATABASE doesn't fail with "database is in use".
DropSelf();
}
/// <summary>
/// Best-effort drop of this fixture's database — never let a teardown failure
/// pollute later runs. SINGLE_USER WITH ROLLBACK IMMEDIATE detaches lingering
/// pooled connections so the DROP DATABASE doesn't fail with "database is in use".
/// Deliberately NOT gated by <see cref="MigrationGate"/>: holding a create+migrate
/// slot at teardown would starve the fixtures still trying to start.
/// </summary>
private void DropSelf()
{
try
{
// Connection-pool cleanup is necessary because EF's MigrateAsync leaves
@@ -197,6 +357,7 @@ public sealed class MsSqlMigrationFixture : IDisposable
connection.Open();
using var cmd = connection.CreateCommand();
cmd.CommandTimeout = DatabaseDdlCommandTimeoutSeconds;
cmd.CommandText =
$"IF DB_ID(N'{DatabaseName}') IS NOT NULL " +
$"BEGIN " +
@@ -208,7 +369,8 @@ public sealed class MsSqlMigrationFixture : IDisposable
catch
{
// Swallow — the database name carries a random guid suffix so a
// stranded test database does not collide with future runs.
// stranded test database does not collide with future runs, and the
// next process's orphan sweep will clear it.
}
}
@@ -234,4 +396,189 @@ public sealed class MsSqlMigrationFixture : IDisposable
};
return builder.ConnectionString;
}
/// <summary>
/// A machine-wide counting semaphore over the create+migrate window, built from
/// SQL Server session-scoped application locks on <c>master</c>
/// (deferred-work register row 82).
/// </summary>
/// <remarks>
/// <para>
/// <b>Why not an xunit collection?</b> xunit's parallelism controls only bound
/// the collections inside ONE test assembly running in ONE process. The
/// contention here is between processes — <c>AuditLog.Tests</c>,
/// <c>ConfigurationDatabase.Tests</c> and anything else a solution-level
/// <c>dotnet test</c> starts in parallel all hammer the same container. The
/// arbiter therefore has to live on the shared resource itself, which is the
/// SQL Server instance.
/// </para>
/// <para>
/// <c>sp_getapplock</c> is a binary mutex, so a counting semaphore is emulated
/// with <see cref="SlotCount"/> distinctly-named lock resources: a caller walks
/// the slots with a short per-slot timeout and takes the first free one, looping
/// until it wins or the overall deadline passes. Application locks are
/// <b>database-scoped</b>, so every gate connection targets <c>master</c> to make
/// sure all processes contend over the same namespace regardless of which test
/// database they are about to build.
/// </para>
/// <para>
/// Pooling is disabled on the gate connection. A session-scoped application lock
/// is released by <c>sp_reset_connection</c>, which a pooled connection only
/// issues when it is next <i>reused</i> — so a pooled gate connection could keep
/// a slot locked long after Dispose. Closing an unpooled connection ends the
/// session outright, and the explicit <c>sp_releaseapplock</c> makes the normal
/// path deterministic rather than relying on that. A crashed process drops its
/// connection, and SQL Server releases the lock with it, so the gate cannot
/// wedge the suite.
/// </para>
/// <para>
/// The gate never fails a test: if the deadline passes without a slot, it returns
/// an ungated instance and lets the (now generous) command timeouts carry the
/// run. A throttle that could itself become a source of red is not worth having.
/// </para>
/// </remarks>
private sealed class MigrationGate : IDisposable
{
/// <summary>
/// How many fixtures may build a database at once, machine-wide. Sized to keep
/// the dev container busy without saturating it; override with
/// <c>SCADABRIDGE_MSSQL_TEST_MIGRATE_SLOTS</c>.
/// </summary>
private const int DefaultSlotCount = 4;
private const string SlotEnvVar = "SCADABRIDGE_MSSQL_TEST_MIGRATE_SLOTS";
private const string ResourcePrefix = "ScadaBridgeTestMigrate/";
/// <summary>Per-slot wait before moving on to try the next slot.</summary>
private const int PerSlotLockTimeoutMs = 500;
/// <summary>
/// Overall wait for a slot. Long enough to outlast a full queue of migration
/// chains on a loaded server; past it the gate gives up and lets the caller
/// proceed ungated rather than failing.
/// </summary>
private static readonly TimeSpan AcquireDeadline = TimeSpan.FromMinutes(10);
private static int SlotCount
{
get
{
var raw = Environment.GetEnvironmentVariable(SlotEnvVar);
return int.TryParse(raw, out var parsed) && parsed > 0 ? parsed : DefaultSlotCount;
}
}
private readonly SqlConnection? _connection;
private readonly string? _resource;
private MigrationGate(SqlConnection? connection, string? resource)
{
_connection = connection;
_resource = resource;
}
public static MigrationGate Acquire(string adminConnectionString)
{
var slots = SlotCount;
SqlConnection? connection = null;
try
{
connection = new SqlConnection(BuildGateConnectionString(adminConnectionString));
connection.Open();
var deadline = DateTime.UtcNow + AcquireDeadline;
// Start each caller at a different slot so they spread out instead of
// all queueing behind slot 0.
var offset = Random.Shared.Next(slots);
while (DateTime.UtcNow < deadline)
{
for (var i = 0; i < slots; i++)
{
var resource = ResourcePrefix + ((offset + i) % slots);
if (TryAcquireSlot(connection, resource))
{
return new MigrationGate(connection, resource);
}
}
}
}
catch
{
// The gate is an optimisation, not a correctness requirement — if it
// cannot be established (permissions, an older server, a transient
// fault) the caller proceeds ungated.
}
connection?.Dispose();
return new MigrationGate(null, null);
}
private static bool TryAcquireSlot(SqlConnection connection, string resource)
{
using var cmd = connection.CreateCommand();
cmd.CommandType = System.Data.CommandType.StoredProcedure;
cmd.CommandText = "sp_getapplock";
cmd.CommandTimeout = (PerSlotLockTimeoutMs / 1000) + 30;
cmd.Parameters.AddWithValue("@Resource", resource);
cmd.Parameters.AddWithValue("@LockMode", "Exclusive");
cmd.Parameters.AddWithValue("@LockOwner", "Session");
cmd.Parameters.AddWithValue("@LockTimeout", PerSlotLockTimeoutMs);
var result = cmd.Parameters.Add("@Result", System.Data.SqlDbType.Int);
result.Direction = System.Data.ParameterDirection.ReturnValue;
cmd.ExecuteNonQuery();
// 0 = granted immediately, 1 = granted after waiting; everything else
// (-1 timeout, -2 cancelled, -3 deadlock victim, -999 error) means "not ours".
var code = result.Value as int? ?? -999;
return code >= 0;
}
private static string BuildGateConnectionString(string adminConnectionString)
{
return new SqlConnectionStringBuilder(adminConnectionString)
{
// Application locks are database-scoped: every process must contend in
// the same database for the slots to mean anything.
InitialCatalog = "master",
// See the remarks — a pooled connection defers the implicit release of a
// session-scoped app lock until the connection is reused.
Pooling = false,
}.ConnectionString;
}
public void Dispose()
{
if (_connection is null)
{
return;
}
try
{
if (_resource is not null)
{
using var cmd = _connection.CreateCommand();
cmd.CommandType = System.Data.CommandType.StoredProcedure;
cmd.CommandText = "sp_releaseapplock";
cmd.Parameters.AddWithValue("@Resource", _resource);
cmd.Parameters.AddWithValue("@LockOwner", "Session");
cmd.ExecuteNonQuery();
}
}
catch
{
// Closing the unpooled connection below ends the session, which releases
// the lock regardless.
}
finally
{
_connection.Dispose();
}
}
}
}