Report what every CI job spends of its retry budget (GH-3787)

.github/workflows/dotnet.yml

@@ -36,6 +36,9 @@ jobs:
           echo "### Version: $version" >> $GITHUB_STEP_SUMMARY
 
       - name: Test
+        # Names this run in the retry ledger written to the job summary (build/RetryLedger.cs).
+        env:
+          CI_JOB_NAME: dotnet-ci
         run: ./build.sh ci
 
       # The CI target now also runs MessageRoutingTests, which boots a real

.github/workflows/http.yml

@@ -35,11 +35,17 @@ jobs:
       - name: Exercise the openapi command
         run: ./build.sh OpenApiCommand --framework net9.0
 
+      # CI_JOB_NAME names each run in the retry ledger written to the job summary
+      # (build/RetryLedger.cs).
       - name: Run HTTP Tests
+        env:
+          CI_JOB_NAME: CIHttp
         run: ./build.sh CIHttp --framework net9.0
 
       # Asp.Versioning tests are pinned to net10.0
       - name: Run HTTP Asp.Versioning Tests
+        env:
+          CI_JOB_NAME: CIHttpAspVersioning
         run: ./build.sh CIHttpAspVersioning
 
       - name: Stop containers

.github/workflows/slow-tests.yml

@@ -45,6 +45,9 @@ jobs:
           dotnet-version: 10.0.x
 
       - name: Run Tests
+        # Names this run in the retry ledger written to the job summary (build/RetryLedger.cs).
+        env:
+          CI_JOB_NAME: CISlowTests
         run: ./build.sh CISlowTests --framework net9.0
 
       - name: Stop containers

.github/workflows/tests.yml

@@ -91,6 +91,9 @@ jobs:
       - name: Run Tests
         env:
           MEMORY_TELEMETRY: ${{ matrix.memory_telemetry }}
+          # Names this job in the retry ledger (build/RetryLedger.cs). GITHUB_JOB is the matrix's
+          # job id -- the same string, "test", for all thirty of these -- so it cannot be used.
+          CI_JOB_NAME: ${{ matrix.target }}
         run: |
           # The sampler has to live inside this step: when the runner is killed, later steps are
           # skipped, so only what has already been streamed to this step's log survives. See #3771.
@@ -111,6 +114,65 @@ jobs:
           echo "::endgroup::"
           free -m
 
+      # The per-job half of GH-3787. `if: always()` because a job that FAILED is exactly the one
+      # whose retry count is worth having -- and a job killed by the 20-minute cap uploads nothing
+      # at all, which the roll-up below reports as unmeasured rather than as clean.
+      - name: Upload retry ledger
+        if: always()
+        uses: actions/upload-artifact@v7
+        with:
+          name: test-ledger-${{ matrix.target }}
+          path: artifacts/test-ledger/
+          if-no-files-found: ignore
+          retention-days: 30
+
       - name: Stop containers
         if: always()
         run: docker compose down
+
+  # The run-level half of GH-3787. Aggregates every job's ledger into one table on the run summary
+  # and diffs it against the last `main` run that published one.
+  #
+  # This exists because the absolute retry count was never the signal: CIAzureServiceBus sat at 22 of
+  # 25 retries for four consecutive GREEN main runs, and the step from 1 to 22 between two adjacent
+  # runs was the thing worth seeing. Nowhere had that number ever been written down to compare
+  # against. Informational only -- it never fails the run.
+  flakiness:
+    name: Flakiness roll-up
+    needs: test
+    if: always()
+    runs-on: ubuntu-latest
+    permissions:
+      actions: read
+      contents: read
+    steps:
+      - name: Checkout
+        uses: actions/checkout@v6
+        with:
+          fetch-depth: 1
+
+      # Fails when nothing matches, which is a legitimate state: every test job can have died before
+      # it wrote a ledger. The roll-up reports that as unmeasured, so it must survive to run.
+      - name: Download retry ledgers
+        continue-on-error: true
+        uses: actions/download-artifact@v8
+        with:
+          pattern: test-ledger-*
+          path: ledgers
+          merge-multiple: false
+
+      - name: Roll up
+        env:
+          GH_TOKEN: ${{ github.token }}
+        run: ./build/flakiness-report.sh ledgers rollup
+
+      # This run's aggregate becomes the next run's baseline. Only from `main`: a PR's numbers are
+      # measured against main, never the other way round, or one noisy branch would move the bar.
+      - name: Publish this run's baseline
+        if: github.ref == 'refs/heads/main'
+        uses: actions/upload-artifact@v7
+        with:
+          name: test-ledger-run
+          path: rollup/aggregate.json
+          if-no-files-found: warn
+          retention-days: 90

build/RetryLedger.cs

@@ -0,0 +1,198 @@
+using System;
+using System.IO;
+using System.Linq;
+using System.Text;
+using System.Text.Json;
+using Bobcat.Supervisor;
+using Nuke.Common.IO;
+using Serilog;
+
+// The retry ledger: what every supervised run reports about its OWN flakiness, where somebody will
+// actually see it. See GH-3787.
+//
+// The problem this exists for: CIAzureServiceBus was green for four consecutive main runs while
+// spending 22 of its 25-retry budget on every one of them — the same 22 tests failing on the first
+// attempt and passing alone in a fresh process, because the emulator wasn't warm yet. That was 85%
+// of all flakiness in the repository, and nothing in the GitHub UI distinguishes a job at 22/25
+// retries from one at 0/25. Both render as a green tick.
+//
+// Bobcat already logged all of it. Serilog warnings are not GitHub annotations, though — the
+// annotations endpoint for that job returns an empty list — so reading them meant opening the log
+// of a job that PASSED, which nobody has a reason to do. It was found by accident.
+//
+// Three outputs, deliberately:
+//
+//   - `$GITHUB_STEP_SUMMARY` markdown, so the numbers are on the run page without opening a log.
+//   - a `::warning` workflow command when the count is nonzero, so it reaches the Annotations panel.
+//   - a JSON ledger under artifacts/test-ledger/, uploaded per job and aggregated by the
+//     `flakiness` roll-up job in tests.yml, which diffs the run against the last completed main run.
+//
+// The third is the one that matters most. The absolute count mattered less than the CHANGE in it:
+// the step from 1 to 22 between two adjacent main runs was the real signal, and no baseline existed
+// anywhere to notice it against.
+//
+// Deliberately NOT here: failing the build past a retry threshold. A suite legitimately sitting at
+// 3 today would be one bad day away from a red main, and the value is in visibility, not a cliff.
+partial class Build
+{
+    /// <summary>
+    /// Per-project ledger files, one per project+framework, uploaded as a CI artifact. Under
+    /// artifacts/ because <see cref="Clean"/> empties it at the start of every run, so a ledger can
+    /// never be a stale leftover from a previous invocation.
+    /// </summary>
+    static AbsolutePath LedgerDirectory => RootDirectory / "artifacts" / "test-ledger";
+
+    /// <summary>
+    /// The CI job this run belongs to (e.g. CIAzureServiceBus). Set by tests.yml from the matrix
+    /// target; the Nuke target name isn't reachable from here and GITHUB_JOB reports the matrix's
+    /// job id ("test"), which is the same string for all thirty jobs.
+    /// </summary>
+    static string ledgerJobName => Environment.GetEnvironmentVariable("CI_JOB_NAME") is { Length: > 0 } name
+        ? name
+        : "local";
+
+    void recordLedger(string projectName, string framework, SupervisorResults results)
+    {
+        var entry = new LedgerEntry
+        {
+            Job = ledgerJobName,
+            Project = projectName,
+            Framework = framework,
+            Tests = results.Tests.Count,
+            CleanPasses = results.CleanPasses.Count,
+            PassedOnRetry = results.PassedOnRetry.Count,
+            RetriesPerformed = results.RetriesPerformed,
+            Failed = results.Failed.Count,
+            Indeterminate = results.Indeterminate.Count,
+            WorkerFaults = results.WorkerFaults.Count,
+            AbortReason = results.AbortReason,
+            // Bounded by the budget itself: the point of the list is to name the suspects, not to
+            // reproduce the log.
+            FlakyTests = results.PassedOnRetry.Select(x => x.DisplayName).Take(MaxRetriesPerRun).ToArray()
+        };
+
+        writeLedgerFile(entry);
+        appendStepSummary(entry);
+        annotate(entry);
+    }
+
+    static void writeLedgerFile(LedgerEntry entry)
+    {
+        try
+        {
+            LedgerDirectory.CreateDirectory();
+
+            // One file per project+framework: a target can run several projects, and a project can
+            // run under several TFMs, so neither alone is a unique key.
+            var fileName = $"{entry.Job}.{entry.Project}.{entry.Framework}.json";
+            var path = LedgerDirectory / fileName;
+
+            File.WriteAllText(path, JsonSerializer.Serialize(entry, LedgerJson));
+        }
+        catch (Exception e)
+        {
+            // Reporting about the tests must never be what fails the tests.
+            Log.Warning(e, "Could not write the retry ledger for {Project}", entry.Project);
+        }
+    }
+
+    /// <summary>
+    /// Appends this project's row to the job summary. Every supervised project in the job appends
+    /// to the same file, so the header is written once, on the first append.
+    /// </summary>
+    static void appendStepSummary(LedgerEntry entry)
+    {
+        var summaryFile = Environment.GetEnvironmentVariable("GITHUB_STEP_SUMMARY");
+        if (string.IsNullOrEmpty(summaryFile)) return;
+
+        try
+        {
+            var builder = new StringBuilder();
+
+            if (new FileInfo(summaryFile) is { Exists: false } or { Length: 0 })
+            {
+                builder.AppendLine($"### Retry ledger — {entry.Job}");
+                builder.AppendLine();
+                builder.AppendLine("| project | tests | clean | passed on retry | retries | failed | indeterminate |");
+                builder.AppendLine("|---|--:|--:|--:|--:|--:|--:|");
+            }
+
+            builder.AppendLine(
+                $"| {entry.Project} ({entry.Framework}) | {entry.Tests} | {entry.CleanPasses} | " +
+                $"{mark(entry.PassedOnRetry)} | {mark(entry.RetriesPerformed)} | {mark(entry.Failed)} | " +
+                $"{mark(entry.Indeterminate)} |");
+
+            if (entry.AbortReason is not null)
+            {
+                builder.AppendLine();
+                builder.AppendLine($"> **ABORTED** — {entry.AbortReason}");
+            }
+
+            if (entry.FlakyTests.Length > 0)
+            {
+                builder.AppendLine();
+                builder.AppendLine("<details><summary>Tests that only passed on a retry</summary>");
+                builder.AppendLine();
+                foreach (var test in entry.FlakyTests) builder.AppendLine($"- `{test}`");
+                builder.AppendLine();
+                builder.AppendLine("</details>");
+            }
+
+            builder.AppendLine();
+
+            File.AppendAllText(summaryFile, builder.ToString());
+        }
+        catch (Exception e)
+        {
+            Log.Warning(e, "Could not append to $GITHUB_STEP_SUMMARY for {Project}", entry.Project);
+        }
+
+        // Zero reads as zero; anything else is bolded, because the eye is meant to stop on it.
+        static string mark(int count) => count == 0 ? "0" : $"**{count}**";
+    }
+
+    /// <summary>
+    /// Emits the retry count as a GitHub annotation. Serilog's warnings are not annotations — the
+    /// annotations endpoint came back empty for the run that was burning 22 retries — so this has
+    /// to be the literal workflow command on stdout.
+    /// </summary>
+    static void annotate(LedgerEntry entry)
+    {
+        if (Environment.GetEnvironmentVariable("GITHUB_ACTIONS") != "true") return;
+        if (entry.RetriesPerformed == 0) return;
+
+        var suspects = entry.FlakyTests.Length > 0
+            ? $" First flaky test: {entry.FlakyTests[0]}."
+            : "";
+
+        // Workflow commands are newline-delimited, so the message has to be a single line.
+        Console.WriteLine(
+            $"::warning title={entry.Job}: {entry.RetriesPerformed} retries::" +
+            $"{entry.Project} ({entry.Framework}) spent {entry.RetriesPerformed} of its " +
+            $"{MaxRetriesPerRun}-retry budget; " +
+            $"{entry.PassedOnRetry} test(s) passed only on a retry.{suspects}");
+    }
+
+    static readonly JsonSerializerOptions LedgerJson = new() { WriteIndented = true };
+
+    /// <summary>
+    /// One supervised project run, as the roll-up job consumes it. Property names are the contract
+    /// with build/flakiness-report.sh — rename one and the jq there goes silently null, which is why
+    /// that script asserts on the fields it reads.
+    /// </summary>
+    class LedgerEntry
+    {
+        public string Job { get; init; }
+        public string Project { get; init; }
+        public string Framework { get; init; }
+        public int Tests { get; init; }
+        public int CleanPasses { get; init; }
+        public int PassedOnRetry { get; init; }
+        public int RetriesPerformed { get; init; }
+        public int Failed { get; init; }
+        public int Indeterminate { get; init; }
+        public int WorkerFaults { get; init; }
+        public string AbortReason { get; init; }
+        public string[] FlakyTests { get; init; } = [];
+    }
+}

build/SupervisedTests.cs

@@ -43,6 +43,13 @@ partial class Build
     /// </summary>
     [Parameter] readonly bool DisableTestRetry;
 
+    /// <summary>
+    /// Retries a whole project run may spend before every remaining failure is reported as failed
+    /// WITHOUT being retried at all. Read the retry ledger (see RetryLedger.cs) against this number:
+    /// a run at the cap is not "N flaky tests", it is N flaky tests plus an unknown tail.
+    /// </summary>
+    const int MaxRetriesPerRun = 25;
+
     /// <summary>
     /// The standing exclusion every CI target applies: tests tagged [Trait("Category", "Flaky")]
     /// do not run. Same semantics as the old vstest `Category!=Flaky` filter.
@@ -139,7 +146,7 @@ bool runSupervised(string projectPath, string framework, Func<WorkerTest, bool>
             TestFilter = shardFilter is null ? NotFlaky : t => NotFlaky(t) && shardFilter(t),
             RetryBudget = DisableTestRetry
                 ? RetryBudget.None
-                : new RetryBudget { MaxAttemptsPerTest = 3, MaxRetriesPerRun = 25 },
+                : new RetryBudget { MaxAttemptsPerTest = 3, MaxRetriesPerRun = MaxRetriesPerRun },
             // The policy below only ever asks for fresh-process retries, so idle lanes are
             // released before they run: without this, workers+1 test hosts sit resident at once,
             // which OOM-killed 16GB GitHub runners twice — both times during a retry.
@@ -151,7 +158,7 @@ bool runSupervised(string projectPath, string framework, Func<WorkerTest, bool>
 
         var results = supervisor.Run().GetAwaiter().GetResult();
 
-        return report(projectName, results, shardFilter is not null);
+        return report(projectName, framework, results, shardFilter is not null);
     }
 
     /// <summary>
@@ -175,8 +182,10 @@ public Disposition Decide(AttemptContext attempt)
         }
     }
 
-    bool report(string projectName, SupervisorResults results, bool hadShardFilter)
+    bool report(string projectName, string framework, SupervisorResults results, bool hadShardFilter)
     {
+        recordLedger(projectName, framework, results);
+
         if (results.AbortReason is not null)
         {
             Log.Error("=== {Project}: run ABORTED — {Reason} ===", projectName, results.AbortReason);