parallel-make-check: warn when a job runtime drifts >50% from "minutes"

.github/scripts/parallel-make-check.py

@@ -19,7 +19,10 @@
 #   minutes    expected duration, from the Minutes column of a previous
 #              run's summary (default 1.0). Schedule weight only - configs
 #              run longest-first and --shard balances shards by it; a stale
-#              value just packs the schedule a little worse.
+#              value just packs the schedule a little worse, but a run
+#              whose measured time lands more than +/-50% away from it
+#              draws a warning (never a failure) so it is easy to spot
+#              and update.
 #   user_settings  header staged as <builddir>/user_settings.h before
 #              configure (path relative to the source root); pair it with
 #              --enable-usersettings in "configure"
@@ -88,6 +91,9 @@ class Config:
     check: bool = True
     prepare: list[list[str]] = field(default_factory=list)
     run: list[list[str]] = field(default_factory=list)
+    # Whether "minutes" was given in the JSON (vs the 1.0 default); only an
+    # explicit estimate is checked for >50% drift against the real time.
+    minutes_provided: bool = False
 
 SRCDIR = Path(__file__).resolve().parents[2]
 ON_GITHUB = os.environ.get("GITHUB_ACTIONS") == "true"
@@ -208,7 +214,8 @@ def load_configs(opts: argparse.Namespace,
                               entry.get("ldflags", opts.ldflags),
                               float(minutes), user_settings, check,
                               list(entry.get("prepare", [])),
-                              list(entry.get("run", []))))
+                              list(entry.get("run", [])),
+                              minutes_provided="minutes" in entry))
     if not configs:
         error(f"{opts.json}: no configs")
     return configs
@@ -227,8 +234,16 @@ def privatize_dirs(bdir: Path, dirs: list[str]) -> None:
             shutil.copytree(SRCDIR / name, d, symlinks=True)
 
 
+def gh_escape(data: str) -> str:
+    # Percent-encode workflow-command data (GitHub's documented encoding)
+    # so a stray %, CR or LF - e.g. from a config name or step out of the
+    # JSON - can't truncate the command or be parsed as a second one.
+    return data.replace("%", "%25").replace("\r", "%0D").replace("\n", "%0A")
+
+
 def dump(title: str, path: Path) -> None:
-    print(f"::group::{title}" if ON_GITHUB else f"==== {title} ====")
+    # ::group:: is a workflow command; escape its title like warn() does.
+    print(f"::group::{gh_escape(title)}" if ON_GITHUB else f"==== {title} ====")
     try:
         sys.stdout.write(path.read_text(errors="replace"))
     except OSError as e:
@@ -238,6 +253,23 @@ def dump(title: str, path: Path) -> None:
     sys.stdout.flush()
 
 
+def warn(msg: str) -> None:
+    # GitHub surfaces ::warning:: as an annotation at the top of the run;
+    # locally it is just a line. Informational only - never fails the run.
+    print(f"::warning::{gh_escape(msg)}" if ON_GITHUB else f"WARNING: {msg}")
+
+
+def stale_estimate(cfg: Config, minutes: float) -> bool:
+    # "minutes" is only a scheduling estimate (configs run longest-first;
+    # --shard balances by it), never a pass/fail bound. Flag a finished
+    # config whose real time drifted past +/-50% of an explicitly given
+    # estimate so stale values - which pack the schedule worse - are easy
+    # to find and update. Configs that omit "minutes" ride the 1.0 default
+    # placeholder and are left alone.
+    return (cfg.minutes_provided
+            and not 0.5 * cfg.minutes <= minutes <= 1.5 * cfg.minutes)
+
+
 def run_config(cfg: Config, opts: argparse.Namespace) -> tuple[str | None,
                                                                float]:
     if opts.fail_fast and stop_event.is_set():
@@ -344,6 +376,10 @@ def record_failure(step: str) -> str:
             # One line per passing config; the full logs would bloat the CI
             # log (they stay in build-<name>/make-check.log).
             print(f"{cfg.name}: pass [{minutes:.1f} min]")
+            if stale_estimate(cfg, minutes):
+                warn(f"{cfg.name}: ran {minutes:.1f} min but \"minutes\" "
+                     f"says {cfg.minutes:g} (>50% off) - update it in the "
+                     f"config JSON")
             sys.stdout.flush()
         else:
             dump(f"{cfg.name}: FAIL ({failed}) [{minutes:.1f} min]", log)
@@ -364,6 +400,11 @@ def summarize(results: list[tuple[Config, str | None, float]],
             ok = f":x: FAIL ({failed})"
         else:
             ok = ":white_check_mark: pass"
+            if stale_estimate(cfg, minutes):
+                # Non-fatal nudge mirroring the per-config warning, kept in
+                # the summary next to the Minutes value to copy over.
+                ok += (f' :warning: "minutes" {cfg.minutes:g} is >50% off, '
+                       f"update to ~{minutes:.1f}")
         lines.append(f"| {cfg.name} | {ok} | {minutes:.1f} |")
     # Two views of how efficiently the pool used the machine: thread
     # occupancy is the time the workers spent running configs out of the
@@ -495,7 +536,7 @@ def run_one(cfg: Config) -> tuple[Config, str | None, float]:
             else "aborted without a recorded failure"
         if aborted:
             msg += f" ({aborted} config(s) aborted by fail-fast)"
-        print(f"::error::{msg}" if ON_GITHUB else msg)
+        print(f"::error::{gh_escape(msg)}" if ON_GITHUB else msg)
         return 1
     return 0