From a62a77e4b37b15bc71474dbd67c21cca651f6c78 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 20 Sep 2026 13:26:47 +0900 Subject: [PATCH 1/6] observe: keep body generations aligned with retained logs (#134) ObserveModule::configure() used to wipe the single shared es-bodies directory on every injector build, so a retained log's body_ref stopped resolving (or silently pointed at the wrong bytes, since FileBodyStore's sequence numbers restart at 1 each build) as soon as a second session started. Give each session its own timestamp-keyed generation directory instead, and prune stale generations down to the same count passed to DevQueryRepositoryLogModule, so a log is never retained without its bodies. Same fix applied to the bear-observe skill's DevModule.php template. --- .claude/skills/bear-observe/SKILL.md | 2 +- .../bear-observe/templates/DevModule.php | 63 +++++- src/Module/ObserveModule.php | 63 +++++- .../Module/ObserveModuleBodyRetentionTest.php | 202 ++++++++++++++++++ 4 files changed, 323 insertions(+), 7 deletions(-) create mode 100644 tests/Module/ObserveModuleBodyRetentionTest.php diff --git a/.claude/skills/bear-observe/SKILL.md b/.claude/skills/bear-observe/SKILL.md index 70d71d64..b425e64c 100644 --- a/.claude/skills/bear-observe/SKILL.md +++ b/.claude/skills/bear-observe/SKILL.md @@ -242,7 +242,7 @@ $log = $logger->flush(); // その場で受け取る(以降 | 依存の伝播 | `save_*` の `tags` ↔ `invalidate` の `tags` の突き合わせ。`depends_on` を出すのは `#[Cacheable]` の親だけで、donut の親は出さない(§4) | | 何回リソースが走ったか | `resource_request` の数。N+1 は同じ URI の兄弟が並ぶ形で出る | | どこで時間を使ったか | `durationMs`。親から子を引いた残りがその層の自前のコスト | -| 何を返したか | `body_ref` のファイル(`var/log//es-bodies/`) | +| 何を返したか | `body_ref` のファイル(`var/log//es-bodies//`。generation はリクエストごとのディレクトリで、ログと同じ本数だけ残る) | 読み間違えやすい 4 点(いずれも実測): diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index f01d4829..74cbab63 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -8,6 +8,7 @@ use BEAR\EventSourcing\Module\EventSourcingModule; use BEAR\EventSourcing\Recorded; use BEAR\EventSourcing\RecordedMethods; +use BEAR\EventSourcing\Resource\BodyStoreException; use BEAR\EventSourcing\Resource\BodyStoreInterface; use BEAR\EventSourcing\Resource\FileBodyStore; use BEAR\EventSourcing\Resource\SemanticLogInvoker; @@ -21,6 +22,20 @@ use Ray\Di\Scope; use Symfony\Component\Cache\Adapter\AdapterInterface; +use function array_slice; +use function bin2hex; +use function count; +use function glob; +use function gmdate; +use function max; +use function microtime; +use function random_bytes; +use function rmdir; +use function sort; +use function sprintf; + +use const GLOB_ONLYDIR; + /** * Observation context: `dev-` prefix on the app context (`dev-hal-app`, `cli-dev-hal-app`). * @@ -33,11 +48,23 @@ final class DevModule extends AbstractAppModule { private const ORIGINAL_INVOKER = 'original_invoker'; + /** + * Body generations retained alongside log sessions (same count passed to + * DevQueryRepositoryLogModule below): a log's body_ref keeps resolving for as long as the + * log itself survives, and neither is pruned without the other (issue #134). + */ + private const int KEEP_GENERATIONS = 20; + #[Override] protected function configure(): void { - $bodyDir = $this->appMeta->logDir . '/es-bodies'; - FileBodyStore::clearDirectory($bodyDir); + $bodiesRoot = $this->appMeta->logDir . '/es-bodies'; + self::pruneStaleGenerations($bodiesRoot, self::KEEP_GENERATIONS); + // One subdirectory per request: FileBodyStore's body sequence restarts at 1 on every + // injector build, so a directory shared across sessions would let two sessions + // overwrite each other's numbered files. The key sorts chronologically, matching the + // shape of DevQueryRepositoryLogModule's own session filenames. + $bodyDir = $bodiesRoot . '/' . self::generationKey(); $this->rename(InvokerInterface::class, self::ORIGINAL_INVOKER); $this->bind(InvokerInterface::class) @@ -58,7 +85,7 @@ protected function configure(): void // The cache log module owns the writer and the shutdown flush, so the application // writes no flush of its own. - $this->install(new DevQueryRepositoryLogModule($this->appMeta->logDir . '/observe')); + $this->install(new DevQueryRepositoryLogModule($this->appMeta->logDir . '/observe', self::KEEP_GENERATIONS)); // One request, one tree: the resource invoker records into the logger the sink flushes. $this->bind(SemanticLoggerInterface::class) ->toProvider(ObserveLoggerProvider::class)->in(Scope::SINGLETON); @@ -69,4 +96,34 @@ protected function configure(): void $this->bind(AdapterInterface::class)->annotatedWith(EtagPool::class) ->toProvider(DevPoolProvider::class)->in(Scope::SINGLETON); } + + /** Sortable per-request key: zero-padded so lexical order is chronological order. */ + private static function generationKey(): string + { + $now = microtime(true); + $seconds = (int) $now; + $micro = (int) (($now - (float) $seconds) * 1_000_000.0); + + return gmdate('Ymd-His', $seconds) . '-' . sprintf('%06d', $micro) . '-' . bin2hex(random_bytes(4)); + } + + /** + * Deletes body generations beyond $keep, oldest first, leaving room for the one this + * request is about to create. Mirrors LogFileWriter::prune()'s own retention count, so a + * body generation is never pruned while the log session that references it still exists. + */ + private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void + { + $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; + sort($generations); + $overflow = max(0, count($generations) - $keep + 1); + foreach (array_slice($generations, 0, $overflow) as $stale) { + try { + FileBodyStore::clearDirectory($stale); + rmdir($stale); + } catch (BodyStoreException) { + // A sibling process pruning the same generation concurrently is not an error. + } + } + } } diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index 33167f7a..a2fc9d04 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -8,6 +8,7 @@ use BEAR\EventSourcing\Module\EventSourcingModule; use BEAR\EventSourcing\Recorded; use BEAR\EventSourcing\RecordedMethods; +use BEAR\EventSourcing\Resource\BodyStoreException; use BEAR\EventSourcing\Resource\BodyStoreInterface; use BEAR\EventSourcing\Resource\FileBodyStore; use BEAR\EventSourcing\Resource\ParamsFilterInterface; @@ -23,6 +24,20 @@ use Ray\Di\Scope; use Symfony\Component\Cache\Adapter\AdapterInterface; +use function array_slice; +use function bin2hex; +use function count; +use function glob; +use function gmdate; +use function max; +use function microtime; +use function random_bytes; +use function rmdir; +use function sort; +use function sprintf; + +use const GLOB_ONLYDIR; + /** * Observation context: `observe-` prefix on the app context (`cli-observe-fake-hal-app`). * @@ -57,13 +72,25 @@ final class ObserveModule extends AbstractAppModule */ public const array EXTRA_CREDENTIALS = ['resetKey', 'authKey']; + /** + * Body generations retained alongside log sessions (same count passed to + * DevQueryRepositoryLogModule below): a log's body_ref keeps resolving for as long as the + * log itself survives, and neither is pruned without the other (issue #134). + */ + private const int KEEP_GENERATIONS = 20; + private const ORIGINAL_INVOKER = 'original_invoker'; #[Override] protected function configure(): void { - $bodyDir = $this->appMeta->logDir . '/es-bodies'; - FileBodyStore::clearDirectory($bodyDir); + $bodiesRoot = $this->appMeta->logDir . '/es-bodies'; + self::pruneStaleGenerations($bodiesRoot, self::KEEP_GENERATIONS); + // One subdirectory per request: FileBodyStore's body sequence restarts at 1 on every + // injector build, so a directory shared across sessions would let two sessions + // overwrite each other's numbered files. The key sorts chronologically, matching the + // shape of DevQueryRepositoryLogModule's own session filenames. + $bodyDir = $bodiesRoot . '/' . self::generationKey(); $this->bind(ParamsFilterInterface::class)->annotatedWith(Filtered::class) ->toInstance(new SensitiveParamsFilter(self::EXTRA_CREDENTIALS)); @@ -85,7 +112,7 @@ protected function configure(): void // The cache log module owns the writer and the shutdown flush, so the application // writes no flush of its own. - $this->install(new DevQueryRepositoryLogModule($this->appMeta->logDir . '/observe')); + $this->install(new DevQueryRepositoryLogModule($this->appMeta->logDir . '/observe', self::KEEP_GENERATIONS)); // One request, one tree: the resource invoker records into the logger the sink flushes. $this->bind(SemanticLoggerInterface::class) ->toProvider(ObserveLoggerProvider::class)->in(Scope::SINGLETON); @@ -96,4 +123,34 @@ protected function configure(): void $this->bind(AdapterInterface::class)->annotatedWith(EtagPool::class) ->toProvider(DevPoolProvider::class)->in(Scope::SINGLETON); } + + /** Sortable per-request key: zero-padded so lexical order is chronological order. */ + private static function generationKey(): string + { + $now = microtime(true); + $seconds = (int) $now; + $micro = (int) (($now - (float) $seconds) * 1_000_000.0); + + return gmdate('Ymd-His', $seconds) . '-' . sprintf('%06d', $micro) . '-' . bin2hex(random_bytes(4)); + } + + /** + * Deletes body generations beyond $keep, oldest first, leaving room for the one this + * request is about to create. Mirrors LogFileWriter::prune()'s own retention count, so a + * body generation is never pruned while the log session that references it still exists. + */ + private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void + { + $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; + sort($generations); + $overflow = max(0, count($generations) - $keep + 1); + foreach (array_slice($generations, 0, $overflow) as $stale) { + try { + FileBodyStore::clearDirectory($stale); + rmdir($stale); + } catch (BodyStoreException) { + // A sibling process pruning the same generation concurrently is not an error. + } + } + } } diff --git a/tests/Module/ObserveModuleBodyRetentionTest.php b/tests/Module/ObserveModuleBodyRetentionTest.php new file mode 100644 index 00000000..12c4261f --- /dev/null +++ b/tests/Module/ObserveModuleBodyRetentionTest.php @@ -0,0 +1,202 @@ +bind(SemanticLoggerInterface::class)->toInstance($this->logger); + // TestModule's DevModule chain wraps BecomingInterface in DevBecoming, which + // flushes the semantic logger after every becoming — the same conflict + // ObserveModule's own docblock keeps it out of `dev` for. Undo it here so a + // resource that runs a Be transition (e.g. page://self/product) still closes + // its resource_request scope instead of finding it already flushed out from + // under it. + $this->bind(BecomingInterface::class)->to(Becoming::class); + // Fresh, process-local pools per session: DevPoolProvider's on-disk + // FilesystemAdapter is what makes a real CLI run's second request a hit — + // exactly what an isolated test must not depend on, or leave behind. + $this->bind(AdapterInterface::class)->annotatedWith(ResourceObjectPool::class) + ->toInstance(new ArrayAdapter()); + $this->bind(AdapterInterface::class)->annotatedWith(EtagPool::class) + ->toInstance(new ArrayAdapter()); + } + }; + + $injector = new Injector($wrapper, dirname(__DIR__, 2) . '/var/tmp/test'); + + return $injector->getInstance(ResourceInterface::class); + } + + /** @return array */ + private static function flushToTree(SemanticLoggerInterface $logger): array + { + /** @var array */ + return json_decode(json_encode($logger->flush(), JSON_THROW_ON_ERROR), true, 512, JSON_THROW_ON_ERROR); + } + + private static function bodyPath(string $bodyRef): string + { + return str_starts_with($bodyRef, 'file://') ? substr($bodyRef, 7) : $bodyRef; + } + + private static function removeTree(string $dir): void + { + if (! is_dir($dir)) { + return; + } + + $iterator = new RecursiveIteratorIterator( + new RecursiveDirectoryIterator($dir, FilesystemIterator::SKIP_DOTS), + RecursiveIteratorIterator::CHILD_FIRST, + ); + foreach ($iterator as $file) { + /** @var FilesystemIterator $file phpcs and psalm both accept the SPL leaf type here */ + $file->isDir() ? rmdir($file->getPathname()) : unlink($file->getPathname()); + } + + rmdir($dir); + } + + public function testBodyWrittenInOneInjectorGenerationSurvivesALaterInjectorCreation(): void + { + $logger1 = new SemanticLogger(); + $resource1 = $this->buildSession($logger1); + + $ro1 = $resource1->get('page://self/products'); + $this->assertSame(200, $ro1->code, 'fixture must actually reach the products page'); + + $tree1 = self::flushToTree($logger1); + $bodyRef1 = $tree1['open'][0]['open'][0]['close']['context']['body_ref'] ?? null; + $this->assertIsString($bodyRef1, 'the nested app:// call must record a body_ref'); + $bodyPath1 = self::bodyPath($bodyRef1); + $this->assertFileExists($bodyPath1, 'the body this session just wrote must exist right after writing it'); + $bytesBefore = (string) file_get_contents($bodyPath1); + + // A later injector creation: a brand new ObserveModule::configure() run, the same shape + // as a second `php bin/observe.php` process starting. Same context, so the same + // logDir/es-bodies root — the exact scenario issue #134 broke: FileBodyStore's + // clearDirectory() wiped every earlier session's bodies out from under this second run. + // + // This session's own request records no body at all (page://self/product resolves its + // data through a direct MediaQuery, no nested app:// call — see + // ExcludedResponseBodyStore's own contract for why the outer page:// response itself + // never gets a body_ref), so nothing in this session can recreate session 1's file by + // coincidence: if it is gone after this session, this session's own clearing broke it. + $logger2 = new SemanticLogger(); + $resource2 = $this->buildSession($logger2); + + $ro2 = $resource2->get('page://self/product', ['productCode' => 'sample-001']); + $this->assertSame(200, $ro2->code, 'second session fixture must actually reach the product page'); + $tree2 = self::flushToTree($logger2); + $this->assertArrayNotHasKey( + 'body_ref', + $tree2['open'][0]['close']['context'], + 'fixture precondition: this session must itself write zero bodies, so a survival check ' + . 'right after it cannot pass by the second session coincidentally recreating the same file', + ); + + $this->assertFileExists( + $bodyPath1, + "the first session's body_ref must still resolve after a later injector creation that wrote no " + . 'bodies of its own (issue #134)', + ); + $this->assertSame( + $bytesBefore, + (string) file_get_contents($bodyPath1), + "the first session's body content must be unchanged", + ); + + // A third session that does write a body must land in its own generation, never reusing + // (and so overwriting) the first session's numbered file. + $logger3 = new SemanticLogger(); + $resource3 = $this->buildSession($logger3); + + $ro3 = $resource3->get('page://self/products'); + $this->assertSame(200, $ro3->code, 'third session fixture must also reach the products page'); + $tree3 = self::flushToTree($logger3); + $bodyRef3 = $tree3['open'][0]['open'][0]['close']['context']['body_ref'] ?? null; + $this->assertIsString($bodyRef3, 'the third session must also record its own body_ref'); + $bodyPath3 = self::bodyPath($bodyRef3); + $this->assertNotSame($bodyPath1, $bodyPath3, 'each body-writing session must use its own generation'); + + $this->assertFileExists($bodyPath1, "the first session's body_ref must still resolve after a third session"); + $this->assertSame( + $bytesBefore, + (string) file_get_contents($bodyPath1), + "the first session's body content must remain unchanged after a third session", + ); + } +} From f0df8381e212fb04d967587ef4b2fe516fbd2f74 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 20 Sep 2026 13:36:01 +0900 Subject: [PATCH 2/6] =?UTF-8?q?=E4=BF=9D=E6=8C=81=E4=B8=96=E4=BB=A3?= =?UTF-8?q?=E6=95=B0=E3=82=92=20100=20=E3=81=AB=E6=88=BB=E3=81=99?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit DevQueryRepositoryLogModule の既定は 100。20 を渡すとログ保持が黙って 1/5 になり、過去ログを読み戻す bear-observe の手順が短くなる。100 世代でも 実測 804KB なので、body を揃える目的に削減は不要。 --- .claude/skills/bear-observe/templates/DevModule.php | 5 ++++- src/Module/ObserveModule.php | 5 ++++- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index 74cbab63..c53864f3 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -52,8 +52,11 @@ final class DevModule extends AbstractAppModule * Body generations retained alongside log sessions (same count passed to * DevQueryRepositoryLogModule below): a log's body_ref keeps resolving for as long as the * log itself survives, and neither is pruned without the other (issue #134). + * + * Matches DevQueryRepositoryLogModule's own default so aligning the two lifetimes does not + * shorten the log history the bear-observe skill tells people to read back through. */ - private const int KEEP_GENERATIONS = 20; + private const int KEEP_GENERATIONS = 100; #[Override] protected function configure(): void diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index a2fc9d04..7c843811 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -76,8 +76,11 @@ final class ObserveModule extends AbstractAppModule * Body generations retained alongside log sessions (same count passed to * DevQueryRepositoryLogModule below): a log's body_ref keeps resolving for as long as the * log itself survives, and neither is pruned without the other (issue #134). + * + * Matches DevQueryRepositoryLogModule's own default so aligning the two lifetimes does not + * shorten the log history the bear-observe skill tells people to read back through. */ - private const int KEEP_GENERATIONS = 20; + private const int KEEP_GENERATIONS = 100; private const ORIGINAL_INVOKER = 'original_invoker'; From 80ba6f24a04be9fe42158fc27ceaf470110e5049 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Mon, 21 Sep 2026 10:17:00 +0900 Subject: [PATCH 3/6] =?UTF-8?q?=E5=89=AA=E5=AE=9A=E3=81=AE=20rmdir=20?= =?UTF-8?q?=E3=82=92=E7=AB=B6=E5=90=88=E5=AE=89=E5=85=A8=E3=81=AB=E3=81=99?= =?UTF-8?q?=E3=82=8B?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit clearDirectory() で空にした後の rmdir は装飾的で、失敗しても孤児は 生まれない(その body を参照するログも消えている)。一方、並行 prune に 負けた場合に裸の rmdir() は「既に望む状態」に対して警告を出す。 --- .claude/skills/bear-observe/templates/DevModule.php | 13 ++++++++++++- src/Module/ObserveModule.php | 13 ++++++++++++- 2 files changed, 24 insertions(+), 2 deletions(-) diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index c53864f3..a8c077d6 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -27,6 +27,7 @@ use function count; use function glob; use function gmdate; +use function is_dir; use function max; use function microtime; use function random_bytes; @@ -123,10 +124,20 @@ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): vo foreach (array_slice($generations, 0, $overflow) as $stale) { try { FileBodyStore::clearDirectory($stale); - rmdir($stale); } catch (BodyStoreException) { // A sibling process pruning the same generation concurrently is not an error. + continue; } + + // The directory is empty by now, so removing it is cosmetic: leaving one behind + // orphans nothing, because the log that referenced its bodies is pruned too. A + // concurrent prune can win the race between these two calls, so an unchecked + // rmdir() would emit a warning for a state that is already the desired one. + if (! is_dir($stale)) { + continue; + } + + @rmdir($stale); } } } diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index 7c843811..67c5b945 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -29,6 +29,7 @@ use function count; use function glob; use function gmdate; +use function is_dir; use function max; use function microtime; use function random_bytes; @@ -150,10 +151,20 @@ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): vo foreach (array_slice($generations, 0, $overflow) as $stale) { try { FileBodyStore::clearDirectory($stale); - rmdir($stale); } catch (BodyStoreException) { // A sibling process pruning the same generation concurrently is not an error. + continue; } + + // The directory is empty by now, so removing it is cosmetic: leaving one behind + // orphans nothing, because the log that referenced its bodies is pruned too. A + // concurrent prune can win the race between these two calls, so an unchecked + // rmdir() would emit a warning for a state that is already the desired one. + if (! is_dir($stale)) { + continue; + } + + @rmdir($stale); } } } From fdfcd88dc7542e3c367deb351fb35a9a60e6692e Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Mon, 21 Sep 2026 13:21:10 +0900 Subject: [PATCH 4/6] =?UTF-8?q?body=20=E4=B8=96=E4=BB=A3=E3=82=92=E3=83=AD?= =?UTF-8?q?=E3=82=B0=E3=82=88=E3=82=8A=E5=A4=9A=E3=81=8F=E4=BD=9C=E3=82=89?= =?UTF-8?q?=E3=81=AA=E3=81=84?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit configure() はルーティング前に必ず走り、FileBodyStore はコンストラクタで ディレクトリを作る。そのため記録されないリクエスト(OPTIONS など)でも世代が 1つ増える一方ログは書かれず、保持窓がずれて「保持中のログの body_ref が 指す世代が既に剪定済み」になりうる — #134 の再発。 body が実際に保存されたときだけディレクトリを作ることで、世代は必ず ログ以下になり構造的に解消する。剪定の +1 も不要になった。 --- .../bear-observe/templates/DevModule.php | 47 +++++++++++--- src/Module/DeferredFileBodyStore.php | 43 +++++++++++++ src/Module/ObserveModule.php | 26 +++++--- .../Module/ObserveModuleBodyRetentionTest.php | 62 +++++++++++++++++++ 4 files changed, 159 insertions(+), 19 deletions(-) create mode 100644 src/Module/DeferredFileBodyStore.php diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index a8c077d6..07e76f29 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -16,7 +16,9 @@ use BEAR\QueryRepository\DevQueryRepositoryLogModule; use BEAR\RepositoryModule\Annotation\EtagPool; use BEAR\RepositoryModule\Annotation\ResourceObjectPool; +use BEAR\Resource\AbstractRequest; use BEAR\Resource\InvokerInterface; +use BEAR\Resource\ResourceObject; use Koriym\SemanticLogger\SemanticLoggerInterface; use Override; use Ray\Di\Scope; @@ -64,10 +66,10 @@ protected function configure(): void { $bodiesRoot = $this->appMeta->logDir . '/es-bodies'; self::pruneStaleGenerations($bodiesRoot, self::KEEP_GENERATIONS); - // One subdirectory per request: FileBodyStore's body sequence restarts at 1 on every - // injector build, so a directory shared across sessions would let two sessions - // overwrite each other's numbered files. The key sorts chronologically, matching the - // shape of DevQueryRepositoryLogModule's own session filenames. + // One subdirectory per stored body set: FileBodyStore's sequence restarts at 1 on every + // injector build, so a directory shared across sessions would let two sessions overwrite + // each other's numbered files. The key sorts chronologically, matching the shape of + // DevQueryRepositoryLogModule's own session filenames. $bodyDir = $bodiesRoot . '/' . self::generationKey(); $this->rename(InvokerInterface::class, self::ORIGINAL_INVOKER); @@ -84,7 +86,29 @@ protected function configure(): void // reads visible in the tree. $this->bind(RecordedMethods::class)->annotatedWith(Recorded::class) ->toInstance(new RecordedMethods(RecordedMethods::WITH_READS)); - $this->bind(BodyStoreInterface::class)->toInstance(new FileBodyStore($bodyDir)); + // Deferred, not `new FileBodyStore($bodyDir)`: that constructor creates its directory + // eagerly, and configure() runs before routing knows the request method. A request that + // records nothing (an OPTIONS preflight never reaches the recorded methods, and + // LogFileWriter::write() returns early when nothing was opened) would then add a + // generation without adding a log, letting the body window advance past the log window + // until a retained log's body_ref points at a pruned generation. Creating the directory + // only when a body is stored makes generations strictly rarer than log sessions. + $this->bind(BodyStoreInterface::class)->toInstance( + new class ($bodyDir) implements BodyStoreInterface { + private FileBodyStore|null $store = null; + + public function __construct(private readonly string $dir) + { + } + + public function __invoke(AbstractRequest $request, ResourceObject $ro): string|null + { + $this->store ??= new FileBodyStore($this->dir); + + return ($this->store)($request, $ro); + } + }, + ); $this->install(new EventSourcingModule()); // The cache log module owns the writer and the shutdown flush, so the application @@ -112,15 +136,20 @@ private static function generationKey(): string } /** - * Deletes body generations beyond $keep, oldest first, leaving room for the one this - * request is about to create. Mirrors LogFileWriter::prune()'s own retention count, so a - * body generation is never pruned while the log session that references it still exists. + * Deletes body generations beyond $keep, oldest first. + * + * Shares its retention count with LogFileWriter::prune(). A generation is only created when a + * body is actually stored, which requires a recorded request, which writes a log session — so + * generations are always rarer than logs and the body window spans at least as far back as the + * log window. A retained log's `body_ref` therefore still resolves. The converse does not hold + * and is not claimed: a crashed process can leave a generation whose log was never written, + * and that generation is pruned on count alone. */ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void { $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; sort($generations); - $overflow = max(0, count($generations) - $keep + 1); + $overflow = max(0, count($generations) - $keep); foreach (array_slice($generations, 0, $overflow) as $stale) { try { FileBodyStore::clearDirectory($stale); diff --git a/src/Module/DeferredFileBodyStore.php b/src/Module/DeferredFileBodyStore.php new file mode 100644 index 00000000..f26f7a39 --- /dev/null +++ b/src/Module/DeferredFileBodyStore.php @@ -0,0 +1,43 @@ +store ??= new FileBodyStore($this->dir); + + return ($this->store)($request, $ro); + } +} diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index 67c5b945..a56f9ba7 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -81,7 +81,7 @@ final class ObserveModule extends AbstractAppModule * Matches DevQueryRepositoryLogModule's own default so aligning the two lifetimes does not * shorten the log history the bear-observe skill tells people to read back through. */ - private const int KEEP_GENERATIONS = 100; + public const int KEEP_GENERATIONS = 100; private const ORIGINAL_INVOKER = 'original_invoker'; @@ -90,10 +90,11 @@ protected function configure(): void { $bodiesRoot = $this->appMeta->logDir . '/es-bodies'; self::pruneStaleGenerations($bodiesRoot, self::KEEP_GENERATIONS); - // One subdirectory per request: FileBodyStore's body sequence restarts at 1 on every - // injector build, so a directory shared across sessions would let two sessions - // overwrite each other's numbered files. The key sorts chronologically, matching the - // shape of DevQueryRepositoryLogModule's own session filenames. + // One subdirectory per stored body set: FileBodyStore's sequence restarts at 1 on every + // injector build, so a directory shared across sessions would let two sessions overwrite + // each other's numbered files. The key sorts chronologically, matching the shape of + // DevQueryRepositoryLogModule's own session filenames. DeferredFileBodyStore creates it + // only if a body is actually stored, which is what keeps generations rarer than logs. $bodyDir = $bodiesRoot . '/' . self::generationKey(); $this->bind(ParamsFilterInterface::class)->annotatedWith(Filtered::class) @@ -111,7 +112,7 @@ protected function configure(): void $this->bind(RecordedMethods::class)->annotatedWith(Recorded::class) ->toInstance(new RecordedMethods(RecordedMethods::WITH_READS)); $this->bind(BodyStoreInterface::class) - ->toInstance(new ExcludedResponseBodyStore(new FileBodyStore($bodyDir))); + ->toInstance(new ExcludedResponseBodyStore(new DeferredFileBodyStore($bodyDir))); $this->install(new EventSourcingModule()); // The cache log module owns the writer and the shutdown flush, so the application @@ -139,15 +140,20 @@ private static function generationKey(): string } /** - * Deletes body generations beyond $keep, oldest first, leaving room for the one this - * request is about to create. Mirrors LogFileWriter::prune()'s own retention count, so a - * body generation is never pruned while the log session that references it still exists. + * Deletes body generations beyond $keep, oldest first. + * + * Shares its retention count with LogFileWriter::prune(). A generation is only created when a + * body is actually stored ({@see DeferredFileBodyStore}), which requires a recorded request, + * which writes a log session — so generations are always rarer than logs and the body window + * spans at least as far back as the log window. A retained log's `body_ref` therefore still + * resolves. The converse does not hold and is not claimed: a crashed process can leave a + * generation whose log was never written, and that generation is pruned on count alone. */ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void { $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; sort($generations); - $overflow = max(0, count($generations) - $keep + 1); + $overflow = max(0, count($generations) - $keep); foreach (array_slice($generations, 0, $overflow) as $stale) { try { FileBodyStore::clearDirectory($stale); diff --git a/tests/Module/ObserveModuleBodyRetentionTest.php b/tests/Module/ObserveModuleBodyRetentionTest.php index 12c4261f..a2dc8b86 100644 --- a/tests/Module/ObserveModuleBodyRetentionTest.php +++ b/tests/Module/ObserveModuleBodyRetentionTest.php @@ -25,14 +25,19 @@ use function dirname; use function file_get_contents; +use function file_put_contents; +use function glob; use function is_dir; use function json_decode; use function json_encode; +use function mkdir; use function rmdir; +use function sprintf; use function str_starts_with; use function substr; use function unlink; +use const GLOB_ONLYDIR; use const JSON_THROW_ON_ERROR; /** @@ -199,4 +204,61 @@ public function testBodyWrittenInOneInjectorGenerationSurvivesALaterInjectorCrea "the first session's body content must remain unchanged after a third session", ); } + + public function testAnInjectorThatRecordsNothingAddsNoGeneration(): void + { + // configure() runs before routing knows the request method, so a build that goes on to + // record nothing (an OPTIONS preflight, a process that never dispatches) must not consume + // a generation. If it did, the body window would advance without the log window and + // retention would eventually prune a generation a retained log still points at. + $this->buildSession(new SemanticLogger()); + $this->buildSession(new SemanticLogger()); + $this->buildSession(new SemanticLogger()); + + $this->assertSame( + [], + self::generations(), + 'building an injector without storing a body must not create a generation directory', + ); + } + + public function testGenerationsBeyondTheRetentionCountArePrunedOldestFirst(): void + { + $root = dirname(__DIR__, 2) . '/var/log/' . self::CONTEXT . '/es-bodies'; + mkdir($root, 0775, true); + // One more than the module keeps, so the deletion branch has to run. The `.bear-es-bodies` + // marker is what FileBodyStore::clearDirectory() checks before deleting anything, so a + // generation without it is refused — planting it is what makes these fixtures real. + $planted = []; + for ($i = 0; $i <= ObserveModule::KEEP_GENERATIONS; $i++) { + $dir = $root . '/' . sprintf('20200101-000000-%06d-0000000%d', $i, $i % 10); + mkdir($dir, 0775, true); + file_put_contents($dir . '/.bear-es-bodies', ''); + file_put_contents($dir . '/000001.json', '{}'); + $planted[] = $dir; + } + + $this->buildSession(new SemanticLogger()); + + $survivors = self::generations(); + $this->assertCount( + ObserveModule::KEEP_GENERATIONS, + $survivors, + 'the retention count is the ceiling, and the deletion branch must enforce it', + ); + $this->assertNotContains($planted[0], $survivors, 'the oldest generation must be the one pruned'); + $this->assertContains( + $planted[ObserveModule::KEEP_GENERATIONS], + $survivors, + 'the newest generation must survive', + ); + } + + /** @return list */ + private static function generations(): array + { + $found = glob(dirname(__DIR__, 2) . '/var/log/' . self::CONTEXT . '/es-bodies/*', GLOB_ONLYDIR); + + return $found === false ? [] : $found; + } } From 577affdc49c505c510cca51dc260a0d41ccd7426 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Mon, 21 Sep 2026 13:26:36 +0900 Subject: [PATCH 5/6] =?UTF-8?q?=E5=89=AA=E5=AE=9A=E3=81=AE=20catch=20?= =?UTF-8?q?=E3=81=8C=E4=BD=95=E3=82=92=E9=A3=B2=E3=81=BF=E8=BE=BC=E3=82=80?= =?UTF-8?q?=E3=81=8B=E3=82=92=E6=AD=A3=E7=A2=BA=E3=81=AB=E6=9B=B8=E3=81=8F?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 「並行 prune は異常ではない」だけでは不十分で、この catch は FileBodyStore のオーナーシップ拒否(マーカー無しディレクトリ)も 飲み込む。どちらも本モジュールの責務ではなく、所有していない ディレクトリは削除せず放置する、と明示する。 --- .claude/skills/bear-observe/templates/DevModule.php | 5 ++++- src/Module/ObserveModule.php | 5 ++++- 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index 07e76f29..292ff499 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -154,7 +154,10 @@ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): vo try { FileBodyStore::clearDirectory($stale); } catch (BodyStoreException) { - // A sibling process pruning the same generation concurrently is not an error. + // Skipped, not reported: a sibling process pruning the same generation wins the + // race, and a directory without FileBodyStore's ownership marker is refused on + // purpose. Neither is this module's to fix, and an unowned directory is left + // where it is rather than deleted. continue; } diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index a56f9ba7..3f5f23c2 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -158,7 +158,10 @@ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): vo try { FileBodyStore::clearDirectory($stale); } catch (BodyStoreException) { - // A sibling process pruning the same generation concurrently is not an error. + // Skipped, not reported: a sibling process pruning the same generation wins the + // race, and a directory without FileBodyStore's ownership marker is refused on + // purpose. Neither is this module's to fix, and an unowned directory is left + // where it is rather than deleted. continue; } From c09fc267804e361657f2abbaf50ab157d83b9161 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Mon, 21 Sep 2026 13:31:07 +0900 Subject: [PATCH 6/6] =?UTF-8?q?=E5=89=AA=E5=AE=9A=E3=81=AE=E5=AF=BE?= =?UTF-8?q?=E8=B1=A1=E3=82=92=20body=20store=20=E3=81=8C=E6=89=80=E6=9C=89?= =?UTF-8?q?=E3=81=99=E3=82=8B=E3=83=87=E3=82=A3=E3=83=AC=E3=82=AF=E3=83=88?= =?UTF-8?q?=E3=83=AA=E3=81=AB=E9=99=90=E3=82=8B?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit es-bodies/ に紛れた非所有ディレクトリを上限に数えると過剰削除になる。 最新側に並ぶ名前(小文字は ASCII で数字より後、例 es-bodies/tmp)だと overflow だけが増え、最古から切る slice は所有世代のみで埋まるため、 stray 1つにつき実世代が1つ失われ body 窓がログ窓より短くなる。 オーナーシップマーカーを持つものだけを世代として数える。 --- .../bear-observe/templates/DevModule.php | 21 +++++++++++++++- src/Module/ObserveModule.php | 21 +++++++++++++++- .../Module/ObserveModuleBodyRetentionTest.php | 25 +++++++++++++++++++ 3 files changed, 65 insertions(+), 2 deletions(-) diff --git a/.claude/skills/bear-observe/templates/DevModule.php b/.claude/skills/bear-observe/templates/DevModule.php index 292ff499..edc80320 100644 --- a/.claude/skills/bear-observe/templates/DevModule.php +++ b/.claude/skills/bear-observe/templates/DevModule.php @@ -30,6 +30,7 @@ use function glob; use function gmdate; use function is_dir; +use function is_file; use function max; use function microtime; use function random_bytes; @@ -60,6 +61,11 @@ final class DevModule extends AbstractAppModule * shorten the log history the bear-observe skill tells people to read back through. */ private const int KEEP_GENERATIONS = 100; + /** + * Ownership marker FileBodyStore writes into each directory it manages; its own copy of this + * name is private, so pruning re-states it rather than miscounting a directory it does not own. + */ + private const string BODY_STORE_MARKER = '.bear-es-bodies'; #[Override] protected function configure(): void @@ -147,7 +153,20 @@ private static function generationKey(): string */ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void { - $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; + // Only directories carrying FileBodyStore's ownership marker. Counting anything else + // toward the cap over-prunes: a foreign directory that sorts newer than the generations + // (any lowercase name does — ASCII puts letters after digits) inflates the overflow while + // the oldest-first slice stays entirely ours, so one stray `es-bodies/tmp` permanently + // costs one real generation and shrinks the body window below the log window. + $generations = []; + foreach (glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: [] as $candidate) { + if (! is_file($candidate . '/' . self::BODY_STORE_MARKER)) { + continue; + } + + $generations[] = $candidate; + } + sort($generations); $overflow = max(0, count($generations) - $keep); foreach (array_slice($generations, 0, $overflow) as $stale) { diff --git a/src/Module/ObserveModule.php b/src/Module/ObserveModule.php index 3f5f23c2..76e0b0c9 100644 --- a/src/Module/ObserveModule.php +++ b/src/Module/ObserveModule.php @@ -30,6 +30,7 @@ use function glob; use function gmdate; use function is_dir; +use function is_file; use function max; use function microtime; use function random_bytes; @@ -82,6 +83,11 @@ final class ObserveModule extends AbstractAppModule * shorten the log history the bear-observe skill tells people to read back through. */ public const int KEEP_GENERATIONS = 100; + /** + * Ownership marker FileBodyStore writes into each directory it manages; its own copy of this + * name is private, so pruning re-states it rather than miscounting a directory it does not own. + */ + private const string BODY_STORE_MARKER = '.bear-es-bodies'; private const ORIGINAL_INVOKER = 'original_invoker'; @@ -151,7 +157,20 @@ private static function generationKey(): string */ private static function pruneStaleGenerations(string $bodiesRoot, int $keep): void { - $generations = glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: []; + // Only directories carrying FileBodyStore's ownership marker. Counting anything else + // toward the cap over-prunes: a foreign directory that sorts newer than the generations + // (any lowercase name does — ASCII puts letters after digits) inflates the overflow while + // the oldest-first slice stays entirely ours, so one stray `es-bodies/tmp` permanently + // costs one real generation and shrinks the body window below the log window. + $generations = []; + foreach (glob($bodiesRoot . '/*', GLOB_ONLYDIR) ?: [] as $candidate) { + if (! is_file($candidate . '/' . self::BODY_STORE_MARKER)) { + continue; + } + + $generations[] = $candidate; + } + sort($generations); $overflow = max(0, count($generations) - $keep); foreach (array_slice($generations, 0, $overflow) as $stale) { diff --git a/tests/Module/ObserveModuleBodyRetentionTest.php b/tests/Module/ObserveModuleBodyRetentionTest.php index a2dc8b86..c930f24e 100644 --- a/tests/Module/ObserveModuleBodyRetentionTest.php +++ b/tests/Module/ObserveModuleBodyRetentionTest.php @@ -254,6 +254,31 @@ public function testGenerationsBeyondTheRetentionCountArePrunedOldestFirst(): vo ); } + public function testAForeignDirectoryDoesNotCostARealGeneration(): void + { + $root = dirname(__DIR__, 2) . '/var/log/' . self::CONTEXT . '/es-bodies'; + mkdir($root, 0775, true); + // `tmp` sorts AFTER the timestamped names (ASCII puts letters after digits), so counting it + // inflates the overflow while the oldest-first slice stays entirely ours — the shape that + // silently costs one real generation per stray directory. + $foreign = $root . '/tmp'; + mkdir($foreign, 0775, true); + + $owned = []; + for ($i = 0; $i < ObserveModule::KEEP_GENERATIONS; $i++) { + $dir = $root . '/' . sprintf('20200101-000000-%06d-0000000%d', $i, $i % 10); + mkdir($dir, 0775, true); + file_put_contents($dir . '/.bear-es-bodies', ''); + $owned[] = $dir; + } + + $this->buildSession(new SemanticLogger()); + + $survivors = self::generations(); + $this->assertContains($owned[0], $survivors, 'exactly the retention count is owned, so none may be pruned'); + $this->assertContains($foreign, $survivors, 'a directory the body store does not own must be left alone'); + } + /** @return list */ private static function generations(): array {