diff --git a/CHANGELOG.md b/CHANGELOG.md index ced79548..ddd596f3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -8,6 +8,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] ### Added +- The dependency evidence in `docs/reading-the-log.md` is now stated per parent declaration (`#[Cacheable]` / `#[CacheableResponse]` / `#[DonutCache]`), pinned by `DonutDependencyEvidenceTest` (#188). - `UriScopedHttpCacheInterface::isNotModifiedFor($uri, $server)` and `ScopedValidatorInterface::hasEtagFor($etag, $uri)`: the conditional-request answer, scoped to the resource that was asked for (#197). `HttpCacheInterface::isNotModified()` receives the request environment and nothing else, so it can only ask whether the offered validator is alive somewhere in the pool - a client or intermediary returning a validator it holds for another URI was answered 304 about content this server never sent it. An application opts in by routing before the check; routing costs a path match, not a resource run. The ETag entry now stores the URI tag it was issued for, where it used to store the constant `etag`: entries written by an older version cannot be scoped, so each client pays one full response after the upgrade, once. The unscoped method is unchanged. - `durationMs` on the `cache_hit` / `cache_miss` **close**: what the answer cost. A hit close measures serving from the pool, a miss close measures the resource run and the write it triggered, so the pair is what says whether the cache is worth having - the sign, not the difference, since a miss includes the fill. A bare event (`layer: donut`) carries null: no scope, nothing to measure. Every other question the log answers is about correctness; this is the first one about cost. - Cache observability is now built on [Koriym.SemanticLogger](https://github.com/koriym/Koriym.SemanticLogger): an open/event/close tree whose nesting **is** the embed/dependency structure (a parent's embedded children nest under it). Typed `AbstractContext` subclasses live in `src/Log/Context/` with per-context JSON Schemas in `docs/schemas/context/`. diff --git a/docs/llms-full.txt b/docs/llms-full.txt index b70ebb20..590f2c52 100644 --- a/docs/llms-full.txt +++ b/docs/llms-full.txt @@ -186,7 +186,7 @@ Cache operations are logged as an open/event/close tree (Koriym.SemanticLogger) | `get` | open | A resource/donut GET scope; embedded child GETs nest under it | | `cache_hit` / `cache_miss` (`layer`) | close/event | Lookup outcome (`layer`: `resource` / `donut` / `donut-view` / `etag`) | | `command` (`method`/`annotations`/`source`) | open | A write scope; `source` names the producing interceptor, `annotations` its `#[Refresh]`/`#[Purge]` attributes (empty on the CacheableResponse path by design) | -| `depends_on` (`parent`/`child`/`childTags`) | event | Parent registered a dependency on a child's tags | +| `depends_on` (`parent`/`child`/`childTags`) | event | Parent registered a dependency on a child's tags. Written by `QueryRepository::put()` only, so a `#[Cacheable]` parent records it (its child tags land on `save_value`/`save_view` and `save_etag`) and a donut parent never does: a `#[CacheableResponse]` parent's child tags show up on `save_etag`/`save_donut_view` (never on `save_donut`), a `#[DonutCache]` parent's only in `cdn_headers.surrogateKeys` | | `save_value` / `save_view` / `save_etag` / `save_donut` / `save_donut_view` | event | What was stored, with `tags`, `requestedTtl` (seconds until expiry; 0/null = no expiry set), and the `saved` outcome | | `pre_write_cleanup` (`uri`) | event | Marker recorded by a writer right before it clears the entry it is about to rewrite; the `invalidate` immediately following it in the same scope is pre-write cleanup, not a real invalidation | | `invalidate` (`tags`/`roPool`/`etagPool`/`cdn`/`durationMs`) | event | Tag invalidation outcome; `cdn` is tri-state: `purged` (a configured purger ran), `failed` (the purge threw — fail-closed, after the local pools were invalidated), `skipped` (NullPurger, no CDN configured). Pre-write cleanup vs real invalidation is recorded at the source via the `pre_write_cleanup` marker — see below | @@ -214,7 +214,7 @@ A donut refresh is not marked in any response header — only in the log (`refre ### Verifying the event-driven cache from logs -- Event-driven entries appear with their configured TTL in seconds (`requestedTtl` = seconds until expiry; the `never` convention = 31536000 = 1 year, effectively indefinite). `0`/`null` also mean no expiry is set. Such entries live until an `invalidate` event with a matching tag — correlate `save_*` `tags` with `invalidate` `tags` to confirm a write busted its dependents. +- Event-driven entries appear with their configured TTL in seconds (`requestedTtl` = seconds until expiry; the `never` convention = 31536000 = 1 year, effectively indefinite). `0`/`null` also mean no expiry is set. Such entries live until an `invalidate` event with a matching tag — correlate `save_*` `tags` with `invalidate` `tags` to confirm a write busted its dependents. Which `save_*` carries a child's tags is decided by the parent's declaration: `#[Cacheable]` puts them on `save_value`/`save_view` and `save_etag`, records a `depends_on` edge as well, and the parent closes `cache_miss` once the child is purged; `#[CacheableResponse]` records no `depends_on`, tags `save_etag`/`save_donut_view` but never `save_donut` (the shell has to outlive the child), and after a child purge still closes `cache_hit{layer: donut-view}` with a `refresh_donut` inside — a hit with no `refresh_donut` is the stale shape; `#[DonutCache]` stores no child tag at all (they reach only `cdn_headers.surrogateKeys`) and every read after the first is `refresh_donut` + `put_skipped{not-cacheable}`. - A `get` scope with no events and a `cache_hit` close was served from cache; nesting mirrors the embed structure of resources; `manual_*` scopes mark non-AOP entry points — a direct `put()`, `purge()`, `invalidateTags()` or donut write (`putStatic()`/`putDonut()`), the whole write rooted in one `manual_store` scope. - A miss scope without `save_*` events means no put happened — look for a `put_skipped` event recording why (`reason`: `etag-present`, `error-code` with the actual response `code`, or `not-cacheable` for donut pages served from their template plus inner caches). A non-200 GET yields `put_skipped{error-code, code}` + `purge` + `invalidate` (for commands, a 4xx `command_result` with no invalidation events). - An `invalidate` is pre-write cleanup iff the event immediately preceding it in the same scope's event stream is a `pre_write_cleanup` marker — the writer records the purpose at the source (`QueryRepository::doPut()` and `DonutRepository::putStatic()`/`putDonut()` emit the marker right before clearing the entry they are about to rewrite), so nothing is inferred from tag correlation and no case is undecidable. Any `invalidate` without the marker is a real invalidation (a `#[Refresh]` command shows both shapes: the purge's invalidate has no marker, the re-put's deleteEtag is marker-preceded). The cleanup uses the resource's own URI tag — which is also its parents' surrogate key — so a child refill visibly purges the parent entry, by design. diff --git a/docs/llms.txt b/docs/llms.txt index 5af048e6..3b2c1698 100644 --- a/docs/llms.txt +++ b/docs/llms.txt @@ -45,7 +45,7 @@ Cache operations are logged as an open/event/close tree (Koriym.SemanticLogger) Verifying the event-driven cache from logs: -- Event-driven entries appear with their configured TTL in seconds (`requestedTtl` = seconds until expiry; the `never` convention = 31536000 = 1 year, effectively indefinite). `0`/`null` also mean no expiry is set. Such entries live until an `invalidate` event with a matching tag — correlate `save_*` `tags` with `invalidate` `tags` to confirm a write busted its dependents. +- Event-driven entries appear with their configured TTL in seconds (`requestedTtl` = seconds until expiry; the `never` convention = 31536000 = 1 year, effectively indefinite). `0`/`null` also mean no expiry is set. Such entries live until an `invalidate` event with a matching tag — correlate `save_*` `tags` with `invalidate` `tags` to confirm a write busted its dependents. Which `save_*` carries a child's tags is decided by the parent's declaration: `#[Cacheable]` puts them on `save_value`/`save_view` and `save_etag`, records a `depends_on` edge as well, and the parent closes `cache_miss` once the child is purged; `#[CacheableResponse]` records no `depends_on`, tags `save_etag`/`save_donut_view` but never `save_donut` (the shell has to outlive the child), and after a child purge still closes `cache_hit{layer: donut-view}` with a `refresh_donut` inside — a hit with no `refresh_donut` is the stale shape; `#[DonutCache]` stores no child tag at all (they reach only `cdn_headers.surrogateKeys`) and every read after the first is `refresh_donut` + `put_skipped{not-cacheable}`. - `cdn_headers` records the CDN-facing response headers verbatim at every donut write/refresh (`headers`: literal name => value, e.g. `CDN-Cache-Control`/`Surrogate-Control`/`Akamai-Cache-Control` and `Surrogate-Key`/`Edge-Cache-Tag`; `surrogateKeys`: the split purge-key list). The bound setter's default appears here even when `put_donut` says `sMaxAge: null`; no lifetime header in the map = the response gave the CDN no lifetime directive (the `putDonut` kind); the CDN's own behavior is outside this log. Correlate `invalidate` `tags` with `surrogateKeys` to confirm a purge reached the responses the CDN holds. - A `conditional_request` scope closing `cache_hit{layer: etag}` is the 304 decision: the whole request answered from the ETag pool without running the resource (`cache_miss{layer: etag}` = the validator is stale, a full response follows). - A `get` scope with no events and a `cache_hit` close was served from cache; nesting mirrors the embed structure of resources; `manual_*` scopes mark non-AOP entry points — a direct `put()`, `purge()`, `invalidateTags()` or donut write (`putStatic()`/`putDonut()`), the whole write rooted in one `manual_store` scope. diff --git a/docs/reading-the-log.ja.md b/docs/reading-the-log.ja.md index 92174cd8..2790537f 100644 --- a/docs/reading-the-log.ja.md +++ b/docs/reading-the-log.ja.md @@ -95,7 +95,7 @@ get page://self/html/blog-posting ← スコープ: open されて clos | `put_donut` | `uri`, `requestedTtl`, `sMaxAge` | donut の書き込みを要求した。要求時の lifetime つき | | `refresh_donut` | `uri` | キャッシュ済み donut をそのまま返さず再合成した | | `cdn_headers` | `uri`, `headers`, `surrogateKeys` | 応答に実際に付いた CDN 向けヘッダ | -| `depends_on` | `parent`, `child`, `childTags` | 依存の辺 1 本。子のタグが親に加わった | +| `depends_on` | `parent`, `child`, `childTags` | 依存の辺 1 本。子のタグが親に加わった。記録するのは `#[Cacheable]` の put だけ | | `pre_write_cleanup` | `uri` | 書き込み側が、上書きするエントリを消す直前 | | `invalidate` | `tags`, `roPool`, `etagPool`, `cdn`, `durationMs` | タグを無効化した。対象ごとの結果つき | | `purge` | `uri` | URI 指定の破棄を要求した | @@ -179,6 +179,17 @@ get page://self/html/blog-posting ← スコープ: open されて clos 突き合わせます。交差しないタグは、その書き込みがそのエントリを残したことを意味します — これが 内側から見た「stale を配信している」状態です。 +**子のタグがどのエントリに載るかは、親の宣言で決まります。** `#[Cacheable]` の親は `depends_on` の辺を +記録し、子のタグを自分の `save_value`/`save_view` と `save_etag` に載せます。だから子を purge すると +親のエントリも一緒に消え、次の read は `cache_miss` で閉じます。`#[CacheableResponse]` の親は +`depends_on` を出しません — donut の書き込みは `put()` を通らないからです。子のタグは `save_etag` と +`save_donut_view` に載り、`save_donut` には載りません。殻は子より長く生きて再合成の土台になるからです。 +子を purge した後もこの親は `cache_hit{layer: donut-view}` で閉じ、中に `refresh_donut` と新しい +`save_etag`/`save_donut_view` があります。この hit が健全な形で、stale は `refresh_donut` の無い +`cache_hit` です。`#[DonutCache]` の親は子のタグをどこにも保存しません — `cdn_headers.surrogateKeys` +まで届いて、そこで終わりです。2 回目からの read は毎回、`refresh_donut` のあとに +`put_skipped{reason: not-cacheable}` が続きます。子を purge して変わるのは、入れ子の `get` だけです。 + **エントリが期限切れになる設計かどうかは、TTL ではなく `cache_policy.expiry` を読みます。** `expiry: "never"` は「無効化が届くまで」という意図です。解決した数値は保険であり、アプリが `Expiry` を どう束縛したかで変わります — 既定のインストールでは `never` が 31536000 秒になり、意図的な 1 年 TTL と @@ -226,6 +237,8 @@ ETag プールだけでリクエスト全体に答えています。304 が現 **donut の `cache_hit` に出るのは最終層です。** ページがキャッシュから来たのか、出力の途中で 再合成されたのかはスコープの中にあります — `refresh_donut` イベントがあれば再合成です。 +子を purge した後の `#[CacheableResponse]` の親がまさにこの形です。残っていたテンプレートが read を +hit にし、中身を新しくするのは再合成のほうです。 ## 実例 diff --git a/docs/reading-the-log.md b/docs/reading-the-log.md index 16ad4f0e..9f68e924 100644 --- a/docs/reading-the-log.md +++ b/docs/reading-the-log.md @@ -97,7 +97,7 @@ operation inside a GET or a command is an ordinary event there instead. | `put_donut` | `uri`, `requestedTtl`, `sMaxAge` | a donut write was requested, with the lifetime asked for | | `refresh_donut` | `uri` | a cached donut was recomposed rather than served as-is | | `cdn_headers` | `uri`, `headers`, `surrogateKeys` | the CDN-facing headers the response actually carried | -| `depends_on` | `parent`, `child`, `childTags` | one dependency edge: the child's tags were added to the parent | +| `depends_on` | `parent`, `child`, `childTags` | one dependency edge: the child's tags were added to the parent. Only a `#[Cacheable]` put records one | | `pre_write_cleanup` | `uri` | the writer is about to clear the entry it will rewrite | | `invalidate` | `tags`, `roPool`, `etagPool`, `cdn`, `durationMs` | tags were invalidated, with a result per target | | `purge` | `uri` | a URI-targeted bust was requested | @@ -185,6 +185,19 @@ correlation. Any `invalidate` without the marker is a real invalidation. `tags` of a later `invalidate`. Tags that do not meet mean the write left that entry standing — which is what serving stale looks like from the inside. +**Which entry carries a child's tags is decided by the parent's declaration.** A `#[Cacheable]` +parent records a `depends_on` edge and puts the child's tags on its `save_value`/`save_view` and +`save_etag`, so purging the child takes the parent's entry with it and the next read closes +`cache_miss`. A `#[CacheableResponse]` parent records no `depends_on` — the donut writer never +calls `put()` — and puts the child's tags on `save_etag` and `save_donut_view` but deliberately not +on `save_donut`, the shell that has to outlive the child. After the child is purged that parent +still closes `cache_hit{layer: donut-view}`, with a `refresh_donut` and a fresh +`save_etag`/`save_donut_view` inside: that is the healthy shape, and stale is a `cache_hit` with no +`refresh_donut` in it. A `#[DonutCache]` parent stores no child tag anywhere — they reach +`cdn_headers.surrogateKeys` and stop there — so every read after the first is `refresh_donut` +then `put_skipped{reason: not-cacheable}`, and purging the child changes only the child's own +nested `get`. + **Read `cache_policy.expiry`, not a TTL, to learn whether an entry is meant to expire.** `expiry: "never"` means until invalidation; the number it resolves to is a backstop and depends on how the application bound `Expiry` — a default install turns `never` into 31536000 seconds, which @@ -234,7 +247,9 @@ validator was issued for the resource that was requested, which is the question poses; an application gets it by routing first, which costs a path match and not a resource run. **A donut `cache_hit` reports the final layer.** Whether the page came from the cache or was -recomposed on the way out is inside the scope: a `refresh_donut` event means recomposed. +recomposed on the way out is inside the scope: a `refresh_donut` event means recomposed. A +`#[CacheableResponse]` page read after its child was purged is exactly that shape — the template it +kept makes the read a hit, and the recomposition is what makes the page fresh. ## Worked example diff --git a/tests/CACHE_DEPENDENCY_TESTS.md b/tests/CACHE_DEPENDENCY_TESTS.md index 4a7186d8..7914d2ba 100644 --- a/tests/CACHE_DEPENDENCY_TESTS.md +++ b/tests/CACHE_DEPENDENCY_TESTS.md @@ -78,6 +78,24 @@ purge(Comment) → BlogPosting invalidated **Test:** `DonutRepositoryTest::testCacheDependency` +Which log entry carries the child's tags — and so what the parent's next read looks like — is +decided by the parent's cache declaration, not by the embed: + +| Parent declaration | Child tags recorded on | Parent's read after the child is purged | +|---|---|---| +| `#[Cacheable]` | `depends_on`, `save_value`/`save_view`, `save_etag` | `cache_miss{layer: resource}` | +| `#[CacheableResponse]` | `save_etag`, `save_donut_view`, never `save_donut` | `cache_hit{layer: donut-view}` holding a `refresh_donut` | +| `#[DonutCache]` | `cdn_headers.surrogateKeys` only | unchanged: `refresh_donut` + `put_skipped{not-cacheable}` | + +**Tests:** `DonutDependencyEvidenceTest` — `testCacheableParentRecordsADependsOnEdge`, +`testCacheableParentTagsValueAndEtagWithTheChild`, +`testCacheableParentMissesAfterItsChildIsPurged`, +`testCacheableResponseWriteRecordsNoDependsOnEdge`, +`testCacheableResponseTagsEtagAndViewWithTheChildButNotTheTemplate`, +`testCacheableResponseRebuildsFromItsTemplateAfterTheChildIsPurged`, +`testDonutCacheKeepsTheChildTagsOutOfTheStore`, +`testDonutCacheReadShapeIsUnchangedByPurgingTheChild` + ### Tag-Based Invalidation Resources can be invalidated by their URI-derived tags. @@ -266,6 +284,10 @@ All dependency tests verify both resource cache and ETag invalidation: `refresh_donut` event inside the scope; the close label is intentionally coarse. When the page is not entire-content cacheable, no page-level save follows the rebuild — recorded as `put_skipped` with `reason=not-cacheable`. + A `#[CacheableResponse]` page read right after its child was purged is this shape, so a + reader expecting the `#[Cacheable]` shape (`cache_miss`) reads a healthy rebuild as a stale + serve. The stale shape is a `cache_hit` with no `refresh_donut` in it + (`DonutDependencyEvidenceTest::testCacheableResponseRebuildsFromItsTemplateAfterTheChildIsPurged`). - **Legacy `RepositoryLoggerInterface` receives no events.** Internal cache code logs through `SemanticLoggerInterface`; the deprecated flat interface stays bound for code BC but its instance stays empty. Consumers should migrate to the SemanticLogger tree. diff --git a/tests/DonutDependencyEvidenceTest.php b/tests/DonutDependencyEvidenceTest.php new file mode 100644 index 00000000..f80e50e9 --- /dev/null +++ b/tests/DonutDependencyEvidenceTest.php @@ -0,0 +1,224 @@ +override(new TwigModule([dirname(__DIR__) . '/tests/Fake/fake-app/var/templates'])); + $this->boot($module); + } + + private function bootCacheableApp(): void + { + $this->boot(new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld'))); + } + + private function boot(AbstractModule $module): void + { + $injector = new Injector($module, __DIR__ . '/tmp'); + $this->resource = $injector->getInstance(ResourceInterface::class); + $this->queryRepository = $injector->getInstance(QueryRepositoryInterface::class); + $this->logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class); + } + + public function testCacheableParentRecordsADependsOnEdge(): void + { + $this->bootCacheableApp(); + $this->resource->get(self::CACHEABLE); + $tree = $this->flushAndValidate($this->logger); + + $edges = self::dependsOnEdgesFrom($tree, self::CACHEABLE); + $this->assertCount(1, $edges, '#[Cacheable] merges the child tags through CacheDependency, which is what emits the edge'); + $this->assertStringContainsString('"child":"' . self::CACHEABLE_CHILD . '"', $edges[0]); + $this->assertStringContainsString('"' . self::CACHEABLE_CHILD_URI_TAG . '"', $edges[0], "the child's URI tag is what the edge carries into the parent"); + } + + public function testCacheableParentTagsValueAndEtagWithTheChild(): void + { + $this->bootCacheableApp(); + $this->resource->get(self::CACHEABLE); + $tree = $this->flushAndValidate($this->logger); + + $saveValue = self::eventContextsJsonOf($tree, 'save_value', self::CACHEABLE); + $this->assertCount(1, $saveValue); + $this->assertStringContainsString('"' . self::CACHEABLE_CHILD_URI_TAG . '"', $saveValue[0], "the child's URI tag is on the entry a child purge has to reach"); + + $saveEtag = self::eventContextsJsonOf($tree, 'save_etag', self::CACHEABLE); + $this->assertCount(1, $saveEtag); + $this->assertStringContainsString('"' . self::CACHEABLE_CHILD_URI_TAG . '"', $saveEtag[0], "the child's URI tag is on the validator too"); + } + + public function testCacheableParentMissesAfterItsChildIsPurged(): void + { + $this->bootCacheableApp(); + $this->resource->get(self::CACHEABLE); + $this->flushAndValidate($this->logger); + $this->queryRepository->purge(new Uri(self::CACHEABLE_CHILD)); + $this->flushAndValidate($this->logger); + + $this->resource->get(self::CACHEABLE); + $tree = $this->flushAndValidate($this->logger); + + $close = self::scopeCloseOf($tree, 'get', self::CACHEABLE); + $this->assertNotNull($close); + $this->assertSame('cache_miss', $close[0], "the child's tag was on the parent entry, so the purge took the parent with it"); + $this->assertStringContainsString('"layer":"resource"', $close[1]); + } + + public function testCacheableResponseWriteRecordsNoDependsOnEdge(): void + { + $this->bootDonutApp(); + $this->resource->get(self::CACHEABLE_RESPONSE); + $tree = $this->flushAndValidate($this->logger); + + $this->assertSame([], self::dependsOnEdgesFrom($tree, self::CACHEABLE_RESPONSE), 'a #[CacheableResponse] write never reaches CacheDependency'); + } + + public function testCacheableResponseTagsEtagAndViewWithTheChildButNotTheTemplate(): void + { + $this->bootDonutApp(); + $this->resource->get(self::CACHEABLE_RESPONSE); + $tree = $this->flushAndValidate($this->logger); + + $saveEtag = self::eventContextsJsonOf($tree, 'save_etag', self::CACHEABLE_RESPONSE); + $this->assertCount(1, $saveEtag); + $this->assertStringContainsString('"' . self::CHILD_URI_TAG . '"', $saveEtag[0], "the child's URI tag reaches the validator"); + $this->assertStringContainsString('"' . self::CHILD_SURROGATE_KEY . '"', $saveEtag[0], "the child's declared Surrogate-Key reaches the validator"); + + $saveDonutView = self::eventContextsJsonOf($tree, 'save_donut_view', self::CACHEABLE_RESPONSE); + $this->assertCount(1, $saveDonutView); + $this->assertStringContainsString('"' . self::CHILD_URI_TAG . '"', $saveDonutView[0], "the child's URI tag reaches the page view"); + $this->assertStringContainsString('"' . self::CHILD_SURROGATE_KEY . '"', $saveDonutView[0], "the child's declared Surrogate-Key reaches the page view"); + + $saveDonut = self::eventContextsJsonOf($tree, 'save_donut', self::CACHEABLE_RESPONSE); + $this->assertCount(1, $saveDonut); + $this->assertStringNotContainsString('"' . self::CHILD_URI_TAG . '"', $saveDonut[0], 'the template outlives the child so the shell can be recomposed'); + $this->assertStringNotContainsString('"' . self::CHILD_SURROGATE_KEY . '"', $saveDonut[0], 'the template outlives the child so the shell can be recomposed'); + } + + public function testCacheableResponseRebuildsFromItsTemplateAfterTheChildIsPurged(): void + { + $this->bootDonutApp(); + $this->resource->get(self::CACHEABLE_RESPONSE); + $this->flushAndValidate($this->logger); + $this->queryRepository->purge(new Uri(self::CHILD)); + $this->flushAndValidate($this->logger); + + $this->resource->get(self::CACHEABLE_RESPONSE); + $tree = $this->flushAndValidate($this->logger); + + $close = self::scopeCloseOf($tree, 'get', self::CACHEABLE_RESPONSE); + $this->assertNotNull($close); + $this->assertSame('cache_hit', $close[0], 'the page came out of the donut layer, not out of a resource run'); + $this->assertStringContainsString('"layer":"donut-view"', $close[1]); + $this->assertNotSame([], self::eventContextsJsonOf($tree, 'refresh_donut', self::CACHEABLE_RESPONSE), 'a hit without this event is the stale shape'); + $this->assertNotSame([], self::eventContextsJsonOf($tree, 'save_donut_view', self::CACHEABLE_RESPONSE), 'the recomposed page is stored again'); + $this->assertSame([], self::dependsOnEdgesFrom($tree, self::CACHEABLE_RESPONSE), 'recomposition records no dependency edge either'); + + $childClose = self::scopeCloseOf($tree, 'get', self::CHILD); + $this->assertNotNull($childClose); + $this->assertSame('cache_miss', $childClose[0], 'the purge landed on the child, which is where the freshness came from'); + } + + public function testDonutCacheKeepsTheChildTagsOutOfTheStore(): void + { + $this->bootDonutApp(); + $this->resource->get(self::DONUT_CACHE); + $tree = $this->flushAndValidate($this->logger); + + $saveDonut = self::eventContextsJsonOf($tree, 'save_donut', self::DONUT_CACHE); + $this->assertCount(1, $saveDonut); + $this->assertStringNotContainsString('"' . self::CHILD_URI_TAG . '"', $saveDonut[0], 'the template is the only entry, and it is not tagged by its children'); + $this->assertStringNotContainsString('"' . self::CHILD_SURROGATE_KEY . '"', $saveDonut[0], 'the template is the only entry, and it is not tagged by its children'); + $this->assertSame([], self::eventContextsJsonOf($tree, 'save_etag', self::DONUT_CACHE), 'no validator is stored for a page that is never stored'); + $this->assertSame([], self::eventContextsJsonOf($tree, 'save_donut_view', self::DONUT_CACHE), 'no page view is stored'); + $this->assertSame([], self::dependsOnEdgesFrom($tree, self::DONUT_CACHE), 'a #[DonutCache] write never reaches CacheDependency'); + + $cdnHeaders = self::eventContextsJsonOf($tree, 'cdn_headers', self::DONUT_CACHE); + $this->assertNotSame([], $cdnHeaders); + $this->assertStringContainsString('"' . self::CHILD_URI_TAG . '"', $cdnHeaders[0], "the child's tag travels to the edge, the one place this parent records it"); + $this->assertStringContainsString('"' . self::CHILD_SURROGATE_KEY . '"', $cdnHeaders[0], "the child's declared Surrogate-Key travels with it"); + } + + public function testDonutCacheReadShapeIsUnchangedByPurgingTheChild(): void + { + $this->bootDonutApp(); + $this->resource->get(self::DONUT_CACHE); + $this->flushAndValidate($this->logger); + + $this->resource->get(self::DONUT_CACHE); + $warm = $this->flushAndValidate($this->logger); + $warmTypes = self::scopeEventTypesOf($warm, 'get', self::DONUT_CACHE); + $this->assertSame(['cache_hit', 'refresh_donut', 'cdn_headers', 'put_skipped'], $warmTypes); + + $this->queryRepository->purge(new Uri(self::CHILD)); + $this->flushAndValidate($this->logger); + + $this->resource->get(self::DONUT_CACHE); + $tree = $this->flushAndValidate($this->logger); + + $this->assertSame($warmTypes, self::scopeEventTypesOf($tree, 'get', self::DONUT_CACHE), 'the parent never recorded the dependency, so purging the child cannot change its shape'); + $close = self::scopeCloseOf($tree, 'get', self::DONUT_CACHE); + $this->assertNotNull($close); + $this->assertSame('cache_hit', $close[0]); + $this->assertStringContainsString('"layer":"donut-view"', $close[1]); + $this->assertStringContainsString('"reason":"not-cacheable"', self::eventContextsJsonOf($tree, 'put_skipped', self::DONUT_CACHE)[0]); + + $childClose = self::scopeCloseOf($tree, 'get', self::CHILD); + $this->assertNotNull($childClose); + $this->assertSame('cache_miss', $childClose[0], 'the only thing the purge changed is the embedded child'); + } + + /** + * @param array $tree + * + * @return list + */ + private static function dependsOnEdgesFrom(array $tree, string $parent): array + { + $edges = self::eventContextsJsonOf($tree, 'depends_on'); + + return array_values(array_filter($edges, static fn (string $json): bool => str_contains($json, '"parent":"' . $parent . '"'))); + } +} diff --git a/tests/SemanticLogTreeTrait.php b/tests/SemanticLogTreeTrait.php index cf85b1a3..23ddb394 100644 --- a/tests/SemanticLogTreeTrait.php +++ b/tests/SemanticLogTreeTrait.php @@ -134,33 +134,142 @@ private static function contextJsonOf(array $tree, string $type): string|null */ private static function eventContextJsonOf(array $tree, string $type): string|null { - $found = self::findEventContextJson($tree['open'] ?? [], $type); - if ($found !== null) { - return $found; - } + return self::eventContextsJsonOf($tree, $type)[0] ?? null; + } - $events = $tree['events'] ?? []; - if (! is_array($events)) { - return null; - } + /** + * JSON of the first close context whose type matches, or null if absent + * + * @param array $tree + */ + private static function closeContextJsonOf(array $tree, string $type): string|null + { + return self::findCloseContextJson($tree['open'] ?? [], $type); + } - foreach ($events as $event) { - if (is_array($event) && ($event['type'] ?? null) === $type) { - return (string) json_encode($event['context'] ?? null, JSON_UNESCAPED_SLASHES); - } + /** + * JSON of every event context whose type matches, depth-first, optionally for one `uri` only + * + * One type can be emitted for several URIs in one session - a parent and the children + * it embeds both `save_etag` - so a tag assertion has to name whose event it reads. + * + * @param array $tree + * + * @return list + */ + private static function eventContextsJsonOf(array $tree, string $type, string|null $uri = null): array + { + $contexts = []; + self::collectEventContextsJson($tree['open'] ?? [], $type, $uri, $contexts); + self::appendEventContextsJson($tree['events'] ?? [], $type, $uri, $contexts); + + return $contexts; + } + + /** + * Close of the first `$openType` scope opened for `$uri`, as `[type, context JSON]` + * + * @param array $tree + * + * @return array{string, string}|null + */ + private static function scopeCloseOf(array $tree, string $openType, string $uri): array|null + { + $scope = self::findScope($tree['open'] ?? [], $openType, $uri); + $close = $scope === null ? null : $scope['close'] ?? null; + if (! is_array($close) || ! isset($close['type']) || ! is_string($close['type'])) { + return null; } - return null; + return [$close['type'], (string) json_encode($close['context'] ?? null, JSON_UNESCAPED_SLASHES)]; } /** - * JSON of the first close context whose type matches, or null if absent + * Event `type`s of the first `$openType` scope opened for `$uri`, that scope's own events only * * @param array $tree + * + * @return list */ - private static function closeContextJsonOf(array $tree, string $type): string|null + private static function scopeEventTypesOf(array $tree, string $openType, string $uri): array { - return self::findCloseContextJson($tree['open'] ?? [], $type); + $scope = self::findScope($tree['open'] ?? [], $openType, $uri); + $types = []; + if ($scope !== null) { + self::walkEvents($scope['events'] ?? [], $types); + } + + return $types; + } + + /** + * @param mixed $nodes + * @param list $contexts + */ + private static function collectEventContextsJson(mixed $nodes, string $type, string|null $uri, array &$contexts): void + { + if (! is_array($nodes)) { + return; + } + + foreach ($nodes as $node) { + if (! is_array($node)) { + continue; + } + + self::appendEventContextsJson($node['events'] ?? [], $type, $uri, $contexts); + self::collectEventContextsJson($node['open'] ?? [], $type, $uri, $contexts); + } + } + + /** + * @param mixed $events + * @param list $contexts + */ + private static function appendEventContextsJson(mixed $events, string $type, string|null $uri, array &$contexts): void + { + if (! is_array($events)) { + return; + } + + foreach ($events as $event) { + if (! is_array($event) || ($event['type'] ?? null) !== $type) { + continue; + } + + $context = $event['context'] ?? null; + if ($uri !== null && (! is_array($context) || ($context['uri'] ?? null) !== $uri)) { + continue; + } + + $contexts[] = (string) json_encode($context, JSON_UNESCAPED_SLASHES); + } + } + + /** @return array|null */ + private static function findScope(mixed $nodes, string $openType, string $uri): array|null + { + if (! is_array($nodes)) { + return null; + } + + foreach ($nodes as $node) { + if (! is_array($node)) { + continue; + } + + $context = $node['context'] ?? null; + if (($node['type'] ?? null) === $openType && is_array($context) && ($context['uri'] ?? null) === $uri) { + return $node; + } + + $found = self::findScope($node['open'] ?? [], $openType, $uri); + if ($found !== null) { + return $found; + } + } + + return null; } /** @@ -301,35 +410,6 @@ private static function findContextJson(mixed $nodes, string $type): string|null return null; } - private static function findEventContextJson(mixed $nodes, string $type): string|null - { - if (! is_array($nodes)) { - return null; - } - - foreach ($nodes as $node) { - if (! is_array($node)) { - continue; - } - - $events = $node['events'] ?? []; - if (is_array($events)) { - foreach ($events as $event) { - if (is_array($event) && ($event['type'] ?? null) === $type) { - return (string) json_encode($event['context'] ?? null, JSON_UNESCAPED_SLASHES); - } - } - } - - $found = self::findEventContextJson($node['open'] ?? [], $type); - if ($found !== null) { - return $found; - } - } - - return null; - } - private static function findCloseContextJson(mixed $nodes, string $type): string|null { if (! is_array($nodes)) {