From 39cd255485d3cbff67be8f55d3b5ca9d5e486022 Mon Sep 17 00:00:00 2001 From: David SF <64162682+dsfaccini@users.noreply.github.com> Date: Fri, 17 Jul 2026 12:50:09 -0500 Subject: [PATCH] fix(cache_stability): latch collapse state so a sustained collapse warns once The re-baseline fix warned once only when the collapsed prefix stayed at the collapsed read value. Macroscope found the hole: a provider that keeps writing an unread cache (read stays low, write stays high) re-baselines to read+write, holds the mark high, and re-warns every step; re-baselining to read alone still lets the intervening max() re-grow the mark and warns every other step. Track a per-key `collapsed` latch instead: warn only on the transition into a collapse, keep the prefix as a plain high-water mark, and re-arm when a healthy read-back clears the latch. A sustained collapse -- caching off, or a prefix that moves every request -- warns exactly once; a genuine second collapse after the cache re-stabilizes warns again. Drop the "may be added as the capability matures" hedge from the Logfire docs. --- docs/cache-stability.md | 6 +-- pydantic_ai_harness/cache_stability/README.md | 23 +++++----- .../cache_stability/_capability.py | 37 ++++++++------- tests/cache_stability/test_cache_stability.py | 45 +++++++++++++++++-- 4 files changed, 79 insertions(+), 32 deletions(-) diff --git a/docs/cache-stability.md b/docs/cache-stability.md index b57335c..db2b475 100644 --- a/docs/cache-stability.md +++ b/docs/cache-stability.md @@ -20,9 +20,9 @@ Cache Stability Monitor is a released, non-experimental capability. Pydantic AI Prompt caching pays off only while the cacheable prefix (tools, then system instructions, then message history) stays byte-stable across a run's consecutive requests. When something moves that prefix -- reordered tools, a timestamp injected into instructions, a serialization-level block hop -- the provider re-charges tokens it could have served from cache. -This is the **observe** signal: it reads the provider's own verdict rather than guessing from the structured request. On each response it reads `usage.cache_read_tokens` and tracks the cacheable prefix the run has established (`cache_read_tokens + cache_write_tokens`), keyed by the response's `(provider_name, model_name)`. Because message history is append-only, a stable prefix means each request for that model reads back at least what the previous one cached; a large drop is the observable signature of a collapse. +This is the **observe** signal: it reads the provider's own verdict rather than guessing from the structured request. On each response it reads `usage.cache_read_tokens` and tracks the largest cacheable prefix the run has established (`cache_read_tokens + cache_write_tokens`, a high-water mark), keyed by the response's `(provider_name, model_name)`. Because message history is append-only, a stable prefix means each request for that model reads back at least what the previous one cached; a large drop is the observable signature of a collapse. -When a request reads back less than `collapse_ratio` of the established prefix, the monitor emits a `CacheBustWarning` and re-baselines the tracked prefix to the collapsed value. A sustained collapse -- for example caching toggled off mid-run, which reports `read == 0, write == 0` on every remaining step -- therefore warns once, not on every request. +When a request reads back less than `collapse_ratio` of the established prefix, the monitor emits a `CacheBustWarning` once and latches that key, staying quiet about the collapse until a healthy read-back re-stabilizes the cache. A sustained collapse -- caching toggled off mid-run (`read == 0, write == 0`), or a prefix that moves every request so the provider keeps writing a cache nothing reads back -- therefore warns once, not on every request. ```python from pydantic_ai import Agent @@ -78,7 +78,7 @@ import logging logging.captureWarnings(True) # warnings.warn(...) -> the 'py.warnings' logger -> Logfire ``` -For now the monitor emits a warning only; a dedicated Logfire event may be added as the capability matures. +The monitor's signal is the `CacheBustWarning`; routing it through `logging` is how it reaches Logfire. ## Composition diff --git a/pydantic_ai_harness/cache_stability/README.md b/pydantic_ai_harness/cache_stability/README.md index a1641b6..5999d3e 100644 --- a/pydantic_ai_harness/cache_stability/README.md +++ b/pydantic_ai_harness/cache_stability/README.md @@ -13,16 +13,19 @@ that collapse visible. This is the **observe** signal: it reads the provider's own verdict rather than guessing from the structured request. On each response it reads -`usage.cache_read_tokens` and tracks the cacheable prefix the run has established -(`cache_read_tokens + cache_write_tokens`), keyed by the response's -`(provider_name, model_name)`. Because message history is append-only, a stable -prefix means each request for that model reads back at least what the previous one -cached; a large drop is the observable signature of a collapse. +`usage.cache_read_tokens` and tracks the largest cacheable prefix the run has +established (`cache_read_tokens + cache_write_tokens`, a high-water mark), keyed by +the response's `(provider_name, model_name)`. Because message history is +append-only, a stable prefix means each request for that model reads back at least +what the previous one cached; a large drop is the observable signature of a +collapse. When a request reads back less than `collapse_ratio` of the established prefix, the -monitor warns and re-baselines the tracked prefix to the collapsed value. A sustained -collapse -- for example caching toggled off mid-run, which reports `read == 0, -write == 0` on every remaining step -- therefore warns once, not on every request. +monitor warns once and latches that key, staying quiet about the collapse until a +healthy read-back re-stabilizes the cache. A sustained collapse -- caching toggled +off mid-run (`read == 0, write == 0`), or a prefix that moves every request so the +provider keeps writing a cache nothing reads back -- therefore warns once, not on +every request. Keying per provider and model means a mid-run model switch does not warn: a `FallbackModel` failover or a per-step model change uses a different cache key, so @@ -120,8 +123,8 @@ import logging logging.captureWarnings(True) # warnings.warn(...) -> the 'py.warnings' logger -> Logfire ``` -For now the monitor emits a warning only; a dedicated Logfire event may be added -as the capability matures. +The monitor's signal is the `CacheBustWarning`; routing it through `logging` is how +it reaches Logfire. ## Composition diff --git a/pydantic_ai_harness/cache_stability/_capability.py b/pydantic_ai_harness/cache_stability/_capability.py index 7f10d8b..bbb24ba 100644 --- a/pydantic_ai_harness/cache_stability/_capability.py +++ b/pydantic_ai_harness/cache_stability/_capability.py @@ -42,10 +42,16 @@ _SILENCE_HINT = ( @dataclass class _KeyState: - """Per-(provider, model) cache observation: the established prefix and when it was last seen.""" + """Per-(provider, model) cache observation. + + `prefix` is the high-water mark of the established cacheable prefix, `seen_at` is when this + key was last observed, and `collapsed` latches whether the last observation was already a + collapse -- so a sustained collapse warns once and re-arms only after the cache re-stabilizes. + """ prefix: int seen_at: float + collapsed: bool = False @dataclass @@ -93,12 +99,12 @@ class CacheStabilityMonitor(AbstractCapability[AgentDepsT]): """Warn when a run's prompt cache hit collapses between requests. Attach it to any agent whose model uses prompt caching. On each response the monitor - reads `usage.cache_read_tokens` and tracks the cacheable prefix the run has established - (`cache_read_tokens + cache_write_tokens`), keyed by the response's - `(provider_name, model_name)`. When a later request for the same key reads back fewer than - `collapse_ratio` of that established prefix, it emits a `CacheBustWarning` and re-baselines - the tracked prefix to the collapsed value, so a sustained collapse warns once rather than on - every subsequent request. + reads `usage.cache_read_tokens` and tracks the largest cacheable prefix the run has + established (`cache_read_tokens + cache_write_tokens`, a high-water mark), keyed by the + response's `(provider_name, model_name)`. When a later request for the same key reads back + fewer than `collapse_ratio` of that established prefix, it emits a `CacheBustWarning` once + and then stays quiet about that collapse until a healthy read-back re-stabilizes the cache, + so a sustained collapse warns once rather than on every subsequent request. Keying per provider and model means a mid-run model switch does not warn: a `FallbackModel` failover or a per-step model change uses a different cache key, so it starts a fresh mark @@ -183,11 +189,14 @@ class CacheStabilityMonitor(AbstractCapability[AgentDepsT]): now = _now() entry = state.keys.get(key) if entry is None: - established, prev_seen = 0, now + established, prev_seen, collapsed = 0, now, False else: - established, prev_seen = entry.prefix, entry.seen_at - new_prefix = read + usage.cache_write_tokens - if established >= self.min_prefix_tokens and read < established * self.collapse_ratio: + established, prev_seen, collapsed = entry.prefix, entry.seen_at, entry.collapsed + is_collapse = established >= self.min_prefix_tokens and read < established * self.collapse_ratio + # Warn on the transition into a collapse only; the latch keeps a sustained collapse -- and a + # provider that keeps writing an unread cache (read stays low, write stays high) -- to one + # warning, and re-arms once a healthy read-back clears it. + if is_collapse and not collapsed: wasted = established - read gap = now - prev_seen if gap > self.cache_ttl_seconds: @@ -205,9 +214,5 @@ class CacheStabilityMonitor(AbstractCapability[AgentDepsT]): CacheBustWarning, stacklevel=2, ) - # Re-baseline to the collapsed prefix so a sustained collapse warns once, not per step. - prefix = new_prefix - else: - prefix = max(established, new_prefix) - state.keys[key] = _KeyState(prefix, now) + state.keys[key] = _KeyState(max(established, read + usage.cache_write_tokens), now, is_collapse) return response diff --git a/tests/cache_stability/test_cache_stability.py b/tests/cache_stability/test_cache_stability.py index 721471a..f5be8b5 100644 --- a/tests/cache_stability/test_cache_stability.py +++ b/tests/cache_stability/test_cache_stability.py @@ -244,9 +244,9 @@ async def test_expiry_gap_measured_per_key_after_switch_away_and_back(monkeypatc async def test_caching_off_mid_run_warns_once_not_per_step() -> None: """A `0/0` response after an established prefix warns once, not on every remaining request. - Caching toggled off mid-run reports read==0, write==0. Against a high-water mark that only - grew, that tripped the collapse check on every subsequent step. Re-baselining the mark to the - collapsed prefix surfaces the collapse once and then stays quiet. + Caching toggled off mid-run reports read==0, write==0. Against a mark that only grew, that + tripped the collapse check on every subsequent step. The collapse latch surfaces it once and + then stays quiet until a healthy read-back re-arms it. """ usages = [_usage(read=0, write=8000), _usage(read=0, write=0), _usage(read=0, write=0)] agent = _agent(usages, CacheStabilityMonitor()) @@ -257,6 +257,45 @@ async def test_caching_off_mid_run_warns_once_not_per_step() -> None: assert 'request 2' in str(busts[0].message) +async def test_sustained_collapse_with_cache_writes_warns_once() -> None: + """A run that keeps writing an unread cache (read stays low, write stays high) warns once. + + Each step reports read==0, write==2000: the prefix moves every request, so the provider + re-writes a cache nothing reads back. Re-baselining the mark to `read + write` would hold it + at 2000 and re-warn; re-baselining to `read` would still let the intervening `max()` re-grow + it and warn every other step. The collapse latch is what holds it to a single warning. + """ + usages = [ + _usage(read=0, write=8000), + _usage(read=0, write=2000), + _usage(read=0, write=2000), + _usage(read=0, write=2000), + ] + agent = _agent(usages, CacheStabilityMonitor()) + with pytest.warns(CacheBustWarning) as record: + await agent.run('hi') + busts = [w for w in record if issubclass(w.category, CacheBustWarning)] + assert len(busts) == 1 + assert 'request 2' in str(busts[0].message) + + +async def test_recollapse_after_restabilize_warns_again() -> None: + """The latch re-arms: a healthy read-back between two collapses lets the second one warn.""" + usages = [ + _usage(read=0, write=8000), # establish 8000 + _usage(read=100), # collapse -> warn (request 2) + _usage(read=8000, write=200), # healthy read-back re-stabilizes, clearing the latch + _usage(read=100), # collapse again -> warn (request 4) + ] + agent = _agent(usages, CacheStabilityMonitor()) + with pytest.warns(CacheBustWarning) as record: + await agent.run('hi') + busts = [str(w.message) for w in record if issubclass(w.category, CacheBustWarning)] + assert len(busts) == 2 + assert 'request 2' in busts[0] + assert 'request 4' in busts[1] + + def test_invalid_config_rejected() -> None: """Out-of-range thresholds fail fast at construction rather than distorting detection.""" with pytest.raises(ValueError, match='collapse_ratio'):