Merge b647-ci: Gitea-compatible artifact upload + deterministic CI-flaky tests (#606)

Claude-Session: https://claude.ai/code/session_01Ef2ozxS7QPanGT8uoATbTe
2026-10-08 20:45:50 -04:00
parent 46bf939ff5 beccfc6404
commit 46b4ab6947
36 changed files with 476 additions and 132 deletions
@@ -69,9 +69,11 @@ public sealed class CalculationDriverInputQualityTests
        }
    }

+    // 30 s ceiling: covers a cold Roslyn compile of the first evaluation on a loaded CI runner, where
+    // 10 s ran out (#606). A quiescence wait — it returns the instant the pump drains.
    private static async Task Settle(CalculationDriver driver)
    {
-        var deadline = DateTime.UtcNow + TimeSpan.FromSeconds(10);
+        var deadline = DateTime.UtcNow + TimeSpan.FromSeconds(30);
        while (DateTime.UtcNow < deadline)
        {
            if (driver.IsEvaluationIdle) return;
@@ -46,10 +46,12 @@ public sealed class CalculationDriverTests
    ///     <c>OnDependencyValue</c> and run on the driver's own worker (Driver.Calculation-005), so a test
    ///     that used to assert on the very next line now settles first. Quiescence, not a sleep: the work
    ///     is enqueued synchronously inside the callback, so "idle" can never be observed before it lands.
+    ///     The 30 s ceiling covers a cold Roslyn compile of the first evaluation on a loaded CI runner,
+    ///     where 10 s ran out (#606); quiescence returns the instant the pump drains, so it costs nothing.
    /// </summary>
    private static async Task Settle(CalculationDriver driver)
    {
-        var idle = await WaitUntil(() => driver.IsEvaluationIdle, TimeSpan.FromSeconds(10));
+        var idle = await WaitUntil(() => driver.IsEvaluationIdle, TimeSpan.FromSeconds(30));
        idle.ShouldBeTrue("the calc driver's evaluation pump should have drained");
    }

@@ -60,6 +60,15 @@ public sealed class CalculationEvaluatorTests

    /// <summary>An infinite-loop script returns Failure ("timed out") within the wall-clock budget instead
    /// of wedging the caller. The whole call is WaitAsync-bounded so a regression FAILS rather than hangs.</summary>
+    /// <summary>
+    ///     A CPU-bound script that outlives the 200 ms run timeout by 25x but still ENDS. A timed-out script
+    ///     is abandoned, not stopped, so the old <c>while(true){}</c> pinned one core for the rest of the test
+    ///     process — starving every parallel suite on a small CI runner (#606). <c>System.DateTime</c> is
+    ///     outside the sandbox deny-list.
+    /// </summary>
+    private const string BoundedSpinScript =
+        "var end = System.DateTime.UtcNow.AddSeconds(5); while (System.DateTime.UtcNow < end) { } return 0;";
+
    [Fact]
    public async Task Evaluate_infinite_loop_script_fails_within_timeout_and_does_not_hang()
    {
@@ -67,10 +76,15 @@ public sealed class CalculationEvaluatorTests
            NullLogger<CalculationEvaluator>.Instance, NoOpScriptRoot(), TimeSpan.FromMilliseconds(200));

        var evalTask = Task.Run(
-            () => sut.Evaluate("calc-loop", "while(true){}return 0;", new Dictionary<string, object?>()),
+            () => sut.Evaluate("calc-loop", BoundedSpinScript, new Dictionary<string, object?>()),
            TestContext.Current.CancellationToken);

-        var result = await evalTask.WaitAsync(TimeSpan.FromSeconds(5), TestContext.Current.CancellationToken);
+        // The outer bound covers the Roslyn COMPILE as well as the run — the 200 ms run timeout starts
+        // only once the script is compiled — and a cold compile on a loaded CI runner took the old 5 s
+        // budget on every one of four consecutive Gitea runs (#606). 30 s is still a hard bound, so a
+        // hang still fails the test; and because the spin ends after 5 s, a timeout that never fires
+        // now fails it too (Success == true), rather than only failing as a hang.
+        var result = await evalTask.WaitAsync(TimeSpan.FromSeconds(30), TestContext.Current.CancellationToken);

        result.Success.ShouldBeFalse();
        result.Reason.ShouldNotBeNull();
@@ -68,8 +68,12 @@ public sealed class FocasLoggingTests

        await drv.InitializeAsync("{}", CancellationToken.None);

-        // Give the probe loop one tick or two to log.
-        await Task.Delay(250);
+        // Wait for the probe loop's first swallowed-exception log instead of sleeping a fixed 250 ms:
+        // on a loaded CI runner no tick had run yet and Entries was empty (#606). A presence wait —
+        // it returns as soon as the entry lands, and a loop that never logs still fails below.
+        var deadline = DateTime.UtcNow.AddSeconds(10);
+        while (!HasProbeEntry(logger) && DateTime.UtcNow < deadline)
+            await Task.Delay(10, TestContext.Current.CancellationToken);

        await drv.ShutdownAsync(CancellationToken.None);

@@ -77,15 +81,23 @@ public sealed class FocasLoggingTests
        // failure or the probe loop. Without logging there's literally no record on a wedged
        // CNC — exactly the gap the finding called out.
        logger.Entries.ShouldNotBeEmpty();
-        logger.Entries.Any(e => e.Message.Contains("probe", StringComparison.OrdinalIgnoreCase)
-                                 || (e.Exception?.Message.Contains("simulated probe failure") ?? false))
+        HasProbeEntry(logger)
            .ShouldBeTrue("at least one log entry should reference the probe loop or surface the swallowed exception");
    }

+    private static bool HasProbeEntry<T>(CapturingLogger<T> logger) =>
+        logger.Entries.Any(e => e.Message.Contains("probe", StringComparison.OrdinalIgnoreCase)
+                                 || (e.Exception?.Message.Contains("simulated probe failure") ?? false));
+
    private sealed class CapturingLogger<T> : ILogger<T>
    {
-        /// <summary>Gets the captured log entries.</summary>
-        public List<(LogLevel Level, string Message, Exception? Exception)> Entries { get; } = new();
+        private readonly List<(LogLevel Level, string Message, Exception? Exception)> _entries = new();
+
+        /// <summary>Gets a snapshot of the captured log entries (written from the probe loop's thread).</summary>
+        public IReadOnlyList<(LogLevel Level, string Message, Exception? Exception)> Entries
+        {
+            get { lock (_entries) return _entries.ToArray(); }
+        }

        /// <summary>Begins a logging scope.</summary>
        /// <param name="state">The scope state.</param>
@@ -104,7 +116,7 @@ public sealed class FocasLoggingTests
        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception,
            Func<TState, Exception?, string> formatter)
        {
-            Entries.Add((logLevel, formatter(state, exception), exception));
+            lock (_entries) _entries.Add((logLevel, formatter(state, exception), exception));
        }

        private sealed class NullScope : IDisposable
@@ -134,8 +134,16 @@ public sealed class ReconnectSupervisorTests

        sup.ReportTransportFailure(new IOException("initial"));

-        // Allow the loop to attempt at least twice.
-        await Task.Delay(100);
+        // Wait for the loop's first failed reopen to land rather than sleeping a fixed 100 ms: on a
+        // loaded CI runner the recovery loop had not been scheduled yet, so LastError still held the
+        // reported cause ("initial") — #606. A presence wait returns the instant the condition holds.
+        var deadline = DateTime.UtcNow.AddMilliseconds(WaitMs);
+        while (DateTime.UtcNow < deadline
+               && sup.LastError?.Contains("reopen broke", StringComparison.OrdinalIgnoreCase) != true)
+        {
+            await Task.Delay(5, TestContext.Current.CancellationToken);
+        }
+
        sup.LastError.ShouldNotBeNull();
        sup.LastError.ShouldContain("reopen broke"); // updates from the loop's failed reopen attempts
    }
@@ -169,8 +169,12 @@ public sealed class ModbusLifecycleHygieneTests
        var drv = new ModbusDriver(opts, "modbus-1", _ => fake);
        await drv.InitializeAsync("{}", CancellationToken.None);

-        // Let the probe + re-probe loops spin a few iterations.
-        await Task.Delay(200);
+        // Wait for the probe loop to issue its first send instead of sleeping a fixed 200 ms — on a
+        // loaded CI runner the loop had not run yet and the precondition below read 0 (#606). This is a
+        // presence wait (returns as soon as a send lands); the post-dispose absence window stays fixed.
+        var deadline = DateTime.UtcNow.AddSeconds(10);
+        while (Interlocked.CompareExchange(ref fake.SendCount, 0, 0) == 0 && DateTime.UtcNow < deadline)
+            await Task.Delay(10, TestContext.Current.CancellationToken);
        var sendsAtDispose = Interlocked.CompareExchange(ref fake.SendCount, 0, 0);
        sendsAtDispose.ShouldBeGreaterThan(0, "background probe loop should have issued at least one send");

@@ -20,6 +20,7 @@ public sealed class ModbusSubscribeOptionsTests
        public ushort CurrentValue;
        public int WritesSent;
        public int FC06Count;
+        public int ReadCount;
        /// <summary>Establishes a connection (no-op for testing).</summary>
        /// <param name="ct">The cancellation token.</param>
        public Task ConnectAsync(CancellationToken ct) => Task.CompletedTask;
@@ -33,6 +34,8 @@ public sealed class ModbusSubscribeOptionsTests
            {
                case 0x03:
                {
+                    // Counted BEFORE CurrentValue is read, so a read counted after a step saw that step.
+                    Interlocked.Increment(ref ReadCount);
                    var qty = (ushort)((pdu[3] << 8) | pdu[4]);
                    var resp = new byte[2 + qty * 2];
                    resp[0] = 0x03; resp[1] = (byte)(qty * 2);
@@ -53,6 +56,27 @@ public sealed class ModbusSubscribeOptionsTests
        }
        /// <summary>Disposes the transport (no-op for testing).</summary>
        public ValueTask DisposeAsync() => ValueTask.CompletedTask;
+
+        /// <summary>
+        ///     Step the register and wait until the poll loop has demonstrably observed it: two FC03 reads
+        ///     counted after the step. The first may be the one that read the new value; the poll loop is
+        ///     sequential, so the second cannot start until the first's publish has been raised. Replaces a
+        ///     fixed 150 ms sleep that, on a loaded CI runner, let a whole step go unpolled — the deadband
+        ///     test then saw [102, 107] or [100, 107] (#606).
+        /// </summary>
+        /// <param name="value">The new register value.</param>
+        public async Task StepAndObserveAsync(ushort value)
+        {
+            CurrentValue = value;
+            var target = Volatile.Read(ref ReadCount) + 2;
+            var deadline = DateTime.UtcNow.AddSeconds(10);
+            while (Volatile.Read(ref ReadCount) < target)
+            {
+                if (DateTime.UtcNow > deadline)
+                    throw new TimeoutException($"poll loop did not read register value {value} within 10 s");
+                await Task.Delay(5);
+            }
+        }
    }

    /// <summary>Verifies that deadband filter suppresses changes below the threshold.</summary>
@@ -73,14 +97,10 @@ public sealed class ModbusSubscribeOptionsTests
        var sub = await drv.SubscribeAsync(["Temp"], TimeSpan.FromMilliseconds(50), CancellationToken.None);
        try
        {
-            fake.CurrentValue = 100;
-            await Task.Delay(150);
-            fake.CurrentValue = 102;
-            await Task.Delay(150);
-            fake.CurrentValue = 106;
-            await Task.Delay(150);
-            fake.CurrentValue = 107;
-            await Task.Delay(150);
+            await fake.StepAndObserveAsync(100);
+            await fake.StepAndObserveAsync(102);
+            await fake.StepAndObserveAsync(106);
+            await fake.StepAndObserveAsync(107);
        }
        finally
        {
@@ -112,8 +132,8 @@ public sealed class ModbusSubscribeOptionsTests
        var sub = await drv.SubscribeAsync(["Temp"], TimeSpan.FromMilliseconds(50), CancellationToken.None);
        try
        {
-            fake.CurrentValue = 100; await Task.Delay(150);
-            fake.CurrentValue = 101; await Task.Delay(150); // tiny change still publishes
+            await fake.StepAndObserveAsync(100);
+            await fake.StepAndObserveAsync(101); // tiny change still publishes
        }
        finally { await drv.UnsubscribeAsync(sub, CancellationToken.None); }