Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 26 additions & 2 deletions .github/workflows/quarto-pages-deploy.yml
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,17 @@ jobs:
- 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:
RUNNERS_READ_PAT: ${{ secrets.RUNNERS_READ_PAT }}
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
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -285,6 +299,16 @@ 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:
RUNNERS_READ_PAT: ${{ secrets.RUNNERS_READ_PAT }}
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
Expand Down Expand Up @@ -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'
Expand Down
164 changes: 160 additions & 4 deletions scripts/quarto_render_timing.py
Original file line number Diff line number Diff line change
Expand Up @@ -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::
Expand All @@ -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:
Expand Down Expand Up @@ -117,7 +142,94 @@ 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")
# 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:
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/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


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"]
Expand All @@ -138,6 +250,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]}`")
Expand All @@ -146,22 +265,59 @@ 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")
except OSError as exc:
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:
Expand Down
74 changes: 74 additions & 0 deletions scripts/tests/test_quarto_render_timing.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
"""
from __future__ import annotations

import json
import sys
from pathlib import Path

Expand Down Expand Up @@ -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
Loading