From 37fa192eb454c906088eddcf81178ca6de06ed08 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Thu, 20 Aug 2026 07:06:42 +0900 Subject: [PATCH 1/2] Add captured demo logs and a cache traceability report demo/logs/ holds the validated session output (tree + JSON) of all four demos; the whole demo/ and docs/ trees are already export-ignored, so neither the logs nor the report ships in a release archive. --- demo/logs/run-degraded.log | 2864 ++++++++++++++++++++++++++ demo/logs/run-dependency.log | 1681 +++++++++++++++ demo/logs/run-donut.log | 600 ++++++ demo/logs/run.log | 457 ++++ docs/cache-traceability-report.ja.md | 75 + docs/cache-traceability-report.md | 75 + 6 files changed, 5752 insertions(+) create mode 100644 demo/logs/run-degraded.log create mode 100644 demo/logs/run-dependency.log create mode 100644 demo/logs/run-donut.log create mode 100644 demo/logs/run.log create mode 100644 docs/cache-traceability-report.ja.md create mode 100644 docs/cache-traceability-report.md diff --git a/demo/logs/run-degraded.log b/demo/logs/run-degraded.log new file mode 100644 index 00000000..94a815b5 --- /dev/null +++ b/demo/logs/run-degraded.log @@ -0,0 +1,2864 @@ +=== Degraded-Path Demo === + +The happy paths live in the other three demos. This one provokes the failures and +refusals a cache normally hides, and shows what the log records for each: + +A. Recorded refusals + 1. GET app://self/code returns 203 -> put_skipped{error-code, 203} + purge + 2. GET a page that presets its own ETag -> put_skipped{etag-present} + 3. Donut page, not whole-page cacheable -> put_donut, then refresh_donut + + put_skipped{not-cacheable} + 4. DELETE that fails validation (400) -> command_result{400}, NO invalidation + 5. GET a view-type cacheable resource -> save_view + 6. Direct put()/invalidateTags() -> manual_store{,_result}, manual_invalidate +B. Cache server down -> cache_error{read}, served live anyway +C. CDN purge, both outcomes -> invalidate{cdn: purged} / {cdn: failed}, + the failure propagating fail-closed +D. Pool refuses writes -> save_value/save_etag saved=false, + manual_store_result{failed} +E. Pool refuses writes, donut page -> save_donut/save_donut_view saved=false +F. Pool refuses invalidation -> invalidate{roPool: failed, etagPool: failed} +G. The other command producers -> command{source: DonutCommandInterceptor}, + command{source: RefreshInterceptor} +H. A finite TTL under #[HttpCache] -> save_* with requestedTtl=10, private Cache-Control +I. Direct putStatic(ttl, sMaxAge) -> manual_store{,_result} rooting a donut + write with real ttl/sMaxAge + +=== Executing... === +A1 GET app://self/code -> 203 (not stored) +A2 GET page://self/html/self-etag -> put skipped (etag-present) +A3 GET donut page twice around a purge -> refresh_donut + put_skipped(not-cacheable) +A4 DELETE page://self/html/comment -> 400 (no invalidation) +A5 GET app://self/view -> save_view (rendered view stored) +A6 direct put() -> stored=true, direct invalidateTags() of two tags -> manual scopes + +=== Cache Log Tree — A. recorded refusals === +get uri=app://self/code +├── put_skipped uri=app://self/code reason=error-code code=203 [event] +├── purge uri=app://self/code [event] +├── invalidate tags=[_code_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +└── layer=resource +get uri=page://self/html/self-etag +├── cache_miss layer=donut [event] +├── put_skipped uri=page://self/html/self-etag reason=etag-present [event] +└── layer=donut-view +get uri=page://self/html/blog-posting-donut +├── cache_miss layer=donut [event] +├── put_donut uri=page://self/html/blog-posting-donut [event] +├── cdn_headers uri=page://self/html/blog-posting-donut surrogateKeys=[_html_blog-posting-donut_ +2 items] [event] +├── pre_write_cleanup uri=page://self/html/blog-posting-donut [event] +├── invalidate tags=[_html_blog-posting-donut_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_donut uri=page://self/html/blog-posting-donut tags=[_html_blog-posting-donut_] saved=true [event] +├── get uri=page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ └── layer=resource +└── layer=donut-view +manual_purge uri=page://self/html/comment +├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +└── result=purged +get uri=page://self/html/blog-posting-donut +├── cache_hit layer=donut [event] +├── refresh_donut uri=page://self/html/blog-posting-donut [event] +├── cdn_headers uri=page://self/html/blog-posting-donut surrogateKeys=[_html_blog-posting-donut_ +2 items] [event] +├── put_skipped uri=page://self/html/blog-posting-donut reason=not-cacheable [event] +├── get uri=page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ └── layer=resource +└── layer=donut-view +command method=onDelete source=CommandInterceptor +└── code=400 +get uri=app://self/view +├── pre_write_cleanup uri=app://self/view [event] +├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/view etag="3559920818" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=true [event] +└── layer=resource +manual_store uri=app://self/view +├── pre_write_cleanup uri=app://self/view [event] +├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/view etag="3559920818" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=true [event] +└── result=stored +manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] +├── invalidate tags=[_demo_manual_tag_, _demo_second_tag_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +└── result=invalidated + +=== Cache Log JSON — A. recorded refusals === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/code" + }, + "events": [ + { + "id": "put_skipped_1", + "type": "put_skipped", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_skipped.json", + "context": { + "uri": "app://self/code", + "reason": "error-code", + "code": 203 + } + }, + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "app://self/code" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_code_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.084 + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/self-etag" + }, + "events": [ + { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_skipped_2", + "type": "put_skipped", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_skipped.json", + "context": { + "uri": "page://self/html/self-etag", + "reason": "etag-present", + "code": null + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "get_3", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting-donut" + }, + "open": [ + { + "id": "get_4", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_5", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_4", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting-donut", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting-donut", + "headers": { + "Surrogate-Key": "_html_blog-posting-donut_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "_html_blog-posting-donut_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting-donut" + } + }, + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting-donut_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting-donut", + "tags": [ + "_html_blog-posting-donut_" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_6", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "manual_purge_1", + "type": "manual_purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "invalidate_4", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + } + ], + "close": { + "id": "manual_purge_result_1", + "type": "manual_purge_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge_result.json", + "context": { + "result": "purged" + } + } + }, + { + "id": "get_5", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting-donut" + }, + "open": [ + { + "id": "get_6", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_3", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_5", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_2", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_2", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_7", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_hit_1", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "donut" + } + }, + { + "id": "refresh_donut_1", + "type": "refresh_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/refresh_donut.json", + "context": { + "uri": "page://self/html/blog-posting-donut" + } + }, + { + "id": "cdn_headers_2", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting-donut", + "headers": { + "Surrogate-Key": "_html_blog-posting-donut_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "_html_blog-posting-donut_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "put_skipped_3", + "type": "put_skipped", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_skipped.json", + "context": { + "uri": "page://self/html/blog-posting-donut", + "reason": "not-cacheable", + "code": null + } + } + ], + "close": { + "id": "cache_hit_2", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onDelete", + "annotations": [], + "source": "CommandInterceptor" + }, + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 400 + } + } + }, + { + "id": "get_7", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/view" + }, + "events": [ + { + "id": "pre_write_cleanup_4", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/view" + } + }, + { + "id": "invalidate_6", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_view_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "cache_policy_3", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/view", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_3", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/view", + "etag": "\"3559920818\"", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_view_1", + "type": "save_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_view.json", + "context": { + "uri": "app://self/view", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_8", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "manual_store_1", + "type": "manual_store", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store.json", + "context": { + "uri": "app://self/view" + }, + "events": [ + { + "id": "pre_write_cleanup_5", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/view" + } + }, + { + "id": "invalidate_7", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_view_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "cache_policy_4", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/view", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_4", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/view", + "etag": "\"3559920818\"", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_view_2", + "type": "save_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_view.json", + "context": { + "uri": "app://self/view", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "manual_store_result_1", + "type": "manual_store_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store_result.json", + "context": { + "result": "stored" + } + } + }, + { + "id": "manual_invalidate_1", + "type": "manual_invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_invalidate.json", + "context": { + "tags": [ + "_demo_manual_tag_", + "_demo_second_tag_" + ] + }, + "events": [ + { + "id": "invalidate_8", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_demo_manual_tag_", + "_demo_second_tag_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + } + ], + "close": { + "id": "manual_invalidate_result_1", + "type": "manual_invalidate_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_invalidate_result.json", + "context": { + "result": "invalidated" + } + } + } + ] +} +Schema validation: OK (59 entries) + (warning) RuntimeException: cache server down +B GET app://self/value -> 200 served live; the outage is logged, not swallowed + +=== Cache Log Tree — B. cache layer down === +get uri=app://self/value +├── cache_error uri=app://self/value operation=read error=cache server down exceptionClass=RuntimeException [event] +└── layer=resource + +=== Cache Log JSON — B. cache layer down === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "cache_error_1", + "type": "cache_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_error.json", + "context": { + "uri": "app://self/value", + "operation": "read", + "error": "cache server down", + "exceptionClass": "RuntimeException" + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ] +} +Schema validation: OK (3 entries) +C1 configured purger ran -> cdn=purged, tags purged: _value_, _value_ + +=== Cache Log Tree — C1. CDN purge succeeded === +get uri=app://self/value +├── pre_write_cleanup uri=app://self/value [event] +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=purged (+1 more) [event] +├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/value etag="2442337131" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=true [event] +└── layer=resource +manual_purge uri=app://self/value +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=purged (+1 more) [event] +└── result=purged + +=== Cache Log JSON — C1. CDN purge succeeded === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/value" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "purged", + "durationMs": 0.006 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/value", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/value", + "etag": "\"2442337131\"", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/value", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "manual_purge_1", + "type": "manual_purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "purged", + "durationMs": 0.003 + } + } + ], + "close": { + "id": "manual_purge_result_1", + "type": "manual_purge_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge_result.json", + "context": { + "result": "purged" + } + } + } + ] +} +Schema validation: OK (10 entries) + (warning) BEAR\QueryRepository\FakeCdnPurgeFailed: purge failed: _value_ +C2 purge propagated the CDN failure: purge failed: _value_ + +=== Cache Log Tree — C2. CDN purge failed (fail-closed) === +get uri=app://self/value +├── pre_write_cleanup uri=app://self/value [event] +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=failed (+1 more) [event] +├── cache_error uri=app://self/value operation=write error=purge failed: _value_ exceptionClass=FakeCdnPurgeFailed [event] +└── layer=resource +manual_purge uri=app://self/value +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=failed (+1 more) [event] +└── result=failed + +=== Cache Log JSON — C2. CDN purge failed (fail-closed) === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/value" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "failed", + "durationMs": 0.368 + } + }, + { + "id": "cache_error_1", + "type": "cache_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_error.json", + "context": { + "uri": "app://self/value", + "operation": "write", + "error": "purge failed: _value_", + "exceptionClass": "BEAR\\QueryRepository\\FakeCdnPurgeFailed" + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "manual_purge_1", + "type": "manual_purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "failed", + "durationMs": 0.004 + } + } + ], + "close": { + "id": "manual_purge_result_1", + "type": "manual_purge_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge_result.json", + "context": { + "result": "failed" + } + } + } + ] +} +Schema validation: OK (8 entries) +C3 Akamai flavor -> cdn_headers: Akamai-Cache-Control=max-age=31536000, keys in Edge-Cache-Tag + +=== Cache Log Tree — C3. Akamai CDN headers === +get uri=page://self/html/blog-posting +├── cache_miss layer=donut [event] +├── put_donut uri=page://self/html/blog-posting [event] +├── cdn_headers uri=page://self/html/blog-posting surrogateKeys=[blog-posting-page, _html_blog-posting_ +2 items] [event] +├── pre_write_cleanup uri=page://self/html/blog-posting [event] +├── invalidate tags=[_html_blog-posting_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_etag uri=page://self/html/blog-posting etag="4066413688" tags=[_html_blog-posting_] saved=true [event] +├── save_donut_view uri=page://self/html/blog-posting tags=[_html_blog-posting_] saved=true [event] +├── save_donut uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page] saved=true [event] +├── get uri=page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ └── layer=resource +└── layer=donut-view + +=== Cache Log JSON — C3. Akamai CDN headers === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting" + }, + "open": [ + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting", + "headers": { + "Akamai-Cache-Control": "max-age=31536000", + "Edge-Cache-Tag": "blog-posting-page _html_blog-posting_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting", + "etag": "\"4066413688\"", + "tags": [ + "_html_blog-posting_" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_view_1", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + } + ] +} +Schema validation: OK (17 entries) +D GET a value-type and a view-type resource -> save_value / save_view saved=false +D direct put() against the same pool -> manual_store_result: failed + +=== Cache Log Tree — D. write-refusing pool === +get uri=app://self/value +├── pre_write_cleanup uri=app://self/value [event] +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/value etag="553249087" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] +└── layer=resource +get uri=app://self/view +├── pre_write_cleanup uri=app://self/view [event] +├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/view etag="7707204" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=false [event] +└── layer=resource +manual_store uri=app://self/value +├── pre_write_cleanup uri=app://self/value [event] +├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] +├── save_etag uri=app://self/value etag="553249087" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] +└── result=failed + +=== Cache Log JSON — D. write-refusing pool === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/value" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/value", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/value", + "etag": "\"553249087\"", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/value", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/view" + }, + "events": [ + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/view" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_view_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_2", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/view", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/view", + "etag": "\"7707204\"", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": false + } + }, + { + "id": "save_view_1", + "type": "save_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_view.json", + "context": { + "uri": "app://self/view", + "tags": [ + "_view_" + ], + "requestedTtl": 31536000, + "saved": false + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "manual_store_1", + "type": "manual_store", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "pre_write_cleanup_3", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/value" + } + }, + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_3", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/value", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_3", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/value", + "etag": "\"553249087\"", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + }, + { + "id": "save_value_2", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/value", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + } + ], + "close": { + "id": "manual_store_result_1", + "type": "manual_store_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store_result.json", + "context": { + "result": "failed" + } + } + } + ] +} +Schema validation: OK (21 entries) +E GET donut page -> save_donut / save_donut_view saved=false + +=== Cache Log Tree — E. donut writes refused === +get uri=page://self/html/blog-posting +├── cache_miss layer=donut [event] +├── put_donut uri=page://self/html/blog-posting [event] +├── cdn_headers uri=page://self/html/blog-posting surrogateKeys=[blog-posting-page, _html_blog-posting_ +2 items] [event] +├── pre_write_cleanup uri=page://self/html/blog-posting [event] +├── invalidate tags=[_html_blog-posting_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_etag uri=page://self/html/blog-posting etag="4066413688" tags=[blog-posting-page, _html_blog-posting_ +2 items] saved=false [event] +├── save_donut_view uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page +2 items] saved=false [event] +├── save_donut uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page] saved=false [event] +├── get uri=page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=false [event] +│ └── layer=resource +└── layer=donut-view + +=== Cache Log JSON — E. donut writes refused === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting" + }, + "open": [ + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": false + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": false + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting", + "etag": "\"4066413688\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": false + } + }, + { + "id": "save_donut_view_1", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": false + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page" + ], + "requestedTtl": null, + "saved": false + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + } + ] +} +Schema validation: OK (17 entries) +F invalidateTags() on pools that refuse it -> roPool=failed etagPool=failed + +=== Cache Log Tree — F. invalidation refused === +manual_invalidate tags=[_demo_stuck_tag_] +├── invalidate tags=[_demo_stuck_tag_] roPool=failed etagPool=failed cdn=skipped (+1 more) [event] +└── result=failed + +=== Cache Log JSON — F. invalidation refused === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "manual_invalidate_1", + "type": "manual_invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_invalidate.json", + "context": { + "tags": [ + "_demo_stuck_tag_" + ] + }, + "events": [ + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_demo_stuck_tag_" + ], + "roPool": "failed", + "etagPool": "failed", + "cdn": "skipped", + "durationMs": 0.002 + } + } + ], + "close": { + "id": "manual_invalidate_result_1", + "type": "manual_invalidate_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_invalidate_result.json", + "context": { + "result": "failed" + } + } + } + ] +} +Schema validation: OK (3 entries) +G1 DELETE a whole-page donut resource -> command{source: DonutCommandInterceptor} + +=== Cache Log Tree — G1. donut command === +get uri=page://self/html/blog-posting?id=0 +├── cache_miss layer=donut [event] +├── put_donut uri=page://self/html/blog-posting?id=0 [event] +├── cdn_headers uri=page://self/html/blog-posting?id=0 surrogateKeys=[blog-posting-page +3 items] [event] +├── pre_write_cleanup uri=page://self/html/blog-posting?id=0 [event] +├── invalidate tags=[_html_blog-posting_id=0] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_etag uri=page://self/html/blog-posting?id=0 etag="2699203007" tags=[blog-posting-page +3 items] saved=true [event] +├── save_donut_view uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +3 items] saved=true [event] +├── save_donut uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +1 items] saved=true [event] +├── get uri=page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ └── layer=resource +└── layer=donut-view +command method=onDelete source=DonutCommandInterceptor +├── purge uri=page://self/html/blog-posting?id=0 [event] +├── invalidate tags=[_html_blog-posting_id=0] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── get uri=page://self/html/blog-posting?id=0 +│ ├── cache_miss layer=donut [event] +│ ├── put_donut uri=page://self/html/blog-posting?id=0 [event] +│ ├── cdn_headers uri=page://self/html/blog-posting?id=0 surrogateKeys=[blog-posting-page +3 items] [event] +│ ├── pre_write_cleanup uri=page://self/html/blog-posting?id=0 [event] +│ ├── invalidate tags=[_html_blog-posting_id=0] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── save_etag uri=page://self/html/blog-posting?id=0 etag="2699203007" tags=[blog-posting-page +3 items] saved=true [event] +│ ├── save_donut_view uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +3 items] saved=true [event] +│ ├── save_donut uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +1 items] saved=true [event] +│ ├── get uri=page://self/html/comment +│ │ └── layer=resource +│ └── layer=donut-view +└── code=200 + +=== Cache Log JSON — G1. donut command === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + }, + "open": [ + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_id=0 _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_id=0" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.006 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "etag": "\"2699203007\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_view_1", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onDelete", + "annotations": [], + "source": "DonutCommandInterceptor" + }, + "open": [ + { + "id": "get_3", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + }, + "open": [ + { + "id": "get_4", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "close": { + "id": "cache_hit_1", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_4", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_2", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_2", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_id=0 _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_3", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + } + }, + { + "id": "invalidate_4", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_id=0" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "save_etag_3", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "etag": "\"2699203007\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_view_2", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_2", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_5", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + } + ], + "events": [ + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + } + }, + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_id=0" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + } + ], + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 200 + } + } + } + ] +} +Schema validation: OK (33 entries) +G2 PUT a non-cacheable #[Refresh] resource -> command{source: RefreshInterceptor} + +=== Cache Log Tree — G2. refresh command === +command method=onPut annotations=[1 items] source=RefreshInterceptor +├── purge uri=app://self/refresh-dest?id=1 [event] +├── invalidate tags=[_refresh-dest_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── pre_write_cleanup uri=app://self/refresh-dest?id=1 [event] +├── invalidate tags=[_refresh-dest_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_etag uri=app://self/refresh-dest?id=1 etag="85792652" tags=[_refresh-dest_id=1] saved=true [event] +├── save_value uri=app://self/refresh-dest?id=1 tags=[_refresh-dest_id=1] saved=true [event] +└── code=200 + +=== Cache Log JSON — G2. refresh command === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onPut", + "annotations": [ + { + "class": "BEAR\\RepositoryModule\\Annotation\\Refresh", + "uri": "app://self/refresh-dest{?id}" + } + ], + "source": "RefreshInterceptor" + }, + "events": [ + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "app://self/refresh-dest?id=1" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_refresh-dest_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.007 + } + }, + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/refresh-dest?id=1" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_refresh-dest_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/refresh-dest?id=1", + "etag": "\"85792652\"", + "tags": [ + "_refresh-dest_id=1" + ], + "requestedTtl": 0, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/refresh-dest?id=1", + "tags": [ + "_refresh-dest_id=1" + ], + "requestedTtl": 0, + "saved": true + } + } + ], + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 200 + } + } + } + ] +} +Schema validation: OK (8 entries) +G3 PUT a #[Purge]-only resource -> command.annotations lists Annotation\Purge x2, level-two purged: true + +=== Cache Log Tree — G3. purge-only command === +command method=onPut annotations=[2 items] source=RefreshInterceptor +├── purge uri=page://self/dep/purge-src?id=1 [event] +├── invalidate tags=[_dep_purge-src_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── purge uri=page://self/dep/level-two [event] +├── invalidate tags=[_dep_level-two_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +└── code=200 + +=== Cache Log JSON — G3. purge-only command === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onPut", + "annotations": [ + { + "class": "BEAR\\RepositoryModule\\Annotation\\Purge", + "uri": "page://self/dep/purge-src{?id}" + }, + { + "class": "BEAR\\RepositoryModule\\Annotation\\Purge", + "uri": "page://self/dep/level-two" + } + ], + "source": "RefreshInterceptor" + }, + "events": [ + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "page://self/dep/purge-src?id=1" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_purge-src_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "purge_2", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "page://self/dep/level-two" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-two_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + } + ], + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 200 + } + } + } + ] +} +Schema validation: OK (6 entries) +H GET a #[Cacheable(expirySecond: 10), HttpCache(isPrivate: true)] resource -> Cache-Control: private, max-age=10 + the save events carry requestedTtl=10, not the 31536000 `never` placeholder + +=== Cache Log Tree — H. finite TTL === +get uri=app://self/http-cache-control-with-cache… +├── pre_write_cleanup uri=app://self/http-cache-control-with-cache… [event] +├── invalidate tags=[_http-cache-control-with-cacheable_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/http-cache-control-with-cache… expirySecond=10 resolvedTtl=10 [event] +├── save_etag uri=app://self/http-cache-control-with-cache… etag="3810187743" tags=[_http-cache-control-with-cacheable_] requestedTtl=10 (+1 more) [event] +├── save_value uri=app://self/http-cache-control-with-cache… tags=[_http-cache-control-with-cacheable_] requestedTtl=10 saved=true [event] +└── layer=resource + +=== Cache Log JSON — H. finite TTL === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/http-cache-control-with-cacheable" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/http-cache-control-with-cacheable" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_http-cache-control-with-cacheable_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/http-cache-control-with-cacheable", + "expiry": null, + "expirySecond": 10, + "expiryAt": null, + "resolvedTtl": 10 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/http-cache-control-with-cacheable", + "etag": "\"3810187743\"", + "tags": [ + "_http-cache-control-with-cacheable_" + ], + "requestedTtl": 10, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/http-cache-control-with-cacheable", + "tags": [ + "_http-cache-control-with-cacheable_" + ], + "requestedTtl": 10, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ] +} +Schema validation: OK (7 entries) +I direct putStatic(ttl: 60, sMaxAge: 30) -> put_donut{ttl: 60, sMaxAge: 30}: + the template entry keeps ttl=60 while the rendered view and its ETag take ttl=30, + and the whole write is rooted in manual_store{,_result} — cleanup invalidate included + +=== Cache Log Tree — I. donut write through the repository API === +manual_store uri=page://self/html/blog-posting?id=0 +├── put_donut uri=page://self/html/blog-posting?id=0 requestedTtl=60 sMaxAge=30 [event] +├── cdn_headers uri=page://self/html/blog-posting?id=0 surrogateKeys=[blog-posting-page +3 items] [event] +├── pre_write_cleanup uri=page://self/html/blog-posting?id=0 [event] +├── invalidate tags=[_html_blog-posting_id=0] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +├── save_etag uri=page://self/html/blog-posting?id=0 etag="2699203007" tags=[blog-posting-page +3 items] requestedTtl=30 (+1 more) [event] +├── save_donut_view uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +3 items] requestedTtl=30 saved=true [event] +├── save_donut uri=page://self/html/blog-posting?id=0 tags=[_html_blog-posting_id=0 +3 items] requestedTtl=60 saved=true [event] +└── result=stored + +=== Cache Log JSON — I. donut write through the repository API === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "manual_store_1", + "type": "manual_store", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + }, + "events": [ + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "requestedTtl": 60, + "sMaxAge": 30 + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_id=0 _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting?id=0" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_id=0" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "etag": "\"2699203007\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_id=0", + "_html_comment_", + "comment01" + ], + "requestedTtl": 30, + "saved": true + } + }, + { + "id": "save_donut_view_1", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": 30, + "saved": true + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting?id=0", + "tags": [ + "_html_blog-posting_id=0", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": 60, + "saved": true + } + } + ], + "close": { + "id": "manual_store_result_1", + "type": "manual_store_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_store_result.json", + "context": { + "result": "stored" + } + } + } + ] +} +Schema validation: OK (9 entries) +J GET app://self/value -> 200 served live while the store is unreachable: + pool_error{read} for the lookup and pool_error{write} for the store, with the + backend's own message - without them the miss reads exactly like a cold one + +=== Cache Log Tree — J. the store is down and says so === +get uri=app://self/value +├── pool_error key=ro-_value_ operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── pre_write_cleanup uri=app://self/value [event] +├── pool_error operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── pool_error operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── invalidate tags=[_value_] roPool=failed etagPool=failed cdn=skipped (+1 more) [event] +├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] +├── pool_error key=2540363928 operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── pool_error key=2540363928 operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── save_etag uri=app://self/value etag="2540363928" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── pool_error key=ro-_value_ operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── pool_error key=ro-_value_ operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] +└── layer=resource + +=== Cache Log JSON — J. the store is down and says so === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/value" + }, + "events": [ + { + "id": "pool_error_1", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "ro-_value_", + "operation": "read", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/value" + } + }, + { + "id": "pool_error_2", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "", + "operation": "write", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "pool_error_3", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "", + "operation": "write", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_value_" + ], + "roPool": "failed", + "etagPool": "failed", + "cdn": "skipped", + "durationMs": 0.162 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/value", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "pool_error_4", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "2540363928", + "operation": "read", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "pool_error_5", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "2540363928", + "operation": "write", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/value", + "etag": "\"2540363928\"", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + }, + { + "id": "pool_error_6", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "ro-_value_", + "operation": "read", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "pool_error_7", + "type": "pool_error", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", + "context": { + "key": "ro-_value_", + "operation": "write", + "error": "Redis connection failed: Connection refused", + "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/value", + "tags": [ + "_value_" + ], + "requestedTtl": 31536000, + "saved": false + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ] +} +Schema validation: OK (14 entries) diff --git a/demo/logs/run-dependency.log b/demo/logs/run-dependency.log new file mode 100644 index 00000000..128e4335 --- /dev/null +++ b/demo/logs/run-dependency.log @@ -0,0 +1,1681 @@ +=== Cache Dependency Demo === + +This demo executes the following scenarios: + +1. Initial access to level-one (3-level chain) + - LevelOne embeds LevelTwo embeds LevelThree + - All three will be cache-miss, dependencies registered + +2. Re-access level-one + - Should be cache-hit + +3. Write to level-three (PUT) + - The command purges the written resource and refreshes it in place + - The surrogate-key cascade busts level-two and level-one + - The log shows a command scope (method/annotations/source) + driving the purge — cause and effect in one subtree + +4. Re-access level-one after the write + - level-one and level-two are cache-miss (rebuilt from the + refreshed leaf, which is served from cache) + +5. Access ParentA and ParentB + - Both embed ChildC (shared dependency) + +6. Purge child-c (manual repository purge) + - Should invalidate both ParentA and ParentB + - A direct purge() roots a top-level manual_purge scope — + a different entry kind than the command scope in 3 + +7. Re-access both parents after purge + - Both should be cache-miss (regenerated) + +=== Executing... === +=== Cache Log Tree === +get uri=page://self/dep/level-one +├── uri: page://self/dep/level-one +├── pre_write_cleanup uri=page://self/dep/level-one [event] +│ └── uri: page://self/dep/level-one +├── invalidate tags=[_dep_level-one_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_level-one_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.077 +├── depends_on parent=page://self/dep/level-one child=page://self/dep/level-two childTags=[_dep_level-two_, _dep_level-three_] [event] +│ ├── parent: page://self/dep/level-one +│ ├── child: page://self/dep/level-two +│ ├── childTags[0]: _dep_level-two_ +│ └── childTags[1]: _dep_level-three_ +├── cache_policy uri=page://self/dep/level-one expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/level-one +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/level-one etag="3589457708" tags=[_dep_level-two_, _dep_level-three_ +1 items] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/level-one +│ ├── etag: "3589457708" +│ ├── tags[0]: _dep_level-two_ +│ ├── tags[1]: _dep_level-three_ +│ ├── tags[2]: _dep_level-one_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/level-one tags=[_dep_level-one_, _dep_level-two_ +1 items] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/level-one +│ ├── tags[0]: _dep_level-one_ +│ ├── tags[1]: _dep_level-two_ +│ ├── tags[2]: _dep_level-three_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/level-two +│ ├── uri: page://self/dep/level-two +│ ├── pre_write_cleanup uri=page://self/dep/level-two [event] +│ │ └── uri: page://self/dep/level-two +│ ├── invalidate tags=[_dep_level-two_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _dep_level-two_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.003 +│ ├── depends_on parent=page://self/dep/level-two child=page://self/dep/level-three childTags=[_dep_level-three_] [event] +│ │ ├── parent: page://self/dep/level-two +│ │ ├── child: page://self/dep/level-three +│ │ └── childTags[0]: _dep_level-three_ +│ ├── cache_policy uri=page://self/dep/level-two expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/dep/level-two etag="2687912183" tags=[_dep_level-three_, _dep_level-two_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── etag: "2687912183" +│ │ ├── tags[0]: _dep_level-three_ +│ │ ├── tags[1]: _dep_level-two_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/dep/level-two tags=[_dep_level-two_, _dep_level-three_] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── tags[0]: _dep_level-two_ +│ │ ├── tags[1]: _dep_level-three_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── get uri=page://self/dep/level-three +│ │ ├── uri: page://self/dep/level-three +│ │ ├── pre_write_cleanup uri=page://self/dep/level-three [event] +│ │ │ └── uri: page://self/dep/level-three +│ │ ├── invalidate tags=[_dep_level-three_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ │ ├── tags[0]: _dep_level-three_ +│ │ │ ├── roPool: invalidated +│ │ │ ├── etagPool: invalidated +│ │ │ ├── cdn: skipped +│ │ │ └── durationMs: 0.002 +│ │ ├── cache_policy uri=page://self/dep/level-three expiry=never resolvedTtl=31536000 [event] +│ │ │ ├── uri: page://self/dep/level-three +│ │ │ ├── expiry: never +│ │ │ └── resolvedTtl: 31536000 +│ │ ├── save_etag uri=page://self/dep/level-three etag="3467047581" tags=[_dep_level-three_] requestedTtl=31536000 (+1 more) [event] +│ │ │ ├── uri: page://self/dep/level-three +│ │ │ ├── etag: "3467047581" +│ │ │ ├── tags[0]: _dep_level-three_ +│ │ │ ├── requestedTtl: 31536000 +│ │ │ └── saved: 1 +│ │ ├── save_value uri=page://self/dep/level-three tags=[_dep_level-three_] requestedTtl=31536000 saved=true [event] +│ │ │ ├── uri: page://self/dep/level-three +│ │ │ ├── tags[0]: _dep_level-three_ +│ │ │ ├── requestedTtl: 31536000 +│ │ │ └── saved: 1 +│ │ └── close +│ │ └── layer: resource +│ └── close +│ └── layer: resource +└── close + └── layer: resource +get uri=page://self/dep/level-one +├── uri: page://self/dep/level-one +└── close + └── layer: resource +command method=onPut source=CommandInterceptor +├── method: onPut +├── source: CommandInterceptor +├── purge uri=page://self/dep/level-three [event] +│ └── uri: page://self/dep/level-three +├── invalidate tags=[_dep_level-three_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_level-three_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.004 +├── get uri=page://self/dep/level-three +│ ├── uri: page://self/dep/level-three +│ ├── pre_write_cleanup uri=page://self/dep/level-three [event] +│ │ └── uri: page://self/dep/level-three +│ ├── invalidate tags=[_dep_level-three_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _dep_level-three_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.002 +│ ├── cache_policy uri=page://self/dep/level-three expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/dep/level-three +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/dep/level-three etag="3467047581" tags=[_dep_level-three_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/dep/level-three +│ │ ├── etag: "3467047581" +│ │ ├── tags[0]: _dep_level-three_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/dep/level-three tags=[_dep_level-three_] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/dep/level-three +│ │ ├── tags[0]: _dep_level-three_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── code: 200 +get uri=page://self/dep/level-one +├── uri: page://self/dep/level-one +├── pre_write_cleanup uri=page://self/dep/level-one [event] +│ └── uri: page://self/dep/level-one +├── invalidate tags=[_dep_level-one_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_level-one_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.003 +├── depends_on parent=page://self/dep/level-one child=page://self/dep/level-two childTags=[_dep_level-two_, _dep_level-three_] [event] +│ ├── parent: page://self/dep/level-one +│ ├── child: page://self/dep/level-two +│ ├── childTags[0]: _dep_level-two_ +│ └── childTags[1]: _dep_level-three_ +├── cache_policy uri=page://self/dep/level-one expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/level-one +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/level-one etag="2765543874" tags=[_dep_level-two_, _dep_level-three_ +1 items] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/level-one +│ ├── etag: "2765543874" +│ ├── tags[0]: _dep_level-two_ +│ ├── tags[1]: _dep_level-three_ +│ ├── tags[2]: _dep_level-one_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/level-one tags=[_dep_level-one_, _dep_level-two_ +1 items] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/level-one +│ ├── tags[0]: _dep_level-one_ +│ ├── tags[1]: _dep_level-two_ +│ ├── tags[2]: _dep_level-three_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/level-two +│ ├── uri: page://self/dep/level-two +│ ├── pre_write_cleanup uri=page://self/dep/level-two [event] +│ │ └── uri: page://self/dep/level-two +│ ├── invalidate tags=[_dep_level-two_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _dep_level-two_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.002 +│ ├── depends_on parent=page://self/dep/level-two child=page://self/dep/level-three childTags=[_dep_level-three_] [event] +│ │ ├── parent: page://self/dep/level-two +│ │ ├── child: page://self/dep/level-three +│ │ └── childTags[0]: _dep_level-three_ +│ ├── cache_policy uri=page://self/dep/level-two expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/dep/level-two etag="2556918568" tags=[_dep_level-three_, _dep_level-two_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── etag: "2556918568" +│ │ ├── tags[0]: _dep_level-three_ +│ │ ├── tags[1]: _dep_level-two_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/dep/level-two tags=[_dep_level-two_, _dep_level-three_] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/dep/level-two +│ │ ├── tags[0]: _dep_level-two_ +│ │ ├── tags[1]: _dep_level-three_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── get uri=page://self/dep/level-three +│ │ ├── uri: page://self/dep/level-three +│ │ └── close +│ │ └── layer: resource +│ └── close +│ └── layer: resource +└── close + └── layer: resource +get uri=page://self/dep/parent-a +├── uri: page://self/dep/parent-a +├── pre_write_cleanup uri=page://self/dep/parent-a [event] +│ └── uri: page://self/dep/parent-a +├── invalidate tags=[_dep_parent-a_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_parent-a_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.004 +├── depends_on parent=page://self/dep/parent-a child=page://self/dep/child-c childTags=[_dep_child-c_] [event] +│ ├── parent: page://self/dep/parent-a +│ ├── child: page://self/dep/child-c +│ └── childTags[0]: _dep_child-c_ +├── cache_policy uri=page://self/dep/parent-a expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/parent-a +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/parent-a etag="1107844390" tags=[_dep_child-c_, _dep_parent-a_] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/parent-a +│ ├── etag: "1107844390" +│ ├── tags[0]: _dep_child-c_ +│ ├── tags[1]: _dep_parent-a_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/parent-a tags=[_dep_parent-a_, _dep_child-c_] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/parent-a +│ ├── tags[0]: _dep_parent-a_ +│ ├── tags[1]: _dep_child-c_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/child-c +│ ├── uri: page://self/dep/child-c +│ ├── pre_write_cleanup uri=page://self/dep/child-c [event] +│ │ └── uri: page://self/dep/child-c +│ ├── invalidate tags=[_dep_child-c_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.003 +│ ├── cache_policy uri=page://self/dep/child-c expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/dep/child-c etag="2238209645" tags=[_dep_child-c_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── etag: "2238209645" +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/dep/child-c tags=[_dep_child-c_] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── layer: resource +get uri=page://self/dep/parent-b +├── uri: page://self/dep/parent-b +├── pre_write_cleanup uri=page://self/dep/parent-b [event] +│ └── uri: page://self/dep/parent-b +├── invalidate tags=[_dep_parent-b_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_parent-b_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.003 +├── depends_on parent=page://self/dep/parent-b child=page://self/dep/child-c childTags=[_dep_child-c_] [event] +│ ├── parent: page://self/dep/parent-b +│ ├── child: page://self/dep/child-c +│ └── childTags[0]: _dep_child-c_ +├── cache_policy uri=page://self/dep/parent-b expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/parent-b +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/parent-b etag="3116109313" tags=[_dep_child-c_, _dep_parent-b_] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/parent-b +│ ├── etag: "3116109313" +│ ├── tags[0]: _dep_child-c_ +│ ├── tags[1]: _dep_parent-b_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/parent-b tags=[_dep_parent-b_, _dep_child-c_] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/parent-b +│ ├── tags[0]: _dep_parent-b_ +│ ├── tags[1]: _dep_child-c_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/child-c +│ ├── uri: page://self/dep/child-c +│ └── close +│ └── layer: resource +└── close + └── layer: resource +manual_purge uri=page://self/dep/child-c +├── uri: page://self/dep/child-c +├── invalidate tags=[_dep_child-c_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_child-c_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.003 +└── close + └── result: purged +get uri=page://self/dep/parent-a +├── uri: page://self/dep/parent-a +├── pre_write_cleanup uri=page://self/dep/parent-a [event] +│ └── uri: page://self/dep/parent-a +├── invalidate tags=[_dep_parent-a_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_parent-a_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.003 +├── depends_on parent=page://self/dep/parent-a child=page://self/dep/child-c childTags=[_dep_child-c_] [event] +│ ├── parent: page://self/dep/parent-a +│ ├── child: page://self/dep/child-c +│ └── childTags[0]: _dep_child-c_ +├── cache_policy uri=page://self/dep/parent-a expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/parent-a +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/parent-a etag="1107844390" tags=[_dep_child-c_, _dep_parent-a_] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/parent-a +│ ├── etag: "1107844390" +│ ├── tags[0]: _dep_child-c_ +│ ├── tags[1]: _dep_parent-a_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/parent-a tags=[_dep_parent-a_, _dep_child-c_] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/parent-a +│ ├── tags[0]: _dep_parent-a_ +│ ├── tags[1]: _dep_child-c_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/child-c +│ ├── uri: page://self/dep/child-c +│ ├── pre_write_cleanup uri=page://self/dep/child-c [event] +│ │ └── uri: page://self/dep/child-c +│ ├── invalidate tags=[_dep_child-c_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.002 +│ ├── cache_policy uri=page://self/dep/child-c expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/dep/child-c etag="2238209645" tags=[_dep_child-c_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── etag: "2238209645" +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/dep/child-c tags=[_dep_child-c_] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/dep/child-c +│ │ ├── tags[0]: _dep_child-c_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── layer: resource +get uri=page://self/dep/parent-b +├── uri: page://self/dep/parent-b +├── pre_write_cleanup uri=page://self/dep/parent-b [event] +│ └── uri: page://self/dep/parent-b +├── invalidate tags=[_dep_parent-b_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _dep_parent-b_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.005 +├── depends_on parent=page://self/dep/parent-b child=page://self/dep/child-c childTags=[_dep_child-c_] [event] +│ ├── parent: page://self/dep/parent-b +│ ├── child: page://self/dep/child-c +│ └── childTags[0]: _dep_child-c_ +├── cache_policy uri=page://self/dep/parent-b expiry=never resolvedTtl=31536000 [event] +│ ├── uri: page://self/dep/parent-b +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=page://self/dep/parent-b etag="3116109313" tags=[_dep_child-c_, _dep_parent-b_] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: page://self/dep/parent-b +│ ├── etag: "3116109313" +│ ├── tags[0]: _dep_child-c_ +│ ├── tags[1]: _dep_parent-b_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=page://self/dep/parent-b tags=[_dep_parent-b_, _dep_child-c_] requestedTtl=31536000 saved=true [event] +│ ├── uri: page://self/dep/parent-b +│ ├── tags[0]: _dep_parent-b_ +│ ├── tags[1]: _dep_child-c_ +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── get uri=page://self/dep/child-c +│ ├── uri: page://self/dep/child-c +│ └── close +│ └── layer: resource +└── close + └── layer: resource + +=== Cache Log JSON === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-one" + }, + "open": [ + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-two" + }, + "open": [ + { + "id": "get_3", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-three" + }, + "events": [ + { + "id": "pre_write_cleanup_3", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-three" + } + }, + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-three_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.002 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-three", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-three", + "etag": "\"3467047581\"", + "tags": [ + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-three", + "tags": [ + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-two" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-two_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "depends_on_1", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/level-two", + "child": "page://self/dep/level-three", + "childTags": [ + "_dep_level-three_" + ] + } + }, + { + "id": "cache_policy_2", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-two", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-two", + "etag": "\"2687912183\"", + "tags": [ + "_dep_level-three_", + "_dep_level-two_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_2", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-two", + "tags": [ + "_dep_level-two_", + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-one" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-one_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.077 + } + }, + { + "id": "depends_on_2", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/level-one", + "child": "page://self/dep/level-two", + "childTags": [ + "_dep_level-two_", + "_dep_level-three_" + ] + } + }, + { + "id": "cache_policy_3", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-one", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_3", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-one", + "etag": "\"3589457708\"", + "tags": [ + "_dep_level-two_", + "_dep_level-three_", + "_dep_level-one_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_3", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-one", + "tags": [ + "_dep_level-one_", + "_dep_level-two_", + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_4", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-one" + }, + "close": { + "id": "cache_hit_1", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onPut", + "annotations": [], + "source": "CommandInterceptor" + }, + "open": [ + { + "id": "get_5", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-three" + }, + "events": [ + { + "id": "pre_write_cleanup_4", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-three" + } + }, + { + "id": "invalidate_5", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-three_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.002 + } + }, + { + "id": "cache_policy_4", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-three", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_4", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-three", + "etag": "\"3467047581\"", + "tags": [ + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_4", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-three", + "tags": [ + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_4", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "page://self/dep/level-three" + } + }, + { + "id": "invalidate_4", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-three_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + } + ], + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 200 + } + } + }, + { + "id": "get_6", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-one" + }, + "open": [ + { + "id": "get_7", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-two" + }, + "open": [ + { + "id": "get_8", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/level-three" + }, + "close": { + "id": "cache_hit_2", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_6", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-two" + } + }, + { + "id": "invalidate_7", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-two_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.002 + } + }, + { + "id": "depends_on_3", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/level-two", + "child": "page://self/dep/level-three", + "childTags": [ + "_dep_level-three_" + ] + } + }, + { + "id": "cache_policy_5", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-two", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_5", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-two", + "etag": "\"2556918568\"", + "tags": [ + "_dep_level-three_", + "_dep_level-two_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_5", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-two", + "tags": [ + "_dep_level-two_", + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_5", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_5", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/level-one" + } + }, + { + "id": "invalidate_6", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_level-one_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "depends_on_4", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/level-one", + "child": "page://self/dep/level-two", + "childTags": [ + "_dep_level-two_", + "_dep_level-three_" + ] + } + }, + { + "id": "cache_policy_6", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/level-one", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_6", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/level-one", + "etag": "\"2765543874\"", + "tags": [ + "_dep_level-two_", + "_dep_level-three_", + "_dep_level-one_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_6", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/level-one", + "tags": [ + "_dep_level-one_", + "_dep_level-two_", + "_dep_level-three_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_6", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_9", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/parent-a" + }, + "open": [ + { + "id": "get_10", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/child-c" + }, + "events": [ + { + "id": "pre_write_cleanup_8", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/child-c" + } + }, + { + "id": "invalidate_9", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_child-c_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_7", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/child-c", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_7", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/child-c", + "etag": "\"2238209645\"", + "tags": [ + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_7", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/child-c", + "tags": [ + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_7", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_7", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/parent-a" + } + }, + { + "id": "invalidate_8", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_parent-a_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + }, + { + "id": "depends_on_5", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/parent-a", + "child": "page://self/dep/child-c", + "childTags": [ + "_dep_child-c_" + ] + } + }, + { + "id": "cache_policy_8", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/parent-a", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_8", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/parent-a", + "etag": "\"1107844390\"", + "tags": [ + "_dep_child-c_", + "_dep_parent-a_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_8", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/parent-a", + "tags": [ + "_dep_parent-a_", + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_8", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_11", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/parent-b" + }, + "open": [ + { + "id": "get_12", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/child-c" + }, + "close": { + "id": "cache_hit_3", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_9", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/parent-b" + } + }, + { + "id": "invalidate_10", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_parent-b_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "depends_on_6", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/parent-b", + "child": "page://self/dep/child-c", + "childTags": [ + "_dep_child-c_" + ] + } + }, + { + "id": "cache_policy_9", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/parent-b", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_9", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/parent-b", + "etag": "\"3116109313\"", + "tags": [ + "_dep_child-c_", + "_dep_parent-b_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_9", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/parent-b", + "tags": [ + "_dep_parent-b_", + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_9", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "manual_purge_1", + "type": "manual_purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge.json", + "context": { + "uri": "page://self/dep/child-c" + }, + "events": [ + { + "id": "invalidate_11", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_child-c_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + } + ], + "close": { + "id": "manual_purge_result_1", + "type": "manual_purge_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge_result.json", + "context": { + "result": "purged" + } + } + }, + { + "id": "get_13", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/parent-a" + }, + "open": [ + { + "id": "get_14", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/child-c" + }, + "events": [ + { + "id": "pre_write_cleanup_11", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/child-c" + } + }, + { + "id": "invalidate_13", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_child-c_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.002 + } + }, + { + "id": "cache_policy_10", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/child-c", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_10", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/child-c", + "etag": "\"2238209645\"", + "tags": [ + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_10", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/child-c", + "tags": [ + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_10", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_10", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/parent-a" + } + }, + { + "id": "invalidate_12", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_parent-a_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "depends_on_7", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/parent-a", + "child": "page://self/dep/child-c", + "childTags": [ + "_dep_child-c_" + ] + } + }, + { + "id": "cache_policy_11", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/parent-a", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_11", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/parent-a", + "etag": "\"1107844390\"", + "tags": [ + "_dep_child-c_", + "_dep_parent-a_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_11", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/parent-a", + "tags": [ + "_dep_parent-a_", + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_11", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_15", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/parent-b" + }, + "open": [ + { + "id": "get_16", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/dep/child-c" + }, + "close": { + "id": "cache_hit_4", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "pre_write_cleanup_12", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/dep/parent-b" + } + }, + { + "id": "invalidate_14", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_dep_parent-b_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + }, + { + "id": "depends_on_8", + "type": "depends_on", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/depends_on.json", + "context": { + "parent": "page://self/dep/parent-b", + "child": "page://self/dep/child-c", + "childTags": [ + "_dep_child-c_" + ] + } + }, + { + "id": "cache_policy_12", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/dep/parent-b", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_12", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/dep/parent-b", + "etag": "\"3116109313\"", + "tags": [ + "_dep_child-c_", + "_dep_parent-b_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_12", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/dep/parent-b", + "tags": [ + "_dep_parent-b_", + "_dep_child-c_" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_12", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ] +} +Schema validation: OK (107 entries) diff --git a/demo/logs/run-donut.log b/demo/logs/run-donut.log new file mode 100644 index 00000000..36f34c39 --- /dev/null +++ b/demo/logs/run-donut.log @@ -0,0 +1,600 @@ +=== Donut Cache Demo === + +This demo executes the following scenarios: + +1. Initial access to blog-posting + - BlogPosting (donut outer shell) is created + - Comment (dynamic inner) is embedded + - Both donut structure and content are cached + +2. Re-access blog-posting + - Should be cache-hit (full page from cache) + +3. Invalidate comment (inner content only) + - Comment cache is purged + - Donut structure remains, inner content refreshed + +4. Access blog-posting after comment invalidation + - Donut is found, but needs refresh + - Only Comment is regenerated, donut structure reused + +Every donut write and refresh also records what it told the CDN (cdn_headers): +the literal CDN-Cache-Control the response carries - including the setter's +default of 10 that no put_donut field reveals - and the Surrogate-Key list a +purge's tags must reach to drop the page at the edge. + +=== Executing... === +=== Cache Log Tree === +get uri=page://self/html/blog-posting +├── uri: page://self/html/blog-posting +├── cache_miss layer=donut [event] +│ └── layer: donut +├── put_donut uri=page://self/html/blog-posting [event] +│ └── uri: page://self/html/blog-posting +├── cdn_headers uri=page://self/html/blog-posting surrogateKeys=[blog-posting-page, _html_blog-posting_ +2 items] [event] +│ ├── uri: page://self/html/blog-posting +│ ├── surrogateKeys[0]: blog-posting-page +│ ├── surrogateKeys[1]: _html_blog-posting_ +│ ├── surrogateKeys[2]: _html_comment_ +│ └── surrogateKeys[3]: comment01 +├── pre_write_cleanup uri=page://self/html/blog-posting [event] +│ └── uri: page://self/html/blog-posting +├── invalidate tags=[_html_blog-posting_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _html_blog-posting_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.006 +├── save_etag uri=page://self/html/blog-posting etag="4066413688" tags=[blog-posting-page, _html_blog-posting_ +2 items] saved=true [event] +│ ├── uri: page://self/html/blog-posting +│ ├── etag: "4066413688" +│ ├── tags[0]: blog-posting-page +│ ├── tags[1]: _html_blog-posting_ +│ ├── tags[2]: _html_comment_ +│ ├── tags[3]: comment01 +│ └── saved: 1 +├── save_donut_view uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page +2 items] saved=true [event] +│ ├── uri: page://self/html/blog-posting +│ ├── tags[0]: _html_blog-posting_ +│ ├── tags[1]: blog-posting-page +│ ├── tags[2]: _html_comment_ +│ ├── tags[3]: comment01 +│ └── saved: 1 +├── save_donut uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page] saved=true [event] +│ ├── uri: page://self/html/blog-posting +│ ├── tags[0]: _html_blog-posting_ +│ ├── tags[1]: blog-posting-page +│ └── saved: 1 +├── get uri=page://self/html/comment +│ ├── uri: page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ │ └── uri: page://self/html/comment +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _html_comment_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.106 +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── etag: "1889150619" +│ │ ├── tags[0]: comment01 +│ │ ├── tags[1]: _html_comment_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── tags[0]: _html_comment_ +│ │ ├── tags[1]: comment01 +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── layer: donut-view +get uri=page://self/html/blog-posting +├── uri: page://self/html/blog-posting +└── close + └── layer: donut-view +manual_purge uri=page://self/html/comment +├── uri: page://self/html/comment +├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _html_comment_ +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.004 +└── close + └── result: purged +get uri=page://self/html/blog-posting +├── uri: page://self/html/blog-posting +├── cache_hit layer=donut [event] +│ └── layer: donut +├── refresh_donut uri=page://self/html/blog-posting [event] +│ └── uri: page://self/html/blog-posting +├── cdn_headers uri=page://self/html/blog-posting surrogateKeys=[blog-posting-page, _html_blog-posting_ +2 items] [event] +│ ├── uri: page://self/html/blog-posting +│ ├── surrogateKeys[0]: blog-posting-page +│ ├── surrogateKeys[1]: _html_blog-posting_ +│ ├── surrogateKeys[2]: _html_comment_ +│ └── surrogateKeys[3]: comment01 +├── save_etag uri=page://self/html/blog-posting etag="4066413688" tags=[blog-posting-page, _html_blog-posting_ +2 items] saved=true [event] +│ ├── uri: page://self/html/blog-posting +│ ├── etag: "4066413688" +│ ├── tags[0]: blog-posting-page +│ ├── tags[1]: _html_blog-posting_ +│ ├── tags[2]: _html_comment_ +│ ├── tags[3]: comment01 +│ └── saved: 1 +├── save_donut_view uri=page://self/html/blog-posting tags=[_html_blog-posting_, blog-posting-page +2 items] saved=true [event] +│ ├── uri: page://self/html/blog-posting +│ ├── tags[0]: _html_blog-posting_ +│ ├── tags[1]: blog-posting-page +│ ├── tags[2]: _html_comment_ +│ ├── tags[3]: comment01 +│ └── saved: 1 +├── get uri=page://self/html/comment +│ ├── uri: page://self/html/comment +│ ├── pre_write_cleanup uri=page://self/html/comment [event] +│ │ └── uri: page://self/html/comment +│ ├── invalidate tags=[_html_comment_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _html_comment_ +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.003 +│ ├── cache_policy uri=page://self/html/comment expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=page://self/html/comment etag="1889150619" tags=[comment01, _html_comment_] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── etag: "1889150619" +│ │ ├── tags[0]: comment01 +│ │ ├── tags[1]: _html_comment_ +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=page://self/html/comment tags=[_html_comment_, comment01] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: page://self/html/comment +│ │ ├── tags[0]: _html_comment_ +│ │ ├── tags[1]: comment01 +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── layer: donut-view + +=== Cache Log JSON === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting" + }, + "open": [ + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.106 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut" + } + }, + { + "id": "put_donut_1", + "type": "put_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/put_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "requestedTtl": null, + "sMaxAge": null + } + }, + { + "id": "cdn_headers_1", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/blog-posting" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_blog-posting_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.006 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting", + "etag": "\"4066413688\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_view_1", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_1", + "type": "save_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "get_3", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting" + }, + "close": { + "id": "cache_hit_1", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "donut-view" + } + } + }, + { + "id": "manual_purge_1", + "type": "manual_purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.004 + } + } + ], + "close": { + "id": "manual_purge_result_1", + "type": "manual_purge_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/manual_purge_result.json", + "context": { + "result": "purged" + } + } + }, + { + "id": "get_4", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/blog-posting" + }, + "open": [ + { + "id": "get_5", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "page://self/html/comment" + }, + "events": [ + { + "id": "pre_write_cleanup_3", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "page://self/html/comment" + } + }, + { + "id": "invalidate_4", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_html_comment_" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_2", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "page://self/html/comment", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_3", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/comment", + "etag": "\"1889150619\"", + "tags": [ + "comment01", + "_html_comment_" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_2", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "page://self/html/comment", + "tags": [ + "_html_comment_", + "comment01" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_4", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "cache_hit_2", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "donut" + } + }, + { + "id": "refresh_donut_1", + "type": "refresh_donut", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/refresh_donut.json", + "context": { + "uri": "page://self/html/blog-posting" + } + }, + { + "id": "cdn_headers_2", + "type": "cdn_headers", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cdn_headers.json", + "context": { + "uri": "page://self/html/blog-posting", + "headers": { + "CDN-Cache-Control": "max-age=10 stale-while-revalidate=10", + "Surrogate-Key": "blog-posting-page _html_blog-posting_ _html_comment_ comment01" + }, + "surrogateKeys": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ] + } + }, + { + "id": "save_etag_4", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "page://self/html/blog-posting", + "etag": "\"4066413688\"", + "tags": [ + "blog-posting-page", + "_html_blog-posting_", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + }, + { + "id": "save_donut_view_2", + "type": "save_donut_view", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_donut_view.json", + "context": { + "uri": "page://self/html/blog-posting", + "tags": [ + "_html_blog-posting_", + "blog-posting-page", + "_html_comment_", + "comment01" + ], + "requestedTtl": null, + "saved": true + } + } + ], + "close": { + "id": "cache_hit_3", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "donut-view" + } + } + } + ] +} +Schema validation: OK (36 entries) diff --git a/demo/logs/run.log b/demo/logs/run.log new file mode 100644 index 00000000..9cb06fa9 --- /dev/null +++ b/demo/logs/run.log @@ -0,0 +1,457 @@ +*** onGet() method invoked *** +get +200 +ETag:"3651684678" +Last-Modified:Wed, 19 Aug 2026 21:58:43 GMT +Cache-Control:max-age=31536000 +{ + "name": "bear", + "update": 0 +} + +get +200 +ETag:"3651684678" +Last-Modified:Wed, 19 Aug 2026 21:58:43 GMT +Cache-Control:max-age=31536000 +Age:0 +{ + "name": "bear", + "update": 0 +} + +*** onPatch() method invoked *** +*** onGet() method invoked *** +patch +200 +ETag:"294422241" +Last-Modified:Wed, 19 Aug 2026 21:58:43 GMT +Cache-Control:max-age=31536000 +{ + "name": "kuma", + "update": 1 +} + +patch +200 +ETag:"294422241" +Last-Modified:Wed, 19 Aug 2026 21:58:43 GMT +Cache-Control:max-age=31536000 +Age:0 +{ + "name": "kuma", + "update": 1 +} + +patch +200 +ETag:"294422241" +Last-Modified:Wed, 19 Aug 2026 21:58:43 GMT +Cache-Control:max-age=31536000 +Age:0 +{ + "name": "kuma", + "update": 1 +} + +conditional GET with the held validator -> 304 (etag hit) +conditional GET with a stale validator -> 200 (etag miss) + +=== Cache Log Tree === +get uri=app://self/user?id=1 +├── uri: app://self/user?id=1 +├── pre_write_cleanup uri=app://self/user?id=1 [event] +│ └── uri: app://self/user?id=1 +├── invalidate tags=[_user_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _user_id=1 +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.223 +├── cache_policy uri=app://self/user?id=1 expiry=never resolvedTtl=31536000 [event] +│ ├── uri: app://self/user?id=1 +│ ├── expiry: never +│ └── resolvedTtl: 31536000 +├── save_etag uri=app://self/user?id=1 etag="3651684678" tags=[_user_id=1] requestedTtl=31536000 (+1 more) [event] +│ ├── uri: app://self/user?id=1 +│ ├── etag: "3651684678" +│ ├── tags[0]: _user_id=1 +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +├── save_value uri=app://self/user?id=1 tags=[_user_id=1] requestedTtl=31536000 saved=true [event] +│ ├── uri: app://self/user?id=1 +│ ├── tags[0]: _user_id=1 +│ ├── requestedTtl: 31536000 +│ └── saved: 1 +└── close + └── layer: resource +get uri=app://self/user?id=1 +├── uri: app://self/user?id=1 +└── close + └── layer: resource +command method=onPatch source=CommandInterceptor +├── method: onPatch +├── source: CommandInterceptor +├── purge uri=app://self/user?id=1 [event] +│ └── uri: app://self/user?id=1 +├── invalidate tags=[_user_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ ├── tags[0]: _user_id=1 +│ ├── roPool: invalidated +│ ├── etagPool: invalidated +│ ├── cdn: skipped +│ └── durationMs: 0.005 +├── get uri=app://self/user?id=1 +│ ├── uri: app://self/user?id=1 +│ ├── pre_write_cleanup uri=app://self/user?id=1 [event] +│ │ └── uri: app://self/user?id=1 +│ ├── invalidate tags=[_user_id=1] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] +│ │ ├── tags[0]: _user_id=1 +│ │ ├── roPool: invalidated +│ │ ├── etagPool: invalidated +│ │ ├── cdn: skipped +│ │ └── durationMs: 0.003 +│ ├── cache_policy uri=app://self/user?id=1 expiry=never resolvedTtl=31536000 [event] +│ │ ├── uri: app://self/user?id=1 +│ │ ├── expiry: never +│ │ └── resolvedTtl: 31536000 +│ ├── save_etag uri=app://self/user?id=1 etag="294422241" tags=[_user_id=1] requestedTtl=31536000 (+1 more) [event] +│ │ ├── uri: app://self/user?id=1 +│ │ ├── etag: "294422241" +│ │ ├── tags[0]: _user_id=1 +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ ├── save_value uri=app://self/user?id=1 tags=[_user_id=1] requestedTtl=31536000 saved=true [event] +│ │ ├── uri: app://self/user?id=1 +│ │ ├── tags[0]: _user_id=1 +│ │ ├── requestedTtl: 31536000 +│ │ └── saved: 1 +│ └── close +│ └── layer: resource +└── close + └── code: 200 +get uri=app://self/user?id=1 +├── uri: app://self/user?id=1 +└── close + └── layer: resource +get uri=app://self/user?id=1 +├── uri: app://self/user?id=1 +└── close + └── layer: resource +get uri=app://self/user?id=1 +├── uri: app://self/user?id=1 +└── close + └── layer: resource +conditional_request ifNoneMatch="294422241" +├── ifNoneMatch: "294422241" +└── close + └── layer: etag +conditional_request ifNoneMatch="stale" +├── ifNoneMatch: "stale" +└── close + └── layer: etag + +=== Cache Log JSON === +{ + "$schema": "https://koriym.github.io/Koriym.SemanticLogger/schemas/semantic-log.json", + "open": [ + { + "id": "get_1", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "events": [ + { + "id": "pre_write_cleanup_1", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/user?id=1" + } + }, + { + "id": "invalidate_1", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_user_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.223 + } + }, + { + "id": "cache_policy_1", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/user?id=1", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_1", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/user?id=1", + "etag": "\"3651684678\"", + "tags": [ + "_user_id=1" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_1", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/user?id=1", + "tags": [ + "_user_id=1" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_1", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_2", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "close": { + "id": "cache_hit_1", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "command_1", + "type": "command", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command.json", + "context": { + "method": "onPatch", + "annotations": [], + "source": "CommandInterceptor" + }, + "open": [ + { + "id": "get_3", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "events": [ + { + "id": "pre_write_cleanup_2", + "type": "pre_write_cleanup", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pre_write_cleanup.json", + "context": { + "uri": "app://self/user?id=1" + } + }, + { + "id": "invalidate_3", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_user_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.003 + } + }, + { + "id": "cache_policy_2", + "type": "cache_policy", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json", + "context": { + "uri": "app://self/user?id=1", + "expiry": "never", + "expirySecond": null, + "expiryAt": null, + "resolvedTtl": 31536000 + } + }, + { + "id": "save_etag_2", + "type": "save_etag", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", + "context": { + "uri": "app://self/user?id=1", + "etag": "\"294422241\"", + "tags": [ + "_user_id=1" + ], + "requestedTtl": 31536000, + "saved": true + } + }, + { + "id": "save_value_2", + "type": "save_value", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_value.json", + "context": { + "uri": "app://self/user?id=1", + "tags": [ + "_user_id=1" + ], + "requestedTtl": 31536000, + "saved": true + } + } + ], + "close": { + "id": "cache_miss_2", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "resource" + } + } + } + ], + "events": [ + { + "id": "purge_1", + "type": "purge", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/purge.json", + "context": { + "uri": "app://self/user?id=1" + } + }, + { + "id": "invalidate_2", + "type": "invalidate", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/invalidate.json", + "context": { + "tags": [ + "_user_id=1" + ], + "roPool": "invalidated", + "etagPool": "invalidated", + "cdn": "skipped", + "durationMs": 0.005 + } + } + ], + "close": { + "id": "command_result_1", + "type": "command_result", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/command_result.json", + "context": { + "code": 200 + } + } + }, + { + "id": "get_4", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "close": { + "id": "cache_hit_2", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_5", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "close": { + "id": "cache_hit_3", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "get_6", + "type": "get", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/get.json", + "context": { + "uri": "app://self/user?id=1" + }, + "close": { + "id": "cache_hit_4", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "resource" + } + } + }, + { + "id": "conditional_request_1", + "type": "conditional_request", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/conditional_request.json", + "context": { + "ifNoneMatch": "\"294422241\"" + }, + "close": { + "id": "cache_hit_5", + "type": "cache_hit", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_hit.json", + "context": { + "layer": "etag" + } + } + }, + { + "id": "conditional_request_2", + "type": "conditional_request", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/conditional_request.json", + "context": { + "ifNoneMatch": "\"stale\"" + }, + "close": { + "id": "cache_miss_3", + "type": "cache_miss", + "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_miss.json", + "context": { + "layer": "etag" + } + } + } + ] +} +Schema validation: OK (30 entries) diff --git a/docs/cache-traceability-report.ja.md b/docs/cache-traceability-report.ja.md new file mode 100644 index 00000000..3d55bb8f --- /dev/null +++ b/docs/cache-traceability-report.ja.md @@ -0,0 +1,75 @@ +# キャッシュ追跡可能性レポート — 次期リリース（1.16.2 → Unreleased） + +2026-08-19 にマージされた 7 PR（#191, #192, #193, #194, #195, #196, #198）を含む Unreleased セクション全体について、キャッシュの「追跡可能性（traceability）」と「明示性（explicitness）」がどれだけ高まったかをまとめる。 + +## 1. 前版（1.16.2）で観測不可能だったもの + +旧ログはフラットな op-string 形式（`RepositoryLoggerInterface`）で、以下の故障・判断クラスが記録されず、ログ読者には区別が付かなかった。 + +| # | 沈黙していた事態 | 前版での見え方 | +|---|---|---| +| 1 | キャッシュバックエンドの停止（Redis/Memcached 不接続） | 普通のミスの連続と同一（symfony/cache アダプタは投げずに miss/false を返す） | +| 2 | プールが書き込みを拒否（save が false を返した） | 成功した save と同一 | +| 3 | CDN パージが未設定（NullPurger） | 実際にパージされた `purged` と同一 | +| 4 | CDN パージの失敗 | ローカル無効化だけが起き、CDN は stale のまま・記録なし | +| 5 | value エントリの保存がレンダリングに依存し、renderer 不在で保存が警告に劣化（#193） | キャッシュが空のまま・理由の記録なし | +| 6 | `Surrogate-Key` 非宣言ページの donut テンプレートが無タグで保存され、どの `invalidateTags()` も届かない（#194） | purge が content と validator を落として不死の shell を残す・記録なし | +| 7 | 独自 `Surrogate-Key` 宣言で埋め込み依存の追跡が失われる 1.16.0 退行（#195） | purge 済みの子を配信し続ける・記録なし | +| 8 | ログが記録した TTL と実際に保存された TTL の不一致（負の TTL をそのまま記録）、`sMaxAge` という誤ラベル | ログがストアの事実と矛盾 | +| 9 | リソースが宣言した寿命（preset / expirySecond / expiryAt のどれが決めたか）（#196） | 解決後の数値だけでは `never`（無効化まで生きる意図）と意図的な 1 年 TTL が区別できない | +| 10 | 304 判断そのもの（ETag プールだけでリクエスト全体に回答） | どの `get` スコープにも現れない | +| 11 | 書き込み・無効化の発起者がフレームワークかアプリか | 区別不可 | +| 12 | アプリ自身の `SemanticLoggerInterface` 束縛の奪取（#191） | install 順次第で静かに入れ替わる | + +## 2. 後版（次期リリース）での可視化 + +| # | 事態 | 記録するコンテキスト | +|---|---|---| +| 1 | ストア停止 | `pool_error {key, operation, error, exceptionClass}` — アダプタ自身の報告をそのまま運ぶ | +| 2 | 書き込み拒否 | 全 5 save コンテキストの `saved` フィールド（accept/reject） | +| 3 | CDN 未設定 | `invalidate.cdn = skipped`（tri-state: `purged` / `failed` / `skipped`） | +| 4 | CDN パージ失敗 | `invalidate {cdn: failed}` + fail-closed（ローカル無効化 → 記録 → 例外伝播） | +| 5 | レンダリングなし保存 | 修正済み。value パスは `$ro->view === null` で body にフォールバックし、ETag は body を追う | +| 6 | 無タグテンプレート | 修正済み。テンプレートは自 URI タグで保存され `purge($uri)` が届く | +| 7 | 依存追跡の喪失 | 修正済み。宣言キーと埋め込み依存が併存し、`depends_on` で追跡が記録される | +| 8 | TTL の矛盾 | 修正済み。要求値は記録時点でクランプ、フィールド名は `requestedTtl`（要求した値であり、ストアの実効寿命ではない） | +| 9 | 寿命の宣言 | `cache_policy {expiry, expirySecond, expiryAt, resolvedTtl}` — 3 宣言のうち決め手だけが記録され、`resolvedTtl` と読み比べられる | +| 10 | 304 判断 | `conditional_request {ifNoneMatch}` が `cache_hit/cache_miss{layer: etag}` で閉じる | +| 11 | 発起者 | `command.source`（interceptor 名）と `manual_store` / `manual_purge` / `manual_invalidate` スコープ（結果は close に） | +| 12 | 束縛の奪取 | `#[CacheLog]` 修飾子で分離。アプリの束縛は無修飾のまま生きる | + +## 3. 明示性を支える機構（量） + +- **28 の型付きコンテキスト**（`src/Log/Context/`）、それぞれに公開 JSON Schema（`docs/schemas/context/`、28 ファイル、うち 9 が enum を持つ） +- **木構造 = 依存構造**: open/event/close の入れ子がそのまま embed/依存の構造。親の子は親の下にぶら下がる +- **ソース記録の原則**: 効果が確定した場所で記録する（lifetime はクランプした場所で、CDN ヘッダは setter 適用後に読み戻し、cleanup は実行者が `pre_write_cleanup` でマーク） +- **unknown ≠ absent**: 判別できないものは推測せず `unknown` と記録（`operation` のフォールバック等） + +## 4. 主張を守る強制レイヤ + +1. **スキーマ検証**: テストの全 flush が公開スキーマに照合され、diagnostics も fail 扱い（`failOnDiagnostics`）。ロガーが投げなくてもプロトコル退行はテストが落とす +2. **自己検証デモ**: 4 スクリプト（`run.php` / `run-dependency.php` / `run-donut.php` / `run-degraded.php`）がセッションツリーと JSON を出力し、オフライン照合で違反時は非ゼロ終了 +3. **語彙閉包**: `DemoLogCoverageTest`（6 tests / 22 assertions）が、全コンテキストクラス・全スキーマ enum 値・全 save コンテキストの `saved` 両結果・全 `command.source` 生成元がデモ出力に現れることを要求。デモされないコンテキストは出荷できない +4. **シーケンス pin**: donut 書き込みのイベント順序そのものを assert。発火の増減はレビュー対象の変更になる +5. **ミューテーション検証**: 発火地点の削除・結果語の反転・既定値の変更を殺す pin を mutation testing で選定 + +## 5. 実測エビデンス + +- 全スイート **283 tests / 812 assertions 緑**（1.x 先端 `283badd`） +- 修正系 PR の pin テストは旧コードで FAIL を確認済み（バグの再現性を検証してから修正）: + - #193: 旧コードで `FakeThrowingRenderer` に到達し warning 化、ETag が body を追わない + - #194: 旧コードで `save_donut` が `"tags":[]` を記録（無タグ = 無効化不能をイベントレベルで実測） + - #195: 旧コードで宣言キーと埋め込み依存の併存が崩れる 2 テストが FAIL + - #191: 旧コードでアプリの logger 束縛が奪われる FAIL、`__unserialize` 復元後の全書き込みが uninitialized property で Error +- デモログを `demo/logs/` に収録（4 ファイル計 5,602 行、全デモ exit 0・オフラインスキーマ照合通過） +- マルチ環境: ext-redis / Predis、POSIX / Windows でのメッセージ差異をポータブルな契約 assert に整理 + +## 6. 宣言する境界（ログが記録しないもの） + +- CDN 自体の挙動（エッジが実際に保持・パージしたか）はログの外。記録するのは「CDN に何を送ったか」まで +- Memcached の `pool_error` は実機サーバなしの閉ポートテストでは Redis のみで検証。配線は symfony の共通機構 +- 記録は既定で off（`NullSemanticLogger`）。健全なセッションに故障エントリは含まれないことを実測済み + +## 7. まとめ + +前版では「キャッシュが効かない」「古いコンテンツが残る」とき、ログには原因と無関係なミスの列しかなかった。次期リリースでは、保存・参照・無効化・304・CDN・障害の各判断が、それが確定した場所で型付きイベントとして記録され、公開スキーマ・デモ・ミューテーション選定の pin で「ログが嘘をつかない」こと自体がテストされる。沈黙していた 12 の故障・判断クラス（§1）のすべてに記録経路か修正が入った。 diff --git a/docs/cache-traceability-report.md b/docs/cache-traceability-report.md new file mode 100644 index 00000000..909160f5 --- /dev/null +++ b/docs/cache-traceability-report.md @@ -0,0 +1,75 @@ +# Cache Traceability Report — Next Release (1.16.2 → Unreleased) + +How much the next release improves cache **traceability** and **explicitness**, covering the whole Unreleased section including the seven PRs merged on 2026-08-19 (#191, #192, #193, #194, #195, #196, #198). + +## 1. What 1.16.2 could not observe + +The previous log was a flat op-string format (`RepositoryLoggerInterface`). The following failure and decision classes went unrecorded — indistinguishable to a log reader. + +| # | Silent condition | How it looked before | +|---|---|---| +| 1 | Cache backend down (Redis/Memcached unreachable) | Identical to a run of ordinary misses (symfony/cache adapters answer miss/false instead of throwing) | +| 2 | Pool refusing a write (save returning `false`) | Identical to a successful save | +| 3 | No CDN purger configured (NullPurger) | Identical to a real purge (`purged`) | +| 4 | CDN purge failure | Local invalidation happened, CDN stayed stale, nothing recorded | +| 5 | Value-entry stores depending on rendering; without a renderer every store degraded to a warning (#193) | Cache stayed empty, no reason recorded | +| 6 | Donut templates of pages declaring no `Surrogate-Key` stored untagged, unreachable by any `invalidateTags()` (#194) | Purge dropped content and validator, leaving an immortal shell, unrecorded | +| 7 | 1.16.0 regression: declaring a custom `Surrogate-Key` lost embed dependency tracking (#195) | Purged children kept being served, unrecorded | +| 8 | Logged TTL contradicting the stored TTL (negative lifetimes recorded verbatim), the misleading `sMaxAge` label | The log contradicted the store's facts | +| 9 | Which declaration decided an entry's lifetime (preset / `expirySecond` / `expiryAt`) (#196) | The resolved number alone cannot separate `never` (live until invalidated) from a deliberate 1-year TTL | +| 10 | The 304 decision itself (the whole request answered from the ETag pool) | Appeared in no `get` scope | +| 11 | Who initiated a write or invalidation — framework or application | Indistinguishable | +| 12 | Hijack of the application's own `SemanticLoggerInterface` binding (#191) | Silently swapped depending on install order | + +## 2. What the next release records + +| # | Condition | Recording context | +|---|---|---| +| 1 | Store down | `pool_error {key, operation, error, exceptionClass}` — the adapter's own report, carried | +| 2 | Write refused | `saved` field on all five save contexts (accept/reject) | +| 3 | No CDN configured | `invalidate.cdn = skipped` (tri-state: `purged` / `failed` / `skipped`) | +| 4 | CDN purge failure | `invalidate {cdn: failed}` + fail-closed (local pools first, outcome logged, then the exception propagates) | +| 5 | Store without rendering | Fixed. The value path falls back to the body with `$ro->view === null`, and the ETag follows the body | +| 6 | Untagged template | Fixed. Templates are stored under their own URI tag, so `purge($uri)` reaches them | +| 7 | Lost dependency tracking | Fixed. Declared keys and embed dependencies coexist; tracking is recorded as `depends_on` | +| 8 | TTL contradiction | Fixed. The requested lifetime is clamped where recorded; the field is `requestedTtl` — what was asked, not the store's effective lifetime | +| 9 | Declared lifetime | `cache_policy {expiry, expirySecond, expiryAt, resolvedTtl}` — exactly the deciding declaration is recorded, readable against `resolvedTtl` | +| 10 | 304 decision | `conditional_request {ifNoneMatch}` closes with `cache_hit`/`cache_miss` at layer `etag` | +| 11 | Initiator | `command.source` (the producing interceptor) and `manual_store` / `manual_purge` / `manual_invalidate` scopes, outcome on the close | +| 12 | Binding hijack | Separated behind the `#[CacheLog]` qualifier; the application's binding stays untouched | + +## 3. The mechanisms behind explicitness, quantified + +- **28 typed contexts** (`src/Log/Context/`), each with a published JSON Schema (`docs/schemas/context/`, 28 files, 9 with enums) +- **Tree structure = dependency structure**: open/event/close nesting *is* the embed/dependency structure — a parent's children hang under it +- **Record at the source**: effects are recorded where they become final (lifetimes clamped where logged, CDN headers read back after the setters ran, cleanup marked by the writer via `pre_write_cleanup`) +- **unknown ≠ absent**: what cannot be discriminated is recorded as `unknown`, never guessed (e.g. the `operation` fallback) + +## 4. Enforcement layers defending the claims + +1. **Schema validation** — every test flush is validated against the published schemas with diagnostics treated as failures (`failOnDiagnostics`); a logging-protocol regression fails the suite even though the logger never throws +2. **Self-verifying demos** — four scripts (`run.php` / `run-dependency.php` / `run-donut.php` / `run-degraded.php`) print the session tree and JSON and validate offline, exiting non-zero on any violation +3. **Vocabulary closure** — `DemoLogCoverageTest` (6 tests / 22 assertions) requires every context class, every schema enum value, both `saved` outcomes per save context, and all `command.source` producers to appear in demo output; an undemonstrated context cannot ship +4. **Sequence pins** — the exact event order of the donut writes is asserted, so any added or removed emission is a reviewed change +5. **Mutation verification** — pins were selected by mutation testing: removing an emission site, inverting an outcome word, changing a default + +## 5. Measured evidence + +- Full suite: **283 tests / 812 assertions, green** (1.x tip `283badd`) +- Every fix PR's pin tests were confirmed FAIL on the old code (reproduction before fix): + - #193: old code reached `FakeThrowingRenderer` and degraded to a warning; the ETag did not follow the body + - #194: old code recorded `save_donut` with `"tags":[]` — untagged = unreachable, observed at event level + - #195: two tests FAIL on old code where declared keys and embed dependencies broke each other + - #191: old code hijacked the app's logger binding (FAIL); writes after `__unserialize` restore errored on an uninitialized property +- Demo logs are committed under `demo/logs/` (4 files, 5,602 lines total; every demo exits 0 and passes offline schema validation) +- Portability: ext-redis / Predis and POSIX / Windows message differences are pinned as portable contract assertions + +## 6. Declared boundaries — what the log does not record + +- The CDN's own behavior (what the edge actually held or purged) is outside the log; it records what was *sent* to the CDN +- Memcached `pool_error` is verified with a closed-port probe only for Redis; the wiring is symfony's shared mechanism +- Recording is off by default (`NullSemanticLogger`); a healthy session was measured to contain no failure entries + +## 7. Summary + +In 1.16.2, when "the cache doesn't work" or "stale content survives", the log held a run of misses unrelated to the cause. In the next release, every decision — store, read, invalidation, 304, CDN, failure — is recorded as a typed event at the site where it becomes true, and the log's honesty itself is tested via published schemas, self-verifying demos, and mutation-selected pins. All twelve previously silent failure and decision classes (§1) now have a recording path or a fix. From 39fafe5e224317d2e213463448b2e2ad18a5a867 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Thu, 20 Aug 2026 07:20:31 +0900 Subject: [PATCH 2/2] Fix the stale ttl echo in the degraded demo and a report overstatement MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The session I echo still showed the pre-#192 log vocabulary (put_donut{ttl: ...}) while the tree below it prints requestedTtl. The API argument names (ttl/sMaxAge) are unchanged; only the described log fields were stale. Log re-captured. Report §1 row 5: stores degrade to a warning when the renderer throws, not when none is bound (an unbound renderer falls back to JsonRenderer and the store succeeds). --- demo/logs/run-degraded.log | 68 ++++++++++++++-------------- demo/run-degraded.php | 4 +- docs/cache-traceability-report.ja.md | 2 +- docs/cache-traceability-report.md | 2 +- 4 files changed, 38 insertions(+), 38 deletions(-) diff --git a/demo/logs/run-degraded.log b/demo/logs/run-degraded.log index 94a815b5..6ea86dfe 100644 --- a/demo/logs/run-degraded.log +++ b/demo/logs/run-degraded.log @@ -79,14 +79,14 @@ get uri=app://self/view ├── pre_write_cleanup uri=app://self/view [event] ├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/view etag="3559920818" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/view etag="844952131" tags=[_view_] requestedTtl=31536000 (+1 more) [event] ├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=true [event] └── layer=resource manual_store uri=app://self/view ├── pre_write_cleanup uri=app://self/view [event] ├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/view etag="3559920818" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/view etag="844952131" tags=[_view_] requestedTtl=31536000 (+1 more) [event] ├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=true [event] └── result=stored manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] @@ -134,7 +134,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.084 + "durationMs": 0.283 } } ], @@ -218,7 +218,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.005 + "durationMs": 0.006 } }, { @@ -372,7 +372,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.003 + "durationMs": 0.014 } } ], @@ -594,7 +594,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/view", - "etag": "\"3559920818\"", + "etag": "\"844952131\"", "tags": [ "_view_" ], @@ -652,7 +652,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.005 + "durationMs": 0.004 } }, { @@ -673,7 +673,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/view", - "etag": "\"3559920818\"", + "etag": "\"844952131\"", "tags": [ "_view_" ], @@ -727,7 +727,7 @@ manual_invalidate tags=[_demo_manual_tag_, _demo_second_tag_] "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.005 + "durationMs": 0.006 } } ], @@ -794,7 +794,7 @@ get uri=app://self/value ├── pre_write_cleanup uri=app://self/value [event] ├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=purged (+1 more) [event] ├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/value etag="2442337131" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/value etag="1359910855" tags=[_value_] requestedTtl=31536000 (+1 more) [event] ├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=true [event] └── layer=resource manual_purge uri=app://self/value @@ -853,7 +853,7 @@ manual_purge uri=app://self/value "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/value", - "etag": "\"2442337131\"", + "etag": "\"1359910855\"", "tags": [ "_value_" ], @@ -963,7 +963,7 @@ manual_purge uri=app://self/value "roPool": "invalidated", "etagPool": "invalidated", "cdn": "failed", - "durationMs": 0.368 + "durationMs": 0.446 } }, { @@ -1082,7 +1082,7 @@ get uri=page://self/html/blog-posting "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.004 + "durationMs": 0.007 } }, { @@ -1258,21 +1258,21 @@ get uri=app://self/value ├── pre_write_cleanup uri=app://self/value [event] ├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/value etag="553249087" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/value etag="1727834961" tags=[_value_] requestedTtl=31536000 (+1 more) [event] ├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] └── layer=resource get uri=app://self/view ├── pre_write_cleanup uri=app://self/view [event] ├── invalidate tags=[_view_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/view expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/view etag="7707204" tags=[_view_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/view etag="3097302823" tags=[_view_] requestedTtl=31536000 (+1 more) [event] ├── save_view uri=app://self/view tags=[_view_] requestedTtl=31536000 saved=false [event] └── layer=resource manual_store uri=app://self/value ├── pre_write_cleanup uri=app://self/value [event] ├── invalidate tags=[_value_] roPool=invalidated etagPool=invalidated cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] -├── save_etag uri=app://self/value etag="553249087" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── save_etag uri=app://self/value etag="1727834961" tags=[_value_] requestedTtl=31536000 (+1 more) [event] ├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] └── result=failed @@ -1328,7 +1328,7 @@ manual_store uri=app://self/value "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/value", - "etag": "\"553249087\"", + "etag": "\"1727834961\"", "tags": [ "_value_" ], @@ -1407,7 +1407,7 @@ manual_store uri=app://self/value "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/view", - "etag": "\"7707204\"", + "etag": "\"3097302823\"", "tags": [ "_view_" ], @@ -1486,7 +1486,7 @@ manual_store uri=app://self/value "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/value", - "etag": "\"553249087\"", + "etag": "\"1727834961\"", "tags": [ "_value_" ], @@ -1580,7 +1580,7 @@ get uri=page://self/html/blog-posting "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.004 + "durationMs": 0.006 } }, { @@ -1878,7 +1878,7 @@ command method=onDelete source=DonutCommandInterceptor "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.005 + "durationMs": 0.012 } }, { @@ -1989,7 +1989,7 @@ command method=onDelete source=DonutCommandInterceptor "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.006 + "durationMs": 0.005 } }, { @@ -2287,7 +2287,7 @@ command method=onPut annotations=[1 items] source=RefreshInterceptor "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.007 + "durationMs": 0.009 } }, { @@ -2309,7 +2309,7 @@ command method=onPut annotations=[1 items] source=RefreshInterceptor "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.004 + "durationMs": 0.003 } }, { @@ -2404,7 +2404,7 @@ command method=onPut annotations=[2 items] source=RefreshInterceptor "roPool": "invalidated", "etagPool": "invalidated", "cdn": "skipped", - "durationMs": 0.005 + "durationMs": 0.004 } }, { @@ -2540,8 +2540,8 @@ get uri=app://self/http-cache-control-with-cache… ] } Schema validation: OK (7 entries) -I direct putStatic(ttl: 60, sMaxAge: 30) -> put_donut{ttl: 60, sMaxAge: 30}: - the template entry keeps ttl=60 while the rendered view and its ETag take ttl=30, +I direct putStatic(ttl: 60, sMaxAge: 30) -> put_donut{requestedTtl: 60, sMaxAge: 30}: + the template entry records requestedTtl=60 while the rendered view and its ETag record 30, and the whole write is rooted in manual_store{,_result} — cleanup invalidate included === Cache Log Tree — I. donut write through the repository API === @@ -2691,9 +2691,9 @@ get uri=app://self/value ├── pool_error operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] ├── invalidate tags=[_value_] roPool=failed etagPool=failed cdn=skipped (+1 more) [event] ├── cache_policy uri=app://self/value expiry=never resolvedTtl=31536000 [event] -├── pool_error key=2540363928 operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] -├── pool_error key=2540363928 operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] -├── save_etag uri=app://self/value etag="2540363928" tags=[_value_] requestedTtl=31536000 (+1 more) [event] +├── pool_error key=174171846 operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── pool_error key=174171846 operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] +├── save_etag uri=app://self/value etag="174171846" tags=[_value_] requestedTtl=31536000 (+1 more) [event] ├── pool_error key=ro-_value_ operation=read error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] ├── pool_error key=ro-_value_ operation=write error=Redis connection failed: Connection refu… exceptionClass=InvalidArgumentException [event] ├── save_value uri=app://self/value tags=[_value_] requestedTtl=31536000 saved=false [event] @@ -2763,7 +2763,7 @@ get uri=app://self/value "roPool": "failed", "etagPool": "failed", "cdn": "skipped", - "durationMs": 0.162 + "durationMs": 0.242 } }, { @@ -2783,7 +2783,7 @@ get uri=app://self/value "type": "pool_error", "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", "context": { - "key": "2540363928", + "key": "174171846", "operation": "read", "error": "Redis connection failed: Connection refused", "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" @@ -2794,7 +2794,7 @@ get uri=app://self/value "type": "pool_error", "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json", "context": { - "key": "2540363928", + "key": "174171846", "operation": "write", "error": "Redis connection failed: Connection refused", "exceptionClass": "Symfony\\Component\\Cache\\Exception\\InvalidArgumentException" @@ -2806,7 +2806,7 @@ get uri=app://self/value "schemaUrl": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/save_etag.json", "context": { "uri": "app://self/value", - "etag": "\"2540363928\"", + "etag": "\"174171846\"", "tags": [ "_value_" ], diff --git a/demo/run-degraded.php b/demo/run-degraded.php index 4da2c3fe..d2966604 100644 --- a/demo/run-degraded.php +++ b/demo/run-degraded.php @@ -409,8 +409,8 @@ protected function configure(): void $page = $resource->get('page://self/html/blog-posting?id=0'); $logger->flush(); // drain the GET session: this scenario is about the direct write $donutRepository->putStatic($page, ttl: 60, sMaxAge: 30); -echo 'I direct putStatic(ttl: 60, sMaxAge: 30) -> put_donut{ttl: 60, sMaxAge: 30}:' . PHP_EOL; -echo ' the template entry keeps ttl=60 while the rendered view and its ETag take ttl=30,' . PHP_EOL; +echo 'I direct putStatic(ttl: 60, sMaxAge: 30) -> put_donut{requestedTtl: 60, sMaxAge: 30}:' . PHP_EOL; +echo ' the template entry records requestedTtl=60 while the rendered view and its ETag record 30,' . PHP_EOL; echo ' and the whole write is rooted in manual_store{,_result} — cleanup invalidate included' . PHP_EOL; $report($logger->flush(), 'I. donut write through the repository API'); diff --git a/docs/cache-traceability-report.ja.md b/docs/cache-traceability-report.ja.md index 3d55bb8f..2b501a5b 100644 --- a/docs/cache-traceability-report.ja.md +++ b/docs/cache-traceability-report.ja.md @@ -12,7 +12,7 @@ | 2 | プールが書き込みを拒否（save が false を返した） | 成功した save と同一 | | 3 | CDN パージが未設定（NullPurger） | 実際にパージされた `purged` と同一 | | 4 | CDN パージの失敗 | ローカル無効化だけが起き、CDN は stale のまま・記録なし | -| 5 | value エントリの保存がレンダリングに依存し、renderer 不在で保存が警告に劣化（#193） | キャッシュが空のまま・理由の記録なし | +| 5 | value エントリの保存がレンダリングに依存し、renderer が例外を投げると保存が警告に劣化（#193） | キャッシュが空のまま・理由の記録なし | | 6 | `Surrogate-Key` 非宣言ページの donut テンプレートが無タグで保存され、どの `invalidateTags()` も届かない（#194） | purge が content と validator を落として不死の shell を残す・記録なし | | 7 | 独自 `Surrogate-Key` 宣言で埋め込み依存の追跡が失われる 1.16.0 退行（#195） | purge 済みの子を配信し続ける・記録なし | | 8 | ログが記録した TTL と実際に保存された TTL の不一致（負の TTL をそのまま記録）、`sMaxAge` という誤ラベル | ログがストアの事実と矛盾 | diff --git a/docs/cache-traceability-report.md b/docs/cache-traceability-report.md index 909160f5..7666009b 100644 --- a/docs/cache-traceability-report.md +++ b/docs/cache-traceability-report.md @@ -12,7 +12,7 @@ The previous log was a flat op-string format (`RepositoryLoggerInterface`). The | 2 | Pool refusing a write (save returning `false`) | Identical to a successful save | | 3 | No CDN purger configured (NullPurger) | Identical to a real purge (`purged`) | | 4 | CDN purge failure | Local invalidation happened, CDN stayed stale, nothing recorded | -| 5 | Value-entry stores depending on rendering; without a renderer every store degraded to a warning (#193) | Cache stayed empty, no reason recorded | +| 5 | Value-entry stores depending on rendering; a renderer that throws degraded every store to a warning (#193) | Cache stayed empty, no reason recorded | | 6 | Donut templates of pages declaring no `Surrogate-Key` stored untagged, unreachable by any `invalidateTags()` (#194) | Purge dropped content and validator, leaving an immortal shell, unrecorded | | 7 | 1.16.0 regression: declaring a custom `Surrogate-Key` lost embed dependency tracking (#195) | Purged children kept being served, unrecorded | | 8 | Logged TTL contradicting the stored TTL (negative lifetimes recorded verbatim), the misleading `sMaxAge` label | The log contradicted the store's facts |