Merge pull request #2160 from vyos/claude/smoke-hardening-2

docs-gates: re-land HTTPError close + detail logging; widen smoke retry envelope

2 files changed, 162 insertions, 44 deletions

diff --git a/scripts/docs_gates/smoke.py b/scripts/docs_gates/smoke.py
index 2dab82ff..770e93e3 100644
--- a/scripts/docs_gates/smoke.py
+++ b/scripts/docs_gates/smoke.py
@@ -31,11 +31,17 @@ USER_AGENT = "vyos-docs-smoke/1.0 (+https://github.com/vyos/vyos-documentation)"
 # can lose a propagation race: for a few minutes a probe may be served by the PREVIOUS version
 # (wrong status / stale X-Docs-Build). Rather than fail-fast, each round re-probes ONLY the
 # still-failing probes — this preserves the full per-probe failure enumeration (diagnostic
-# value) while adding at most (MAX_ROUNDS - 1) inter-round sleeps. DEADLINE_SECONDS caps total
-# wall-clock so a pile-up of slow / timing-out probes cannot run unbounded.
-MAX_ROUNDS = 3
-RETRY_SLEEP_SECONDS = 20
+# value) while adding at most (MAX_ROUNDS - 1) inter-round sleeps. Envelope widened to 5 rounds
+# x 30s after an observed propagation wave outlasted 3 rounds x 20s (a path still stale at
+# round 3): 4 x 30s = 2 min now covers the observed 1-2+ min waves. The green path still costs
+# zero extra time (no retries), and DEADLINE_SECONDS=480 still bounds the worst case.
+MAX_ROUNDS = 5
+RETRY_SLEEP_SECONDS = 30
 DEADLINE_SECONDS = 480
+# Per-socket-op timeout (connect + read), capped down to the remaining deadline budget on each
+# probe so a probe that starts late cannot overshoot DEADLINE_SECONDS. Pages are small, so this
+# socket-op timeout also bounds body reads adequately — no separate body-read deadline is needed.
+PROBE_TIMEOUT_SECONDS = 30
 
 
 class _NoRedirect(urllib.request.HTTPRedirectHandler):
@@ -85,33 +91,42 @@ def search_mount_present(html: str) -> bool:
     return SEARCH_MOUNT_MARKER in html
 
 
-def _probe_once(host: str, probe: Probe, expect_sha: str, access_id: str,
-                access_secret: str) -> tuple[bool, int | None, str | None, str | None]:
-    """One probe attempt. Returns (ok, status, docs_build, error). ANY exception in the open
-    OR body-read path — including a transport error DURING HTTPError.read() — is contained and
-    yields (False, None, None, <msg>): a retryable failure, never a traceback that crashes the
-    gate. status/docs_build are surfaced for retry logging."""
+def _probe_once(host: str, probe: Probe, expect_sha: str, access_id: str, access_secret: str,
+                timeout: float = PROBE_TIMEOUT_SECONDS,
+                ) -> tuple[bool, int | None, str | None, str | None]:
+    """One probe attempt. Returns (ok, status, docs_build, detail). `detail` names the failed
+    check(s) — "status" / "docs-build" / "apex-build" / "search-mount" joined by "+", or the
+    transport error text — and is None when ok. `timeout` is the per-socket-op deadline (connect
+    + read); run() caps it to the remaining budget so a late probe can't overshoot the overall
+    deadline. ANY exception in the open OR body-read path (including a transport error DURING
+    HTTPError.read()) is contained and yields (False, None, None, <error text>): a retryable
+    failure, never a traceback. The HTTPError response stream is always closed — it owns a
+    socket, so a bare e.read() would leak it."""
     req = urllib.request.Request(f"https://{host}{probe.path}", method="GET")
     req.add_header("CF-Access-Client-Id", access_id)
     req.add_header("CF-Access-Client-Secret", access_secret)
     req.add_header("User-Agent", USER_AGENT)
     try:
         try:
-            with _OPENER.open(req, timeout=30) as resp:
+            with _OPENER.open(req, timeout=timeout) as resp:
                 status, headers, body = resp.status, resp.headers, resp.read()
         except urllib.error.HTTPError as e:  # non-2xx still carries headers/body
-            status, headers, body = e.code, e.headers, e.read()
+            with e:  # HTTPError is file-like and owns the response socket — always close it
+                status, headers, body = e.code, e.headers, e.read()
     except Exception as e:  # noqa: BLE001 — open OR read failure → retryable probe result
         return False, None, None, str(e)
-    ok = status == probe.expect_status
+    reasons: list[str] = []
+    if status != probe.expect_status:
+        reasons.append("status")
     if probe.assert_docs_build and not docs_build_ok(headers.get("X-Docs-Build"), expect_sha):
-        ok = False
+        reasons.append("docs-build")
     if probe.assert_apex_build and not headers.get("X-Apex-Build"):
-        ok = False
+        reasons.append("apex-build")
     if probe.assert_search_mount and not search_mount_present(
             body.decode("utf-8", errors="replace")):
-        ok = False
-    return ok, status, headers.get("X-Docs-Build"), None
+        reasons.append("search-mount")
+    detail = "+".join(reasons) if reasons else None
+    return not reasons, status, headers.get("X-Docs-Build"), detail
 
 
 def run(host: str, slug: str, expect_sha: str, access_id: str, access_secret: str,
@@ -122,12 +137,13 @@ def run(host: str, slug: str, expect_sha: str, access_id: str, access_secret: st
     DEADLINE_SECONDS bounds total wall-clock — on breach, unresolved probes count as failed."""
     plan = probe_plan(slug, pdf, critical)
     start = time.monotonic()
+    deadline = start + DEADLINE_SECONDS      # absolute — a hard upper bound on total wall-clock
     pending = list(plan)                     # probes not yet passed
     detail_by_path: dict[str, str] = {}      # last failure detail per path, for logging
     deadline_hit = False
 
-    def _past_deadline() -> bool:
-        return time.monotonic() - start >= DEADLINE_SECONDS
+    def _remaining() -> float:
+        return deadline - time.monotonic()
 
     for round_num in range(1, MAX_ROUNDS + 1):
         if not pending:
@@ -135,29 +151,30 @@ def run(host: str, slug: str, expect_sha: str, access_id: str, access_secret: st
         still_failing: list[Probe] = []
         unprobed: list[Probe] = []
         for i, probe in enumerate(pending):
-            if _past_deadline():             # checked before each probe
+            remaining = _remaining()         # checked before each probe
+            if remaining < 1:                # < 1s budget: don't start a probe that could overshoot
                 deadline_hit = True
                 unprobed = pending[i:]       # not reached this round → still unresolved
                 break
-            ok, status, docs_build, error = _probe_once(
-                host, probe, expect_sha, access_id, access_secret)
+            ok, status, docs_build, detail = _probe_once(
+                host, probe, expect_sha, access_id, access_secret,
+                timeout=min(PROBE_TIMEOUT_SECONDS, max(1, remaining)))
             if ok:
                 continue
             still_failing.append(probe)
-            detail = f"status={status} docs-build={docs_build}"
-            if error is not None:
-                detail += f" error={error}"
-            detail_by_path[probe.path] = detail
+            detail_by_path[probe.path] = (
+                f"status={status} docs-build={docs_build} detail={detail}")
         pending = still_failing + unprobed
         if deadline_hit or not pending or round_num == MAX_ROUNDS:
             break
-        if _past_deadline():                 # checked before the inter-round sleep
+        remaining = _remaining()             # checked before the inter-round sleep
+        if remaining <= 0:                   # no budget left → deadline path (skip the sleep)
             deadline_hit = True
             break
         for probe in pending:
             print(f"SMOKE-RETRY {probe.path}: round {round_num} "
                   f"{detail_by_path[probe.path]}", file=sys.stderr)
-        time.sleep(RETRY_SLEEP_SECONDS)
+        time.sleep(min(RETRY_SLEEP_SECONDS, remaining))   # never sleep past the deadline
 
     if deadline_hit:
         print("SMOKE-DEADLINE: overall deadline reached — remaining probes counted as failed",
diff --git a/scripts/docs_gates/test_smoke.py b/scripts/docs_gates/test_smoke.py
index 063b3a7a..a2654dcf 100644
--- a/scripts/docs_gates/test_smoke.py
+++ b/scripts/docs_gates/test_smoke.py
@@ -101,39 +101,48 @@ class _FakeResp:
 
 
 class _FakeOpener:
-    """Yields queued responses in order; an Exception item is raised (models a transport
-    error, or a non-2xx delivered as HTTPError). Records each opened Request for assertions."""
+    """Yields queued responses in order; an Exception item is raised (models a transport error,
+    or a non-2xx delivered as HTTPError). Records each opened Request + the timeout it was
+    called with, for assertions."""
 
     def __init__(self, responses: list[object]):
         self._responses = list(responses)
         self.calls: list[urllib.request.Request] = []
+        self.timeouts: list[float | None] = []
 
     def open(self, req: urllib.request.Request, timeout: float | None = None) -> object:
         self.calls.append(req)
+        self.timeouts.append(timeout)
         item = self._responses.pop(0)
         if isinstance(item, Exception):
             raise item
         return item
 
 
-def _http_error(code: int, headers: dict[str, str]) -> urllib.error.HTTPError:
-    hdrs = Message()
-    for k, v in headers.items():
-        hdrs[k] = v
-    return urllib.error.HTTPError("https://host.invalid/x", code, "msg", hdrs, io.BytesIO(b""))
+class _RecordingBody(io.BytesIO):
+    """HTTPError.fp stand-in: records close() (so tests can assert the response stream is
+    closed) and can optionally raise on read (a transport error DURING body read). urllib's
+    addbase binds read through to fp and closes fp on close(), so overriding them here is what
+    e.read() / closing e actually hit."""
 
-
-class _ReadBoom(io.BytesIO):
-    """A body whose .read() raises — models a transport error DURING HTTPError.read().
-    urllib's addbase binds the instance's read to fp.read, so overriding it on the fp is the
-    reliable way to make e.read() blow up."""
+    def __init__(self, data: bytes = b"", raise_on_read: bool = False):
+        super().__init__(data)
+        self.close_calls = 0
+        self._raise_on_read = raise_on_read
 
     def read(self, *args: object) -> bytes:  # noqa: D401
-        raise OSError("reset during body read")
+        if self._raise_on_read:
+            raise OSError("reset during body read")
+        return super().read(*args)
+
+    def close(self) -> None:
+        self.close_calls += 1
+        super().close()
 
 
 def _http_error_read_boom(code: int) -> urllib.error.HTTPError:
-    return urllib.error.HTTPError("https://host.invalid/x", code, "msg", Message(), _ReadBoom())
+    return urllib.error.HTTPError(
+        "https://host.invalid/x", code, "msg", Message(), _RecordingBody(raise_on_read=True))
 
 
 class _PathOpener:
@@ -144,10 +153,12 @@ class _PathOpener:
     def __init__(self, by_path: dict[str, list[object]]):
         self._by_path = {p: list(v) for p, v in by_path.items()}
         self.calls: list[str] = []
+        self.timeouts: list[float | None] = []
 
     def open(self, req: urllib.request.Request, timeout: float | None = None) -> object:
         path = urlsplit(req.full_url).path
         self.calls.append(path)
+        self.timeouts.append(timeout)
         item = self._by_path[path].pop(0)
         if isinstance(item, Exception):
             raise item
@@ -188,10 +199,10 @@ def test_httperror_read_crash_is_contained_as_failure(monkeypatch):
     monkeypatch.setattr(smoke, "_OPENER", _FakeOpener([_http_error_read_boom(502)]))
     probe = smoke.Probe("/en/rolling/index.html", 200,
                         assert_docs_build=False, assert_apex_build=False)
-    ok, status, docs_build, error = smoke._probe_once("host", probe, "sha", "id", "sec")
+    ok, status, docs_build, detail = smoke._probe_once("host", probe, "sha", "id", "sec")
     assert ok is False
     assert status is None and docs_build is None
-    assert error is not None and "reset during body read" in error
+    assert detail is not None and "reset during body read" in detail
 
 
 def test_sleeps_once_per_inter_round_gap_not_per_probe(monkeypatch):
@@ -263,3 +274,93 @@ def test_probe_plan_dedups_index_html():
     assert len(index_probes) == 1                       # not duplicated by the critical list
     assert index_probes[0].assert_search_mount is True  # still the single search-mount probe
     assert sum(1 for p in plan if p.path == "/en/rolling/cli.html") == 1  # cli.html preserved
+
+
+# --- CR round 2: close the HTTPError response stream (it owns a socket) + name the failed
+# assertion in retry/fail logs. ---
+
+def test_httperror_response_is_closed(monkeypatch):
+    # HTTPError owns the response socket; the expected-404 path must close it, not leak.
+    body = _RecordingBody(b"not found")
+    monkeypatch.setattr(smoke, "_OPENER", _FakeOpener([
+        urllib.error.HTTPError("https://host.invalid/x", 404, "msg", Message(), body)]))
+    probe = smoke.Probe("/en/rolling/missing.html", 404,
+                        assert_docs_build=False, assert_apex_build=False)
+    ok, *_ = smoke._probe_once("host", probe, "sha", "id", "sec")
+    assert ok is True                # 404 expected → passes
+    assert body.close_calls >= 1     # response stream closed (no socket leak / ResourceWarning)
+
+
+def test_httperror_response_is_closed_even_when_read_raises(monkeypatch):
+    body = _RecordingBody(raise_on_read=True)
+    monkeypatch.setattr(smoke, "_OPENER", _FakeOpener([
+        urllib.error.HTTPError("https://host.invalid/x", 502, "msg", Message(), body)]))
+    probe = smoke.Probe("/en/rolling/index.html", 200,
+                        assert_docs_build=False, assert_apex_build=False)
+    ok, _, _, detail = smoke._probe_once("host", probe, "sha", "id", "sec")
+    assert ok is False
+    assert detail is not None and "reset during body read" in detail
+    assert body.close_calls >= 1     # close still attempted despite the read raising
+
+
+def test_apex_build_failure_is_named_in_logs(monkeypatch, capsys):
+    # 200 but no X-Apex-Build: without a named detail the log read "status=200 docs-build=None".
+    probe = smoke.Probe("/versions.json", 200, assert_docs_build=False, assert_apex_build=True)
+    monkeypatch.setattr(smoke, "probe_plan", lambda slug, pdf, critical: [probe])
+    monkeypatch.setattr(smoke, "MAX_ROUNDS", 1)
+    monkeypatch.setattr(smoke, "_OPENER", _PathOpener({"/versions.json": [_FakeResp(200, {})]}))
+    assert smoke.run("host", "rolling", "sha", "id", "sec", None, []) == 1
+    err = capsys.readouterr().err
+    assert "SMOKE-FAIL /versions.json:" in err
+    assert "detail=apex-build" in err   # names the failed check
+    assert "status=200" in err          # existing fields preserved
+
+
+def test_search_mount_failure_is_named_in_logs(monkeypatch, capsys):
+    # 200 + correct build, but the HTML lacks the #vyos-search mount div.
+    probe = smoke.Probe("/en/rolling/index.html", 200, assert_docs_build=True,
+                        assert_apex_build=False, assert_search_mount=True)
+    monkeypatch.setattr(smoke, "probe_plan", lambda slug, pdf, critical: [probe])
+    monkeypatch.setattr(smoke, "MAX_ROUNDS", 1)
+    monkeypatch.setattr(smoke, "_OPENER", _PathOpener({
+        "/en/rolling/index.html": [_FakeResp(200, {"X-Docs-Build": "goodsha"},
+                                             b"<html>no search</html>")]}))
+    assert smoke.run("host", "rolling", "goodsha", "id", "sec", None, []) == 1
+    assert "detail=search-mount" in capsys.readouterr().err
+
+
+def test_probe_once_detail_joins_multiple_failed_checks(monkeypatch):
+    # wrong status AND missing X-Apex-Build → detail "status+apex-build"
+    monkeypatch.setattr(smoke, "_OPENER", _FakeOpener([_FakeResp(500, {})]))
+    probe = smoke.Probe("/versions.json", 200, assert_docs_build=False, assert_apex_build=True)
+    ok, _, _, detail = smoke._probe_once("host", probe, "sha", "id", "sec")
+    assert ok is False
+    assert detail == "status+apex-build"
+
+
+# --- Adversarial round: DEADLINE_SECONDS is a HARD bound — the per-probe socket timeout and the
+# inter-round sleep are both capped to the remaining budget so neither can overshoot it. ---
+
+def test_probe_timeout_capped_to_remaining_budget(monkeypatch):
+    monkeypatch.setattr(smoke, "probe_plan", lambda slug, pdf, critical: _plan(["/a"]))
+    monkeypatch.setattr(smoke, "DEADLINE_SECONDS", 5)  # << PROBE_TIMEOUT_SECONDS (30)
+    opener = _PathOpener({"/a": [_FakeResp(200, {})]})
+    monkeypatch.setattr(smoke, "_OPENER", opener)
+    smoke.run("host", "rolling", "sha", "id", "sec", None, [])
+    assert opener.timeouts, "the probe recorded the timeout it was opened with"
+    t = opener.timeouts[0]
+    assert 1 <= t <= smoke.DEADLINE_SECONDS    # capped DOWN to the ~5s remaining budget
+    assert t < smoke.PROBE_TIMEOUT_SECONDS      # NOT the full 30s socket timeout
+
+
+def test_inter_round_sleep_capped_to_remaining_budget(monkeypatch):
+    monkeypatch.setattr(smoke, "probe_plan", lambda slug, pdf, critical: _plan(["/a"]))
+    monkeypatch.setattr(smoke, "DEADLINE_SECONDS", 10)  # << RETRY_SLEEP_SECONDS (30)
+    sleeps: list[float] = []
+    monkeypatch.setattr(smoke.time, "sleep", lambda s: sleeps.append(s))
+    opener = _PathOpener({"/a": [_FakeResp(500, {}), _FakeResp(200, {})]})  # fail r1, pass r2
+    monkeypatch.setattr(smoke, "_OPENER", opener)
+    assert smoke.run("host", "rolling", "sha", "id", "sec", None, []) == 0
+    assert len(sleeps) == 1
+    assert 0 < sleeps[0] <= smoke.DEADLINE_SECONDS  # capped to the ~10s remaining budget
+    assert sleeps[0] < smoke.RETRY_SLEEP_SECONDS     # NOT the full 30s sleep