From fbe8170408240997c9f903f3650d1507ce7181f9 Mon Sep 17 00:00:00 2001 From: jsboige Date: Mon, 7 Sep 2026 07:14:32 +0200 Subject: [PATCH 1/2] feat(ci,#14597): sample runner-park occupation as the render-timing covariate The post-render amplification (2:56 vs 15:09 on the same runners across days) correlates with WHEN the run happened, not WHERE (dispatch ai-01 2026-09-07): #14429 documents 19/22 busy during the slow window vs 0/28 now. Instrument the covariate before choosing a remedy: - new --sample-occupation mode: at job START (before the ~20 min render), count busy/online self-hosted runners via /actions/runners (stdlib urllib, Link-pagination capped), write occupation.json; - the report step merges it into the phase table and prints one greppable record per run: "#14597-covariates: runner=...,busy=...,online=..., total=...,doc_s=...,post_s=...,total_s=..." -- >=6 full runs can then be harvested from job logs and regressed on BOTH covariates; - both legs (build + validate-pr full mode) wired; jobs gain actions: read; - measurement, never a gate: 403/missing token/bad JSON degrade to "not sampled"/na, build stays green. 13 tests (7 new). See #14597 Co-Authored-By: Claude-Code --- .github/workflows/quarto-pages-deploy.yml | 28 +++- scripts/quarto_render_timing.py | 149 ++++++++++++++++++++- scripts/tests/test_quarto_render_timing.py | 74 ++++++++++ 3 files changed, 245 insertions(+), 6 deletions(-) diff --git a/.github/workflows/quarto-pages-deploy.yml b/.github/workflows/quarto-pages-deploy.yml index 46da08a351..da64c0d7e6 100644 --- a/.github/workflows/quarto-pages-deploy.yml +++ b/.github/workflows/quarto-pages-deploy.yml @@ -85,10 +85,21 @@ jobs: timeout-minutes: 60 permissions: contents: read + actions: read # #14597 : lister les self-hosted runners (covariable d'occupation) steps: - name: Checkout uses: actions/checkout@v4 + - name: Sample runner-park occupation (#14597) + # Covariable d'occupation (dispatch ai-01 2026-09-07) : busy/online du + # parc au DEMARRAGE du job, fusionne dans le tableau du step "Report + # render phase timings". Mesure pas gate : 403 -> "not sampled". + # Doit tourner AVANT le rendu (~20 min) : le compte doit decrire le + # parc au moment ou le job demarre, pas ou il finit. + env: + GITHUB_TOKEN: ${{ github.token }} + run: python scripts/quarto_render_timing.py --sample-occupation occupation.json + - name: Set up Quarto # Routage #14283 (feu vert ai-01 2026-09-02) : PAS quarto-dev/quarto-actions/setup@v2 — # elle installe un .deb via `sudo apt -y install`, et l'image du pool self-hosted est @@ -161,7 +172,10 @@ jobs: # Mesure (#14597), pas une gate : exit 0 toujours, "not found" si un # marqueur manque (changement de format de log Quarto = rapport dégradé, # pas un build rouge). Ajoute le tableau de phases au job summary. - run: python scripts/quarto_render_timing.py render-timed.log + # --occupation : busy/online echantillonne au demarrage (step amont) ; + # --runner-name implicite via $RUNNER_NAME. Imprime aussi la ligne + # greppable "#14597-covariates:" pour la moisson multi-runs. + run: python scripts/quarto_render_timing.py render-timed.log --occupation occupation.json - name: Restore kernel language (hygiene) # Le checkout CI est ephemere : le restore n'est pas indispensable, mais il @@ -230,6 +244,7 @@ jobs: timeout-minutes: 60 permissions: contents: read + actions: read # #14597 : lister les self-hosted runners (covariable d'occupation) pull-requests: write # pour poster le commentaire de gate steps: - name: Checkout @@ -285,6 +300,15 @@ jobs: --head "${{ github.event.pull_request.head.sha }}" \ --apply --github-output + - name: Sample runner-park occupation (#14597) + # Meme covariable qu'en jambe build, echantillonnee au plus tot APRES + # le scope : seul un rendu COMPLET (mode full) sera rapporte, inutile + # de consommer un appel API sur un rendu scope. + if: steps.scope.outputs.mode == 'full' + env: + GITHUB_TOKEN: ${{ github.token }} + run: python scripts/quarto_render_timing.py --sample-occupation occupation.json + - name: Normalize .NET kernel language for Quarto (C# -> csharp) if: steps.scope.outputs.mode != 'empty' run: python scripts/quarto_csharp_kernel_fix.py apply @@ -314,7 +338,7 @@ jobs: # des runs a 53 min (#14225). Sur un rendu scope (1-2 documents), la # phase post-rendu n'est pas representative et le rapport resterait muet. if: steps.scope.outputs.mode == 'full' - run: python scripts/quarto_render_timing.py render-timed.log + run: python scripts/quarto_render_timing.py render-timed.log --occupation occupation.json - name: Restore kernel language (hygiene) if: steps.scope.outputs.mode != 'empty' diff --git a/scripts/quarto_render_timing.py b/scripts/quarto_render_timing.py index 7a11a1b6f9..f03eb14c96 100644 --- a/scripts/quarto_render_timing.py +++ b/scripts/quarto_render_timing.py @@ -26,6 +26,26 @@ ``not found`` for any marker absent from the log, so a Quarto log-format change degrades the report rather than breaking the build. +Runner-park occupation covariate (dispatch ai-01 2026-09-07) +------------------------------------------------------------ +The post-render amplification (2:56 vs 15:09) correlated with WHEN the run +happened, not WHERE: the same runners show both regimes across days. The +surviving covariate is park OCCUPATION (busy/online at job start, cf #14429 +19/22 busy during the slow window vs 0/28 during the fast one). The workflow +samples it in a FIRST step (before the ~20 min render -- the count must +describe the park when the job started, not when it finished):: + + python scripts/quarto_render_timing.py --sample-occupation occupation.json + +then the report step merges it into the table and prints a one-line +machine-readable record (greppable across >=6 runs for the two regressions: +runner name vs occupation):: + + #14597-covariates: runner=...,busy=...,online=...,total=...,doc_s=...,post_s=...,total_s=... + +Both paths degrade, never gate: an HTTP 403 or a missing occupation file +reports ``not sampled``/``na`` and the build stays green. + Local usage ----------- The same format is produced outside CI by:: @@ -41,14 +61,19 @@ from __future__ import annotations import argparse +import json import os import re import sys -from datetime import datetime +import urllib.error +import urllib.request +from datetime import datetime, timezone TS_RE = re.compile(r"^(\d{2}:\d{2}:\d{2})\s?") DOC_RE = re.compile(r"\[\s*(\d+)\s*/\s*(\d+)\s*\]") OUTPUT_RE = re.compile(r"Output created:\s*(\S+)") +LINK_NEXT_RE = re.compile(r'<([^>]+)>;\s*rel="next"') +MAX_RUNNER_PAGES = 10 def _parse(ts: str) -> datetime: @@ -117,7 +142,79 @@ def analyse(raw: str) -> dict[str, object]: } -def render_report(r: dict[str, object]) -> str: +def parse_runners_pages(pages: list[dict]) -> dict[str, int]: + """Count total/online/busy across ``/actions/runners`` API pages.""" + runners = [r for page in pages for r in page.get("runners", [])] + return { + "total": len(runners), + "online": sum(1 for r in runners if r.get("status") == "online"), + "busy": sum(1 for r in runners if r.get("busy") is True), + } + + +def sample_occupation(out_path: str) -> int: + """Fetch the repo's self-hosted runner park now; write counts to OUT. + + Measurement, never a gate: any failure (missing token, HTTP error, bad + JSON) still writes a JSON file carrying the error and exits 0, so the + report step degrades to ``not sampled`` instead of redding the build. + """ + api = os.environ.get("GITHUB_API_URL", "https://api.github.com") + repo = os.environ.get("GITHUB_REPOSITORY") + token = os.environ.get("GITHUB_TOKEN") + sampled = datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ") + result: dict[str, object] = {"sampled_at": sampled} + if repo and token: + url = f"{api}/repos/{repo}/actions/runners?per_page=100" + pages: list[dict] = [] + try: + for _ in range(MAX_RUNNER_PAGES): + req = urllib.request.Request( + url, headers={"Authorization": f"Bearer {token}", + "Accept": "application/vnd.github+json"}) + with urllib.request.urlopen(req, timeout=15) as resp: + pages.append(json.loads(resp.read().decode("utf-8"))) + nxt = LINK_NEXT_RE.search(resp.headers.get("Link", "") or "") + if not nxt: + break + url = nxt.group(1) + result.update(parse_runners_pages(pages)) + except (urllib.error.URLError, OSError, ValueError) as exc: + result["error"] = str(exc) + else: + result["error"] = "GITHUB_REPOSITORY/GITHUB_TOKEN not set" + try: + with open(out_path, "w", encoding="utf-8") as fh: + json.dump(result, fh) + except OSError as exc: + print(f"quarto_render_timing: cannot write {out_path}: {exc}", file=sys.stderr) + return 0 + + +def load_occupation(path: str | None) -> dict[str, object] | None: + """Read an occupation.json written by --sample-occupation; None if unusable.""" + if not path: + return None + try: + with open(path, "r", encoding="utf-8") as fh: + data = json.load(fh) + return data if isinstance(data, dict) else None + except (OSError, ValueError): + return None + + +def _secs(a: datetime | None, b: datetime | None) -> int | None: + if a is None or b is None: + return None + delta = (b - a).total_seconds() + if delta < 0: # same midnight-wrap rule as _fmt + delta += 86400 + return int(round(delta)) + + +def render_report(r: dict[str, object], + occupation: dict[str, object] | None = None, + runner: str | None = None) -> str: first = r["first"] last_doc = r["last_doc"] output_created = r["output_created"] @@ -138,6 +235,13 @@ def phase(a, b): f"| post-render (silent) | {phase(last_doc[0] if last_doc else None, output_created[0] if output_created else None)} |", f"| total to `Output created` | {phase(first, output_created[0] if output_created else None)} |", ] + if occupation and "busy" in occupation: + lines.append(f"| park busy/online at start " + f"| {occupation['busy']}/{occupation['online']} (sampled {occupation.get('sampled_at', '?')}) |") + else: + lines.append("| park busy/online at start | not sampled |") + if runner: + lines.append(f"| runner | {runner} |") if last_doc: lines.append("") lines.append(f"last document line: `{last_doc[1]}`") @@ -146,13 +250,47 @@ def phase(a, b): return "\n".join(lines) +def covariates_line(r: dict[str, object], + occupation: dict[str, object] | None, + runner: str | None) -> str: + """One greppable record so >=6 runs can be harvested from job logs and + regressed on BOTH covariates (runner identity vs park occupation).""" + def or_na(value): + return value if value is not None else "na" + doc = _secs(r["first"], r["last_doc"][0] if r["last_doc"] else None) + post = _secs(r["last_doc"][0] if r["last_doc"] else None, + r["output_created"][0] if r["output_created"] else None) + total = _secs(r["first"], r["output_created"][0] if r["output_created"] else None) + runner = (runner or "na").replace(",", ";").replace(" ", "-") + if occupation and "busy" in occupation: + busy, online, tot = occupation["busy"], occupation["online"], occupation["total"] + else: + busy = online = tot = "na" + return (f"#14597-covariates: runner={runner},busy={busy},online={online}," + f"total={tot},doc_s={or_na(doc)},post_s={or_na(post)},total_s={or_na(total)}") + + def main(argv: list[str] | None = None) -> int: ap = argparse.ArgumentParser( description="Report doc-phase vs post-render timings from a " "timestamped `quarto render` log (measurement, never a gate).") - ap.add_argument("log", help="path to the timestamped render log") + ap.add_argument("log", nargs="?", help="path to the timestamped render log") + ap.add_argument("--sample-occupation", metavar="OUT", + help="instead of reporting, query the repo runner park now " + "and write busy/online counts to OUT (early workflow step)") + ap.add_argument("--occupation", metavar="PATH", + help="occupation.json written by --sample-occupation " + "(merged into the report as the park covariate)") + ap.add_argument("--runner-name", default=os.environ.get("RUNNER_NAME"), + help="runner identity for the covariate record " + "(defaults to $RUNNER_NAME)") args = ap.parse_args(argv) + if args.sample_occupation: + return sample_occupation(args.sample_occupation) + if not args.log: + ap.error("log path required unless --sample-occupation is given") + try: with open(args.log, "rb") as fh: raw = fh.read().decode("utf-8", errors="replace") @@ -160,8 +298,11 @@ def main(argv: list[str] | None = None) -> int: print(f"quarto_render_timing: cannot read {args.log}: {exc}", file=sys.stderr) return 0 - report = render_report(analyse(raw)) + occupation = load_occupation(args.occupation) + r = analyse(raw) + report = render_report(r, occupation=occupation, runner=args.runner_name) print(report) + print(covariates_line(r, occupation, args.runner_name)) summary = os.environ.get("GITHUB_STEP_SUMMARY") if summary: with open(summary, "a", encoding="utf-8") as fh: diff --git a/scripts/tests/test_quarto_render_timing.py b/scripts/tests/test_quarto_render_timing.py index 41539eddec..b595ea0bf7 100644 --- a/scripts/tests/test_quarto_render_timing.py +++ b/scripts/tests/test_quarto_render_timing.py @@ -18,6 +18,7 @@ """ from __future__ import annotations +import json import sys from pathlib import Path @@ -97,3 +98,76 @@ def test_cr_segment_without_timestamp_is_not_its_own_event(): r = qrt.analyse("03:00:00 \x1b[1m\x1b[34m\r[ 1/900] a.ipynb\x1b[39m\n03:09:00 Output created: _site/index.html\n") assert r["doc_count"] == 900 assert qrt._fmt((r["output_created"][0] - r["last_doc"][0]).total_seconds()) == "9:00" + + +# --- runner-park occupation covariate (dispatch ai-01 2026-09-07) --- + +OCC = {"sampled_at": "2026-09-07T05:20:00Z", "total": 28, "online": 26, "busy": 2} + + +def test_parse_runners_pages_counts_across_pages(): + # Shape of GET /repos/{repo}/actions/runners (runners[] per page, Link + # pagination handled by the caller): busy counts only busy==true, online + # only status=="online", offline runners still count toward total. + pages = [ + {"total_count": 3, "runners": [ + {"name": "a", "status": "online", "busy": True}, + {"name": "b", "status": "online", "busy": False}, + ]}, + {"total_count": 3, "runners": [ + {"name": "c", "status": "offline", "busy": False}, + ]}, + ] + assert qrt.parse_runners_pages(pages) == {"total": 3, "online": 2, "busy": 1} + + +def test_occupation_row_rendered_when_sampled(): + report = qrt.render_report(qrt.analyse(LOG), occupation=OCC, runner="ai-01-wsl-3") + assert "| park busy/online at start | 2/26 (sampled 2026-09-07T05:20:00Z) |" in report + assert "| runner | ai-01-wsl-3 |" in report + + +def test_occupation_missing_degrades_to_not_sampled(): + report = qrt.render_report(qrt.analyse(LOG)) + assert "| park busy/online at start | not sampled |" in report + assert "| runner |" not in report + + +def test_covariates_line_harvestable(): + # The record must stay one line, comma-separated, "na" on missing pieces, + # so >=6 runs can be grepped from job logs and regressed as CSV. + line = qrt.covariates_line(qrt.analyse(LOG), OCC, "ai-01-linux-docker-5") + assert line == ("#14597-covariates: runner=ai-01-linux-docker-5,busy=2," + "online=26,total=28,doc_s=929,post_s=767,total_s=1696") + # no occupation, no markers at all -> all na, still one line + empty = qrt.covariates_line(qrt.analyse("nope\n"), None, None) + assert empty == ("#14597-covariates: runner=na,busy=na,online=na," + "total=na,doc_s=na,post_s=na,total_s=na") + + +def test_covariates_line_runner_sanitized(): + # commas/spaces in a runner name would break CSV harvesting + line = qrt.covariates_line(qrt.analyse(LOG), None, "foo bar,baz") + assert "runner=foo-bar;baz," in line + + +def test_load_occupation_rejects_unusable(tmp_path): + good = tmp_path / "occ.json" + good.write_text('{"sampled_at": "x", "total": 1, "online": 1, "busy": 0}', encoding="utf-8") + assert qrt.load_occupation(str(good))["busy"] == 0 + bad = tmp_path / "bad.json" + bad.write_text("{not json", encoding="utf-8") + assert qrt.load_occupation(str(bad)) is None + assert qrt.load_occupation(str(tmp_path / "absent.json")) is None + assert qrt.load_occupation(None) is None + + +def test_sample_occupation_without_env_writes_error_and_exits_zero(tmp_path, monkeypatch): + # No GITHUB_REPOSITORY/GITHUB_TOKEN -> no HTTP attempt, error recorded, + # exit 0 (measurement, never a gate). + monkeypatch.delenv("GITHUB_REPOSITORY", raising=False) + monkeypatch.delenv("GITHUB_TOKEN", raising=False) + out = tmp_path / "occupation.json" + assert qrt.sample_occupation(str(out)) == 0 + data = json.loads(out.read_text(encoding="utf-8")) + assert "error" in data and "sampled_at" in data From bafb9587ac6fdf22196efa7219058b22a96a9439 Mon Sep 17 00:00:00 2001 From: jsboige Date: Mon, 7 Sep 2026 07:41:46 +0200 Subject: [PATCH 2/2] fix(ci,#14597): sample runners via RUNNERS_READ_PAT + visible diagnostic First instrumented run (34086099812) proved the pipeline end-to-end (runner + durations in the covariates line) but busy/online came back na: listing self-hosted runners is admin-scoped and GITHUB_TOKEN gets a 403 even with actions:read. Follow the repo convention instead -- the read-only RUNNERS_READ_PAT secret (check_runner_starvation.py, linux-runner-starvation-advisory.yml), available on same-repo PRs. GITHUB_TOKEN stays as fallback; the now-useless actions: read grants are dropped. The sampling step also prints one [occupation] line to the job log so a future failure is visible immediately, not 20 min later in the report. Live check: busy=0 online=28 total=34 against the real API. See #14597 Co-Authored-By: Claude-Code --- .github/workflows/quarto-pages-deploy.yml | 4 ++-- scripts/quarto_render_timing.py | 19 +++++++++++++++++-- 2 files changed, 19 insertions(+), 4 deletions(-) diff --git a/.github/workflows/quarto-pages-deploy.yml b/.github/workflows/quarto-pages-deploy.yml index da64c0d7e6..c0b4900a9a 100644 --- a/.github/workflows/quarto-pages-deploy.yml +++ b/.github/workflows/quarto-pages-deploy.yml @@ -85,7 +85,6 @@ jobs: timeout-minutes: 60 permissions: contents: read - actions: read # #14597 : lister les self-hosted runners (covariable d'occupation) steps: - name: Checkout uses: actions/checkout@v4 @@ -97,6 +96,7 @@ jobs: # Doit tourner AVANT le rendu (~20 min) : le compte doit decrire le # parc au moment ou le job demarre, pas ou il finit. env: + RUNNERS_READ_PAT: ${{ secrets.RUNNERS_READ_PAT }} GITHUB_TOKEN: ${{ github.token }} run: python scripts/quarto_render_timing.py --sample-occupation occupation.json @@ -244,7 +244,6 @@ jobs: timeout-minutes: 60 permissions: contents: read - actions: read # #14597 : lister les self-hosted runners (covariable d'occupation) pull-requests: write # pour poster le commentaire de gate steps: - name: Checkout @@ -306,6 +305,7 @@ jobs: # de consommer un appel API sur un rendu scope. if: steps.scope.outputs.mode == 'full' env: + RUNNERS_READ_PAT: ${{ secrets.RUNNERS_READ_PAT }} GITHUB_TOKEN: ${{ github.token }} run: python scripts/quarto_render_timing.py --sample-occupation occupation.json diff --git a/scripts/quarto_render_timing.py b/scripts/quarto_render_timing.py index f03eb14c96..5fb209a207 100644 --- a/scripts/quarto_render_timing.py +++ b/scripts/quarto_render_timing.py @@ -161,7 +161,14 @@ def sample_occupation(out_path: str) -> int: """ api = os.environ.get("GITHUB_API_URL", "https://api.github.com") repo = os.environ.get("GITHUB_REPOSITORY") - token = os.environ.get("GITHUB_TOKEN") + # Listing self-hosted runners is an admin-scoped endpoint: GITHUB_TOKEN + # gets a 403 there even with actions:read (confirmed on the first + # instrumented run, 34086099812). The repo convention is the read-only + # RUNNERS_READ_AT secret (cf scripts/ci/check_runner_starvation.py and + # linux-runner-starvation-advisory.yml) -- prefer it, keep GITHUB_TOKEN + # as a fallback so local/manual runs still work with a plain token. + token = (os.environ.get("RUNNERS_READ_PAT") + or os.environ.get("GITHUB_TOKEN")) sampled = datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ") result: dict[str, object] = {"sampled_at": sampled} if repo and token: @@ -182,10 +189,18 @@ def sample_occupation(out_path: str) -> int: except (urllib.error.URLError, OSError, ValueError) as exc: result["error"] = str(exc) else: - result["error"] = "GITHUB_REPOSITORY/GITHUB_TOKEN not set" + result["error"] = "GITHUB_REPOSITORY/RUNNERS_READ_PAT/GITHUB_TOKEN not set" try: with open(out_path, "w", encoding="utf-8") as fh: json.dump(result, fh) + # One diagnostic line in the job log: the first instrumented run + # failed silently (occupation.json was only ever read at the END of + # the job, 20 min later) -- the cause was invisible in the log. + if "error" in result: + print(f"[occupation] not sampled: {result['error']}") + else: + print(f"[occupation] busy={result['busy']} online={result['online']} " + f"total={result['total']} at {result['sampled_at']}") except OSError as exc: print(f"quarto_render_timing: cannot write {out_path}: {exc}", file=sys.stderr) return 0