From 9dd8c781f24ef288464926a224dc7bb315a210ac Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 06:43:24 +0000 Subject: [PATCH 1/6] Make backend-outage skips diagnosable MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit '155 skipped: backend outage' gave a reader nothing to debug with and no basis for deciding to ignore. The circuit breaker now records every event to a shared per-run log: the test that hit the backend first, with the URL of the failing call (pulled from the exception chain) and how it failed; each health probe's verdict (HTTP status or exception, with elapsed time); and every test the breaker fast-skipped. Skip messages carry the failing call or probe inline, and at session end the master aggregates the log into outage_report.md / outage_report.json. The existing skip report embeds the markdown — job summary, the neutral 'Run completeness' check, and the sticky PR comment all carry it, with the failing URLs as clickable links and the skipped-test list folded into a details block; the warning annotation gains a one-line digest. Verified end to end with a simulated trigger under the real conftest (during which the owl.virtualflybrain.org probe genuinely timed out and was named in the fast-skip message — the feature demonstrating itself). --- .github/workflows/python-test.yml | 28 +++- conftest.py | 214 ++++++++++++++++++++++++++++-- tests/test_outage_reporting.py | 177 ++++++++++++++++++++++++ 3 files changed, 407 insertions(+), 12 deletions(-) create mode 100644 tests/test_outage_reporting.py diff --git a/.github/workflows/python-test.yml b/.github/workflows/python-test.yml index 2efa2b9..a641ea4 100644 --- a/.github/workflows/python-test.yml +++ b/.github/workflows/python-test.yml @@ -90,8 +90,21 @@ jobs: echo "No test output captured."; exit 0 fi summary=$(grep -Eo '[0-9]+ skipped' pytest_output.log | tail -1 || true) + # conftest.py writes outage_report.md when the circuit breaker + # tripped: which test hit the backend first, the URL of the call + # that failed or timed out and how, the health-probe verdicts, and + # the full list of fast-skipped tests. Embed it wherever the skip + # is reported so the reader can debug or decide to ignore. + digest="" + if [ -f outage_report.md ]; then + digest=$(grep -m1 -oE 'call: \[[^]]+\]|FAILED[^|]*' outage_report.md | head -1 || true) + { + echo "" + cat outage_report.md + } >> "$GITHUB_STEP_SUMMARY" + fi if [ -n "$summary" ]; then - echo "::warning title=Tests skipped — VFB backend unreachable::${summary}. These are NOT test failures and not a problem with this branch: the VFB backend (Neo4j / SOLR / Owlery) did not answer, so those queries went unverified this run. Treat a green check with skips as an incomplete run — re-run once the backend is healthy before relying on it. See the job log for the list." + echo "::warning title=Tests skipped — VFB backend unreachable::${summary}. ${digest:+First failure: ${digest}. }These are NOT test failures and not a problem with this branch: the VFB backend (Neo4j / SOLR / Owlery) did not answer, so those queries went unverified this run. Treat a green check with skips as an incomplete run — re-run once the backend is healthy before relying on it. Full detail (failing URLs, probe verdicts, skipped-test list): the job summary and the PR comment." else echo "No tests skipped." fi @@ -118,6 +131,15 @@ jobs: core.info('No pytest_output.log to read: ' + e.message); } + // conftest.py's outage report: the failing calls (as clickable + // links), the probe verdicts, and the fast-skipped test list. + let outage = ''; + try { + outage = fs.readFileSync('outage_report.md', 'utf8').trim(); + } catch (e) { + core.info('No outage_report.md (breaker never tripped).'); + } + const { owner, repo } = context.repo; const issue_number = context.issue.number; @@ -151,7 +173,8 @@ jobs: `(Neo4j / SOLR / Owlery) did not answer, so those queries went ` + `unverified. This is not a branch failure — but the run is ` + `incomplete.\n\n${rerun}` + - (summary ? '\n\n```\n' + summary + '\n```' : '')) + (summary ? '\n\n```\n' + summary + '\n```' : '') + + (outage ? '\n\n' + outage : '')) : 'Every backend-dependent test reached the VFB backend and ran.', }, }); @@ -172,6 +195,7 @@ jobs: '', '> ' + rerun, summary ? '\n```\n' + summary + '\n```' : '', + outage ? '\n' + outage : '', '', 'Posted automatically. This comment is removed once a run completes with zero skips.', ].join('\n'); diff --git a/conftest.py b/conftest.py index 0091f69..05cff00 100644 --- a/conftest.py +++ b/conftest.py @@ -33,7 +33,9 @@ health probe and skip fast while the backend stays down, resuming the moment it answers again. Zero cost on a healthy run. """ +import json import os +import re import socket import tempfile import time @@ -87,6 +89,31 @@ def _is_connection_failure(exc): return False +_URL_RE = re.compile(r"https?://[^\s'\"<>)\]]+") + + +def _failure_url(exc): + """Best-effort URL of the call behind a transport failure. + + Walks the exception chain looking for the attributes ``requests`` (and + friends) hang the request on, then falls back to the first URL printed in + any message in the chain. Returns None when nothing URL-shaped is found — + the report then still carries the exception text. + """ + seen = set() + while exc is not None and id(exc) not in seen: + seen.add(id(exc)) + for attr in ("request", "response"): + url = getattr(getattr(exc, attr, None), "url", None) + if url: + return str(url) + match = _URL_RE.search(str(exc)) + if match: + return match.group(0).rstrip(".,;:") + exc = exc.__cause__ or exc.__context__ + return None + + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_makereport(item, call): """Turn a transport-level failure into a skip (never an empty result), and @@ -96,13 +123,18 @@ def pytest_runtest_makereport(item, call): if rep.when in ("setup", "call") and rep.failed and call.excinfo is not None: exc = call.excinfo.value if _is_connection_failure(exc): + url = _failure_url(exc) + suffix = f" (call: {url})" if url else "" rep.outcome = "skipped" rep.longrepr = ( str(item.fspath), item.location[1] or 0, - f"VFB backend unreachable: {type(exc).__name__}: {exc}", + f"VFB backend unreachable: {type(exc).__name__}: {exc}{suffix}", ) _mark_outage() + _record_event("trigger", test=item.nodeid, kind="connection-failure", + error=f"{type(exc).__name__}: {str(exc)[:300]}", + url=url) elif "pytest-timeout" in str(exc): # A test hit the per-test ceiling. If the backend is down this is an # outage casualty, not a slow query — record it and let it read as a @@ -122,8 +154,11 @@ def pytest_runtest_makereport(item, call): str(item.fspath), item.location[1] or 0, "VFB backend outage: test timed out and a health probe " - "confirms the backend is down", + "confirms the backend is down" + + _probe_failure_suffix(), ) + _record_event("trigger", test=item.nodeid, kind="timeout", + error=str(exc)[:300], url=None) # -------------------------------------------------------------------------- @@ -180,6 +215,27 @@ def _raising_commit_list(*args, **kwargs): _PROBE_CACHE_S = 10 # re-probe at most this often, per worker _PROBE_TIMEOUT_S = 5 +#: Shared event log for the outage report — same run-keyed scheme as the +#: latch, JSON-lines so xdist workers can append concurrently. The session +#: master aggregates it into outage_report.md/.json at session end. +_OUTAGE_EVENTS = _OUTAGE_LATCH + "_events.jsonl" + +#: Where the aggregated report lands (the invocation directory, so CI steps +#: can pick it up next to pytest_output.log). +OUTAGE_REPORT_MD = "outage_report.md" +OUTAGE_REPORT_JSON = "outage_report.json" + + +def _record_event(event, **fields): + """Append one outage event; never let reporting break the run.""" + fields.update(event=event, time=time.time(), + worker=os.environ.get("PYTEST_XDIST_WORKER", "master")) + try: + with open(_OUTAGE_EVENTS, "a") as fh: + fh.write(json.dumps(fields) + "\n") + except OSError: + pass + # Cheap health endpoints. Any HTTP answer — even Owlery's 404 on the base path — # means the host is reachable; a 5xx or a transport error means it is not. _PROBE_URLS = ( @@ -193,8 +249,14 @@ def _raising_commit_list(*args, **kwargs): def pytest_sessionstart(session): # Start every run with a clean latch — the latch path can be reused across # runs launched from the same shell, and a stale one would make the first - # tests probe needlessly. + # tests probe needlessly. The event log is cleared too (only here, never + # on mid-run recovery: an outage that came and went still gets reported). _clear_outage() + if not os.environ.get("PYTEST_XDIST_WORKER"): + try: + os.remove(_OUTAGE_EVENTS) + except OSError: + pass def _mark_outage(): @@ -223,23 +285,50 @@ def _clear_outage(): def _backend_down(): """Short, per-worker-cached health probe. True if any VFB backend is unreachable or returning 5xx. Errs toward 'down' so a partial outage still - trips the breaker rather than letting those tests time out.""" + trips the breaker rather than letting those tests time out. + + Alongside the boolean, every probe's outcome (URL, status or error, + elapsed time) is kept in ``_probe_cache["detail"]`` and recorded to the + outage report whenever the answer is 'down' — the report is the place a + person decides whether to debug or to ignore, and it needs to say which + backend failed and how, not just that one did. + """ now = time.time() if now - _probe_cache["at"] < _PROBE_CACHE_S: return _probe_cache["down"] down = False + detail = [] for url in _PROBE_URLS: + started = time.time() try: - if requests.get(url, timeout=_PROBE_TIMEOUT_S).status_code >= 500: - down = True - break - except requests.RequestException: + status = requests.get(url, timeout=_PROBE_TIMEOUT_S).status_code + entry = {"url": url, "ok": status < 500, "status": status, + "elapsed_s": round(time.time() - started, 2)} + except requests.RequestException as exc: + entry = {"url": url, "ok": False, "status": None, + "error": f"{type(exc).__name__}: {str(exc)[:200]}", + "elapsed_s": round(time.time() - started, 2)} + detail.append(entry) + if not entry["ok"]: down = True break - _probe_cache.update(at=now, down=down) + _probe_cache.update(at=now, down=down, detail=detail) + if down: + _record_event("probe", probes=detail) return down +def _probe_failure_suffix(): + """One-line ' (probe: -> )' for skip messages, from + the most recent probe round; empty when no failing probe is on record.""" + for entry in _probe_cache.get("detail") or []: + if not entry.get("ok"): + how = entry.get("error") or f"HTTP {entry.get('status')}" + return " (probe: %s -> %s after %ss)" % ( + entry["url"], how, entry.get("elapsed_s")) + return "" + + # How long, and how often, to keep re-probing after a pytest-timeout before # concluding the backend is genuinely healthy (so the hang was a real code # defect, not an outage). Sized to cover the observed lag between a heavy query @@ -271,7 +360,112 @@ def pytest_runtest_setup(item): again, so a transient blip only pauses the suite briefly.""" if _outage_signalled_recently(): if _backend_down(): + _record_event("skip", test=item.nodeid) pytest.skip("VFB backend outage detected mid-run — skipping to avoid " - "per-test timeouts; re-run once the backend is healthy") + "per-test timeouts; re-run once the backend is healthy" + + _probe_failure_suffix()) else: _clear_outage() + + +# -------------------------------------------------------------------------- +# Outage report — aggregate the events into something a person can act on +# -------------------------------------------------------------------------- + +def _md_link(url): + return "[%s](%s)" % (url, url) + + +def build_outage_report(events): + """(markdown, summary_line) from the recorded events. + + The markdown is what the CI steps embed in the job summary and the + sticky PR comment, so URLs are rendered as links: the point of the + report is that the person reading it can click the failing call, + see how it failed, and decide between debugging and ignoring. + """ + triggers, skips, probes = [], [], [] + seen_triggers, seen_skips = set(), set() + for event in events: + if event.get("event") == "trigger" and event.get("test") not in seen_triggers: + seen_triggers.add(event.get("test")) + triggers.append(event) + elif event.get("event") == "skip" and event.get("test") not in seen_skips: + seen_skips.add(event.get("test")) + skips.append(event) + elif event.get("event") == "probe": + probes.append(event) + + summary = ("%d test(s) hit the backend directly and failed; %d more were " + "fast-skipped by the circuit breaker" + % (len(triggers), len(skips))) + + lines = ["## VFB backend outage report", "", + summary + ". Details below decide between debugging and " + "re-running: a transport error against a known-good URL is an " + "outage (re-run later); anything else deserves a look.", ""] + + if triggers: + lines += ["### What failed first", ""] + for event in sorted(triggers, key=lambda e: e.get("time", 0)): + call = (" — call: " + _md_link(event["url"])) if event.get("url") else "" + lines.append("- `%s` (%s): %s%s" + % (event.get("test"), event.get("kind"), + event.get("error", "").replace("\n", " "), call)) + lines.append("") + + if probes: + lines += ["### Health probes at detection", ""] + # The latest round is the decisive one; earlier rounds add nothing. + for entry in probes[-1].get("probes", []): + if entry.get("ok"): + lines.append("- OK — %s (HTTP %s in %ss)" + % (_md_link(entry["url"]), entry.get("status"), + entry.get("elapsed_s"))) + else: + how = entry.get("error") or ("HTTP %s" % entry.get("status")) + lines.append("- **FAILED** — %s: %s after %ss" + % (_md_link(entry["url"]), how, + entry.get("elapsed_s"))) + lines.append("") + + if skips: + names = sorted(event.get("test", "") for event in skips) + lines += ["### Tests fast-skipped by the circuit breaker (%d)" % len(names), + "", "
Full list", ""] + lines += ["- `%s`" % name for name in names] + lines += ["", "
", ""] + + return "\n".join(lines), summary + + +def pytest_sessionfinish(session, exitstatus): + """On the session master, turn the shared event log into + ``outage_report.md`` / ``outage_report.json`` beside the invocation + directory's pytest output, for the CI skip report to embed.""" + if os.environ.get("PYTEST_XDIST_WORKER"): + return # workers report; the master writes + events = [] + try: + with open(_OUTAGE_EVENTS) as fh: + for line in fh: + try: + events.append(json.loads(line)) + except ValueError: + continue + except OSError: + return # no outage this run — no report + if not events: + return + outdir = str(session.config.invocation_params.dir) + markdown, summary = build_outage_report(events) + try: + with open(os.path.join(outdir, OUTAGE_REPORT_MD), "w") as fh: + fh.write(markdown) + with open(os.path.join(outdir, OUTAGE_REPORT_JSON), "w") as fh: + json.dump(events, fh, indent=1) + print("\nVFB backend outage detected this run: %s.\n" + "Report written to %s (markdown) and %s (raw events)." + % (summary, OUTAGE_REPORT_MD, OUTAGE_REPORT_JSON)) + except OSError: + pass diff --git a/tests/test_outage_reporting.py b/tests/test_outage_reporting.py new file mode 100644 index 0000000..a873700 --- /dev/null +++ b/tests/test_outage_reporting.py @@ -0,0 +1,177 @@ +"""The outage report the root conftest builds when the circuit breaker trips. + +The report exists so a person reading "N tests skipped" can decide between +debugging and ignoring: it must name the tests, carry the URL of the call +that failed or timed out (as a clickable link), and say how it failed. +These tests pin that contract without needing an outage. +""" + +import importlib.util +import json +import os + +import pytest +import requests + + +def _load_root_conftest(): + path = os.path.join(os.path.dirname(os.path.dirname( + os.path.abspath(__file__))), "conftest.py") + spec = importlib.util.spec_from_file_location("vfb_root_conftest", path) + module = importlib.util.module_from_spec(spec) + spec.loader.exec_module(module) + return module + + +@pytest.fixture() +def guard(tmp_path, monkeypatch): + module = _load_root_conftest() + monkeypatch.setattr(module, "_OUTAGE_EVENTS", + str(tmp_path / "events.jsonl")) + monkeypatch.setattr(module, "_OUTAGE_LATCH", str(tmp_path / "latch")) + module._probe_cache.update(at=0.0, down=False, detail=None) + return module + + +# --------------------------------------------------------------------------- +# Finding the URL behind a failure +# --------------------------------------------------------------------------- + +def test_failure_url_from_requests_exception(guard): + request = requests.Request( + "GET", "https://pdb.virtualflybrain.org/db/neo4j/tx/commit").prepare() + exc = requests.ConnectionError("boom", request=request) + assert guard._failure_url(exc) == ( + "https://pdb.virtualflybrain.org/db/neo4j/tx/commit") + + +def test_failure_url_from_message_text(guard): + exc = RuntimeError( + "Solr responded with an error (HTTP 503): " + "http://solr.virtualflybrain.org/solr/vfb_json/select?q=x timed out.") + assert guard._failure_url(exc) == ( + "http://solr.virtualflybrain.org/solr/vfb_json/select?q=x") + + +def test_failure_url_walks_the_exception_chain(guard): + inner = RuntimeError("connect to http://owl.virtualflybrain.org/kbs/vfb/ failed") + outer = ConnectionError("wrapped") + outer.__cause__ = inner + assert guard._failure_url(outer) == "http://owl.virtualflybrain.org/kbs/vfb/" + + +def test_failure_url_none_when_nothing_url_shaped(guard): + assert guard._failure_url(ConnectionError("no address here")) is None + + +# --------------------------------------------------------------------------- +# Probe detail +# --------------------------------------------------------------------------- + +def test_probe_records_how_each_backend_answered(guard, monkeypatch): + def fake_get(url, timeout): + if "pdb" in url: + raise requests.ReadTimeout("Read timed out. (read timeout=5)") + + class Resp: + status_code = 200 + return Resp() + + monkeypatch.setattr(guard.requests, "get", fake_get) + assert guard._backend_down() is True + detail = guard._probe_cache["detail"] + assert detail[0]["ok"] and detail[0]["status"] == 200 # solr answered + assert not detail[1]["ok"] and "ReadTimeout" in detail[1]["error"] + # the failing probe reaches the skip message… + assert "pdb.virtualflybrain.org" in guard._probe_failure_suffix() + assert "ReadTimeout" in guard._probe_failure_suffix() + # …and the event log, for the report. + events = [json.loads(line) for line in open(guard._OUTAGE_EVENTS)] + assert events and events[0]["event"] == "probe" + + +def test_probe_suffix_empty_when_healthy(guard): + guard._probe_cache.update(detail=[{"url": "x", "ok": True, "status": 200}]) + assert guard._probe_failure_suffix() == "" + + +# --------------------------------------------------------------------------- +# The report itself +# --------------------------------------------------------------------------- + +def _sample_events(): + return [ + {"event": "trigger", "test": "src/test/test_a.py::test_one", + "kind": "connection-failure", + "error": "ConnectionError: Failed to establish a new connection", + "url": "https://pdb.virtualflybrain.org/db/neo4j/tx/commit", + "time": 1.0}, + {"event": "trigger", "test": "src/test/test_a.py::test_one", # dupe + "kind": "connection-failure", "error": "again", "url": None, + "time": 2.0}, + {"event": "trigger", "test": "src/test/test_b.py::test_two", + "kind": "timeout", "error": "Failed: Timeout >300.0s", "url": None, + "time": 3.0}, + {"event": "probe", "probes": [ + {"url": "http://solr.virtualflybrain.org/solr/vfb_json/admin/ping", + "ok": True, "status": 200, "elapsed_s": 0.1}, + {"url": "http://pdb.virtualflybrain.org/", "ok": False, + "status": None, "error": "ReadTimeout: Read timed out.", + "elapsed_s": 5.0}], "time": 4.0}, + {"event": "skip", "test": "src/test/test_c.py::test_three", "time": 5.0}, + {"event": "skip", "test": "src/test/test_c.py::test_three", "time": 5.5}, + {"event": "skip", "test": "src/test/test_d.py::test_four", "time": 6.0}, + ] + + +def test_report_names_tests_urls_and_failure_modes(guard): + markdown, summary = guard.build_outage_report(_sample_events()) + assert "2 test(s) hit the backend directly" in summary + assert "2 more were fast-skipped" in summary + # the triggering tests, deduplicated, with kind and error + assert markdown.count("test_a.py::test_one") == 1 + assert "connection-failure" in markdown and "timeout" in markdown + # the failing call is a clickable markdown link + assert ("[https://pdb.virtualflybrain.org/db/neo4j/tx/commit]" + "(https://pdb.virtualflybrain.org/db/neo4j/tx/commit)") in markdown + # probe verdicts, both ways, with the URL linked + assert "**FAILED** — [http://pdb.virtualflybrain.org/]" in markdown + assert "OK — [http://solr.virtualflybrain.org" in markdown + assert "ReadTimeout" in markdown + # every fast-skipped test is listed, once, inside a details fold + assert markdown.count("test_c.py::test_three") == 1 + assert "test_d.py::test_four" in markdown + assert "
" in markdown + + +def test_sessionfinish_writes_the_report_files(guard, tmp_path, monkeypatch): + with open(guard._OUTAGE_EVENTS, "w") as fh: + for event in _sample_events(): + fh.write(json.dumps(event) + "\n") + + class Config: + class invocation_params: + dir = str(tmp_path) + + class Session: + config = Config() + + monkeypatch.delenv("PYTEST_XDIST_WORKER", raising=False) + guard.pytest_sessionfinish(Session(), 0) + markdown = (tmp_path / guard.OUTAGE_REPORT_MD).read_text() + assert "VFB backend outage report" in markdown + events = json.loads((tmp_path / guard.OUTAGE_REPORT_JSON).read_text()) + assert len(events) == len(_sample_events()) + + +def test_sessionfinish_silent_when_no_outage(guard, tmp_path, monkeypatch): + class Config: + class invocation_params: + dir = str(tmp_path) + + class Session: + config = Config() + + monkeypatch.delenv("PYTEST_XDIST_WORKER", raising=False) + guard.pytest_sessionfinish(Session(), 0) + assert not (tmp_path / guard.OUTAGE_REPORT_MD).exists() From 37b6d6bcbb34057b5b704e0d8d5034c0ef7bc749 Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 07:34:21 +0000 Subject: [PATCH 2/6] Report every skipped test with its reason, not only breaker skips '1 skipped' was as opaque as '155 skipped': the report only covered the circuit breaker, so an ordinary marker skip (tests/test_preview_warm.py's 'caching disabled: no patch layer to verify') stayed invisible without opening the Actions log. A pytest_runtest_logreport hook now records EVERY skip with its reason (xfails excluded), the report groups them by reason with per-group test lists in details folds, and the outage sections (first failing call with clickable URL, probe verdicts) sit on top when the breaker tripped. Renamed outage_report.* to skipped_tests_report.* to match, written whenever anything skipped. --- .github/workflows/python-test.yml | 28 ++++---- conftest.py | 104 ++++++++++++++++++++---------- tests/test_outage_reporting.py | 45 ++++++++----- 3 files changed, 114 insertions(+), 63 deletions(-) diff --git a/.github/workflows/python-test.yml b/.github/workflows/python-test.yml index a641ea4..79f788c 100644 --- a/.github/workflows/python-test.yml +++ b/.github/workflows/python-test.yml @@ -90,21 +90,22 @@ jobs: echo "No test output captured."; exit 0 fi summary=$(grep -Eo '[0-9]+ skipped' pytest_output.log | tail -1 || true) - # conftest.py writes outage_report.md when the circuit breaker - # tripped: which test hit the backend first, the URL of the call - # that failed or timed out and how, the health-probe verdicts, and - # the full list of fast-skipped tests. Embed it wherever the skip - # is reported so the reader can debug or decide to ignore. + # conftest.py writes skipped_tests_report.md whenever anything + # skipped: every skipped test grouped by reason, and — when the + # circuit breaker tripped — which test hit the backend first, the + # URL of the call that failed or timed out and how, and the + # health-probe verdicts. Embed it wherever the skip is reported + # so the reader can debug or decide to ignore. digest="" - if [ -f outage_report.md ]; then - digest=$(grep -m1 -oE 'call: \[[^]]+\]|FAILED[^|]*' outage_report.md | head -1 || true) + if [ -f skipped_tests_report.md ]; then + digest=$(grep -m1 -oE 'call: \[[^]]+\]|FAILED[^|]*' skipped_tests_report.md | head -1 || true) { echo "" - cat outage_report.md + cat skipped_tests_report.md } >> "$GITHUB_STEP_SUMMARY" fi if [ -n "$summary" ]; then - echo "::warning title=Tests skipped — VFB backend unreachable::${summary}. ${digest:+First failure: ${digest}. }These are NOT test failures and not a problem with this branch: the VFB backend (Neo4j / SOLR / Owlery) did not answer, so those queries went unverified this run. Treat a green check with skips as an incomplete run — re-run once the backend is healthy before relying on it. Full detail (failing URLs, probe verdicts, skipped-test list): the job summary and the PR comment." + echo "::warning title=Tests skipped — VFB backend unreachable::${summary}. ${digest:+First failure: ${digest}. }These are NOT test failures and not a problem with this branch: the VFB backend (Neo4j / SOLR / Owlery) did not answer, so those queries went unverified this run. Treat a green check with skips as an incomplete run — re-run once the backend is healthy before relying on it. Full detail (every skipped test with its reason; failing URLs and probe verdicts for backend failures): the job summary and the PR comment." else echo "No tests skipped." fi @@ -131,13 +132,14 @@ jobs: core.info('No pytest_output.log to read: ' + e.message); } - // conftest.py's outage report: the failing calls (as clickable - // links), the probe verdicts, and the fast-skipped test list. + // conftest.py's skip report: every skipped test grouped by + // reason, plus — for backend failures — the failing calls (as + // clickable links) and the probe verdicts. let outage = ''; try { - outage = fs.readFileSync('outage_report.md', 'utf8').trim(); + outage = fs.readFileSync('skipped_tests_report.md', 'utf8').trim(); } catch (e) { - core.info('No outage_report.md (breaker never tripped).'); + core.info('No skipped_tests_report.md (nothing skipped).'); } const { owner, repo } = context.repo; diff --git a/conftest.py b/conftest.py index 05cff00..2786046 100644 --- a/conftest.py +++ b/conftest.py @@ -215,15 +215,15 @@ def _raising_commit_list(*args, **kwargs): _PROBE_CACHE_S = 10 # re-probe at most this often, per worker _PROBE_TIMEOUT_S = 5 -#: Shared event log for the outage report — same run-keyed scheme as the +#: Shared event log for the skip report — same run-keyed scheme as the #: latch, JSON-lines so xdist workers can append concurrently. The session -#: master aggregates it into outage_report.md/.json at session end. +#: master aggregates it into skipped_tests_report.md/.json at session end. _OUTAGE_EVENTS = _OUTAGE_LATCH + "_events.jsonl" #: Where the aggregated report lands (the invocation directory, so CI steps #: can pick it up next to pytest_output.log). -OUTAGE_REPORT_MD = "outage_report.md" -OUTAGE_REPORT_JSON = "outage_report.json" +SKIP_REPORT_MD = "skipped_tests_report.md" +SKIP_REPORT_JSON = "skipped_tests_report.json" def _record_event(event, **fields): @@ -360,7 +360,6 @@ def pytest_runtest_setup(item): again, so a transient blip only pauses the suite briefly.""" if _outage_signalled_recently(): if _backend_down(): - _record_event("skip", test=item.nodeid) pytest.skip("VFB backend outage detected mid-run — skipping to avoid " "per-test timeouts; re-run once the backend is healthy" + _probe_failure_suffix()) @@ -368,6 +367,28 @@ def pytest_runtest_setup(item): _clear_outage() +def pytest_runtest_logreport(report): + """Record EVERY skipped test with its reason, whatever caused the skip. + + The report answers "N skipped — which, and why?" without opening the + Actions log, so it cannot be limited to the circuit breaker's own + skips: a marker skip, a skipif, an imperative ``pytest.skip`` inside a + test all land here too, each with its reason string. xfails are not + skips and stay out. + """ + if not report.skipped or hasattr(report, "wasxfail"): + return + longrepr = getattr(report, "longrepr", None) + if isinstance(longrepr, tuple) and len(longrepr) == 3: + reason = str(longrepr[2]) + else: + reason = str(longrepr) if longrepr is not None else "" + if reason.startswith("Skipped: "): + reason = reason[len("Skipped: "):] + _record_event("skipped", test=report.nodeid, when=report.when, + reason=reason[:400]) + + # -------------------------------------------------------------------------- # Outage report — aggregate the events into something a person can act on # -------------------------------------------------------------------------- @@ -376,34 +397,41 @@ def _md_link(url): return "[%s](%s)" % (url, url) -def build_outage_report(events): +def build_skip_report(events): """(markdown, summary_line) from the recorded events. The markdown is what the CI steps embed in the job summary and the sticky PR comment, so URLs are rendered as links: the point of the - report is that the person reading it can click the failing call, - see how it failed, and decide between debugging and ignoring. + report is that the person reading it can see every skipped test with + the reason it skipped — and, for backend failures, click the failing + call and see how it failed — then decide between debugging and + ignoring. """ - triggers, skips, probes = [], [], [] - seen_triggers, seen_skips = set(), set() + triggers, skipped, probes = [], {}, [] + seen_triggers = set() for event in events: if event.get("event") == "trigger" and event.get("test") not in seen_triggers: seen_triggers.add(event.get("test")) triggers.append(event) - elif event.get("event") == "skip" and event.get("test") not in seen_skips: - seen_skips.add(event.get("test")) - skips.append(event) + elif event.get("event") == "skipped": + skipped.setdefault(event.get("test"), event.get("reason", "")) elif event.get("event") == "probe": probes.append(event) - summary = ("%d test(s) hit the backend directly and failed; %d more were " - "fast-skipped by the circuit breaker" - % (len(triggers), len(skips))) - - lines = ["## VFB backend outage report", "", - summary + ". Details below decide between debugging and " - "re-running: a transport error against a known-good URL is an " - "outage (re-run later); anything else deserves a look.", ""] + breaker = sum(1 for reason in skipped.values() + if reason.startswith("VFB backend outage detected mid-run")) + summary = "%d test(s) skipped" % len(skipped) + if triggers or breaker: + summary += (" — %d hit the backend directly and failed, %d were " + "fast-skipped by the circuit breaker" + % (len(triggers), breaker)) + + lines = ["## Skipped tests report", "", + summary + ". Every skip is listed below with its reason; for " + "backend failures the failing call and the health-probe " + "verdicts say what to debug — a transport error against a " + "known-good URL is an outage (re-run later); anything else " + "deserves a look.", ""] if triggers: lines += ["### What failed first", ""] @@ -429,20 +457,27 @@ def build_outage_report(events): entry.get("elapsed_s"))) lines.append("") - if skips: - names = sorted(event.get("test", "") for event in skips) - lines += ["### Tests fast-skipped by the circuit breaker (%d)" % len(names), - "", "
Full list", ""] - lines += ["- `%s`" % name for name in names] - lines += ["", "
", ""] + if skipped: + by_reason = {} + for test, reason in skipped.items(): + by_reason.setdefault(reason or "(no reason recorded)", + []).append(test) + lines += ["### All skipped tests (%d), by reason" % len(skipped), ""] + for reason, tests in sorted(by_reason.items(), + key=lambda kv: -len(kv[1])): + lines += ["
%d × %s" + % (len(tests), reason.replace("\n", " ")), ""] + lines += ["- `%s`" % test for test in sorted(tests)] + lines += ["", "
", ""] return "\n".join(lines), summary def pytest_sessionfinish(session, exitstatus): """On the session master, turn the shared event log into - ``outage_report.md`` / ``outage_report.json`` beside the invocation - directory's pytest output, for the CI skip report to embed.""" + ``skipped_tests_report.md`` / ``skipped_tests_report.json`` beside the + invocation directory's pytest output, for the CI skip report to embed. + Written whenever anything skipped; absent on a fully-run session.""" if os.environ.get("PYTEST_XDIST_WORKER"): return # workers report; the master writes events = [] @@ -458,14 +493,13 @@ def pytest_sessionfinish(session, exitstatus): if not events: return outdir = str(session.config.invocation_params.dir) - markdown, summary = build_outage_report(events) + markdown, summary = build_skip_report(events) try: - with open(os.path.join(outdir, OUTAGE_REPORT_MD), "w") as fh: + with open(os.path.join(outdir, SKIP_REPORT_MD), "w") as fh: fh.write(markdown) - with open(os.path.join(outdir, OUTAGE_REPORT_JSON), "w") as fh: + with open(os.path.join(outdir, SKIP_REPORT_JSON), "w") as fh: json.dump(events, fh, indent=1) - print("\nVFB backend outage detected this run: %s.\n" - "Report written to %s (markdown) and %s (raw events)." - % (summary, OUTAGE_REPORT_MD, OUTAGE_REPORT_JSON)) + print("\n%s.\nSkip report written to %s (markdown) and %s " + "(raw events)." % (summary, SKIP_REPORT_MD, SKIP_REPORT_JSON)) except OSError: pass diff --git a/tests/test_outage_reporting.py b/tests/test_outage_reporting.py index a873700..32220e8 100644 --- a/tests/test_outage_reporting.py +++ b/tests/test_outage_reporting.py @@ -1,9 +1,10 @@ -"""The outage report the root conftest builds when the circuit breaker trips. +"""The skip report the root conftest builds whenever tests skip. The report exists so a person reading "N tests skipped" can decide between -debugging and ignoring: it must name the tests, carry the URL of the call -that failed or timed out (as a clickable link), and say how it failed. -These tests pin that contract without needing an outage. +debugging and ignoring: it must name EVERY skipped test with its reason, +and for backend failures carry the URL of the call that failed or timed +out (as a clickable link) and how it failed. These tests pin that +contract without needing an outage. """ import importlib.util @@ -118,16 +119,26 @@ def _sample_events(): {"url": "http://pdb.virtualflybrain.org/", "ok": False, "status": None, "error": "ReadTimeout: Read timed out.", "elapsed_s": 5.0}], "time": 4.0}, - {"event": "skip", "test": "src/test/test_c.py::test_three", "time": 5.0}, - {"event": "skip", "test": "src/test/test_c.py::test_three", "time": 5.5}, - {"event": "skip", "test": "src/test/test_d.py::test_four", "time": 6.0}, + {"event": "skipped", "test": "src/test/test_c.py::test_three", + "reason": "VFB backend outage detected mid-run — skipping to avoid " + "per-test timeouts (probe: http://pdb.virtualflybrain.org/ " + "-> ReadTimeout after 5s)", "time": 5.0}, + {"event": "skipped", "test": "src/test/test_c.py::test_three", + "reason": "duplicate — first reason wins", "time": 5.5}, + {"event": "skipped", "test": "src/test/test_d.py::test_four", + "reason": "VFB backend outage detected mid-run — skipping to avoid " + "per-test timeouts (probe: http://pdb.virtualflybrain.org/ " + "-> ReadTimeout after 5s)", "time": 6.0}, + {"event": "skipped", "test": "tests/test_preview_warm.py::test_patch", + "reason": "caching disabled: no patch layer to verify", "time": 7.0}, ] def test_report_names_tests_urls_and_failure_modes(guard): - markdown, summary = guard.build_outage_report(_sample_events()) - assert "2 test(s) hit the backend directly" in summary - assert "2 more were fast-skipped" in summary + markdown, summary = guard.build_skip_report(_sample_events()) + assert "3 test(s) skipped" in summary + assert "2 hit the backend directly" in summary + assert "2 were fast-skipped" in summary # the triggering tests, deduplicated, with kind and error assert markdown.count("test_a.py::test_one") == 1 assert "connection-failure" in markdown and "timeout" in markdown @@ -138,9 +149,13 @@ def test_report_names_tests_urls_and_failure_modes(guard): assert "**FAILED** — [http://pdb.virtualflybrain.org/]" in markdown assert "OK — [http://solr.virtualflybrain.org" in markdown assert "ReadTimeout" in markdown - # every fast-skipped test is listed, once, inside a details fold + # EVERY skipped test is listed once, grouped by reason, in details folds assert markdown.count("test_c.py::test_three") == 1 assert "test_d.py::test_four" in markdown + assert "duplicate — first reason wins" not in markdown # dedupe kept first + assert "2 × VFB backend outage detected mid-run" in markdown + assert "1 × caching disabled: no patch layer to verify" in markdown + assert "test_preview_warm.py::test_patch" in markdown assert "
" in markdown @@ -158,9 +173,9 @@ class Session: monkeypatch.delenv("PYTEST_XDIST_WORKER", raising=False) guard.pytest_sessionfinish(Session(), 0) - markdown = (tmp_path / guard.OUTAGE_REPORT_MD).read_text() - assert "VFB backend outage report" in markdown - events = json.loads((tmp_path / guard.OUTAGE_REPORT_JSON).read_text()) + markdown = (tmp_path / guard.SKIP_REPORT_MD).read_text() + assert "Skipped tests report" in markdown + events = json.loads((tmp_path / guard.SKIP_REPORT_JSON).read_text()) assert len(events) == len(_sample_events()) @@ -174,4 +189,4 @@ class Session: monkeypatch.delenv("PYTEST_XDIST_WORKER", raising=False) guard.pytest_sessionfinish(Session(), 0) - assert not (tmp_path / guard.OUTAGE_REPORT_MD).exists() + assert not (tmp_path / guard.SKIP_REPORT_MD).exists() From 0d9bb4bd3e17514bcc602418090b82122eb8ecf1 Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 07:34:21 +0000 Subject: [PATCH 3/6] Filter marshmallow warnings by category, not class name MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The examples workflow's move to pytest (PR #96) broke it on Python 3.8: pytest resolves ignore:: filters at startup and exits 4 when the class does not exist, and that job's older marshmallow predates ChangedInMarshmallow4Warning. Both classes subclass DeprecationWarning, so filter DeprecationWarning from the marshmallow module instead — version-proof, and user-code DeprecationWarnings still show. Verified the suite still runs with zero marshmallow warnings leaking. --- pyproject.toml | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/pyproject.toml b/pyproject.toml index 7139454..3b61cd5 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -31,7 +31,14 @@ timeout = 300 # vfb_connect / dataclasses-json) still trigger them. Hiding the # library-internal noise — but NOT user-code DeprecationWarnings — # keeps performance.md readable. +# +# Filtered by category + source module rather than by naming marshmallow's +# own warning classes: pytest resolves a named class at startup and ERRORS +# (exit 4, nothing collected) when it does not exist — which is what broke +# the Python 3.8 examples job, whose older marshmallow predates +# ChangedInMarshmallow4Warning. Both classes subclass DeprecationWarning, +# and the module field pins the filter to warnings raised from inside +# marshmallow, so user-code DeprecationWarnings still show. filterwarnings = [ - "ignore::marshmallow.warnings.RemovedInMarshmallow4Warning", - "ignore::marshmallow.warnings.ChangedInMarshmallow4Warning", + "ignore::DeprecationWarning:marshmallow.*", ] \ No newline at end of file From 5337d345caee299ca4456255c8790177ae4c0bae Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 08:09:53 +0000 Subject: [PATCH 4/6] Treat numpy scalars as numbers in the example shape comparison MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The Python 3.8 examples job failed with 'recorded number, live is int64': on that environment pandas hands counts back as numpy.int64, which the coarse type bucket did not recognise as a number, while the JSON recordings necessarily hold plain numbers. The environment's box type is not a schema property — numpy scalars register with the numbers ABCs (bool_/str_ matched by name), so int64 counts, float64 scores and numpy bools now land in the same bucket as their recorded JSON forms. A recorded number turning into a string still fails. --- src/test/test_example_queries.py | 28 +++++++++++++++++++++++----- 1 file changed, 23 insertions(+), 5 deletions(-) diff --git a/src/test/test_example_queries.py b/src/test/test_example_queries.py index c0e49c1..88dbf03 100644 --- a/src/test/test_example_queries.py +++ b/src/test/test_example_queries.py @@ -25,6 +25,7 @@ """ import json +import numbers import os import pytest @@ -68,14 +69,23 @@ def _expected(name): def _type_bucket(value): """Coarse type category for leaf comparison: content may change freely, - a bool becoming a string may not.""" - if isinstance(value, bool): + a bool becoming a string may not. + + Live results can carry numpy scalars (int64 counts out of pandas on + some environments) where the JSON recording holds plain numbers; both + are "number" — the environment's box type is not a schema property. + numpy scalar types register with the ``numbers`` ABCs, so no numpy + import is needed; ``bool_``/``str_`` are matched by name for the same + reason. + """ + name = type(value).__name__ + if isinstance(value, bool) or name == "bool_": return "bool" - if isinstance(value, (int, float)): + if isinstance(value, numbers.Number): return "number" - if isinstance(value, str): + if isinstance(value, str) or name == "str_": return "string" - return type(value).__name__ + return name def shape_mismatches(expected, live, path="$"): @@ -191,6 +201,14 @@ def test_shape_comparator_catches_regressions(): "flag": True}) +def test_numpy_scalars_count_as_numbers(): + numpy = pytest.importorskip("numpy") + assert not shape_mismatches({"count": 3}, {"count": numpy.int64(5)}) + assert not shape_mismatches({"score": 0.5}, {"score": numpy.float64(1.5)}) + assert not shape_mismatches({"flag": True}, {"flag": numpy.bool_(False)}) + assert shape_mismatches({"count": 3}, {"count": "5"}) # still a drift + + # --------------------------------------------------------------------------- # Re-recording — `python -m src.test.test_example_queries --record` # --------------------------------------------------------------------------- From 9e98f1b79ec5a5e0fa89252b93bee3f01b481cd3 Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 08:11:42 +0000 Subject: [PATCH 5/6] Say what each skipped test does and where it lives MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A nodeid like test_the_public_entry_point_reaches_the_decorated_original still forced the reader into the source tree to understand what went unverified. Every recorded skip and trigger now carries the test's location and the first line of its docstring; the report renders each test as a link to the exact file and line at the run's commit (when the GitHub Actions environment provides one) followed by that summary. Skips are recorded from the makereport wrapper — which holds the item — rather than a separate logreport hook. --- conftest.py | 101 ++++++++++++++++++++++----------- tests/test_outage_reporting.py | 31 +++++++++- 2 files changed, 97 insertions(+), 35 deletions(-) diff --git a/conftest.py b/conftest.py index 2786046..6d85092 100644 --- a/conftest.py +++ b/conftest.py @@ -92,6 +92,22 @@ def _is_connection_failure(exc): _URL_RE = re.compile(r"https?://[^\s'\"<>)\]]+") +def _item_context(item): + """file, line and first docstring line for a test item — the report + reader should learn what a test does and where it lives without + opening the source tree.""" + doc = "" + try: + import inspect + doc = (inspect.getdoc(getattr(item, "obj", None)) or "").strip() + doc = doc.split("\n")[0].strip() + except Exception: + pass + location = getattr(item, "location", ("", 0, "")) + return {"file": str(location[0]).replace("\\", "/"), + "line": (location[1] or 0) + 1, "doc": doc[:240]} + + def _failure_url(exc): """Best-effort URL of the call behind a transport failure. @@ -134,7 +150,7 @@ def pytest_runtest_makereport(item, call): _mark_outage() _record_event("trigger", test=item.nodeid, kind="connection-failure", error=f"{type(exc).__name__}: {str(exc)[:300]}", - url=url) + url=url, **_item_context(item)) elif "pytest-timeout" in str(exc): # A test hit the per-test ceiling. If the backend is down this is an # outage casualty, not a slow query — record it and let it read as a @@ -158,7 +174,25 @@ def pytest_runtest_makereport(item, call): + _probe_failure_suffix(), ) _record_event("trigger", test=item.nodeid, kind="timeout", - error=str(exc)[:300], url=None) + error=str(exc)[:300], url=None, + **_item_context(item)) + + # Record EVERY skipped test — whatever caused the skip — with its + # reason, its location, and the first line of its docstring, so the + # report answers "which tests, doing what, and why?" without opening + # the source. A marker skip, a skipif, an imperative ``pytest.skip`` + # and the breaker's own skips all land here; xfails are not skips + # and stay out. + if rep.skipped and not hasattr(rep, "wasxfail"): + longrepr = rep.longrepr + if isinstance(longrepr, tuple) and len(longrepr) == 3: + reason = str(longrepr[2]) + else: + reason = str(longrepr) if longrepr is not None else "" + if reason.startswith("Skipped: "): + reason = reason[len("Skipped: "):] + _record_event("skipped", test=item.nodeid, when=rep.when, + reason=reason[:400], **_item_context(item)) # -------------------------------------------------------------------------- @@ -367,27 +401,6 @@ def pytest_runtest_setup(item): _clear_outage() -def pytest_runtest_logreport(report): - """Record EVERY skipped test with its reason, whatever caused the skip. - - The report answers "N skipped — which, and why?" without opening the - Actions log, so it cannot be limited to the circuit breaker's own - skips: a marker skip, a skipif, an imperative ``pytest.skip`` inside a - test all land here too, each with its reason string. xfails are not - skips and stay out. - """ - if not report.skipped or hasattr(report, "wasxfail"): - return - longrepr = getattr(report, "longrepr", None) - if isinstance(longrepr, tuple) and len(longrepr) == 3: - reason = str(longrepr[2]) - else: - reason = str(longrepr) if longrepr is not None else "" - if reason.startswith("Skipped: "): - reason = reason[len("Skipped: "):] - _record_event("skipped", test=report.nodeid, when=report.when, - reason=reason[:400]) - # -------------------------------------------------------------------------- # Outage report — aggregate the events into something a person can act on @@ -397,6 +410,23 @@ def _md_link(url): return "[%s](%s)" % (url, url) +def _test_ref(event): + """One report line's worth of test identity: the nodeid — linked to + the exact file and line at this run's commit when the GitHub Actions + environment says where that is — followed by the first line of the + test's docstring, so the reader learns what the test does without + opening the source.""" + label = "`%s`" % event.get("test") + server = os.environ.get("GITHUB_SERVER_URL") + repo = os.environ.get("GITHUB_REPOSITORY") + sha = os.environ.get("GITHUB_SHA") + if server and repo and sha and event.get("file"): + label = "[%s](%s/%s/blob/%s/%s#L%s)" % ( + label, server, repo, sha, event["file"], event.get("line") or 1) + doc = (event.get("doc") or "").strip() + return label + (" — %s" % doc if doc else "") + + def build_skip_report(events): """(markdown, summary_line) from the recorded events. @@ -414,12 +444,13 @@ def build_skip_report(events): seen_triggers.add(event.get("test")) triggers.append(event) elif event.get("event") == "skipped": - skipped.setdefault(event.get("test"), event.get("reason", "")) + skipped.setdefault(event.get("test"), event) elif event.get("event") == "probe": probes.append(event) - breaker = sum(1 for reason in skipped.values() - if reason.startswith("VFB backend outage detected mid-run")) + breaker = sum(1 for event in skipped.values() + if event.get("reason", "").startswith( + "VFB backend outage detected mid-run")) summary = "%d test(s) skipped" % len(skipped) if triggers or breaker: summary += (" — %d hit the backend directly and failed, %d were " @@ -437,8 +468,8 @@ def build_skip_report(events): lines += ["### What failed first", ""] for event in sorted(triggers, key=lambda e: e.get("time", 0)): call = (" — call: " + _md_link(event["url"])) if event.get("url") else "" - lines.append("- `%s` (%s): %s%s" - % (event.get("test"), event.get("kind"), + lines.append("- %s\n %s: %s%s" + % (_test_ref(event), event.get("kind"), event.get("error", "").replace("\n", " "), call)) lines.append("") @@ -459,15 +490,17 @@ def build_skip_report(events): if skipped: by_reason = {} - for test, reason in skipped.items(): - by_reason.setdefault(reason or "(no reason recorded)", - []).append(test) + for event in skipped.values(): + by_reason.setdefault(event.get("reason") or "(no reason recorded)", + []).append(event) lines += ["### All skipped tests (%d), by reason" % len(skipped), ""] - for reason, tests in sorted(by_reason.items(), + for reason, group in sorted(by_reason.items(), key=lambda kv: -len(kv[1])): lines += ["
%d × %s" - % (len(tests), reason.replace("\n", " ")), ""] - lines += ["- `%s`" % test for test in sorted(tests)] + % (len(group), reason.replace("\n", " ")), ""] + lines += ["- " + _test_ref(event) + for event in sorted(group, + key=lambda e: e.get("test", ""))] lines += ["", "
", ""] return "\n".join(lines), summary diff --git a/tests/test_outage_reporting.py b/tests/test_outage_reporting.py index 32220e8..b1257c3 100644 --- a/tests/test_outage_reporting.py +++ b/tests/test_outage_reporting.py @@ -130,7 +130,9 @@ def _sample_events(): "per-test timeouts (probe: http://pdb.virtualflybrain.org/ " "-> ReadTimeout after 5s)", "time": 6.0}, {"event": "skipped", "test": "tests/test_preview_warm.py::test_patch", - "reason": "caching disabled: no patch layer to verify", "time": 7.0}, + "reason": "caching disabled: no patch layer to verify", + "doc": "The public entry point delegates to the decorated original.", + "file": "tests/test_preview_warm.py", "line": 540, "time": 7.0}, ] @@ -156,9 +158,36 @@ def test_report_names_tests_urls_and_failure_modes(guard): assert "2 × VFB backend outage detected mid-run" in markdown assert "1 × caching disabled: no patch layer to verify" in markdown assert "test_preview_warm.py::test_patch" in markdown + # the docstring's first line tells the reader what the test does + assert ("— The public entry point delegates to the decorated original." + in markdown) assert "
" in markdown +def test_report_links_tests_to_source_on_github_actions(guard, monkeypatch): + monkeypatch.setenv("GITHUB_SERVER_URL", "https://github.com") + monkeypatch.setenv("GITHUB_REPOSITORY", "VirtualFlyBrain/VFBquery") + monkeypatch.setenv("GITHUB_SHA", "abc123") + markdown, _ = guard.build_skip_report(_sample_events()) + assert ("[`tests/test_preview_warm.py::test_patch`]" + "(https://github.com/VirtualFlyBrain/VFBquery/blob/abc123/" + "tests/test_preview_warm.py#L540)") in markdown + + +def test_item_context_reads_docstring_and_location(guard): + class Item: + def obj(self): + pass + obj.__doc__ = """Checks the thing. + + Longer detail that must not leak into the one-line summary.""" + location = ("tests/test_x.py", 41, "test_checks") + + context = guard._item_context(Item()) + assert context == {"file": "tests/test_x.py", "line": 42, + "doc": "Checks the thing."} + + def test_sessionfinish_writes_the_report_files(guard, tmp_path, monkeypatch): with open(guard._OUTAGE_EVENTS, "w") as fh: for event in _sample_events(): From 5b7cad384cd503d9a495e63df436920621dd8f68 Mon Sep 17 00:00:00 2001 From: Robbie1977 Date: Sun, 30 Aug 2026 08:15:42 +0000 Subject: [PATCH 6/6] Verify the caching patch chain on every run instead of skipping MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit test_the_public_entry_point_reaches_the_decorated_original skipped whenever VFBQUERY_CACHE_ENABLED=false — which the Run Tests workflow always sets, so CI never once verified the chain it exists to guard and the skip sat unexplained in every run (it was the '1 skipped'). Caching being off is a property of the test process, not of the code under test: when the ambient import ran unpatched, the same assertions now run in a subprocess that imports vfbquery with caching enabled — the real import-time patch path, production's default. No backend is contacted either way; the assertions only inspect bindings. The test now passes in both modes and never skips. --- tests/test_preview_warm.py | 68 ++++++++++++++++++++++++++------------ 1 file changed, 46 insertions(+), 22 deletions(-) diff --git a/tests/test_preview_warm.py b/tests/test_preview_warm.py index 1c8aa7b..2c11e27 100644 --- a/tests/test_preview_warm.py +++ b/tests/test_preview_warm.py @@ -38,6 +38,7 @@ Solr are involved; the decorator tests drive the real wrapper with a fake cache object. """ +import os import threading import time @@ -535,6 +536,28 @@ def test_the_cooldown_is_configurable(): "the cooldown must stay env-tunable") +_PATCH_CHAIN_ASSERTS = """ +import inspect +import vfbquery +from vfbquery import cached_functions +import vfbquery.vfb_queries as vq + +assert hasattr(vq, '_original_get_term_info'), 'patch layer never armed' +assert vfbquery.get_term_info is cached_functions.get_term_info_cached +assert vq.get_term_info is cached_functions.get_term_info_cached +# The delegate declares force_refresh and hands it on explicitly, so a +# refresh survives the extra hop rather than being defaulted away. +params = inspect.signature(cached_functions.get_term_info_cached).parameters +assert 'force_refresh' in params and params['force_refresh'].default is False +src_text = inspect.getsource(cached_functions.get_term_info_cached) +assert 'force_refresh=force_refresh' in src_text +# And what it delegates to is the decorated original, not a second cache +# layer -- double-decorating was its own bug (two Solr reads per request). +assert hasattr(vq._original_get_term_info, '__wrapped__') +assert '_original_get_term_info' in src_text +""" + + def test_the_public_entry_point_reaches_the_decorated_original(): """The warm calls ``vfbquery.get_term_info``, which is not the function in this module: with caching enabled, ``cached_functions`` rebinds it to @@ -542,29 +565,30 @@ def test_the_public_entry_point_reaches_the_decorated_original(): chain -- public name, delegate, ``with_solr_cache``, body -- so the chain is asserted rather than assumed. - Skipped when caching is disabled, because then no patching happens and - there is no delegation to check. + This test used to skip whenever ``VFBQUERY_CACHE_ENABLED=false`` — which + the Run Tests workflow always sets, so CI never verified the chain and + the skip sat unexplained in every run. Caching-off is a property of this + *process*, not of the code under test: when the ambient import ran + unpatched, the same assertions run in a subprocess that imports vfbquery + with caching enabled — the real import-time patch path, production's + default — so the chain is verified on every run, everywhere. No backend + is contacted either way: the assertions only inspect bindings. """ - import vfbquery - from vfbquery import cached_functions - - if not hasattr(vq, '_original_get_term_info'): - pytest.skip("caching disabled: no patch layer to verify") - - assert vfbquery.get_term_info is cached_functions.get_term_info_cached - assert vq.get_term_info is cached_functions.get_term_info_cached - # The delegate declares force_refresh and hands it on explicitly, so a - # refresh survives the extra hop rather than being defaulted away. - import inspect - params = inspect.signature(cached_functions.get_term_info_cached).parameters - assert 'force_refresh' in params and params['force_refresh'].default is False - src_text = inspect.getsource(cached_functions.get_term_info_cached) - assert 'force_refresh=force_refresh' in src_text - # And what it delegates to is the decorated original, not a second cache - # layer -- double-decorating was its own bug (two Solr reads per request). - original = vq._original_get_term_info - assert hasattr(original, '__wrapped__') - assert '_original_get_term_info' in src_text + if hasattr(vq, '_original_get_term_info'): + # Patched in this process (the default of a plain `pytest tests/`): + # assert directly. + exec(compile(_PATCH_CHAIN_ASSERTS, "", "exec"), {}) + return + + import subprocess + import sys + env = dict(os.environ, VFBQUERY_CACHE_ENABLED="true") + proc = subprocess.run( + [sys.executable, "-c", _PATCH_CHAIN_ASSERTS], env=env, + capture_output=True, text=True, timeout=240) + assert proc.returncode == 0, ( + "patch-chain assertions failed in a caching-enabled interpreter:\n" + "stdout:\n%s\nstderr:\n%s" % (proc.stdout[-2000:], proc.stderr[-2000:])) def test_the_stale_self_healing_claim_is_gone():