litellm/tests/llm_translation/test_vcr_conftest_common_banner.py
Mateo Wang 533eab4dbd
fix(tests/vcr): make Redis cassette cache replay deterministically (zero VCR misses on consecutive runs) (#28826)
* test(vcr): make Redis-backed cassettes replay deterministically across runs

- Pin LITELLM_LOCAL_MODEL_COST_MAP=True in the shared VCR harness so the
  per-test importlib.reload(litellm) no longer fetches the model cost map
  from raw.githubusercontent.com. That live fetch was being recorded into
  cassettes; for tests that subsequently skip it was the only recorded
  episode, so the persister refused to save it (skipped tests don't persist)
  and the test re-recorded it live every run (MISS:NOT_PERSISTED).

- Compare-time symmetric matcher tolerance for Google OAuth (ya29.*) tokens,
  observability/telemetry payloads, credential-exchange bodies, and volatile
  UUID/timestamp tokens, so existing cassettes select a recorded episode
  instead of growing past the 50-episode cap and re-recording live.

- Don't record fire-and-forget telemetry (langfuse/arize/otel/...) into
  non-telemetry tests' cassettes. Several modules set litellm.success_callback
  at import time, so observability logging is globally enabled and an async
  flush from the background logging worker lands in an unrelated test's VCR
  window, saved as a spurious MISS:RECORDED (observed: a Langfuse batch from
  another completion landing on test_lowest_latency_routing_buffer). Such a
  request now passes through live (telemetry hosts aren't real-spend hosts);
  tests that actually assert on telemetry keep recording it.

- Dedupe + cap the VCR diagnostic dump so the classification summary survives
  CircleCI's ~400KB step-output truncation.

- Stabilize a non-deterministic rate-limit test body; mark AWS Secrets Manager
  lifecycle tests VCR-incompatible (uniquely-named secrets can't be replayed).

- Mark test_router_text_completion_client VCR-incompatible: it fires 300
  identical requests to verify async-client reuse, but vcrpy patches the HTTP
  transport so replay never exercises the real connection pool the test
  validates, and recording 300 near-identical episodes overflows the
  50-episode cap (MISS:OVERFLOW every run). It hits a free mock endpoint.

- Mark the Vertex AI MaaS Mistral OCR tests (vertex_ai/mistral-ocr-2505)
  VCR-incompatible: the MaaS model is not provisioned in the CI GCP project,
  so the live :rawPredict call fails and the test skips every run, leaving no
  cassette to record (MISS:NOT_PERSISTED every run). Sibling direct-Mistral
  and Azure OCR tests are unaffected and still replay from cache.

* fix(tests/vcr): refresh cassette TTL on read so replayed cassettes don't expire

The Redis VCR persister loaded cassettes with a plain GET, which does not
touch the key's TTL. A cassette that is only ever replayed (HIT/NOOP, never
re-recorded) therefore expired exactly 24h after its last *write*, no matter
how often it was read. Whichever CI run happened to cross that boundary
re-recorded the cassette live and surfaced a spurious VCR MISS on otherwise
deterministic cassettes — the residual per-run flakiness floor (a different
random subset of read-only cassettes expiring each run).

Slide the expiry forward on every successful load (best-effort EXPIRE), so
any cassette used at least once per TTL window stays alive indefinitely and
the 2nd/3rd run of a day replays cleanly.

* fix(tests/vcr): recover from spurious GET-None for existing cassette keys

Under concurrent CI load, the persister's load GET was observed returning
None for a cassette key that demonstrably existed on the (single, non-
clustered) Redis master — an external monitor saw the key present with a
healthy TTL at the same instant the in-process client read None. Because
None is a valid GET result (not a RedisError), the retry-on-error client
config never engaged, so the cassette re-recorded live (a phantom
MISS:RECORDED); for flaky/networked tests the failed live call then
triggered a pytest rerun, which is why a rotating subset of otherwise
deterministic tests missed each run.

On a None result, re-check EXISTS and re-read once. If the key really
exists, use the recovered value and log [vcr-transient-miss-recovered]
(also counted in cassette_cache_health). A genuinely absent key (a new
cassette) still falls through to CassetteNotFoundError.

* chore(tests/vcr): TEMP diagnostic for persistent-miss cassette load path

Logs GET/EXISTS at load time for the three cassettes that re-record every
run despite being present in Redis, to capture what the in-process client
sees. To be reverted before merge.

* chore(tests/vcr): write load diagnostic to Redis (truncation-proof)

CI stdout truncates to the last ~400KB, dropping the early loaddbg lines
for the alphabetically-first failing test. Push the load probe to a Redis
list instead so it survives. To be reverted before merge.

* fix(tests/vcr): don't drop stored telemetry episodes during cassette load

Root cause of the residual per-run misses on present cassettes: vcrpy's
Cassette._load() replays each *stored* interaction through Cassette.append(),
which runs before_record_request on it — and a None return there silently
drops that episode. The telemetry-leak suppressor (_should_drop_telemetry_record)
returns None for telemetry requests, so when a non-telemetry-named test (or the
alphabetically-first test in a worker, whose _current_test_nodeid is still empty)
loaded a cassette containing a Langfuse ingestion episode, the episode was
dropped on read — forcing an endless live re-record (a phantom MISS:RECORDED on
a cassette that was demonstrably present in Redis). Verified by reproducing
Cassette._load() against the real cassette: empty/non-telemetry nodeid -> 0
episodes survive; with the guard -> 1 survives.

Fix: guard the suppressor with a thread-local set around Cassette._load (via a
small idempotent monkeypatch), so the drop only ever stops *new* incidental
telemetry from being recorded and never filters the existing cassette on read.

Also drops the speculative GET-None recovery + its diagnostics from the previous
commits: the load diagnostic showed GET returns the cassette bytes fine
(get=1440B), so the persister never returned a spurious None — the loss happened
later in vcrpy's append. The proven TTL-refresh-on-read fix is retained.

* fix(tests/vcr): drop incidental telemetry export POSTs to stop rotating async-flush misses

litellm's observability loggers flush on a background thread, so a Langfuse
ingestion POST scheduled by one telemetry test can fire mid-way through a
*later* telemetry-named test (after that test's own httpx mock has exited) and
be recorded by VCR as a phantom episode — a non-deterministic MISS:RECORDED /
PARTIAL that rotates onto a different telemetry test from run to run.

Telemetry export POSTs are fire-and-forget; no test asserts on a *recorded*
export response except the pass-through proxy test (which forwards a client POST
to Langfuse ingestion and replays its 207). So _should_drop_telemetry_record now
drops incidental export POSTs for every test except that one. Dropping returns
None (live fire-and-forget, never stored), so it can only turn a phantom miss
into a harmless live call, never the reverse; recorded read-back GETs that
telemetry tests assert on are matched by method and left untouched.

* fix(tests/vcr): restore assertion in test_banner_silent_when_vcr_disabled

The assertion that the banner is suppressed when VCR is disabled was
inadvertently moved into test_diagnostic_log_silent_when_no_dir when
the diagnostic-log tests were added, leaving the disabled-VCR test
verifying nothing.

Co-authored-by: Yassin Kortam <yassin@berri.ai>

---------

Co-authored-by: Cursor Agent <cursoragent@cursor.com>
Co-authored-by: Yassin Kortam <yassin@berri.ai>
2026-05-26 11:30:44 -07:00

393 lines
13 KiB
Python

from __future__ import annotations
import os
import sys
from io import StringIO
import pytest
sys.path.insert(0, os.path.abspath(os.path.join(os.path.dirname(__file__), "..", "..")))
from tests._vcr_conftest_common import ( # noqa: E402
VCR_DIAG_EMIT_MAX_LINES,
emit_cassette_cache_session_banner,
emit_vcr_diagnostic_log,
)
from tests._vcr_redis_persister import ( # noqa: E402
_cache_health,
reset_cassette_cache_health,
)
class _FakeTerminalReporter:
def __init__(self) -> None:
self.buf = StringIO()
def write_sep(self, sep, title="", **kwargs):
if title:
self.buf.write(f"{sep * 5} {title} {sep * 5}\n")
else:
self.buf.write(f"{sep * 60}\n")
def write_line(self, line):
self.buf.write(f"{line}\n")
@property
def output(self) -> str:
return self.buf.getvalue()
@pytest.fixture
def health_reset():
reset_cassette_cache_health()
yield
reset_cassette_cache_health()
@pytest.fixture
def vcr_enabled(monkeypatch):
"""Make :func:`vcr_disabled` return False so the banner emits."""
monkeypatch.setenv("CASSETTE_REDIS_URL", "redis://stub")
monkeypatch.delenv("LITELLM_VCR_DISABLE", raising=False)
monkeypatch.delenv("PYTEST_XDIST_WORKER", raising=False)
@pytest.fixture
def patch_capacity_snapshot(monkeypatch):
"""Stub :func:`cassette_cache_capacity_snapshot` so we don't try to
open a real Redis connection. The fixture returns a setter that
each test uses to inject the snapshot it wants."""
state = {"snapshot": None}
def _stub():
return state["snapshot"]
import tests._vcr_conftest_common as common
monkeypatch.setattr(common, "cassette_cache_capacity_snapshot", _stub)
def _set(snapshot):
state["snapshot"] = snapshot
return _set
def test_banner_silent_when_no_failures_and_capacity_healthy(
health_reset, vcr_enabled, patch_capacity_snapshot
):
patch_capacity_snapshot(
{"used_memory_bytes": 100, "maxmemory_bytes": 1000, "used_pct": 10.0}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
assert reporter.output == ""
def test_banner_red_section_when_save_failures_recorded(
health_reset, vcr_enabled, patch_capacity_snapshot
):
_cache_health["save_failures"] = 3
_cache_health["save_failure_last_error"] = (
"OutOfMemoryError: command not allowed when used memory > 'maxmemory'."
)
patch_capacity_snapshot(
{"used_memory_bytes": 990, "maxmemory_bytes": 1000, "used_pct": 99.0}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
out = reporter.output
assert "VCR CASSETTE CACHE DEGRADED" in out
assert "3 cassette save failure(s)" in out
assert "OutOfMemoryError" in out
assert "99.0% of maxmemory" in out
def test_banner_red_section_when_load_failures_recorded(
health_reset, vcr_enabled, patch_capacity_snapshot
):
_cache_health["load_failures"] = 2
_cache_health["load_failure_last_error"] = "ConnectionError: simulated outage"
patch_capacity_snapshot(None)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
out = reporter.output
assert "VCR CASSETTE CACHE DEGRADED" in out
assert "2 cassette load failure(s)" in out
assert "ConnectionError" in out
def test_banner_yellow_high_water_when_no_failures_but_near_capacity(
health_reset, vcr_enabled, patch_capacity_snapshot
):
patch_capacity_snapshot(
{"used_memory_bytes": 900, "maxmemory_bytes": 1000, "used_pct": 90.0}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
out = reporter.output
assert "VCR CASSETTE CACHE NEAR CAPACITY" in out
assert "90.0% of maxmemory" in out
assert "VCR CASSETTE CACHE DEGRADED" not in out
def test_banner_silent_when_below_high_water_and_no_failures(
health_reset, vcr_enabled, patch_capacity_snapshot
):
patch_capacity_snapshot(
{"used_memory_bytes": 800, "maxmemory_bytes": 1000, "used_pct": 80.0}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
assert reporter.output == ""
def test_banner_silent_when_vcr_disabled(
monkeypatch, health_reset, patch_capacity_snapshot
):
monkeypatch.delenv("CASSETTE_REDIS_URL", raising=False)
_cache_health["save_failures"] = 5
_cache_health["save_failure_last_error"] = "OutOfMemoryError: foo"
patch_capacity_snapshot(
{"used_memory_bytes": 999, "maxmemory_bytes": 1000, "used_pct": 99.9}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
assert reporter.output == ""
# ---------------------------------------------------------------------------
# Diagnostic-log dedup + cap. CircleCI truncates step output to the last
# ~400 KB; an unbounded diagnostic dump pushes the VCR classification summary
# out of the retrievable window, so the dump must dedupe and cap.
# ---------------------------------------------------------------------------
def test_diagnostic_log_dedupes_repeated_blocks(tmp_path, monkeypatch):
monkeypatch.setenv("LITELLM_VCR_DIAG_DIR", str(tmp_path))
(tmp_path / "123.log").write_text(
"\n".join(["[vcr-key-fingerprint-matcher] differ"] * 40 + ["unique line"]),
encoding="utf-8",
)
reporter = _FakeTerminalReporter()
emit_vcr_diagnostic_log(reporter)
out = reporter.output
# The repeated block collapses to a single line with an occurrence count.
assert out.count("[vcr-key-fingerprint-matcher] differ") == 1
assert "(x40)" in out
assert "unique line" in out
def test_diagnostic_log_caps_unique_lines(tmp_path, monkeypatch):
monkeypatch.setenv("LITELLM_VCR_DIAG_DIR", str(tmp_path))
total = VCR_DIAG_EMIT_MAX_LINES + 50
(tmp_path / "123.log").write_text(
"\n".join(f"unique-diagnostic-{i}" for i in range(total)), encoding="utf-8"
)
reporter = _FakeTerminalReporter()
emit_vcr_diagnostic_log(reporter)
out = reporter.output
emitted = sum(1 for ln in out.splitlines() if ln.startswith("unique-diagnostic-"))
assert emitted == VCR_DIAG_EMIT_MAX_LINES
assert "more unique diagnostic line(s) suppressed" in out
def test_diagnostic_log_silent_when_no_dir(tmp_path, monkeypatch):
monkeypatch.setenv("LITELLM_VCR_DIAG_DIR", str(tmp_path / "does-not-exist"))
reporter = _FakeTerminalReporter()
emit_vcr_diagnostic_log(reporter)
assert reporter.output == ""
def test_banner_silent_on_xdist_worker(
monkeypatch, vcr_enabled, health_reset, patch_capacity_snapshot
):
monkeypatch.setenv("PYTEST_XDIST_WORKER", "gw3")
_cache_health["save_failures"] = 1
_cache_health["save_failure_last_error"] = "OutOfMemoryError: bar"
patch_capacity_snapshot(
{"used_memory_bytes": 999, "maxmemory_bytes": 1000, "used_pct": 99.9}
)
reporter = _FakeTerminalReporter()
emit_cassette_cache_session_banner(reporter)
assert reporter.output == ""
# ---------------------------------------------------------------------------
# Telemetry-leak suppression. Several modules set ``litellm.success_callback``
# at import time, so observability logging is globally enabled and an async
# flush can land in an unrelated test's VCR window and be saved as a spurious
# MISS:RECORDED episode. ``_should_drop_telemetry_record`` refuses to record a
# telemetry call for a non-telemetry test (it passes through live instead),
# while tests that actually assert on telemetry keep recording.
# ---------------------------------------------------------------------------
class _FakeRequest:
def __init__(
self, host, scheme="https", method="POST", path="/api/public/ingestion"
):
self.host = host
self.scheme = scheme
self.uri = f"{scheme}://{host}{path}"
self.headers = {}
self.method = method
self.body = b"{}"
@pytest.fixture
def current_test(monkeypatch):
"""Set the module-global current-test nodeid the suppressor reads."""
import tests._vcr_conftest_common as common
def _set(nodeid):
monkeypatch.setattr(common, "_current_test_nodeid", nodeid)
return _set
@pytest.mark.parametrize(
"nodeid,host,method,expected_drop",
[
# Non-telemetry test: incidental telemetry leak is dropped (not recorded).
(
"tests/local_testing/test_lowest_latency_routing.py::test_lowest_latency_routing_buffer[1]",
"us.cloud.langfuse.com",
"POST",
True,
),
(
"tests/local_testing/test_function_call_parsing.py::test_parse",
"us.cloud.langfuse.com",
"POST",
True,
),
(
"tests/llm_translation/test_x.py::test_y",
"otlp.arize.com",
"POST",
True,
),
# Non-telemetry host on a non-telemetry test: never dropped.
(
"tests/local_testing/test_lowest_latency_routing.py::test_lowest_latency_routing_buffer[1]",
"api.openai.com",
"POST",
False,
),
# Telemetry EXPORT POSTs are fire-and-forget and dropped even for
# telemetry-named tests: litellm's background flush makes them rotate
# into a later telemetry test's window as a phantom MISS:RECORDED. The
# e2e suite mocks the export client and asserts on the mock; read-back
# tests assert on a GET — neither needs the recorded export POST.
(
"tests/local_testing/test_alangfuse.py::test_langfuse_logging",
"us.cloud.langfuse.com",
"POST",
True,
),
(
"tests/logging_callback_tests/test_langfuse_e2e_test.py::test_e2e",
"us.cloud.langfuse.com",
"POST",
True,
),
(
"tests/logging_callback_tests/test_dynamic_otel_keys.py::test_keys",
"otlp.arize.com",
"POST",
True,
),
# Read-back GETs that telemetry tests assert on are kept (matched by
# method, so the export-POST drop does not touch them).
(
"tests/local_testing/test_alangfuse.py::test_langfuse_logging",
"us.cloud.langfuse.com",
"GET",
False,
),
# ...but a read-back GET on a NON-telemetry test is still incidental.
(
"tests/local_testing/test_function_call_parsing.py::test_parse",
"us.cloud.langfuse.com",
"GET",
True,
),
# The pass-through proxy test forwards a client POST to Langfuse
# ingestion and asserts the replayed 207 — its export POST is kept.
(
"tests/local_testing/test_pass_through_endpoints.py::test_aaapass_through_endpoint_pass_through_keys_langfuse[False-0-207]",
"us.cloud.langfuse.com",
"POST",
False,
),
],
)
def test_should_drop_telemetry_record(
current_test, nodeid, host, method, expected_drop
):
import tests._vcr_conftest_common as common
current_test(nodeid)
req = _FakeRequest(host, method=method)
assert common._should_drop_telemetry_record(req) is expected_drop
def test_drop_is_suppressed_while_loading_stored_episodes(current_test):
"""During ``Cassette._load`` the drop MUST be inert.
vcrpy replays each stored interaction through ``Cassette.append`` →
``before_record_request``; a ``None`` there silently drops the stored
episode. If the telemetry drop fired on load, an already-recorded
telemetry episode would be deleted the instant a non-telemetry-named
test loaded it, forcing an endless live re-record (a phantom
MISS:RECORDED on a cassette that was present in Redis). The drop must
only stop *new* incidental recordings, never filter the cassette on read.
"""
import tests._vcr_conftest_common as common
# A non-telemetry test loading a stored Langfuse episode: dropped on
# record, but must be KEPT while loading.
current_test("tests/local_testing/test_lowest_latency_routing.py::test_buf")
req = _FakeRequest("us.cloud.langfuse.com")
assert common._should_drop_telemetry_record(req) is True # record path
common._vcr_load_guard.active = True
try:
assert common._vcr_load_in_progress() is True
assert common._should_drop_telemetry_record(req) is False # load path
finally:
common._vcr_load_guard.active = False
assert common._should_drop_telemetry_record(req) is True
def test_load_guard_patch_is_idempotent():
import vcr.cassette as cassette_mod
import tests._vcr_conftest_common as common
common.patch_vcrpy_cassette_load_guard()
first = cassette_mod.Cassette._load
common.patch_vcrpy_cassette_load_guard()
assert cassette_mod.Cassette._load is first
assert getattr(cassette_mod.Cassette._load, "_litellm_load_guarded", False)