Record what a resource declared about its lifetime

CHANGELOG.md

@@ -38,6 +38,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - `LogSinkInterface`/`ShutdownFlush` and `LogWriterInterface`/`LogFileWriter`/`LogStreamWriter`: the log module owns flushing, so no app writes `flush()` in a bootstrap. The sink arms once per process - at construction and again at `SafeSemanticLogger::__unserialize()`, the only hook that runs on every request - and fires after output, after a 304's early `exit()` and after an uncaught error, which a hook on `ResourceObject::transfer()` cannot do (rendering happens inside it, and a 304 never reaches it). The flush is total: a destination that throws is reported to `error_log()` and swallowed, because from a shutdown callback it would otherwise surface as an uncaught fatal after the response was already written. An empty session is never written; `LogFileWriter` creates 0700/0600, names sessions in UTC with a microsecond field so pruning keeps the newest, renames `latest.json` into place so a reader never opens a half-written file, and reports a destination it cannot write instead of emitting warnings from a shutdown handler.
 - Japanese versions of the three human-facing documents, beside their English originals under the convention the repository already uses for `README.ja.md`: `docs/reading-the-log.ja.md`, `docs/why-the-log-records-everything.ja.md`, `docs/what-the-log-proves.ja.md`. The published paths stay where they are - `docs/schemas/context/*.json` is embedded in every entry's `schemaUrl` and `docs/llms*.txt` is served at a well-known path, so neither moves for a language split. `ReadingGuideCoverageTest` now runs against both guides, so a new context type or enum value fails until it is explained in each.
 - `docs/reading-the-log.md`: the reader's guide to the log - the tree grammar (open / event / close), every one of the 26 context types with its fields, every outcome word with what it means, the reading rules that cannot be guessed from a field name (marker-preceded cleanup, degraded vs cold, the 304 shape, tag intersection), a Terminology table that expands the names the log uses for its own parts (`roPool` is the pool bound with `#[ResourceObjectPool]`, `tags` are surrogate keys, `layer` is which store answered rather than which pool was written) and points at the manual for the concepts, and a worked session taken verbatim from a demo. `ReadingGuideCoverageTest` fails if a context type or a schema enum value is not accounted for there, so a published word cannot ship without an explanation. Linked from both READMEs; `docs/llms.txt`/`llms-full.txt` keep the same facts in lookup form and point at it.
+- `cache_policy`: what a resource declared about its lifetime, recorded where the `#[Cacheable]` declaration is read. Exactly one of `expiry` / `expirySecond` / `expiryAt` is non-null - the one that decided - beside the `resolvedTtl` it produced. A TTL alone cannot say whether an entry is meant to expire: the `never` preset resolves to a finite number an application can rebind through `Expiry`, so an event-driven entry and a deliberate 1-year TTL used to log the same lifetime (#186).
 - `Exception\UnsupportedLogStream`: `LogStreamWriter` accepts a filesystem path or `php://stdout|stderr|output` and rejects any other wrapper, so a module argument cannot truncate an unrelated file through `php://filter/…` or ship every session to an `ftp://` host. Writes now take an exclusive lock (`flock`) instead of relying on `file_put_contents` flags, which the default `php://stdout` target silently dropped - concurrent workers could interleave half-lines in the JSONL a collector parses.
 - `PsrLogWriter`: sends a kept session to the application's PSR-3 logger (already in every BEAR app's tree via bear/sunday and bear/resource), passing the tree as structured context under `log` rather than as a message. It is an adapter behind `LogWriterInterface`, not a replacement for it: PSR-3 carries strings, and its level would be a second filter that can drop what the retention policy kept.
 - `ConcurrentRuntimeInterface`/`HostRuntime`: where the sink can prove the host is concurrent (`RR_MODE` set, or inside a Swoole coroutine) it refuses to arm, reports through `error_log()` and **recording stops with it** - `SafeSemanticLogger` falls back to the no-op logger, since an unarmed sink leaves nothing that would ever drain the session. Mode is consulted, never capability (a loaded ext-swoole proves nothing about how the app is served), and the two checks are explicitly not an exhaustive account: a Swoole worker whose logger is built outside a coroutine, FrankenPHP worker mode, ReactPHP, Amp and a long-lived CLI consumer are not detected and must bind their own implementation. Diagnostics use `error_log()` rather than `trigger_error()` because arming happens while the injector builds the logger, where a strict error handler would turn a warning into a boot failure on exactly those hosts.

docs/reading-the-log.ja.md

@@ -86,6 +86,7 @@ get page://self/html/blog-posting          ← スコープ: open されて clos
 
 | 型 | フィールド | 何が分かるか |
 |---|---|---|
+| `cache_policy` | `uri`, `expiry`, `expirySecond`, `expiryAt`, `resolvedTtl` | リソースが宣言した寿命と、それが解決した値 |
 | `save_value` | `uri`, `tags`, `requestedTtl`, `saved` | body をプールに渡した |
 | `save_view` | `uri`, `tags`, `requestedTtl`, `saved` | body + レンダリング済み view を渡した |
 | `save_etag` | `uri`, `etag`, `tags`, `requestedTtl`, `saved` | 検証子を ETag プールに渡した |
@@ -154,6 +155,7 @@ get page://self/html/blog-posting          ← スコープ: open されて clos
 突き合わせます。交差しないタグは、その書き込みがそのエントリを残したことを意味します — これが
 内側から見た「stale を配信している」状態です。
 
+**エントリが期限切れになる設計かどうかは、TTL ではなく `cache_policy.expiry` を読みます。**
 **`requestedTtl` は要求した値で、ストアがどうしたかではありません。** `0`/`null` は「このパッケージは
 期限を設定しなかった」— つまり無効化が届くまで生きるはず、という意図です。それが可能かはバックエンドが
 決めます。`symfony/cache` の `RedisTagAwareAdapter` は期限なしのタグ付きエントリに 8640000 秒(100 日)を

docs/reading-the-log.md

@@ -88,6 +88,7 @@ operation inside a GET or a command is an ordinary event there instead.
 
 | Type | Fields | What it tells you |
 |---|---|---|
+| `cache_policy` | `uri`, `expiry`, `expirySecond`, `expiryAt`, `resolvedTtl` | what the resource declared about its lifetime, and what that resolved to |
 | `save_value` | `uri`, `tags`, `requestedTtl`, `saved` | the body was offered to the pool |
 | `save_view` | `uri`, `tags`, `requestedTtl`, `saved` | body + rendered view were offered |
 | `save_etag` | `uri`, `etag`, `tags`, `requestedTtl`, `saved` | the validator was offered to the ETag pool |
@@ -157,6 +158,7 @@ correlation. Any `invalidate` without the marker is a real invalidation.
 `tags` of a later `invalidate`. Tags that do not meet mean the write left that entry standing —
 which is what serving stale looks like from the inside.
 
+**Read `cache_policy.expiry`, not a TTL, to learn whether an entry is meant to expire.**
 **`requestedTtl` is what was asked for, not what the store did.** `0`/`null` means this package set no
 expiry, so the entry is meant to live until an invalidation reaches it — but the backend decides
 whether that is possible. `symfony/cache`'s `RedisTagAwareAdapter` gives an unexpiring tagged entry

docs/schemas/context/cache_policy.json

@@ -0,0 +1,46 @@
+{
+    "$schema": "https://json-schema.org/draft/2020-12/schema",
+    "$id": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json",
+    "title": "cache_policy",
+    "description": "Event: what the resource declared about its lifetime. `expiry: \"never\"` means the entry is meant to live until an invalidation reaches it; every other declaration means it expires. Read this rather than `resolvedTtl` to learn the intent: the `never` preset resolves to a finite number whose value depends on how the application bound `Expiry`.",
+    "type": "object",
+    "required": [
+        "uri",
+        "expiry",
+        "expirySecond",
+        "expiryAt",
+        "resolvedTtl"
+    ],
+    "properties": {
+        "uri": {
+            "type": "string"
+        },
+        "expiry": {
+            "description": "the `#[Cacheable]` preset that decided this entry (`short` | `medium` | `long` | `never`), or null when a more specific declaration did",
+            "type": [
+                "string",
+                "null"
+            ]
+        },
+        "expirySecond": {
+            "description": "the declared lifetime in seconds, or null when it did not decide this entry",
+            "type": [
+                "integer",
+                "null"
+            ]
+        },
+        "expiryAt": {
+            "description": "the body field carrying an expiry timestamp, or null when it did not decide this entry",
+            "type": [
+                "string",
+                "null"
+            ]
+        },
+        "resolvedTtl": {
+            "description": "seconds the declaration resolved to - what the pools are asked for in the save events that follow",
+            "type": "integer",
+            "minimum": 0
+        }
+    },
+    "additionalProperties": false
+}

docs/what-the-log-proves.ja.md

@@ -14,6 +14,7 @@
 | 4 | 条件付きリクエストはエッジで再検証されたか？ | layer `etag` で `cache_hit`/`cache_miss` を閉じる `conditional_request` `{ifNoneMatch}` — リソースが 1 つも走る前に下される 304 の判定 | `HttpCacheInterface` の両実装が記録する。どちらかの記録を落とすか結果を入れ替えるとスイートが失敗する |
 | 5 | なぜエントリがないのか — 何も保存されていなかったのか(コールド)、それともストアが読めなかったのか(縮退: フレームワークがキャッシュ無しとして振る舞い、リソースを走らせた)？ | `put_skipped` `{reason, code}`、`cache_error` `{operation, exceptionClass}` — `operation: read` が、それでも閉じる `cache_miss` と対になっているものが縮退した読み取り | スキップ理由、失敗した側（`read`/`write`）、throwable のクラスがピン留めされている。`cache_error{read}` + `cache_miss` = 縮退した読み取り、`cache_miss` 単独 = cold |
 | 6 | この書き込みまたは無効化を始めたのは誰か — フレームワークか、アプリケーションか？ | `command` スコープは生成元のインターセプター（`source`）を名指す。直接呼び出しは `manual_store` / `manual_purge` / `manual_invalidate` を根とし、結果は close 側に載る。`pre_write_cleanup` は writer 自身のクリーンアップを示す | 例外を投げる書き込みは `manual_store_result{failed}` で閉じる。呼び出し側が例外を捕まえているのにスコープが `stored` で閉じるのはログが嘘をついている状態であり、テストがそれを禁じる |
+| 7 | このエントリは期限切れになる設計か、それとも何かが無効化するまで生きる設計か? | `cache_policy` `{expiry, expirySecond, expiryAt, resolvedTtl}` — `#[Cacheable]` の宣言を読む場所で記録 | 3 つの宣言のうち non-null は 1 つだけ、それが決めたもの。TTL ではこれに答えられない — `never` プリセットはアプリが再束縛できる有限の数値に解決するので、イベント駆動のエントリと意図的な 1 年 TTL が同じ寿命として記録される |
 
 ## 強制の層
 

docs/what-the-log-proves.md

@@ -21,6 +21,7 @@ is removed or its meaning inverted (verified by mutation testing).
 | 4 | Did a conditional request revalidate at the edge? | `conditional_request` `{ifNoneMatch}` closing `cache_hit`/`cache_miss` at layer `etag` — the 304 decision, made before any resource runs | Both `HttpCacheInterface` implementations record it; dropping either recording or swapping the outcome fails the suite |
 | 5 | Why is there no entry — was nothing stored (cold), or could the store not be read (degraded: the framework ran the resource as if there were no cache)? | `put_skipped` `{reason, code}`, `cache_error` `{operation, exceptionClass}` — `operation: read` paired with the still-closing `cache_miss` is a degraded read | Skip reasons, the failing side (`read`/`write`) and the throwable class are pinned; `cache_error{read}` + `cache_miss` = degraded read, lone `cache_miss` = cold |
 | 6 | Who initiated this write or invalidation — the framework or the application? | `command` scopes name their producing interceptor (`source`); direct calls root in `manual_store` / `manual_purge` / `manual_invalidate` with the outcome on the close; `pre_write_cleanup` marks a writer's own cleanup | A write that throws closes `manual_store_result{failed}` — a scope closing `stored` while the caller catches an exception is the log lying, and a test forbids it |
+| 7 | Is this entry meant to expire, or to live until something invalidates it? | `cache_policy` `{expiry, expirySecond, expiryAt, resolvedTtl}` — recorded where the `#[Cacheable]` declaration is read | Exactly one of the three declarations is non-null: the one that decided. A TTL cannot answer this — the `never` preset resolves to a finite number an application can rebind, so an event-driven entry and a deliberate 1-year TTL log the same lifetime |
 
 ## The enforcement layers
 

src/Log/Context/CachePolicyContext.php

@@ -0,0 +1,34 @@
+<?php
+
+declare(strict_types=1);
+
+namespace BEAR\QueryRepository\Log\Context;
+
+use Koriym\SemanticLogger\AbstractContext;
+
+/**
+ * Event: what the resource declared about its lifetime.
+ *
+ * The resolved TTL alone cannot say whether an entry is meant to expire: the `never` preset
+ * resolves to a finite number, and which number that is depends on how the application bound
+ * `Expiry`. The declaration is deployment-independent, so it is recorded as declared.
+ */
+final class CachePolicyContext extends AbstractContext
+{
+    public const TYPE = 'cache_policy';
+    public const SCHEMA_URL = 'https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/cache_policy.json';
+
+    /**
+     * Exactly one of the three declarations is non-null: the one that decided this entry.
+     *
+     * @param 'short'|'medium'|'long'|'never'|null $expiry
+     */
+    public function __construct(
+        public readonly string $uri,
+        public readonly string|null $expiry,
+        public readonly int|null $expirySecond,
+        public readonly string|null $expiryAt,
+        public readonly int $resolvedTtl,
+    ) {
+    }
+}

src/QueryRepository.php

@@ -5,6 +5,7 @@
 namespace BEAR\QueryRepository;
 
 use BEAR\QueryRepository\Exception\ExpireAtKeyNotExists;
+use BEAR\QueryRepository\Log\Context\CachePolicyContext;
 use BEAR\QueryRepository\Log\Context\ManualPurgeContext;
 use BEAR\QueryRepository\Log\Context\ManualPurgeResultContext;
 use BEAR\QueryRepository\Log\Context\ManualStoreContext;
@@ -85,6 +86,10 @@ private function doPut(ResourceObject $ro): bool
         }
 
         $ttl = $this->getExpiryTime($ro, $cacheable);
+        if ($cacheable instanceof Cacheable) {
+            $this->logger->event($this->cachePolicy($ro, $cacheable, $ttl));
+        }
+
         ($this->headerSetter)($ro, $ttl, $httpCache);
         if (isset($ro->headers[Header::ETAG])) {
             $etag = $ro->headers[Header::ETAG];
@@ -99,6 +104,27 @@ private function doPut(ResourceObject $ro): bool
         return $this->storage->saveValue($ro, $ttl);
     }
 
+    /**
+     * The declaration that decided the lifetime, as declared.
+     *
+     * The precedence is the one {@see self::getExpiryTime()} applies: an expiry field in the body
+     * wins, then an explicit second count, then the preset. Only the winner is recorded, so a
+     * reader never has to re-derive which of the three was in force.
+     */
+    private function cachePolicy(ResourceObject $ro, Cacheable $cacheable, int $ttl): CachePolicyContext
+    {
+        $uri = (string) $ro->uri;
+        if ($cacheable->expiryAt !== '') {
+            return new CachePolicyContext($uri, null, null, $cacheable->expiryAt, $ttl);
+        }
+
+        if ($cacheable->expirySecond !== 0) {
+            return new CachePolicyContext($uri, null, $cacheable->expirySecond, null, $ttl);
+        }
+
+        return new CachePolicyContext($uri, $cacheable->expiry, null, null, $ttl);
+    }
+
     private function setCacheDependency(ResourceObject $ro): void
     {
         /** @var mixed $body */

tests/CachePolicyLogTest.php

@@ -0,0 +1,82 @@
+<?php
+
+declare(strict_types=1);
+
+namespace BEAR\QueryRepository;
+
+use BEAR\RepositoryModule\Annotation\CacheLog;
+use BEAR\Resource\ResourceInterface;
+use Koriym\SemanticLogger\SemanticLoggerInterface;
+use PHPUnit\Framework\TestCase;
+use Ray\Di\Injector;
+
+/**
+ * What the log says about an entry's intended lifetime.
+ *
+ * A resolved TTL cannot answer "is this meant to expire?": the `never` preset resolves to a
+ * finite number, and an application can rebind `Expiry` to make it any number at all. The
+ * declaration is recorded instead, and only the one that decided.
+ */
+class CachePolicyLogTest extends TestCase
+{
+    use SemanticLogTreeTrait;
+
+    private ResourceInterface $resource;
+    private SemanticLoggerInterface $logger;
+
+    protected function setUp(): void
+    {
+        $injector = new Injector(new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')), __DIR__ . '/tmp');
+        $this->resource = $injector->getInstance(ResourceInterface::class);
+        $this->logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class);
+
+        parent::setUp();
+    }
+
+    public function testAPresetIsRecordedAsDeclaredBesideTheNumberItResolvedTo(): void
+    {
+        $this->resource->get('app://self/entry', ['id' => 1]); // #[Cacheable(expiry: 'never')]
+
+        $policy = self::eventContextJsonOf($this->flushAndValidate($this->logger), 'cache_policy');
+
+        $this->assertNotNull($policy);
+        $this->assertStringContainsString('"expiry":"never"', $policy, 'the word the resource declared');
+        $this->assertStringContainsString('"expirySecond":null', $policy, 'seconds did not decide this entry');
+        $this->assertStringContainsString('"expiryAt":null', $policy);
+        // The number is a backstop, and a default install turns `never` into 365 days - which is
+        // why the word has to be in the log: this reads exactly like a deliberate 1-year TTL.
+        $this->assertStringContainsString('"resolvedTtl":31536000', $policy);
+    }
+
+    public function testAnExplicitSecondCountIsTheDeclarationThatDecided(): void
+    {
+        $this->resource->get('app://self/control-none'); // #[Cacheable(expirySecond: 60)]
+
+        $policy = self::eventContextJsonOf($this->flushAndValidate($this->logger), 'cache_policy');
+
+        $this->assertNotNull($policy);
+        $this->assertStringContainsString('"expirySecond":60', $policy);
+        $this->assertStringContainsString('"expiry":null', $policy, 'the preset is not what decided');
+        $this->assertStringContainsString('"resolvedTtl":60', $policy);
+    }
+
+    public function testAnExpiryFieldInTheBodyOutranksThePreset(): void
+    {
+        $this->resource->get('app://self/control-expiry'); // #[Cacheable(expiryAt: 'expiry_at')]
+
+        $policy = self::eventContextJsonOf($this->flushAndValidate($this->logger), 'cache_policy');
+
+        $this->assertNotNull($policy);
+        $this->assertStringContainsString('"expiryAt":"expiry_at"', $policy, 'the body field that carries the deadline');
+        $this->assertStringContainsString('"expiry":null', $policy);
+        $this->assertStringContainsString('"expirySecond":null', $policy);
+    }
+
+    public function testAResourceWithNoCacheableDeclarationHasNoPolicy(): void
+    {
+        // The log carries a policy only where a declaration exists to record.
+        $this->resource->get('app://self/no-http-cache-control');
+
+        $this->assertNull(self::eventContextJsonOf($this->flushAndValidate($this->logger), 'cache_policy'));
+    }
+}