Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
- 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).
- `pool_error`: the cache backend's own report of an operation it refused. `symfony/cache` adapters do not throw at the application - an unreachable store answers a read as a miss and a write as `false` - so a dead store used to be indistinguishable from a cold one on the read side. The pools are now given the cache log through a PSR-3 adapter, so the store that failed is named where every other cache decision already is.
- `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.
Expand Down
36 changes: 36 additions & 0 deletions demo/run-degraded.php
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@

use BEAR\QueryRepository\Cdn\AkamaiModule;
use BEAR\QueryRepository\DonutRepositoryInterface;
use BEAR\QueryRepository\Log\PoolErrorLogger;
use BEAR\QueryRepository\FakeErrorCache;
use BEAR\QueryRepository\FakeEtagPoolModule;
use BEAR\QueryRepository\FakeRefusingPool;
Expand All @@ -61,9 +62,13 @@
use Koriym\SemanticLogger\Stree\RenderConfig;
use Koriym\SemanticLogger\Stree\TreeRenderer;
use Madapaja\TwigModule\TwigModule;
use Psr\Log\LoggerInterface;
use Ray\Di\InjectionPoints;
use Ray\Di\AbstractModule;
use Ray\Di\Injector;
use Symfony\Component\Cache\Adapter\ArrayAdapter;
use Symfony\Component\Cache\Adapter\RedisAdapter;
use Symfony\Component\Cache\Adapter\RedisTagAwareAdapter;
use Symfony\Component\Cache\Adapter\TagAwareAdapter;
use Symfony\Component\Cache\Adapter\TagAwareAdapterInterface;

Expand Down Expand Up @@ -409,3 +414,34 @@ protected function configure(): void
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');

// ------------------------------------------- J. the store is down, and says so
// symfony/cache adapters do not throw: a store that cannot be reached answers a read as a miss
// and a write as false, so session B's outage - an adapter that throws - is not what production
// looks like. A real RedisAdapter pointed at a closed port is, and what makes it visible is the
// PSR-3 logger the pool reports to.
$injector = $newInjector(new class extends AbstractModule {
protected function configure(): void
{
$this->bind(LoggerInterface::class)->annotatedWith('poolError')->to(PoolErrorLogger::class);
$this->bind(TagAwareAdapterInterface::class)
->annotatedWith(ResourceObjectPool::class)
->toConstructor(
RedisTagAwareAdapter::class,
['redis' => 'deadRedis'],
(new InjectionPoints())->addMethod('setLogger', 'poolError'),
);
// lazy=1: with ext-redis the default is an eager connect, and a boot-time throw is not
// the runtime outage this session demonstrates (Predis is lazy by default).
$this->bind()->annotatedWith('deadRedis')->toInstance(RedisAdapter::createConnection('redis://127.0.0.1:1?lazy=1'));
}
});
$resource = $injector->getInstance(ResourceInterface::class);
$logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class);

$ro = $resource->get('app://self/value');
echo sprintf('J GET app://self/value -> %d served live while the store is unreachable:', $ro->code) . PHP_EOL;
echo ' pool_error{read} for the lookup and pool_error{write} for the store, with the' . PHP_EOL;
echo ' backend\'s own message - without them the miss reads exactly like a cold one' . PHP_EOL;

$report($logger->flush(), 'J. the store is down and says so');
19 changes: 19 additions & 0 deletions docs/reading-the-log.ja.md
Original file line number Diff line number Diff line change
Expand Up @@ -102,6 +102,7 @@ get page://self/html/blog-posting ← スコープ: open されて clos
| `put_skipped` | `uri`, `reason`, `code` | miss の後に書き込みを**しなかった**ことと、その理由 |
| `cache_hit` / `cache_miss` | `layer` | 内側の照会。必ず `layer: donut` — donut テンプレートがあったか |
| `cache_error` | `uri`, `operation`, `error`, `exceptionClass` | キャッシュ経路が throw した |
| `pool_error` | `key`, `operation`, `error`, `exceptionClass` | バックエンドが操作を拒み、アダプタが握り潰した |
| `semantic_logger_error` | `kind`, `message`, … | ロガー自体の誤用(コア側の診断で、このパッケージの語彙ではない) |

## 結果が入るフィールド
Expand Down Expand Up @@ -156,12 +157,30 @@ get page://self/html/blog-posting ← スコープ: open されて clos
内側から見た「stale を配信している」状態です。

**エントリが期限切れになる設計かどうかは、TTL ではなく `cache_policy.expiry` を読みます。**
`expiry: "never"` は「無効化が届くまで」という意図です。解決した数値は保険であり、アプリが `Expiry` を
どう束縛したかで変わります — 既定のインストールでは `never` が 31536000 秒になり、意図的な 1 年 TTL と
まったく同じに見えます。`expirySecond` か `expiryAt` が non-null 側なら、そのエントリは期限切れになり、
どの宣言が決めたかも分かります。

**`requestedTtl` は要求した値で、ストアがどうしたかではありません。** `0`/`null` は「このパッケージは
期限を設定しなかった」— つまり無効化が届くまで生きるはず、という意図です。それが可能かはバックエンドが
決めます。`symfony/cache` の `RedisTagAwareAdapter` は期限なしのタグ付きエントリに 8640000 秒(100 日)を
与えます — Redis はタグ集合を期限切れにできないからです。実効寿命はデプロイ側の事実なので、ストアで
読んでください(Redis なら `TTL <key>`)。

**コマンド注釈が届くのは URI で、タグではありません。** `#[Refresh]` と `#[Purge]` が持つのは URI です。
エントリ群が 1 つの無効化ハンドル(エントリを生んだクエリ文字列すべてに渡る corpus タグ)を共有している
リソースは `invalidateTags()` を呼んで無効化し、それは `command` スコープの中ではなく `manual_invalidate`
として現れます。リソースメソッドの外で起きる書き込みにはインターセプタが一切かかりません。その形では
直接呼び出しが唯一の道であり、manual スコープがそのイベントを見える場所に留めています。

**`pool_error` はストアそのもの、`cache_error` はこのパッケージが捕まえた例外です。**
`symfony/cache` のアダプタはアプリに向けて throw しません。到達できないストアは read には miss、
write には `false` を返すので、`cache_error` を生む `catch` には何も届きません。アダプタは代わりに
失敗を PSR-3 ロガーへ報告し、プールにはキャッシュログが渡されています — だからストアが落ちているとき、
miss の隣に `pool_error` が並びます(沈黙にはなりません)。そこで分かるのはプールのキーだけで、
リソース URI ではありません。

**`cdn_headers` に出るのは、応答に実際に付いたヘッダです。** CDN モジュールの暗黙の既定値も含みます。
lifetime ヘッダの無いマップは、CDN に lifetime 指示を与えなかった応答です。`surrogateKeys` と
`invalidate` の `tags` を突き合わせると、パージがエッジの保持物に届き得たかが分かります。
Expand Down
20 changes: 20 additions & 0 deletions docs/reading-the-log.md
Original file line number Diff line number Diff line change
Expand Up @@ -104,6 +104,7 @@ operation inside a GET or a command is an ordinary event there instead.
| `put_skipped` | `uri`, `reason`, `code` | a miss was **not** followed by a write, and why |
| `cache_hit` / `cache_miss` | `layer` | an inner lookup, always `layer: donut` — whether the donut template was there |
| `cache_error` | `uri`, `operation`, `error`, `exceptionClass` | the cache path threw |
| `pool_error` | `key`, `operation`, `error`, `exceptionClass` | the backend refused an operation and the adapter swallowed it |
| `semantic_logger_error` | `kind`, `message`, … | the logger itself was misused (core diagnostic, not this package's vocabulary) |

## Outcome fields
Expand Down Expand Up @@ -159,12 +160,31 @@ correlation. Any `invalidate` without the marker is a real invalidation.
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.**
`expiry: "never"` means until invalidation; the number it resolves to is a backstop and depends on
how the application bound `Expiry` — a default install turns `never` into 31536000 seconds, which
reads exactly like a deliberate 1-year TTL. `expirySecond` or `expiryAt` being the non-null one
means the entry expires, and says who decided.

**`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
8640000 seconds (100 days), because Redis cannot expire tag sets. The effective lifetime is a
property of the deployment, and the store is where to read it: `TTL <key>` on Redis.

**A command annotation reaches a URI, not a tag.** `#[Refresh]` and `#[Purge]` carry a URI, so a
resource whose entries share one invalidation handle - a corpus tag across every query string that
produced an entry - is invalidated by calling `invalidateTags()`, which appears as
`manual_invalidate` rather than inside a `command` scope. A write outside a resource method has no
interceptor at all: in that shape the direct call is the only path, and the manual scope is what
keeps its events visible.

**A `pool_error` is the store itself; a `cache_error` is an exception this package caught.**
`symfony/cache` adapters never throw at the application: an unreachable store answers a read as a
miss and a write as `false`, so nothing reaches the `catch` that produces a `cache_error`. The
adapter reports the failure to a PSR-3 logger instead, and the pools are given the cache log - so
a store that is down is a run of `pool_error` beside the misses, not silence. Only the pool key is
known there, not the resource URI.

**`cdn_headers` shows what the response really carried**, including a CDN module's silent
default. A map with no lifetime header is a response that gave the CDN no lifetime directive.
Correlate its `surrogateKeys` with an `invalidate`'s `tags` to see whether a purge could reach
Expand Down
32 changes: 32 additions & 0 deletions docs/schemas/context/pool_error.json
Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
{
"$schema": "https://json-schema.org/draft/2020-12/schema",
"$id": "https://bearsunday.github.io/BEAR.QueryRepository/schemas/context/pool_error.json",
"title": "pool_error",
"description": "Event: the cache backend refused an operation and the adapter swallowed it. `symfony/cache` never throws at the application - a store that cannot be reached answers a read as a miss and a write as `false` - so a dead store reads exactly like a cold one unless the adapter's own report is recorded. Distinct from `cache_error`, which is an exception this package caught with the resource URI in hand; here only the pool key is known.",
"type": "object",
"required": [
"key",
"operation",
"error",
"exceptionClass"
],
"properties": {
"key": {
"description": "the pool key the adapter was working on, empty when it did not name one",
"type": "string"
},
"operation": {
"description": "which side refused, as the adapter worded it: `read`, `write`, or `unknown` when the wording is not one this package recognises - a mislabelled side is worse than an unlabelled one",
"type": "string"
},
"error": {
"description": "the backend's message",
"type": "string"
},
"exceptionClass": {
"description": "the throwable the adapter caught, or `unknown` when it reported no exception",
"type": "string"
}
},
"additionalProperties": false
}
1 change: 1 addition & 0 deletions docs/what-the-log-proves.ja.md
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@
| 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 が同じ寿命として記録される |
| 8 | ストアは応答しているのか、それとも miss はすべて障害なのか? | `pool_error` `{key, operation, error, exceptionClass}` — 拒んだバックエンドについてのアダプタ自身の報告 | `symfony/cache` はアプリに throw しないので、プールにキャッシュログを渡している。死んだストアからの read は他と同じ miss であり、隣の `pool_error` が「落ちている」と「冷たい」を分ける。実際の Redis アダプタを閉じたポートに向けて実演 |

## 強制の層

Expand Down
1 change: 1 addition & 0 deletions docs/what-the-log-proves.md
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ is removed or its meaning inverted (verified by mutation testing).
| 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 |
| 8 | Is the store answering, or is every miss really an outage? | `pool_error` `{key, operation, error, exceptionClass}` - the adapter's own report of a backend that refused | `symfony/cache` never throws at the application, so the pools are given the cache log: a read from a dead store is a miss like any other, and the `pool_error` beside it is what separates down from cold. Demonstrated against a real Redis adapter pointed at a closed port |

## The enforcement layers

Expand Down
Loading
Loading