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
4 changes: 4 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,3 +1,7 @@
### Strix gate keeps a recovered transient model error from failing a completed scan

- `scripts/ci/strix_quick_gate.sh` `sanitize_known_strix_report_warnings` now also strips strix-agent's `strix.core.execution: transient model/provider error for <agent>; replaying turn (attempt n/m, backoff Ns): …` WARNING lines before the report failure-signal scan. strix-agent 1.5.3 (`strix/core/execution.py:763`) emits that line only inside its bounded transient-retry branch, immediately before the replay runs; an exhausted retry logs `agent run failed for …; marking failed` at ERROR with a traceback and exits non-zero, and both of those still fail the gate. Observed on `.github#1689` run `34013778497`: a completed 63-minute scan (`run.json` `completed`, SARIF 0 results, attempt exit 0) was failed closed as `STRIX_PROVIDER_UNAVAILABLE … exhausted` on three such warnings, and the scheduler then dispatched another same-head scan. The pattern is anchored before the exception repr so the same class keeps matching after a gateway pin advance changes the exception type; re-verify the message format on every strix-agent bump. One documented side effect: when a provider's 503 body appears only inside a retry line's exception repr, removing that line also removes the only text `has_strix_report_provider_failure_signal` would have matched in the report log, which can make `is_model_retryable_error`'s report-only branch read a genuine outage as non-retryable. The direction is fail-closed (an exhausted retry still exits non-zero with its ERROR and traceback retained), and with a contextual-orchestrator primary the verdict branch answers before that classifier is consulted, so no path today changes its outcome; if fallback-model classification is ever wanted for a non-gateway primary, read the pre-sanitize attempt copy that `preserve_attempt_log` already keeps. Tests: `tests/test_strix_recovered_transient_sanitizer.py`.

### Review sidecar preflight postpones a rate-limited account's candidates instead of banning them

- `_preflight_review_agents` no longer ends its walk when every credential account has answered 429 twice in a row. A candidate set aside by `REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429` is postponed to the end of the walk, and once the first pass ends with the readiness target unmet and probe budget left, the postponed candidates are probed in catalog order until the sixteen-probe budget is spent. On 2026-09-06 five sidecar boots whose probes began between 07:24Z and 08:05Z read `probed 6 / skipped 18 / ready 0` and failed closed: `.github` run 34016207820's six probes across all three accounts were refused 429 between 07:49:35.111Z and 07:49:35.767Z, so the rule set every account aside on two same-account requests about 310 ms apart and gave up with ten of sixteen probes unspent — and because deferral needs one ready route, nothing was served either; `keyverse#143`'s 08:20Z `noema-review` repeated it in a second repository (six probes, 369 ms, all 429). The pools are not dead in those minutes: run 34016093772 was inside its own preflight during that burst, and its `llama-3.2-11b` probes on the same two NVIDIA keys answered ready at 07:50:58.7Z and 07:50:59.0Z, 84 seconds after those keys refused. Whether the unspent probes would have found a ready route inside a burst is unmeasured and is not claimed; the change is justified by ending a walk under target with the budget in hand. Of the fourteen boots that ran the merged rule, eight spend all sixteen probes in the first pass and are unchanged; one (`argos` 34014143870, a serving boot at `12 / 12 / 3`) exhausts its candidates under budget and now gains a second pass, as do the five burst boots. The cost is stated rather than assumed: a refused probe costs about 120 ms, a silent one up to the 90 s receive timeout, and the postponed tail holds both (`google/gemma-4-31b-it` answered `TimeoutError` in 15 of the 19 probes that reached it), so the worst case adds up to about 15 minutes to a boot that still fails and the two-stage auto path goes from 8 to 24 requests including the priced stage. The second pass never draws on the shared escalation budget, so the priced fallback keeps the escalations it had. The report gains `postponed_probed_count` (`skipped_count` now counts postponed candidates the budget never reached) and, on a refused probe, `retry_after_s` when the response carried a whole-seconds `Retry-After` header — evidence only, nothing waits on it, so the next census can decide whether a delayed second pass is worth proposing. ADR-0029 is amended. Refs #1948, #1949.
Expand Down
15 changes: 14 additions & 1 deletion scripts/ci/strix_quick_gate.sh
Original file line number Diff line number Diff line change
Expand Up @@ -178,11 +178,24 @@ import sys
root = Path(sys.argv[1])
known_internal_warning = re.compile(
r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d+ WARNING "
r"[^ ]+ - strix\.core\.execution: agent [0-9a-f]+ "
r"[^ ]+ - strix\.core\.execution: "
r"(?:"
r"agent [0-9a-f]+ "
r"(?:"
r"produced non-lifecycle final output in non-interactive mode"
r"|ended a turn without a lifecycle tool call \(interactive=False\)"
r"); forcing tool continuation \(\d+/\d+\): "
# strix-agent 1.5.3 strix/core/execution.py:763 logs this only inside its
# bounded transient-retry branch, immediately before the replay runs, so
# the line means "a retry is happening now", not "the scan failed". An
# exhausted retry logs `agent run failed for …; marking failed` at ERROR
# with a traceback and exits non-zero; neither of those is touched here.
# Anchored before the exception repr on purpose: the same class appears
# as InternalServerError today and as a different type after a gateway
# pin advance. Re-verify the message format on every strix-agent bump.
r"|transient model/provider error for [0-9a-f]+; replaying turn "
r"\(attempt \d+/\d+, backoff [0-9.]+s\): "
r")"
)
known_scanner_warning = re.compile(
r"^(?:│ MODEL QUALITY WARNING\s+│|"
Expand Down
284 changes: 284 additions & 0 deletions tests/test_strix_recovered_transient_sanitizer.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,284 @@
"""Regression contract for strix-agent's recovered transient model errors.

strix-agent 1.5.3 (``strix/core/execution.py:760-763``) retries a transient
model/provider error up to ``_MAX_TRANSIENT_MODEL_RETRIES`` times and, inside
that branch only, logs::

WARNING <run> - strix.core.execution: transient model/provider error for
<agent>; replaying turn (attempt n/m, backoff Ns): <exception repr>

immediately before the replay runs. The line therefore means "a retry is
happening now", never "the scan failed". When the budget is exhausted the same
module logs ``agent run failed for <agent>; marking failed`` at ERROR with a
traceback and the process exits non-zero.

Observed on ContextualWisdomLab/.github#1689 run ``34013778497``: a completed
63-minute scan (``run.json`` status ``completed``, SARIF 0 results, attempt exit
code 0) was failed closed as ``STRIX_PROVIDER_UNAVAILABLE … exhausted`` because
three such WARNING lines survived ``sanitize_known_strix_report_warnings`` and
tripped ``has_strix_report_failure_signal``'s ``WARNING`` scan.

Negative control, as measured by running this file against ``main``'s gate before
this change: **3 failed, 4 passed.** The three that fail are
``test_recovered_transient_replay_warnings_are_sanitized`` (the lines remain and
the failure signal fires), ``test_production_argument_shape_sanitizes_the_scanned_directory``
(the same, through the narrowing branch), and
``test_unrecovered_transient_keeps_the_error_and_traceback`` on its first assertion
only, since ``assertNotIn("replaying turn", ...)`` also needs the new alternative
while its ERROR-and-traceback retention assertions hold on both gates. The four
that pass on both gates are the guards: the two unknown-warning cases, the
foreign-module case, and the pre-existing forced-continuation case.
"""

from __future__ import annotations

import re
import subprocess
import tempfile
import unittest
from pathlib import Path


REPOSITORY_ROOT = Path(__file__).resolve().parents[1]
STRIX_GATE = REPOSITORY_ROOT / "scripts" / "ci" / "strix_quick_gate.sh"

_PREFIX = "strix-pr-scope-qd1fsv_9ee6 - strix.core.execution: "

# The three lines exactly as the run above wrote them (490 characters each).
_REPR = (
"InternalServerError(\"Error code: 500 - {'error': {'code': 'internal_error', "
"'message': 'internal server error', 'detail': {'request_id': '%s'}}, "
"'error_code': 'internal_error', 'error_message': 'internal server error', "
"'error_detail': {'request_id': '%s'}}\")"
)
RECOVERED_LOG = (
"2026-09-06 07:23:08.199 WARNING " + _PREFIX
+ "transient model/provider error for 76d3c83d; replaying turn "
"(attempt 1/5, backoff 2.0s): "
+ _REPR % ("466c7aee94e24a6e811cbd7fd12bc1a9", "466c7aee94e24a6e811cbd7fd12bc1a9")
+ "\n"
"2026-09-06 07:23:10.205 DEBUG strix-pr-scope-qd1fsv_9ee6 - "
"strix.llm.context_budget: No LiteLLM model info for 'openai/orchestrator/free'; "
"using configured fallbacks\n"
"2026-09-06 07:45:20.154 WARNING " + _PREFIX
+ "transient model/provider error for 76d3c83d; replaying turn "
"(attempt 2/5, backoff 4.0s): "
+ _REPR % ("6dbf7b28ee16448592e10bb9728a523f", "6dbf7b28ee16448592e10bb9728a523f")
+ "\n"
"2026-09-06 07:58:54.623 WARNING " + _PREFIX
+ "transient model/provider error for 76d3c83d; replaying turn "
"(attempt 3/5, backoff 8.0s): "
+ _REPR % ("a85b9828eb754e129f62d202359ea316", "a85b9828eb754e129f62d202359ea316")
+ "\n"
"2026-09-06 08:09:35.584 INFO strix-pr-scope-qd1fsv_9ee6 - "
"strix.core.runner: Strix scan strix-pr-scope-qd1fsv_9ee6 done\n"
)

# After the bounded budget is spent strix-agent logs at ERROR with a traceback
# (observed on a same-day run) and exits non-zero. The sanitizer must leave it.
UNRECOVERED_LOG = (
"2026-09-06 07:24:31.010 WARNING strix-pr-scope-5p3h3c_e0d0 - "
"strix.core.execution: transient model/provider error for 6c480eb0; "
"replaying turn (attempt 5/5, backoff 32.0s): InternalServerError(\"Error code: 500\")\n"
"2026-09-06 07:24:40.562 ERROR strix-pr-scope-5p3h3c_e0d0 - "
"strix.core.execution: agent run failed for 6c480eb0; marking failed\n"
"Traceback (most recent call last):\n"
' File "/opt/hostedtoolcache/Python/3.13.15/x64/lib/python3.13/site-packages/'
'strix/core/execution.py", line 676, in _run_cycle\n'
" async for event in stream.stream_events():\n"
"openai.InternalServerError: Error code: 500\n"
)

UNKNOWN_WARNING_LOG = (
"2026-09-06 07:30:00.000 WARNING strix-pr-scope-qd1fsv_9ee6 - "
"strix.core.execution: transient model/provider error for 76d3c83d; "
"giving up after 5 attempts\n"
)

# A different module echoing the same words must not be sanitized: the anchor
# is the logger name, not the phrase.
FOREIGN_MODULE_LOG = (
"2026-09-06 07:30:00.000 WARNING strix-pr-scope-qd1fsv_9ee6 - "
"strix.tools.browser: transient model/provider error for 76d3c83d; "
"replaying turn (attempt 1/5, backoff 2.0s): Timeout\n"
)

LEGACY_LOG = (
"2026-06-18 13:08:05.986 WARNING strix-pr-scope-example - strix.core.execution: "
"agent a9fb4033 produced non-lifecycle final output in non-interactive mode; "
"forcing tool continuation (1/3): {'x': 1}\n"
"2026-08-22 09:53:26.193 WARNING strix-pr-scope-example - strix.core.execution: "
"agent 673f770f ended a turn without a lifecycle tool call (interactive=False); "
"forcing tool continuation (2/3): done\n"
"2026-06-18 13:10:44.089 INFO strix-pr-scope-example - strix.tools.finish.tool: "
"finish_scan: completed scan with 0 vulnerability report(s)\n"
)


def _function_block(source: str, function_name: str) -> str:
"""Return one top-level Bash function, including its closing brace."""

match = re.search(
rf"(?ms)^{re.escape(function_name)}\(\) \{{\n.*?^\}}\n",
source,
)
if match is None:
raise AssertionError(f"missing Bash function: {function_name}")
return match.group(0)


def _sanitize_then_signal(log_text: str) -> tuple[str, bool]:
"""Run the production sanitizer, then the production failure-signal scan.

Returns the report log's remaining text and whether
``has_strix_report_failure_signal`` still fires on it. The report root is a
plain temp directory, so the function's ``STRIX_REPORTS_DIR`` branch
(which resolves the newest run) is not taken and needs no helper.
"""

gate_source = STRIX_GATE.read_text(encoding="utf-8")
blocks = [
_function_block(gate_source, name)
for name in (
"sanitize_known_strix_report_warnings",
"has_strix_report_failure_signal",
)
]
with tempfile.TemporaryDirectory(prefix="strix-recovered-transient-") as temp_dir:
report_root = Path(temp_dir) / "strix_runs" / "strix-pr-scope-qd1fsv_9ee6"
report_root.mkdir(parents=True)
log_path = report_root / "strix.log"
log_path.write_text(log_text, encoding="utf-8")
script = "\n".join(
(
"set -uo pipefail",
'STRIX_REPORTS_DIR="/nonexistent/strix-reports"',
*blocks,
'sanitize_known_strix_report_warnings "$1"',
'if has_strix_report_failure_signal "$1"; then echo signal=1; else echo signal=0; fi',
)
)
completed = subprocess.run(
["bash", "-c", script, "strix-sanitizer", str(report_root)],
check=False,
capture_output=True,
text=True,
)
remaining = log_path.read_text(encoding="utf-8")
if completed.returncode != 0:
raise AssertionError(f"rc={completed.returncode}\n{completed.stderr}")
return remaining, "signal=1" in completed.stdout


def _sanitize_then_signal_production_shape(log_text: str) -> tuple[str, bool]:
"""Same sequence with the argument shape production actually uses.

Production passes ``ACTIVE_REPORTS_DIR``, which equals ``STRIX_REPORTS_DIR``,
so ``has_strix_report_failure_signal`` takes its narrowing branch and scans
only ``latest_strix_report_dir``'s newest run directory. ``_sanitize_then_signal``
hands in that run directory directly and therefore skips the branch; this
helper covers it, so the pair proves the sanitized tree and the scanned tree
are the same one.
"""

gate_source = STRIX_GATE.read_text(encoding="utf-8")
blocks = [
_function_block(gate_source, name)
for name in (
"sanitize_known_strix_report_warnings",
"has_strix_report_failure_signal",
"latest_strix_report_dir",
"is_preexisting_report_dir",
)
]
with tempfile.TemporaryDirectory(prefix="strix-recovered-transient-prod-") as temp_dir:
reports_root = Path(temp_dir) / "reports"
run_dir = reports_root / "strix-pr-scope-qd1fsv_9ee6"
run_dir.mkdir(parents=True)
log_path = run_dir / "strix.log"
log_path.write_text(log_text, encoding="utf-8")
script = "\n".join(
(
"set -uo pipefail",
f'STRIX_REPORTS_DIR="{reports_root}"',
# Non-empty so "${PREEXISTING_REPORT_DIRS[@]}" is safe under set -u.
'PREEXISTING_REPORT_DIRS=("/nonexistent/preexisting")',
*blocks,
'sanitize_known_strix_report_warnings "$STRIX_REPORTS_DIR"',
'if has_strix_report_failure_signal "$STRIX_REPORTS_DIR"; then echo signal=1; else echo signal=0; fi',
)
)
completed = subprocess.run(
["bash", "-c", script, "strix-sanitizer-prod"],
check=False,
capture_output=True,
text=True,
)
remaining = log_path.read_text(encoding="utf-8")
if completed.returncode != 0:
raise AssertionError(f"rc={completed.returncode}\n{completed.stderr}")
return remaining, "signal=1" in completed.stdout


class StrixRecoveredTransientSanitizerTests(unittest.TestCase):
"""Keep a recovered transient model error from failing a completed scan."""

def test_recovered_transient_replay_warnings_are_sanitized(self) -> None:
"""The three observed lines are removed and the WARNING scan stays quiet."""

remaining, signal = _sanitize_then_signal(RECOVERED_LOG)
self.assertNotIn("replaying turn", remaining)
self.assertNotIn("InternalServerError", remaining)
self.assertIn("strix.core.runner: Strix scan strix-pr-scope-qd1fsv_9ee6 done", remaining)
self.assertIn("strix.llm.context_budget", remaining)
self.assertFalse(signal)

def test_unrecovered_transient_keeps_the_error_and_traceback(self) -> None:
"""Only the retry line goes; the ERROR record and its traceback stay for the rc!=0 path."""

remaining, _signal = _sanitize_then_signal(UNRECOVERED_LOG)
self.assertNotIn("replaying turn", remaining)
self.assertIn("agent run failed for 6c480eb0; marking failed", remaining)
self.assertIn("Traceback (most recent call last):", remaining)
self.assertIn("openai.InternalServerError: Error code: 500", remaining)

def test_unknown_execution_warning_still_fails_closed(self) -> None:
"""A WARNING from the same logger with a different message is not sanitized."""

remaining, signal = _sanitize_then_signal(UNKNOWN_WARNING_LOG)
self.assertEqual(remaining, UNKNOWN_WARNING_LOG)
self.assertTrue(signal)

def test_same_words_from_another_module_still_fail_closed(self) -> None:
"""The anchor is the strix.core.execution logger, not the phrase."""

remaining, signal = _sanitize_then_signal(FOREIGN_MODULE_LOG)
self.assertEqual(remaining, FOREIGN_MODULE_LOG)
self.assertTrue(signal)

def test_production_argument_shape_sanitizes_the_scanned_directory(self) -> None:
"""With the reports root passed as production passes it, the narrowed scan is quiet."""

remaining, signal = _sanitize_then_signal_production_shape(RECOVERED_LOG)
self.assertNotIn("replaying turn", remaining)
self.assertIn("strix.core.runner: Strix scan strix-pr-scope-qd1fsv_9ee6 done", remaining)
self.assertFalse(signal)

def test_production_argument_shape_still_fails_closed_on_an_unknown_warning(self) -> None:
"""The narrowing branch does not swallow a warning the sanitizer does not know."""

remaining, signal = _sanitize_then_signal_production_shape(UNKNOWN_WARNING_LOG)
self.assertEqual(remaining, UNKNOWN_WARNING_LOG)
self.assertTrue(signal)

def test_existing_forced_continuation_warnings_remain_sanitized(self) -> None:
"""The two pre-existing alternatives keep working after the regex restructure."""

remaining, signal = _sanitize_then_signal(LEGACY_LOG)
self.assertNotIn("forcing tool continuation", remaining)
self.assertIn("finish_scan: completed scan with 0 vulnerability report(s)", remaining)
self.assertFalse(signal)


if __name__ == "__main__":
unittest.main()
Loading