diff --git a/.github/actions/cache-restore/action.yml b/.github/actions/cache-restore/action.yml index c7df56f58d27..a47b51fd9b6f 100644 --- a/.github/actions/cache-restore/action.yml +++ b/.github/actions/cache-restore/action.yml @@ -25,6 +25,12 @@ outputs: runs: using: composite steps: + - name: Start cache restore measurement + id: receipt-clock + continue-on-error: true + shell: bash + run: echo "started_ns=$(python3 -c 'import time; print(time.monotonic_ns())')" >> "$GITHUB_OUTPUT" + # The provider store only answers its own runners, so a job that lands # anywhere else keeps reading the GitHub store. - name: Restore from the GitHub store @@ -59,3 +65,24 @@ runs: if [ -n "$prefix" ]; then prefixes+=("$prefix"); fi done <<< "$CACHE_RESTORE_KEYS" "$GITHUB_ACTION_PATH/../../../scripts/ci/r2-cache.sh" restore "$CACHE_PATH" "$CACHE_KEY" ${prefixes[@]+"${prefixes[@]}"} + + - name: Report cache restore evidence + id: receipt + if: always() + # Observability cannot change restore behavior or hide a failed action. + continue-on-error: true + shell: bash + env: + CACHE_STARTED_NS: ${{ steps.receipt-clock.outputs.started_ns }} + CACHE_REQUESTED_BACKEND: ${{ inputs.backend }} + CACHE_KEY: ${{ inputs.key }} + CACHE_GITHUB_OUTCOME: ${{ steps.github.outcome }} + CACHE_GITHUB_HIT: ${{ steps.github.outputs.cache-hit }} + CACHE_GITHUB_MATCHED: ${{ steps.github.outputs.cache-matched-key }} + CACHE_WARP_OUTCOME: ${{ steps.warp.outcome }} + CACHE_WARP_HIT: ${{ steps.warp.outputs.cache-hit }} + CACHE_WARP_MATCHED: ${{ steps.warp.outputs.cache-matched-key }} + CACHE_R2_OUTCOME: ${{ steps.r2.outcome }} + CACHE_R2_HIT: ${{ steps.r2.outputs.cache-hit }} + CACHE_R2_MATCHED: ${{ steps.r2.outputs.cache-matched-key }} + run: python3 "$GITHUB_ACTION_PATH/../../../scripts/ci/cache_restore_receipt.py" diff --git a/.github/workflows/ci-cache-receipts.yml b/.github/workflows/ci-cache-receipts.yml new file mode 100644 index 000000000000..60413f234b95 --- /dev/null +++ b/.github/workflows/ci-cache-receipts.yml @@ -0,0 +1,44 @@ +name: CI cache receipt contract + +on: + pull_request: + paths: + - .github/actions/cache-restore/action.yml + - .github/actions/cache-save/action.yml + - .github/workflows/ci.yml + - .github/workflows/nightly.yml + - .github/workflows/ci-cache-receipts.yml + - scripts/ci/cache_restore_receipt.py + - scripts/check-test-determinism.py + - tests/test_ci_cache_restore_receipt.py + - tests/test_ci_pull_request_caches_are_read_only.py + push: + branches: [main] + paths: + - .github/actions/cache-restore/action.yml + - .github/actions/cache-save/action.yml + - .github/workflows/ci.yml + - .github/workflows/nightly.yml + - .github/workflows/ci-cache-receipts.yml + - scripts/ci/cache_restore_receipt.py + - scripts/check-test-determinism.py + - tests/test_ci_cache_restore_receipt.py + - tests/test_ci_pull_request_caches_are_read_only.py + +permissions: + contents: read + +jobs: + receipt-contract: + runs-on: ${{ vars.LINUX_RUNNER || 'blacksmith-4vcpu-ubuntu-2404' }} + timeout-minutes: 5 + steps: + - uses: actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd + with: + persist-credentials: false + - uses: actions/setup-python@a309ff8b426b58ec0e2a45f0f869d46889d02405 # v6 + with: + python-version: '3.12' + - run: python3 -m pip install PyYAML==6.0.3 + - run: python3 tests/test_ci_cache_restore_receipt.py + - run: python3 scripts/check-test-determinism.py --roots tests/test_ci_cache_restore_receipt.py --strict diff --git a/scripts/ci/cache_restore_receipt.py b/scripts/ci/cache_restore_receipt.py new file mode 100644 index 000000000000..b244b704fc6c --- /dev/null +++ b/scripts/ci/cache_restore_receipt.py @@ -0,0 +1,70 @@ +#!/usr/bin/env python3 +"""Report restore-action evidence without inferring the physical cache store.""" + +import json +import os +from pathlib import Path +import time + + +def receipt(environment, now_ns): + env = environment + routes = ("github", "warp", "r2") + selected = [route for route in routes if env.get(f"CACHE_{route.upper()}_OUTCOME") not in (None, "", "skipped")] + route = selected[0] if len(selected) == 1 else None + outcome = env.get(f"CACHE_{route.upper()}_OUTCOME") if route else None + hit = env.get(f"CACHE_{route.upper()}_HIT", "") if route else "" + matched = env.get(f"CACHE_{route.upper()}_MATCHED", "") if route else "" + if outcome == "failure": + result = "error" + elif outcome == "cancelled": + result = "cancelled" + elif outcome != "success": + result = "unknown" + elif hit == "true": + result = "exact" + elif matched: + result = "prefix" + else: + # Cache actions can return success after warning about backend errors. + # An empty matched key proves no restore, not that the service was healthy. + result = "miss_or_unavailable" + try: + start = int(env.get("CACHE_STARTED_NS", "")) + elapsed = round((now_ns - start) / 1_000_000_000, 3) if 0 <= start <= now_ns else None + except ValueError: + elapsed = None + return { + "schema_version": 1, + "requested_backend": env.get("CACHE_REQUESTED_BACKEND", ""), + "action_route": {"github": "github-cache", "warp": "warp-cache", "r2": "r2"}.get(route), + "key": env.get("CACHE_KEY", ""), + "matched_key": matched or None, + "cache_hit_output": hit or None, + "step_outcome": outcome, + "result": result, + "elapsed_seconds": elapsed, + "run_id": env.get("GITHUB_RUN_ID"), + "run_attempt": env.get("GITHUB_RUN_ATTEMPT"), + "job": env.get("GITHUB_JOB"), + "runner_name": env.get("RUNNER_NAME"), + "runner_os": env.get("RUNNER_OS"), + "runner_arch": env.get("RUNNER_ARCH"), + } + + +def main(): + record = receipt(os.environ, time.monotonic_ns()) + print("CMUX_CACHE_RESTORE " + json.dumps(record, sort_keys=True)) + summary = os.environ.get("GITHUB_STEP_SUMMARY") + if summary: + # JSON in an indented block also keeps arbitrary key text from creating + # summary headings or closing a Markdown fence. + with Path(summary).open("a") as output: + output.write("### Cache restore\n\n") + output.write("\n".join(" " + line for line in json.dumps(record, indent=2, sort_keys=True).splitlines())) + output.write("\n\nElapsed time includes action lookup, transfer and extraction. The action route does not identify the physical storage provider.\n") + + +if __name__ == "__main__": + main() diff --git a/tests/test_ci_cache_restore_receipt.py b/tests/test_ci_cache_restore_receipt.py new file mode 100644 index 000000000000..34ef4904af15 --- /dev/null +++ b/tests/test_ci_cache_restore_receipt.py @@ -0,0 +1,126 @@ +#!/usr/bin/env python3 +"""Exercise receipt classification and the real composite's shell wiring.""" + +import importlib.util +import json +import os +from pathlib import Path +import subprocess +import shutil +import tempfile +import unittest + +import yaml + +ROOT = Path(__file__).resolve().parents[1] +SPEC = importlib.util.spec_from_file_location("receipt", ROOT / "scripts/ci/cache_restore_receipt.py") +MODULE = importlib.util.module_from_spec(SPEC) +SPEC.loader.exec_module(MODULE) + + +class CacheRestoreReceiptTests(unittest.TestCase): + def test_contract_runs_when_its_inspected_files_change(self): + workflow = yaml.safe_load((ROOT / ".github/workflows/ci-cache-receipts.yml").read_text()) + events = workflow.get("on", workflow.get(True)) + inspected = { + ".github/actions/cache-restore/action.yml", ".github/actions/cache-save/action.yml", + ".github/workflows/ci.yml", ".github/workflows/nightly.yml", + ".github/workflows/ci-cache-receipts.yml", "scripts/check-test-determinism.py", + "scripts/ci/cache_restore_receipt.py", "tests/test_ci_cache_restore_receipt.py", + "tests/test_ci_pull_request_caches_are_read_only.py", + } + for event in ("pull_request", "push"): + with self.subTest(event=event): + self.assertTrue(inspected.issubset(set(events[event]["paths"]))) + + def test_read_only_guard_accepts_receipts_but_rejects_extra_effects(self): + with tempfile.TemporaryDirectory() as temporary: + fixture = Path(temporary) + for name in ("tests/test_ci_pull_request_caches_are_read_only.py", + ".github/workflows/ci.yml", ".github/workflows/nightly.yml", + ".github/actions/cache-restore/action.yml", ".github/actions/cache-save/action.yml"): + destination = fixture / name + destination.parent.mkdir(parents=True, exist_ok=True) + shutil.copyfile(ROOT / name, destination) + action_path = fixture / ".github/actions/cache-restore/action.yml" + original = action_path.read_text() + for mutation, valid in ((None, True), ("receipt_command", False), ("overlapping_route", False)): + action = yaml.safe_load(original) + if mutation == "receipt_command": + action["runs"]["steps"][-1]["run"] += "\necho unexpected-write" + elif mutation == "overlapping_route": + next(step for step in action["runs"]["steps"] if step.get("id") == "warp")["if"] = "always()" + action_path.write_text(yaml.safe_dump(action)) + result = subprocess.run(["python3", str(fixture / "tests/test_ci_pull_request_caches_are_read_only.py")], capture_output=True, text=True) + with self.subTest(mutation=mutation): + self.assertEqual(result.returncode == 0, valid, result.stdout + result.stderr) + + def test_all_routes_distinguish_exact_prefix_unavailable_and_error(self): + for route in ("github", "warp", "r2"): + for outcome, hit, matched, expected in ( + ("success", "true", "family-exact", "exact"), + ("success", "false", "family-older", "prefix"), + ("success", "", "", "miss_or_unavailable"), + ("success", "false", "", "miss_or_unavailable"), + ("failure", "true", "family-exact", "error"), + ("cancelled", "", "", "cancelled"), + ): + with self.subTest(route=route, expected=expected): + env = {f"CACHE_{route.upper()}_OUTCOME": outcome, + f"CACHE_{route.upper()}_HIT": hit, + f"CACHE_{route.upper()}_MATCHED": matched, + "CACHE_STARTED_NS": "1000000000"} + result = MODULE.receipt(env, 3500000000) + self.assertEqual(result["result"], expected) + self.assertEqual(result["elapsed_seconds"], 2.5) + self.assertEqual(result["matched_key"], matched or None) + + def test_missing_ambiguous_and_invalid_clock_evidence_remains_unknown(self): + for env in ({}, {"CACHE_GITHUB_OUTCOME": "success", "CACHE_R2_OUTCOME": "success"}): + self.assertEqual(MODULE.receipt(env, 100)["result"], "unknown") + for started in ("", "not-a-clock", "-1", "101"): + self.assertIsNone(MODULE.receipt({"CACHE_STARTED_NS": started}, 100)["elapsed_seconds"]) + + def test_real_composite_reports_provider_outputs_without_changing_cache_contract(self): + action = yaml.safe_load((ROOT / ".github/actions/cache-restore/action.yml").read_text()) + steps = action["runs"]["steps"] + start = next(step for step in steps if step.get("id") == "receipt-clock") + report = next(step for step in steps if step.get("id") == "receipt") + self.assertTrue(start["continue-on-error"]) + self.assertEqual(report["if"], "always()") + self.assertTrue(report["continue-on-error"]) + self.assertEqual(action["inputs"]["backend"]["default"], "") + self.assertEqual(action["outputs"]["cache-hit"]["value"], + "${{ steps.github.outputs.cache-hit || steps.warp.outputs.cache-hit || steps.r2.outputs.cache-hit }}") + # Resolve only the expressions present in the real measurement step; + # external cache actions are simulated at their documented output boundary. + with tempfile.TemporaryDirectory() as temporary: + directory = Path(temporary) + env = {**os.environ, "GITHUB_OUTPUT": str(directory / "output"), + "GITHUB_STEP_SUMMARY": str(directory / "summary"), + "GITHUB_ACTION_PATH": str(ROOT / ".github/actions/cache-restore")} + subprocess.run(["bash", "-e", "-c", start["run"]], env=env, check=True) + timestamp = (directory / "output").read_text().strip().split("=", 1)[1] + values = {"inputs.backend": "warp", "inputs.key": "xcode-cas-quote'\n```$never_execute", + "steps.receipt-clock.outputs.started_ns": timestamp} + for route in ("github", "warp", "r2"): + values[f"steps.{route}.outcome"] = "success" if route == "github" else "skipped" + values[f"steps.{route}.outputs.cache-hit"] = "false" if route == "github" else "" + values[f"steps.{route}.outputs.cache-matched-key"] = "xcode-cas-prior" if route == "github" else "" + for name, expression in report["env"].items(): + env[name] = values[expression.removeprefix("${{ ").removesuffix(" }}")] + output = subprocess.check_output(["bash", "-e", "-c", report["run"]], env=env, text=True) + record = json.loads(output.removeprefix("CMUX_CACHE_RESTORE ")) + self.assertEqual(record["action_route"], "github-cache") + self.assertEqual(record["requested_backend"], "warp") + self.assertEqual(record["result"], "prefix") + self.assertEqual(record["key"], values["inputs.key"]) + # This integration case proves clock evidence reaches the receipt. + # Duration arithmetic is asserted against injected clocks above, + # never against the scheduling of these real subprocesses. + self.assertIsInstance(record["elapsed_seconds"], float) + self.assertIn("physical storage provider", (directory / "summary").read_text()) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/test_ci_pull_request_caches_are_read_only.py b/tests/test_ci_pull_request_caches_are_read_only.py index 76f57b18dee5..f310d6b27aea 100644 --- a/tests/test_ci_pull_request_caches_are_read_only.py +++ b/tests/test_ci_pull_request_caches_are_read_only.py @@ -61,6 +61,23 @@ def main() -> int: for kind in ("restore", "save"): action = yaml.safe_load((ROOT / ".github/actions" / f"cache-{kind}" / "action.yml").read_text(encoding="utf-8")) steps = action["runs"]["steps"] + if kind == "restore": + # Measurement is not a fourth cache store. Recognize only these + # fixed nonblocking commands; all other steps still undergo the + # exhaustive store-branch checks below. + measurements = { + "receipt-clock": (None, 'echo "started_ns=$(python3 -c \'import time; print(time.monotonic_ns())\')" >> "$GITHUB_OUTPUT"'), + "receipt": ("always()", 'python3 "$GITHUB_ACTION_PATH/../../../scripts/ci/cache_restore_receipt.py"'), + } + for identifier, (condition, command) in measurements.items(): + matches = [step for step in steps if step.get("id") == identifier] + if len(matches) != 1 or any( + step.get("if") != condition or step.get("run") != command + or step.get("shell") != "bash" or step.get("continue-on-error") is not True + or "uses" in step for step in matches + ): + failures.append(f"cache-restore: {identifier} must be the fixed nonblocking measurement step") + steps = [step for step in steps if step.get("id") not in measurements] conditions = [step.get("if") for step in steps] if conditions != expected_conditions: failures.append(f"cache-{kind}: the store branches must be mutually exclusive and cover every backend, got {conditions}")