Record how long CI takes, so a change in it is visible

Sources/.editorconfig

@@ -28,3 +28,6 @@ file_header_template=\nCopyright (c) 2019-2026 Angouri.\nAngouriMath is licensed
 # rather than the folder.
 [AngouriMath/Core/Entity/Continuous/Entity.Continuous.{Floors,Rounding}.Classes.cs]
 file_header_template=\nCopyright (c) 2019-2026 Angouri.\nAngouriMath is licensed under MIT.\nDetails: https://github.com/asc-community/AngouriMath/blob/master/LICENSE.md.\nWebsite: https://am.angouri.org.\n
+
+[Utils/Utils/CiTiming.cs]
+file_header_template=\nCopyright (c) 2019-2026 Angouri.\nAngouriMath is licensed under MIT.\nDetails: https://github.com/asc-community/AngouriMath/blob/master/LICENSE.md.\nWebsite: https://am.angouri.org.\n

Sources/Utils/Utils/CiTiming.cs

@@ -0,0 +1,322 @@
+//
+// Copyright (c) 2019-2026 Angouri.
+// AngouriMath is licensed under MIT.
+// Details: https://github.com/asc-community/AngouriMath/blob/master/LICENSE.md.
+// Website: https://am.angouri.org.
+//
+
+using System;
+using System.Collections.Generic;
+using System.Diagnostics;
+using System.Globalization;
+using System.IO;
+using System.Linq;
+using System.Text.Encodings.Web;
+using System.Text.Json;
+
+namespace Utils
+{
+    /// <summary>
+    /// How long CI takes, and whether that has changed.
+    /// </summary>
+    /// <remarks>
+    /// <para>
+    /// Run with <c>dotnet run CiTiming</c> from <c>Sources/Utils/Utils</c>. Requires the
+    /// GitHub CLI (<c>gh</c>) to be installed and authenticated; it is the only thing here
+    /// that knows how to talk to the API, and using it avoids a token in this repository.
+    /// </para>
+    /// <para>
+    /// Two durations are reported per job and they answer different questions. <em>Exec</em>
+    /// is from the moment a runner picks the job up to the moment it finishes, which is what
+    /// changes when a test suite grows. <em>Queue</em> is from the run being created to a
+    /// runner picking it up, which changes when several pull requests are in flight and says
+    /// nothing about the code. Reporting only the sum of the two — which is what the web UI
+    /// shows — makes a busy afternoon look like a performance regression.
+    /// </para>
+    /// <para>
+    /// The baseline is committed rather than derived, because GitHub keeps run history for a
+    /// bounded window and logs for ninety days. Without a file in the repository there is
+    /// nothing left to compare against once that window passes, which is exactly the
+    /// situation this was written in.
+    /// </para>
+    /// </remarks>
+    public static class CiTiming
+    {
+        private const string Repo = "asc-community/AngouriMath";
+
+        /// <summary>How many runs to ask for. The API caps a page at a thousand.</summary>
+        private const int RunsToFetch = 400;
+
+        /// <summary>Runs per workflow to open up for per-job timings. Each costs a request.</summary>
+        private const int JobSample = 10;
+
+        /// <summary>Reported as a regression above this. Runner-to-runner noise is a few percent.</summary>
+        private const double RegressionThreshold = 0.15;
+
+        private static void Log(string msg) => Console.WriteLine("CiTiming: " + msg);
+
+        public static void Do()
+        {
+            var baselinePath = Path.Join(Program.GetPathIntoSources(), "Utils", "ci-baseline.json");
+            var recording = Environment.GetEnvironmentVariable("CI_TIMING_RECORD") == "1";
+
+            Log($"asking {Repo} for the last {RunsToFetch} runs");
+            var runs = FetchRuns();
+            if (runs.Count is 0)
+            {
+                Log("no successful runs came back — is gh installed and authenticated?");
+                return;
+            }
+            Log($"{runs.Count} successful runs, "
+                + $"{runs.Min(r => r.Created):yyyy-MM-dd} to {runs.Max(r => r.Created):yyyy-MM-dd}");
+
+            var measured = Measure(runs);
+            var baseline = recording ? null : ReadBaseline(baselinePath);
+            Report(measured, baseline);
+
+            if (recording)
+            {
+                WriteBaseline(baselinePath, measured, runs);
+                Log($"baseline written to {baselinePath}");
+            }
+        }
+
+        private readonly record struct Run(long Id, string Workflow, DateTimeOffset Created);
+
+        private readonly record struct JobTiming(string Workflow, string Job, double Exec, double Queue);
+
+        /// <summary>Median exec and queue seconds for one workflow job, over the sample.</summary>
+        private sealed record Stat(string Workflow, string Job, double Exec, double Queue, int Samples);
+
+        private static List<Run> FetchRuns()
+        {
+            var json = Gh($"run list --repo {Repo} --limit {RunsToFetch} "
+                          + "--json name,conclusion,createdAt,databaseId");
+            if (json is null) return new List<Run>();
+
+            var runs = new List<Run>();
+            foreach (var element in JsonDocument.Parse(json).RootElement.EnumerateArray())
+            {
+                // Only successful runs: a run that failed stopped early, so its duration is
+                // the duration of getting to the failure and not of the work.
+                if (element.GetProperty("conclusion").GetString() != "success") continue;
+                runs.Add(new Run(
+                    element.GetProperty("databaseId").GetInt64(),
+                    element.GetProperty("name").GetString() ?? "?",
+                    DateTimeOffset.Parse(element.GetProperty("createdAt").GetString()!,
+                                         CultureInfo.InvariantCulture)));
+            }
+            return runs;
+        }
+
+        private static List<Stat> Measure(List<Run> runs)
+        {
+            var timings = new List<JobTiming>();
+            foreach (var workflow in runs.Select(r => r.Workflow).Distinct().OrderBy(n => n, StringComparer.Ordinal))
+            {
+                // Newest first, so the answer is about the code as it stands.
+                var sample = runs.Where(r => r.Workflow == workflow)
+                                 .OrderByDescending(r => r.Created)
+                                 .Take(JobSample)
+                                 .ToList();
+                Log($"  {workflow}: opening {sample.Count} runs");
+                foreach (var run in sample)
+                    timings.AddRange(JobsOf(run));
+            }
+
+            return timings
+                .GroupBy(t => (t.Workflow, t.Job))
+                .Select(g => new Stat(g.Key.Workflow, g.Key.Job,
+                                      Median(g.Select(t => t.Exec)), Median(g.Select(t => t.Queue)), g.Count()))
+                .OrderByDescending(s => s.Exec)
+                .ToList();
+        }
+
+        private static IEnumerable<JobTiming> JobsOf(Run run)
+        {
+            var json = Gh($"api /repos/{Repo}/actions/runs/{run.Id}/jobs?per_page=100");
+            if (json is null) yield break;
+
+            JsonElement jobs;
+            try
+            {
+                if (!JsonDocument.Parse(json).RootElement.TryGetProperty("jobs", out jobs)) yield break;
+            }
+            catch (JsonException) { yield break; }
+
+            foreach (var job in jobs.EnumerateArray())
+            {
+                var startedRaw = job.GetProperty("started_at").GetString();
+                var completedRaw = job.GetProperty("completed_at").GetString();
+                if (startedRaw is null || completedRaw is null) continue;
+
+                var started = DateTimeOffset.Parse(startedRaw, CultureInfo.InvariantCulture);
+                var completed = DateTimeOffset.Parse(completedRaw, CultureInfo.InvariantCulture);
+                if (completed <= started) continue;
+
+                yield return new JobTiming(run.Workflow, job.GetProperty("name").GetString() ?? "?",
+                                           (completed - started).TotalSeconds,
+                                           Math.Max(0, (started - run.Created).TotalSeconds));
+            }
+        }
+
+        private static void Report(List<Stat> measured, (Snapshot Latest, List<Snapshot> History)? baseline)
+        {
+            var latest = baseline?.Latest;
+            // The oldest snapshot on file, so a slow drift over many small steps is visible.
+            var oldest = baseline?.History.FirstOrDefault() ?? latest;
+
+            Console.WriteLine();
+            var sinceHeader = oldest is null || oldest == latest ? "" : $"since {oldest.Recorded}";
+            Console.WriteLine($"{"workflow / job",-46}{"exec",8}{"queue",8}"
+                              + $"{(latest is null ? "" : latest.Recorded),12}{"change",9}{sinceHeader,17}");
+            Console.WriteLine(new string('-', 100));
+
+            var regressions = new List<string>();
+            foreach (var stat in measured)
+            {
+                var key = Key(stat);
+                var line = $"{Truncate(key, 46),-46}{Minutes(stat.Exec),8}{Minutes(stat.Queue),8}";
+
+                if (latest is not null && latest.Jobs.TryGetValue(key, out var was) && was > 0)
+                {
+                    var change = (stat.Exec - was) / was;
+                    line += $"{Minutes(was),12}{change,9:+0.0%;-0.0%;0.0%}";
+                    if (change > RegressionThreshold) regressions.Add($"{key} {change:+0%}");
+
+                    if (oldest is not null && oldest != latest
+                        && oldest.Jobs.TryGetValue(key, out var first) && first > 0)
+                        line += $"{(stat.Exec - first) / first,17:+0.0%;-0.0%;0.0%}";
+                }
+                else if (latest is not null)
+                    line += $"{"new",12}";
+
+                Console.WriteLine(line);
+            }
+
+            Console.WriteLine();
+            // The jobs run in parallel, so what a contributor waits for is the slowest one,
+            // not the sum. The sum is what the project costs the runner pool.
+            if (measured.Count > 0)
+                Log($"slowest job {Minutes(measured[0].Exec)} ({measured[0].Job} in {measured[0].Workflow}); "
+                    + $"{Minutes(measured.Sum(s => s.Exec))} of runner time per commit");
+
+            if (regressions.Count > 0)
+            {
+                Log($"{regressions.Count} job(s) above the {RegressionThreshold:P0} threshold since "
+                    + $"{latest!.Recorded}:");
+                foreach (var r in regressions) Log("  " + r);
+            }
+            else if (latest is not null)
+                Log("nothing above the threshold");
+        }
+
+        private static string Key(Stat s) => s.Workflow + " / " + s.Job;
+
+        private static string Minutes(double seconds) => (seconds / 60).ToString("0.0", CultureInfo.InvariantCulture) + "m";
+
+        private static string Truncate(string s, int n) => s.Length <= n ? s : s[..(n - 1)] + "…";
+
+        private static double Median(IEnumerable<double> values)
+        {
+            var sorted = values.OrderBy(v => v).ToList();
+            if (sorted.Count is 0) return 0;
+            return sorted.Count % 2 is 1
+                ? sorted[sorted.Count / 2]
+                : (sorted[sorted.Count / 2 - 1] + sorted[sorted.Count / 2]) / 2;
+        }
+
+        /// <summary>One dated set of measurements: the current one, or an older one kept for history.</summary>
+        private sealed record Snapshot(string Recorded, Dictionary<string, double> Jobs);
+
+        private static (Snapshot Latest, List<Snapshot> History)? ReadBaseline(string path)
+        {
+            if (!File.Exists(path))
+            {
+                Log($"no baseline at {path} — run with CI_TIMING_RECORD=1 to write one");
+                return null;
+            }
+            var root = JsonDocument.Parse(File.ReadAllText(path)).RootElement;
+            var history = new List<Snapshot>();
+            if (root.TryGetProperty("history", out var past))
+                history.AddRange(past.EnumerateArray().Select(ReadSnapshot));
+            return (ReadSnapshot(root), history);
+        }
+
+        private static Snapshot ReadSnapshot(JsonElement element)
+            => new(element.GetProperty("recorded").GetString() ?? "?",
+                   element.GetProperty("jobs").EnumerateObject()
+                          .ToDictionary(p => p.Name, p => p.Value.GetDouble()));
+
+        /// <summary>
+        /// Keeps every earlier snapshot. GitHub drops run history after a bounded window and
+        /// logs after ninety days, so a measurement that is not written down here cannot be
+        /// recovered later — which is how the January 2026 numbers were nearly lost.
+        /// </summary>
+        private static void WriteBaseline(string path, List<Stat> measured, List<Run> runs)
+        {
+            var previous = ReadBaseline(path);
+
+            using var stream = File.Create(path);
+            using var writer = new Utf8JsonWriter(stream, new JsonWriterOptions
+            {
+                Indented = true,
+                Encoder = JavaScriptEncoder.UnsafeRelaxedJsonEscaping, // so "C++ Test" reads as itself
+            });
+            writer.WriteStartObject();
+            writer.WriteString("comment", "Median seconds a CI job spends executing, queue time excluded. "
+                                        + "Written by Sources/Utils/Utils/CiTiming.cs; see its remarks.");
+            writer.WriteString("recorded", runs.Max(r => r.Created).ToString("yyyy-MM-dd"));
+            WriteJobs(writer, measured.ToDictionary(Key, s => s.Exec));
+
+            writer.WriteStartArray("history");
+            if (previous is { } p)
+                foreach (var snapshot in p.History.Append(p.Latest))
+                {
+                    writer.WriteStartObject();
+                    writer.WriteString("recorded", snapshot.Recorded);
+                    WriteJobs(writer, snapshot.Jobs);
+                    writer.WriteEndObject();
+                }
+            writer.WriteEndArray();
+            writer.WriteEndObject();
+        }
+
+        private static void WriteJobs(Utf8JsonWriter writer, Dictionary<string, double> jobs)
+        {
+            writer.WriteStartObject("jobs");
+            foreach (var (key, seconds) in jobs.OrderBy(j => j.Key, StringComparer.Ordinal))
+                writer.WriteNumber(key, Math.Round(seconds, 1));
+            writer.WriteEndObject();
+        }
+
+        /// <summary>Runs <c>gh</c> and hands back stdout, or null with a reason logged.</summary>
+        private static string? Gh(string arguments)
+        {
+            try
+            {
+                using var process = Process.Start(new ProcessStartInfo("gh", arguments)
+                {
+                    RedirectStandardOutput = true,
+                    RedirectStandardError = true,
+                });
+                if (process is null) { Log("could not start gh"); return null; }
+
+                var stdout = process.StandardOutput.ReadToEnd();
+                var stderr = process.StandardError.ReadToEnd();
+                process.WaitForExit();
+                if (process.ExitCode is not 0)
+                {
+                    Log($"gh {arguments.Split(' ')[0]} exited {process.ExitCode}: {stderr.Trim()}");
+                    return null;
+                }
+                return stdout;
+            }
+            catch (Exception e)
+            {
+                Log("gh could not be run: " + e.Message);
+                return null;
+            }
+        }
+    }
+}

Sources/Utils/ci-baseline.json

@@ -0,0 +1,69 @@
+{
+  "comment": "Median seconds a CI job spends executing, queue time excluded. Written by Sources/Utils/Utils/CiTiming.cs; see its remarks.",
+  "recorded": "2026-08-09",
+  "jobs": {
+    "C# Test / Test (macos-latest)": 630.5,
+    "C# Test / Test (ubuntu-latest)": 597.5,
+    "C# Test / Test (windows-latest)": 807,
+    "C#/Kernel Build / AngouriMath (macos-latest)": 39.5,
+    "C#/Kernel Build / AngouriMath (ubuntu-latest)": 57,
+    "C#/Kernel Build / AngouriMath (windows-latest)": 105,
+    "C++ Test / Testing (macos-latest, osx-arm64)": 61,
+    "C++ Test / Testing (ubuntu-latest, linux-x64)": 76,
+    "C++ Test / Testing (windows-latest, win-x64)": 160.5,
+    "F# Build / Test (macos-latest)": 32,
+    "F# Build / Test (ubuntu-latest)": 40,
+    "F# Build / Test (windows-latest)": 87,
+    "F# Test / Test (macos-latest)": 69.5,
+    "F# Test / Test (ubuntu-latest)": 94.5,
+    "F# Test / Test (windows-latest)": 149.5,
+    "Integration Test / ClassLibConsoleApp": 125,
+    "Integration Test / ConsoleApp": 123.5,
+    "Interactive Build / Test (macos-latest)": 43.5,
+    "Interactive Build / Test (ubuntu-latest)": 47,
+    "Interactive Build / Test (windows-latest)": 112.5,
+    "Interactive Test / Test (macos-latest)": 68,
+    "Interactive Test / Test (ubuntu-latest)": 117,
+    "Interactive Test / Test (windows-latest)": 202,
+    "Kernel Benchmark / Benchmark": 568,
+    "Solution Build / Everything": 145.5
+  },
+  "history": [
+    {
+      "recorded": "2026-01-22",
+      "jobs": {
+        "C# Test / Test (macos-latest)": 548.0,
+        "C# Test / Test (ubuntu-latest)": 382.5,
+        "C# Test / Test (windows-latest)": 530.0,
+        "C#/Kernel Build / AngouriMath (macos-latest)": 45.0,
+        "C#/Kernel Build / AngouriMath (ubuntu-latest)": 35.0,
+        "C#/Kernel Build / AngouriMath (windows-latest)": 96.5,
+        "C++ Test / Testing (macos-latest, osx-arm64)": 66.5,
+        "C++ Test / Testing (ubuntu-latest, linux-x64)": 59.0,
+        "C++ Test / Testing (windows-latest, win-x64)": 147.0,
+        "Copilot code review / Agent": 95.0,
+        "Copilot code review / Cleanup artifacts": 5.0,
+        "Copilot code review / CodeQL analysis (csharp)": 185.0,
+        "Copilot code review / Prepare": 5.0,
+        "Copilot code review / Upload results": 9.0,
+        "F# Build / Test (macos-latest)": 44.0,
+        "F# Build / Test (ubuntu-latest)": 35.0,
+        "F# Build / Test (windows-latest)": 99.5,
+        "F# Test / Test (macos-latest)": 87.0,
+        "F# Test / Test (ubuntu-latest)": 76.0,
+        "F# Test / Test (windows-latest)": 158.5,
+        "Integration Test / ClassLibConsoleApp": 127.0,
+        "Integration Test / ConsoleApp": 109.5,
+        "Interactive Build / Test (macos-latest)": 46.5,
+        "Interactive Build / Test (ubuntu-latest)": 42.0,
+        "Interactive Build / Test (windows-latest)": 114.0,
+        "Interactive Test / Test (macos-latest)": 97.5,
+        "Interactive Test / Test (ubuntu-latest)": 87.5,
+        "Interactive Test / Test (windows-latest)": 186.0,
+        "Solution Build / Everything": 143.0,
+        "Upload to MyGet / publish": 111.0,
+        "Upload to NuGet / publish": 97.0
+      }
+    }
+  ]
+}