From b4dc71bf00c10aa5115818929e99fa0d711cd2d3 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 25 Oct 2026 12:08:06 +0900 Subject: [PATCH 1/5] Do not store a donut template whose render threw --- CHANGELOG.md | 1 + src/Exception/DonutRenderAborted.php | 19 +++ src/ResourceDonut.php | 68 +++++++- .../Page/Html/DonutCacheWithThrowingHole.php | 25 +++ .../Html/DonutCacheWithThrowingHole.html.twig | 1 + tests/GracefulLoggingTest.php | 74 ++++++++ tests/ResourceDonutTest.php | 159 +++++++++++++++++- 7 files changed, 341 insertions(+), 6 deletions(-) create mode 100644 src/Exception/DonutRenderAborted.php create mode 100644 tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithThrowingHole.php create mode 100644 tests/Fake/fake-app/var/templates/Page/Html/DonutCacheWithThrowingHole.html.twig diff --git a/CHANGELOG.md b/CHANGELOG.md index 40fa8da5..17525542 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -22,6 +22,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - `LogFileWriter`: two sessions flushed in the same microsecond no longer overwrite each other. The timestamped filename now carries a random suffix, so both survive (#221). - A `#[DonutCache]` page embedding an `#[Embed]` hole whose URI carried two or more query parameters leaked a raw `[le:...]` placeholder to the client and could throw `ParameterException` on the next request - fixed by moving new placeholders to a `[le2:...]` marker (#232). +- A `#[DonutCache]`/`#[CacheableResponse]` page whose render threw - a hole's own resource or the page's own template - no longer stores the empty template BEAR.Resource's `ResourceObject::__toString()` swallows that failure into; that empty template would otherwise be served to every later visitor (since 1.17.0). ## [1.17.0] - 2026-09-17 diff --git a/src/Exception/DonutRenderAborted.php b/src/Exception/DonutRenderAborted.php new file mode 100644 index 00000000..b6f52096 --- /dev/null +++ b/src/Exception/DonutRenderAborted.php @@ -0,0 +1,19 @@ +getMessage()})\n" . + * $e->getTraceAsString()` (vendor/bear/resource/src/ResourceObject.php). Anchored on the + * `#0 ` a Throwable::getTraceAsString() trace always starts with, so an unrelated warning + * that merely happens to look like "Class(message)" is not misread as a swallowed render. + */ + private const SWALLOWED_RENDER_WARNING = '/\A(?[\\\\\w]+)\((?.*)\)\n#0 /s'; + /** * Build the placeholder DonutRequest::__toString() embeds and DonutRenderer matches */ @@ -90,6 +107,11 @@ public function refresh(ResourceInterface $resource, ResourceObject $ro, Uncache try { $ro = $resource->get($uri); $ro->toString(); + } catch (Throwable $e) { + // Unlike create()'s `(string) $ro`, this explicit toString() call does not + // swallow a Throwable into an E_USER_WARNING - it propagates directly, so no + // error-handler guard is needed, only this catch. + throw CacheStoreFailure::from($e); } finally { $mark->leaveHole($uri); } @@ -234,8 +256,52 @@ public static function create(ResourceObject $ro, DonutRendererInterface $storag unset($maybeRequest); } - $donutTemplate = (string) $ro; + $donutTemplate = self::renderTemplateOrAbort($ro); return new self($donutTemplate, $ro->headers, $ttl, $isCacheble, code: $ro->code); } + + /** + * Cast a page RO to its template string, refusing the donut store if the render was + * actually a Throwable that `ResourceObject::__toString()` swallowed (both a hole's own + * render - DonutRequest::__toString() does not catch, so a hole's failure surfaces here + * too - and the composing page's own template failing outside any hole). + * + * A scoped error handler, installed only for the duration of this cast, is the only way + * to see that: the Throwable itself never reaches here, only the E_USER_WARNING the + * swallow leaves behind. On a match it still returns false, so PHP's own handling of + * that original warning (log, display) runs exactly as it would with no handler + * installed at all - only the empty return value this call would otherwise produce is + * refused, via CacheStoreFailure, which the interceptors already catch and degrade. + */ + private static function renderTemplateOrAbort(ResourceObject $ro): string + { + /** @var string|null $abortedRenderMessage */ + $abortedRenderMessage = null; + /** @var callable|null $previous */ + $previous = null; + $previous = set_error_handler( + static function (int $errno, string $errstr, string $errfile = '', int $errline = 0) use (&$abortedRenderMessage, &$previous): bool { + if ($errno === E_USER_WARNING && preg_match(self::SWALLOWED_RENDER_WARNING, $errstr, $match) === 1) { + $abortedRenderMessage = sprintf('%s: %s', $match['class'], $match['message']); + + return false; + } + + return $previous !== null ? (bool) $previous($errno, $errstr, $errfile, $errline) : false; + }, + ); + + try { + $donutTemplate = (string) $ro; + } finally { + restore_error_handler(); + } + + if ($abortedRenderMessage !== null) { + throw CacheStoreFailure::from(new DonutRenderAborted($abortedRenderMessage)); + } + + return $donutTemplate; + } } diff --git a/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithThrowingHole.php b/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithThrowingHole.php new file mode 100644 index 00000000..3cb289bc --- /dev/null +++ b/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithThrowingHole.php @@ -0,0 +1,25 @@ +{{ secret }} diff --git a/tests/GracefulLoggingTest.php b/tests/GracefulLoggingTest.php index 71171a21..81c77982 100644 --- a/tests/GracefulLoggingTest.php +++ b/tests/GracefulLoggingTest.php @@ -242,6 +242,80 @@ protected function configure(): void $this->assertNotNull($close, 'the get scope still closes'); } + /** + * A render that throws must never bake an empty donut template into the store - that + * would serve an empty page to every later visitor (since 1.17.0). The first request's + * write is refused and recorded; a second request is still a cache miss, not a hit + * reading the empty template the bug would have stored. + */ + public function testDonutWriteIsRefusedNotStoredWhenAHoleThrowsDuringRender(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new TwigModule([dirname(__DIR__) . '/tests/Fake/fake-app/var/templates'])); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + $logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class); + + set_error_handler(static fn (): bool => true); // the swallowed-render warning and the degrade warning both fire + try { + $first = $resource->get('page://self/html/donut-cache-with-throwing-hole'); + $this->assertSame(200, $first->code, 'the request still completes even though nothing is stored'); + } finally { + restore_error_handler(); + } + + $tree = $this->flushAndValidate($logger); + $error = self::eventContextJsonOf($tree, 'cache_error'); + $this->assertNotNull($error, 'the aborted render is recorded, not silently cached'); + $this->assertStringContainsString('"operation":"write"', $error); + $this->assertStringContainsString('DonutRenderAborted', $error); + + // If the bug were present, this second request would be a cache HIT serving the + // empty template the first request's write would otherwise have stored. + set_error_handler(static fn (): bool => true); + try { + $resource->get('page://self/html/donut-cache-with-throwing-hole'); + } finally { + restore_error_handler(); + } + + $tree2 = $this->flushAndValidate($logger); + $this->assertNull(self::closeContextJsonOf($tree2, 'cache_hit'), 'a later request must not be served from a cached empty template'); + $this->assertNotNull(self::closeContextJsonOf($tree2, 'cache_miss'), 'a later request is still a cache miss - nothing was ever stored'); + } + + /** + * The same guard refuses a store when the composing page's own template throws, outside + * any hole - `(string) $ro` in ResourceDonut::create() renders the page itself too. + */ + public function testDonutWriteIsRefusedNotStoredWhenThePageTemplateItselfThrows(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new class extends AbstractModule { + protected function configure(): void + { + $this->bind(RenderInterface::class)->to(FakeThrowingRenderer::class); + } + }); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + $logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class); + + set_error_handler(static fn (): bool => true); + try { + $ro = $resource->get('page://self/html/plain-donut-hole'); + $this->assertSame(200, $ro->code, 'the request still completes even though nothing is stored'); + } finally { + restore_error_handler(); + } + + $tree = $this->flushAndValidate($logger); + $error = self::eventContextJsonOf($tree, 'cache_error'); + $this->assertNotNull($error, 'the aborted render is recorded, not silently cached'); + $this->assertStringContainsString('"operation":"write"', $error); + $this->assertStringContainsString('DonutRenderAborted', $error); + } + public function testAValueEntryIsStoredWithoutRenderingTheResource(): void { // An app resource has no template under an html renderer, so any render attempt throws. diff --git a/tests/ResourceDonutTest.php b/tests/ResourceDonutTest.php index 51ad14fa..1b6798be 100644 --- a/tests/ResourceDonutTest.php +++ b/tests/ResourceDonutTest.php @@ -4,21 +4,33 @@ namespace BEAR\QueryRepository; +use BEAR\QueryRepository\Exception\CacheStoreFailure; +use BEAR\Resource\AbstractRequest; use BEAR\Resource\Exception\ParameterException; use BEAR\Resource\Method; +use BEAR\Resource\RenderInterface; use BEAR\Resource\RequestInterface; +use BEAR\Resource\Resource; use BEAR\Resource\ResourceInterface; use BEAR\Resource\ResourceObject; use Madapaja\TwigModule\TwigModule; use PHPUnit\Framework\Attributes\DataProvider; use PHPUnit\Framework\TestCase; +use Ray\Di\AbstractModule; use Ray\Di\Injector; +use ReflectionClassConstant; use RuntimeException; +use function assert; use function dirname; +use function error_clear_last; +use function error_get_last; use function htmlspecialchars; use function http_build_query; +use function is_string; +use function preg_match; +use const E_USER_WARNING; use const ENT_QUOTES; class ResourceDonutTest extends TestCase @@ -143,17 +155,23 @@ public function testRefreshOfALegacyDuplicateKeyPlaceholderStaysExactlyAsWrongAs /** * A legacy `[le:URI]` placeholder for a hole with two REQUIRED query params, corrupted - * the same way, stays exactly as broken as it already was: still a ParameterException, - * the same failure a pre-#232-fix refresh() threw - not this fix's rawurldecode() - * turning it into a different, new failure. + * the same way, fails the re-fetch with the same underlying cause as a pre-#232-fix + * refresh() threw - still a ParameterException, not this fix's rawurldecode() turning it + * into a different, new failure - except that cause now arrives wrapped in a + * CacheStoreFailure instead of surfacing raw, the same conversion any re-fetch failure + * gets so the interceptor can refuse the store instead of caching nothing. */ public function testRefreshOfALegacyMultiParamPlaceholderFailsTheSameWayAsBeforeThisFix(): void { $ro = $this->resource->newInstance('page://self/html/blog-posting-donut'); $donut = new ResourceDonut('

[le:app://self/multi-param-query-hole?id=1&tag=2]

', [], null, false); - $this->expectException(ParameterException::class); - $donut->refresh($this->resource, $ro, $this->mark); + try { + $donut->refresh($this->resource, $ro, $this->mark); + $this->fail('expected the malformed legacy placeholder to fail the re-fetch'); + } catch (CacheStoreFailure $e) { + $this->assertInstanceOf(ParameterException::class, $e->getPrevious()); + } } /** @@ -255,4 +273,135 @@ public function options(string $uri, array $query = []): ResourceObject 'a mark right after the aborted re-fetch must stay filed under TOP_LEVEL, not get displaced by a scope the throw left stuck on the stack', ); } + + /** + * `BEAR\Resource\ResourceObject::__toString()` swallows a Throwable from a failed render + * into an E_USER_WARNING and an empty string - a hole's own onGet() propagates here + * uncaught (`DonutRequest::__toString()` has no catch of its own). Storing that empty + * string as the donut template would serve an empty page to every later visitor (since + * 1.17.0). This also pins BEAR.Resource's warning shape: if a future version changes it, + * the guard's regex stops matching and this test fails instead of silently going back to + * caching empty pages. + */ + public function testCreateRefusesToStoreTheTemplateWhenAHoleThrows(): void + { + $ro = $this->resource->newInstance('page://self/html/donut-cache-with-throwing-hole'); + $resource = $this->resource; + assert($resource instanceof Resource); + $throwingRequest = $resource->get->uri('app://self/throwing-hole'); + assert($throwingRequest instanceof AbstractRequest); + $ro->body = ['secret' => $throwingRequest]; + + error_clear_last(); + $this->expectException(CacheStoreFailure::class); + try { + ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); + } finally { + // The handler returns false on a match, so PHP's own handling of the warning + // still runs unsuppressed - error_get_last() is set by the engine regardless of + // what any handler returns, so this proves the original warning was not lost. + $last = error_get_last(); + $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); + $this->assertSame(E_USER_WARNING, $last['type']); + $this->assertStringContainsString('the hole blew up mid-render', $last['message']); + } + } + + /** + * Pins the guard's regex directly: anchored on `#0 `, the FIRST trace frame specifically, + * not just any frame number - a `.*` message group that merely required SOME `)\n#N ` + * later in the string could still match past a deep-enough trace, swallowing part of it + * into "message" instead of stopping at the true header boundary. + */ + public function testSwallowedRenderWarningRegexMatchesPreciselyAndRejectsUnrelatedWarnings(): void + { + $pattern = (new ReflectionClassConstant(ResourceDonut::class, 'SWALLOWED_RENDER_WARNING'))->getValue(); + assert(is_string($pattern)); + + $vendorShaped = "RuntimeException(the hole blew up mid-render)\n#0 /app/Foo.php(12): bar()\n#1 /app/Baz.php(34): qux()\n#2 {main}"; + $this->assertSame(1, preg_match($pattern, $vendorShaped, $match)); + $this->assertSame('RuntimeException', $match['class']); + $this->assertSame('the hole blew up mid-render', $match['message']); + + foreach (['Undefined array key 3', 'Array to string conversion', 'Deprecated: foo() is deprecated'] as $unrelated) { + $this->assertSame(0, preg_match($pattern, $unrelated), "must not misread: $unrelated"); + } + } + + /** + * The same swallow happens when the composing page's OWN template fails, outside any + * hole - `(string) $ro` in create() renders the page itself, not only its holes. + */ + public function testCreateRefusesToStoreTheTemplateWhenThePageTemplateItselfThrows(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new class extends AbstractModule { + protected function configure(): void + { + $this->bind(RenderInterface::class)->to(FakeThrowingRenderer::class); + } + }); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + $mark = $injector->getInstance(UncacheableMarkInterface::class); + $ro = $resource->newInstance('page://self/html/plain-donut-hole'); + $ro->body = ['value' => 'plain']; + + error_clear_last(); + $this->expectException(CacheStoreFailure::class); + try { + ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $mark); + } finally { + $last = error_get_last(); + $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); + $this->assertSame(E_USER_WARNING, $last['type']); + $this->assertStringContainsString('template not found', $last['message']); + } + } + + /** + * The guard must not refuse a page that renders without error - only the specific + * swallowed-render warning shape triggers it. + */ + public function testCreateStillStoresTheTemplateWhenNothingThrows(): void + { + $ro = $this->resource->newInstance('page://self/html/plain-donut-hole'); + $ro->body = ['value' => 'plain']; + + $donut = ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); + $rendered = $donut->render($ro, new DonutRenderer()); + + $this->assertStringContainsString('plain-donut-hole:plain', (string) $rendered->view); + } + + /** + * Unlike create()'s `(string) $ro`, refresh()'s per-hole `$ro->toString()` (and the + * `$resource->get($uri)` re-fetch that runs the hole's onGet()) does not swallow a + * Throwable - it propagates directly, so this is a plain try/catch, converted to the same + * CacheStoreFailure create() raises, so both paths degrade through the same interceptor + * code. + */ + public function testRefreshRefusesToServeWhenAHoleThrows(): void + { + $ro = $this->resource->newInstance('page://self/html/blog-posting-donut'); + $uri = 'app://self/throwing-hole'; + $donut = new ResourceDonut('

' . ResourceDonut::placeholder($uri) . '

', [], null, false); + + try { + $donut->refresh($this->resource, $ro, $this->mark); + $this->fail('expected the hole throw to be refused as a CacheStoreFailure'); + } catch (CacheStoreFailure $e) { + $this->assertStringContainsString('the hole blew up mid-render', $e->getMessage()); + } + + // Same stack-balance check as testRefreshLeavesTheHoleScopeEvenWhenTheReFetchThrows: + // the catch must not skip the finally that leaves the hole's scope. + $this->mark->mark('after the throw'); + $this->mark->leaveHole($uri); + + $this->assertTrue( + $this->mark->isMarkedForCurrentScope(), + 'a mark right after the refused re-fetch must stay filed under TOP_LEVEL, not get displaced by a scope the throw left stuck on the stack', + ); + } } From 9449c6be9d1415bf5979b332fac98b2621e76e62 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 25 Oct 2026 12:15:57 +0900 Subject: [PATCH 2/5] Address review: document refresh() semantics, strengthen tests, clarify CacheStoreFailure --- CHANGELOG.md | 1 + src/Exception/CacheStoreFailure.php | 9 ++++ tests/GracefulLoggingTest.php | 5 ++ tests/ResourceDonutTest.php | 75 ++++++++++++----------------- 4 files changed, 46 insertions(+), 44 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 17525542..b9fdae06 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -18,6 +18,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - `ResourceDonut::FORMAT` is no longer public; use `ResourceDonut::placeholder()`. `ResourceDonut::refresh()` takes an additional `UncacheableMarkInterface` argument. - Requires `koriym/semantic-logger` `^0.11`. Written logs use its `log` document shape, and diagnostic `kind` is now `code`. - `KeepMutationsAndFailures` also keeps a session cut at the record limit (`semantic_logger_truncated`): a `command` past the limit leaves no other trace. +- `ResourceDonut::refresh()`: a hole that throws while an already-cached `#[DonutCache]` page is recomposed (its own `onGet()` or its render) no longer lets that exception reach the caller. It now degrades the same way a cache-store failure does - recorded as a `cache_error` and served via a fresh, non-donut render of the whole page - so a transient hole failure costs latency, not an error response. A permanently broken hole (for example a corrupted legacy placeholder's `ParameterException`, previously an uncaught 500) now degrades to 200 on every refresh instead. ### Fixed - `LogFileWriter`: two sessions flushed in the same microsecond no longer overwrite each other. The timestamped filename now carries a random suffix, so both survive (#221). diff --git a/src/Exception/CacheStoreFailure.php b/src/Exception/CacheStoreFailure.php index 6b701abd..72f51db6 100644 --- a/src/Exception/CacheStoreFailure.php +++ b/src/Exception/CacheStoreFailure.php @@ -22,6 +22,15 @@ * command or a direct call has no interceptor, so it reaches the caller and the write is not * reported as done. The automatic write inside a GET is caught and degraded - that request * changed nothing, so nothing at an edge became stale by it. + * + * `ResourceDonut::create()`'s render also arrives here, which looks like the "renderer with a + * bug" case this class says it deliberately excludes - but it is not that case: by the time + * `ResourceObject::__toString()` returns, BEAR.Resource has already caught and discarded the + * real Throwable itself (an E_USER_WARNING and `''` are all that is left of it), so there is + * no longer a genuine exception left to let travel - only a reconstruction from that warning's + * text (`Exception\DonutRenderAborted`). Degrading is what lets the response stay servable + * without fabricating a 500 from a guessed cause; the original warning still surfaces + * unsuppressed, and the reconstruction is recorded in the semantic log either way. */ final class CacheStoreFailure extends RuntimeException { diff --git a/tests/GracefulLoggingTest.php b/tests/GracefulLoggingTest.php index 81c77982..e43fcdcb 100644 --- a/tests/GracefulLoggingTest.php +++ b/tests/GracefulLoggingTest.php @@ -270,6 +270,11 @@ public function testDonutWriteIsRefusedNotStoredWhenAHoleThrowsDuringRender(): v $this->assertStringContainsString('"operation":"write"', $error); $this->assertStringContainsString('DonutRenderAborted', $error); + // Independent of what a later request happens to do: directly proves nothing was + // stored, rather than inferring it from a second request's cache_miss. + $resourceStorage = $injector->getInstance(ResourceStorageInterface::class); + $this->assertNull($resourceStorage->getDonut($first->uri), 'nothing was stored after the aborted render'); + // If the bug were present, this second request would be a cache HIT serving the // empty template the first request's write would otherwise have stored. set_error_handler(static fn (): bool => true); diff --git a/tests/ResourceDonutTest.php b/tests/ResourceDonutTest.php index 1b6798be..5e3e8d97 100644 --- a/tests/ResourceDonutTest.php +++ b/tests/ResourceDonutTest.php @@ -18,7 +18,6 @@ use PHPUnit\Framework\TestCase; use Ray\Di\AbstractModule; use Ray\Di\Injector; -use ReflectionClassConstant; use RuntimeException; use function assert; @@ -27,8 +26,6 @@ use function error_get_last; use function htmlspecialchars; use function http_build_query; -use function is_string; -use function preg_match; use const E_USER_WARNING; use const ENT_QUOTES; @@ -157,9 +154,10 @@ public function testRefreshOfALegacyDuplicateKeyPlaceholderStaysExactlyAsWrongAs * A legacy `[le:URI]` placeholder for a hole with two REQUIRED query params, corrupted * the same way, fails the re-fetch with the same underlying cause as a pre-#232-fix * refresh() threw - still a ParameterException, not this fix's rawurldecode() turning it - * into a different, new failure - except that cause now arrives wrapped in a - * CacheStoreFailure instead of surfacing raw, the same conversion any re-fetch failure - * gets so the interceptor can refuse the store instead of caching nothing. + * into a different, new failure. Unlike before this PR, that cause no longer reaches the + * caller raw: it now arrives wrapped in a CacheStoreFailure, the same conversion any + * re-fetch failure gets, so `AbstractDonutCacheInterceptor`'s read path degrades to a + * fresh render instead of a 500 - an intentional behavior change (see CHANGELOG). */ public function testRefreshOfALegacyMultiParamPlaceholderFailsTheSameWayAsBeforeThisFix(): void { @@ -279,9 +277,12 @@ public function options(string $uri, array $query = []): ResourceObject * into an E_USER_WARNING and an empty string - a hole's own onGet() propagates here * uncaught (`DonutRequest::__toString()` has no catch of its own). Storing that empty * string as the donut template would serve an empty page to every later visitor (since - * 1.17.0). This also pins BEAR.Resource's warning shape: if a future version changes it, - * the guard's regex stops matching and this test fails instead of silently going back to - * caching empty pages. + * 1.17.0). + * + * This also pins the guard's precision through the public API: a regex that matched too + * late in the trace would show up here as a reconstructed message polluted with stray + * `#0 `/`.php(` trace fragments, and a regex that stopped matching at all (BEAR.Resource's + * warning shape drifting) would show up as no exception being thrown. */ public function testCreateRefusesToStoreTheTemplateWhenAHoleThrows(): void { @@ -293,39 +294,23 @@ public function testCreateRefusesToStoreTheTemplateWhenAHoleThrows(): void $ro->body = ['secret' => $throwingRequest]; error_clear_last(); - $this->expectException(CacheStoreFailure::class); try { ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); - } finally { - // The handler returns false on a match, so PHP's own handling of the warning - // still runs unsuppressed - error_get_last() is set by the engine regardless of - // what any handler returns, so this proves the original warning was not lost. - $last = error_get_last(); - $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); - $this->assertSame(E_USER_WARNING, $last['type']); - $this->assertStringContainsString('the hole blew up mid-render', $last['message']); + $this->fail('expected the hole throw to refuse the store'); + } catch (CacheStoreFailure $e) { + $this->assertStringStartsWith('Twig\Error\RuntimeError: ', $e->getMessage()); + $this->assertStringContainsString('the hole blew up mid-render', $e->getMessage()); + $this->assertStringNotContainsString('#0 ', $e->getMessage()); + $this->assertStringNotContainsString('.php(', $e->getMessage()); } - } - - /** - * Pins the guard's regex directly: anchored on `#0 `, the FIRST trace frame specifically, - * not just any frame number - a `.*` message group that merely required SOME `)\n#N ` - * later in the string could still match past a deep-enough trace, swallowing part of it - * into "message" instead of stopping at the true header boundary. - */ - public function testSwallowedRenderWarningRegexMatchesPreciselyAndRejectsUnrelatedWarnings(): void - { - $pattern = (new ReflectionClassConstant(ResourceDonut::class, 'SWALLOWED_RENDER_WARNING'))->getValue(); - assert(is_string($pattern)); - - $vendorShaped = "RuntimeException(the hole blew up mid-render)\n#0 /app/Foo.php(12): bar()\n#1 /app/Baz.php(34): qux()\n#2 {main}"; - $this->assertSame(1, preg_match($pattern, $vendorShaped, $match)); - $this->assertSame('RuntimeException', $match['class']); - $this->assertSame('the hole blew up mid-render', $match['message']); - foreach (['Undefined array key 3', 'Array to string conversion', 'Deprecated: foo() is deprecated'] as $unrelated) { - $this->assertSame(0, preg_match($pattern, $unrelated), "must not misread: $unrelated"); - } + // The handler returns false on a match, so PHP's own handling of the warning still + // runs unsuppressed - error_get_last() is set by the engine regardless of what any + // handler returns, so this proves the original warning was not lost. + $last = error_get_last(); + $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); + $this->assertSame(E_USER_WARNING, $last['type']); + $this->assertStringContainsString('the hole blew up mid-render', $last['message']); } /** @@ -348,15 +333,17 @@ protected function configure(): void $ro->body = ['value' => 'plain']; error_clear_last(); - $this->expectException(CacheStoreFailure::class); try { ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $mark); - } finally { - $last = error_get_last(); - $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); - $this->assertSame(E_USER_WARNING, $last['type']); - $this->assertStringContainsString('template not found', $last['message']); + $this->fail('expected the page template throw to refuse the store'); + } catch (CacheStoreFailure $e) { + $this->assertSame('BEAR\QueryRepository\FakeTemplateNotFound: template not found: user.html.twig', $e->getMessage()); } + + $last = error_get_last(); + $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); + $this->assertSame(E_USER_WARNING, $last['type']); + $this->assertStringContainsString('template not found', $last['message']); } /** From 07939b8c31fcd6a361e7178a3165d544757662f7 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 25 Oct 2026 13:40:15 +0900 Subject: [PATCH 3/5] Redesign: detect an aborted donut render via toString(), not a warning-matching error handler --- CHANGELOG.md | 7 +- src/AbstractDonutCacheInterceptor.php | 42 ++- src/DonutRequest.php | 10 +- src/Exception/CacheStoreFailure.php | 15 +- src/Exception/DonutRenderAborted.php | 19 -- src/ResourceDonut.php | 76 ++---- tests/Fake/FakeWarningEmittingRenderer.php | 29 +++ .../Resource/App/AnonymousThrowingHole.php | 24 ++ .../fake-app/src/Resource/App/FlakyHole.php | 33 +++ .../src/Resource/App/HoleWithNoTemplate.php | 23 ++ .../Page/Html/DonutCacheWithFlakyHole.php | 24 ++ .../Page/Html/PlainNoCacheAttribute.php | 21 ++ .../var/templates/App/FlakyHole.html.twig | 1 + .../Html/DonutCacheWithFlakyHole.html.twig | 1 + .../Page/Html/PlainNoCacheAttribute.html.twig | 1 + tests/GracefulLoggingTest.php | 240 +++++++++++++++--- tests/ResourceDonutTest.php | 137 +++++++--- 17 files changed, 531 insertions(+), 172 deletions(-) delete mode 100644 src/Exception/DonutRenderAborted.php create mode 100644 tests/Fake/FakeWarningEmittingRenderer.php create mode 100644 tests/Fake/fake-app/src/Resource/App/AnonymousThrowingHole.php create mode 100644 tests/Fake/fake-app/src/Resource/App/FlakyHole.php create mode 100644 tests/Fake/fake-app/src/Resource/App/HoleWithNoTemplate.php create mode 100644 tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithFlakyHole.php create mode 100644 tests/Fake/fake-app/src/Resource/Page/Html/PlainNoCacheAttribute.php create mode 100644 tests/Fake/fake-app/var/templates/App/FlakyHole.html.twig create mode 100644 tests/Fake/fake-app/var/templates/Page/Html/DonutCacheWithFlakyHole.html.twig create mode 100644 tests/Fake/fake-app/var/templates/Page/Html/PlainNoCacheAttribute.html.twig diff --git a/CHANGELOG.md b/CHANGELOG.md index 7049a08d..024a3853 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,17 +15,18 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed - Deploy this version with a new `CacheVersionModule` version (an app that binds its own cache adapter rather than this package's `Storage*Module`s must clear its pools instead): entries written by earlier versions may hold per-user content, and an earlier version reading this version's donut cache shows raw `[le2:...]` placeholders during a rolling deploy. - A `#[Cacheable]`/`#[CacheableResponse]` response whose own code sets `Cache-Control` to `private` or `no-store` is no longer stored server-side; its header is kept and CDN headers are removed. A value declared by `#[HttpCache]`/`#[NoHttpCache]` is still stored. -- Upgrading changes the Ray.Aop-woven class name - and so the ETag (`crc32($ro::class . ...)`) - for a `#[CacheableResponse]` class or method that also declares an `#[Embed]`, because it is now woven with a new interceptor (#226); a page with no `#[Embed]` keeps its stock woven class and ETag, and a `#[DonutCache]` page never carries an ETag at all, so neither is affected. +- Upgrading changes the Ray.Aop-woven class name - and so the ETag (`crc32($ro::class . ...)`) - for a `#[CacheableResponse]` class or method that also declares an `#[Embed]`, because it is now woven with a new interceptor (#226); a page with no `#[Embed]` keeps its stock woven class and ETag, and a `#[DonutCache]` page never carries an ETag at all, so neither is affected. This release's own `AbstractDonutCacheInterceptor` fix (see Fixed, below) changes that interceptor's own composition too, so a `#[CacheableResponse]`+`#[Embed]` page's ETag shifts again on this upgrade, verified against a live BeMart run (identical body, different ETag only). - `ResourceDonut::FORMAT` is no longer public; use `ResourceDonut::placeholder()`. `ResourceDonut::refresh()` takes an additional `UncacheableMarkInterface` argument. - Requires `koriym/semantic-logger` `^0.11`. Written logs use its `log` document shape, and diagnostic `kind` is now `code`. - Requires `bear/resource` `^1.22.4`. - `KeepMutationsAndFailures` also keeps a session cut at the record limit (`semantic_logger_truncated`): a `command` past the limit leaves no other trace. -- `ResourceDonut::refresh()`: a hole that throws while an already-cached `#[DonutCache]` page is recomposed (its own `onGet()` or its render) no longer lets that exception reach the caller. It now degrades the same way a cache-store failure does - recorded as a `cache_error` and served via a fresh, non-donut render of the whole page - so a transient hole failure costs latency, not an error response. A permanently broken hole (for example a corrupted legacy placeholder's `ParameterException`, previously an uncaught 500) now degrades to 200 on every refresh instead. +- `ResourceDonut::refresh()`: a hole that throws while an already-cached `#[DonutCache]` page is recomposed (its own `onGet()` or its render) no longer lets that exception reach the caller directly from the refresh. It now degrades the same way a cache-store failure does and falls back to rendering the whole page fresh. A transient failure (the hole recovers on that fresh render) now answers 200 with the full body instead of an error. A persistent failure still fails the request - from the fresh render instead of from the refresh - exactly as the page would without the cache attribute at all (for example a corrupted legacy placeholder's `ParameterException`, previously an uncaught 500 straight from the refresh, is still an uncaught exception, just raised one call later). ### Fixed - `LogFileWriter`: two sessions flushed in the same microsecond no longer overwrite each other. The timestamped filename now carries a random suffix, so both survive (#221). - A `#[DonutCache]` page embedding an `#[Embed]` hole whose URI carried two or more query parameters leaked a raw `[le:...]` placeholder to the client and could throw `ParameterException` on the next request - fixed by moving new placeholders to a `[le2:...]` marker (#232). -- A `#[DonutCache]`/`#[CacheableResponse]` page whose render threw - a hole's own resource or the page's own template - no longer stores the empty template BEAR.Resource's `ResourceObject::__toString()` swallows that failure into; that empty template would otherwise be served to every later visitor (since 1.17.0). +- An exception while rendering a `#[DonutCache]`/`#[CacheableResponse]` page - a hole's own resource or the page's own template - no longer stores an empty template that was served to every later visitor (since 1.17.0). The page's own template failure now surfaces exactly as it would for the same page without the cache attribute, instead of being swallowed into an empty page; a hole's failure now surfaces as a clean, catchable exception too - actually a better outcome than an `#[Embed]` of the same resource gets outside a `#[DonutCache]` page, where BEAR.Resource's own `AbstractRequest::__toString()` swallows it into a fatal `E_USER_ERROR` instead. +- A degraded cache read (a down cache pool, or - see above - a hole failing while a cached page is refreshed) now actually renders its fresh-render fallback instead of returning the un-rendered result of running `onGet()` alone: previously such a request answered 200 with an unresolved `#[Embed]` hole still in its body and no view, rather than the composed page. - An embedded child of a `#[DonutCache]`/`#[CacheableResponse]` page is now reused until its query or links change, instead of running again when rendered as a hole after already being read in `onGet()`. Every such execution that was read but never rendered as a hole now tags the stored template and the live response's own Surrogate-Key/ETag, so purging any one of them refreshes the page instead of leaving it stale (#226). - `ResourceBodyEvaluator` no longer crashes materializing an embedded child whose `jsonSerialize()` does not answer the memoized `ResourceObject` (the shape `BEAR\Async\AsyncRequest` overrides it to): such a child is now left unmaterialized instead of asserting. Async support itself remains out of scope. diff --git a/src/AbstractDonutCacheInterceptor.php b/src/AbstractDonutCacheInterceptor.php index 565a053c..3416b8d8 100644 --- a/src/AbstractDonutCacheInterceptor.php +++ b/src/AbstractDonutCacheInterceptor.php @@ -71,21 +71,23 @@ final public function invoke(MethodInvocation $invocation) $this->triggerWarning($e); - return $invocation->proceed(); + /** @var ResourceObject $fresh */ + $fresh = $invocation->proceed(); + + // Same outcome a normal MISS reaches below: render (and, if the render and + // the store both succeed, re-cache) via the full donut path - a degraded + // read must not return $invocation->proceed()'s raw, un-rendered result + // (an un-executed #[Embed] request, `view` still null) directly to the + // caller, which would either show nothing or make a later `(string)` cast + // execute a hole untracked by UncacheableMark/SurrogateKeys, or - for a + // raw (non-donut-wrapped) AbstractRequest - trigger its own E_USER_ERROR. + return $this->handleProceedResult($fresh); } /** @var ResourceObject $ro */ $ro = $invocation->proceed(); - // donut created in ResourceObject - if (isset($ro->headers[Header::ETAG]) || $ro->code >= Code::BAD_REQUEST) { - // Record why this miss is not followed by a put; without it the log looks like a lost write. - $hasEtag = isset($ro->headers[Header::ETAG]); - $this->logger->event(new PutSkippedContext((string) $ro->uri, $hasEtag ? 'etag-present' : 'error-code', $hasEtag ? null : $ro->code)); - return $ro; - } - - return $this->putRecorded($ro); + return $this->handleProceedResult($ro); } finally { $durationMs = round((hrtime(true) - $start) / 1_000_000, 3); // Psalm mis-tracks the $hit flag mutated inside try when read from finally. @@ -99,6 +101,26 @@ final public function invoke(MethodInvocation $invocation) } } + /** + * What runs on a fresh render, whether it is a normal MISS or a read-degrade fallback: + * an already-answered response (an ETag the resource set itself, an error code) is + * served as-is and the non-write recorded; anything else is rendered and stored through + * `putRecorded()`. + */ + private function handleProceedResult(ResourceObject $ro): ResourceObject + { + // donut created in ResourceObject + if (isset($ro->headers[Header::ETAG]) || $ro->code >= Code::BAD_REQUEST) { + // Record why this miss is not followed by a put; without it the log looks like a lost write. + $hasEtag = isset($ro->headers[Header::ETAG]); + $this->logger->event(new PutSkippedContext((string) $ro->uri, $hasEtag ? 'etag-present' : 'error-code', $hasEtag ? null : $ro->code)); + + return $ro; + } + + return $this->putRecorded($ro); + } + /** * Run the donut write, degrading a store failure and recording either way * diff --git a/src/DonutRequest.php b/src/DonutRequest.php index be838867..2165803d 100644 --- a/src/DonutRequest.php +++ b/src/DonutRequest.php @@ -44,8 +44,16 @@ public function __toString(): string // AbstractRequest would double-execute a non-idempotent child, and for an // OnceRequest would still be correct, but there is no reason to prefer a // second call over the result already in hand). + // + // toString(), not (string) $executed: the magic __toString() swallows a + // Throwable from rendering into an E_USER_WARNING and '' - storing that empty + // placeholder content would make a #[CacheableResponse] view persist a hole + // that failed. toString() has no such catch, so the Throwable propagates + // through this __toString() (PHP 8 allows one to throw), through the + // template engine (Twig re-wraps it as a Twig\Error\RuntimeError), up to + // ResourceDonut::create()'s own non-swallowing render of the composing page. $executed = ($this->request)(); - $view = (string) $executed; + $view = $executed->toString(); } finally { $this->mark->leaveHole($uri); } diff --git a/src/Exception/CacheStoreFailure.php b/src/Exception/CacheStoreFailure.php index 72f51db6..09f51b20 100644 --- a/src/Exception/CacheStoreFailure.php +++ b/src/Exception/CacheStoreFailure.php @@ -23,14 +23,13 @@ * reported as done. The automatic write inside a GET is caught and degraded - that request * changed nothing, so nothing at an edge became stale by it. * - * `ResourceDonut::create()`'s render also arrives here, which looks like the "renderer with a - * bug" case this class says it deliberately excludes - but it is not that case: by the time - * `ResourceObject::__toString()` returns, BEAR.Resource has already caught and discarded the - * real Throwable itself (an E_USER_WARNING and `''` are all that is left of it), so there is - * no longer a genuine exception left to let travel - only a reconstruction from that warning's - * text (`Exception\DonutRenderAborted`). Degrading is what lets the response stay servable - * without fabricating a 500 from a guessed cause; the original warning still surfaces - * unsuppressed, and the reconstruction is recorded in the semantic log either way. + * `ResourceDonut::refresh()` also raises this type when a hole throws while an already-cached + * page is being recomposed - deliberately, not by accident: the read path degrades through + * the same catch that handles a storage outage, falling back to a full fresh render + * (`ResourceDonut::create()`), which then fails exactly as the hole would without the cache + * attribute at all if it is genuinely broken, or serves the full page if the failure was + * transient. `create()`'s own render does NOT use this type - a render failure there + * propagates unwrapped, matching a page with no cache attribute (see its docblock). */ final class CacheStoreFailure extends RuntimeException { diff --git a/src/Exception/DonutRenderAborted.php b/src/Exception/DonutRenderAborted.php deleted file mode 100644 index b6f52096..00000000 --- a/src/Exception/DonutRenderAborted.php +++ /dev/null @@ -1,19 +0,0 @@ -getMessage()})\n" . - * $e->getTraceAsString()` (vendor/bear/resource/src/ResourceObject.php). Anchored on the - * `#0 ` a Throwable::getTraceAsString() trace always starts with, so an unrelated warning - * that merely happens to look like "Class(message)" is not misread as a swallowed render. - */ - private const SWALLOWED_RENDER_WARNING = '/\A(?[\\\\\w]+)\((?.*)\)\n#0 /s'; - /** * Build the placeholder DonutRequest::__toString() embeds and DonutRenderer matches */ @@ -239,6 +224,21 @@ private function hashContent(string $view): string return hash('sha256', $view); } + /** + * `(string) $ro` here would call the page's own `ResourceObject::__toString()`, which + * swallows a render Throwable into an E_USER_WARNING and `''` - storing that would bake + * an empty page into the cache for every later visitor (since 1.17.0). `toString()` is + * the same render with no such catch (vendor/bear/resource), the same method + * `BEAR\Sunday\...\HttpResponder::getOutput()` already renders a response with - so a + * failure in the PAGE's own template propagates exactly as it would for a page with no + * cache attribute at all. A HOLE's failure travels too (DonutRequest wraps it with the + * same non-swallowing render, see DonutRequest::__toString()) - a clean, catchable + * exception, actually BETTER than the no-attribute baseline for an embedded hole: an + * un-donut-wrapped `#[Embed]` renders its child via the raw `AbstractRequest::__toString()`, + * which swallows into a fatal E_USER_ERROR instead (verified by execution, not assumed). + * Either way, the original Throwable - not a reconstruction - travels to the caller, and + * nothing past this call ever stores or returns a template. + */ public static function create(ResourceObject $ro, DonutRendererInterface $storage, SurrogateKeys $etags, int|null $ttl, bool $isCacheble, UncacheableMarkInterface $mark): self { // A resource with nothing to return leaves its body null - a 204 typically does, while @@ -256,52 +256,8 @@ public static function create(ResourceObject $ro, DonutRendererInterface $storag unset($maybeRequest); } - $donutTemplate = self::renderTemplateOrAbort($ro); + $donutTemplate = $ro->toString(); return new self($donutTemplate, $ro->headers, $ttl, $isCacheble, code: $ro->code); } - - /** - * Cast a page RO to its template string, refusing the donut store if the render was - * actually a Throwable that `ResourceObject::__toString()` swallowed (both a hole's own - * render - DonutRequest::__toString() does not catch, so a hole's failure surfaces here - * too - and the composing page's own template failing outside any hole). - * - * A scoped error handler, installed only for the duration of this cast, is the only way - * to see that: the Throwable itself never reaches here, only the E_USER_WARNING the - * swallow leaves behind. On a match it still returns false, so PHP's own handling of - * that original warning (log, display) runs exactly as it would with no handler - * installed at all - only the empty return value this call would otherwise produce is - * refused, via CacheStoreFailure, which the interceptors already catch and degrade. - */ - private static function renderTemplateOrAbort(ResourceObject $ro): string - { - /** @var string|null $abortedRenderMessage */ - $abortedRenderMessage = null; - /** @var callable|null $previous */ - $previous = null; - $previous = set_error_handler( - static function (int $errno, string $errstr, string $errfile = '', int $errline = 0) use (&$abortedRenderMessage, &$previous): bool { - if ($errno === E_USER_WARNING && preg_match(self::SWALLOWED_RENDER_WARNING, $errstr, $match) === 1) { - $abortedRenderMessage = sprintf('%s: %s', $match['class'], $match['message']); - - return false; - } - - return $previous !== null ? (bool) $previous($errno, $errstr, $errfile, $errline) : false; - }, - ); - - try { - $donutTemplate = (string) $ro; - } finally { - restore_error_handler(); - } - - if ($abortedRenderMessage !== null) { - throw CacheStoreFailure::from(new DonutRenderAborted($abortedRenderMessage)); - } - - return $donutTemplate; - } } diff --git a/tests/Fake/FakeWarningEmittingRenderer.php b/tests/Fake/FakeWarningEmittingRenderer.php new file mode 100644 index 00000000..8fe986e4 --- /dev/null +++ b/tests/Fake/FakeWarningEmittingRenderer.php @@ -0,0 +1,29 @@ +toString()` propagate the Throwable unexamined. + */ +class AnonymousThrowingHole extends ResourceObject +{ + public function onGet(): ResourceObject + { + throw new class ('anonymous hole blew up') extends RuntimeException { + }; + } +} diff --git a/tests/Fake/fake-app/src/Resource/App/FlakyHole.php b/tests/Fake/fake-app/src/Resource/App/FlakyHole.php new file mode 100644 index 00000000..28f9486b --- /dev/null +++ b/tests/Fake/fake-app/src/Resource/App/FlakyHole.php @@ -0,0 +1,33 @@ + 0) { + self::$failureCount--; + + throw new RuntimeException('the hole is currently broken'); + } + + $this->body['value'] = 'healthy'; + + return $this; + } +} diff --git a/tests/Fake/fake-app/src/Resource/App/HoleWithNoTemplate.php b/tests/Fake/fake-app/src/Resource/App/HoleWithNoTemplate.php new file mode 100644 index 00000000..34cf71e3 --- /dev/null +++ b/tests/Fake/fake-app/src/Resource/App/HoleWithNoTemplate.php @@ -0,0 +1,23 @@ +toString()` call specifically: `ThrowingHole`'s failure happens earlier, + * inside `($this->request)()`, and never reaches that line at all. + */ +class HoleWithNoTemplate extends ResourceObject +{ + public function onGet(): static + { + $this->body['value'] = 'never rendered'; + + return $this; + } +} diff --git a/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithFlakyHole.php b/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithFlakyHole.php new file mode 100644 index 00000000..7cc5ad38 --- /dev/null +++ b/tests/Fake/fake-app/src/Resource/Page/Html/DonutCacheWithFlakyHole.php @@ -0,0 +1,24 @@ +body['value'] = 'plain'; + + return $this; + } +} diff --git a/tests/Fake/fake-app/var/templates/App/FlakyHole.html.twig b/tests/Fake/fake-app/var/templates/App/FlakyHole.html.twig new file mode 100644 index 00000000..40cf72a2 --- /dev/null +++ b/tests/Fake/fake-app/var/templates/App/FlakyHole.html.twig @@ -0,0 +1 @@ +{{ value }} diff --git a/tests/Fake/fake-app/var/templates/Page/Html/DonutCacheWithFlakyHole.html.twig b/tests/Fake/fake-app/var/templates/Page/Html/DonutCacheWithFlakyHole.html.twig new file mode 100644 index 00000000..4c886478 --- /dev/null +++ b/tests/Fake/fake-app/var/templates/Page/Html/DonutCacheWithFlakyHole.html.twig @@ -0,0 +1 @@ +donut-cache-with-flaky-hole:{{ flaky }} diff --git a/tests/Fake/fake-app/var/templates/Page/Html/PlainNoCacheAttribute.html.twig b/tests/Fake/fake-app/var/templates/Page/Html/PlainNoCacheAttribute.html.twig new file mode 100644 index 00000000..2b1aa28d --- /dev/null +++ b/tests/Fake/fake-app/var/templates/Page/Html/PlainNoCacheAttribute.html.twig @@ -0,0 +1 @@ +plain-no-cache-attribute:{{ value }} diff --git a/tests/GracefulLoggingTest.php b/tests/GracefulLoggingTest.php index e43fcdcb..4182e0fc 100644 --- a/tests/GracefulLoggingTest.php +++ b/tests/GracefulLoggingTest.php @@ -12,6 +12,8 @@ use BEAR\Resource\RenderInterface; use BEAR\Resource\ResourceInterface; use BEAR\Resource\Uri; +use ErrorException; +use FakeVendor\HelloWorld\Resource\App\FlakyHole; use FakeVendor\HelloWorld\Resource\Page\Index; use Koriym\SemanticLogger\SemanticLoggerInterface; use Madapaja\TwigModule\TwigModule; @@ -22,6 +24,7 @@ use Symfony\Component\Cache\Adapter\ArrayAdapter; use Symfony\Component\Cache\Adapter\TagAwareAdapter; use Symfony\Component\Cache\Adapter\TagAwareAdapterInterface; +use Twig\Error\Error as TwigError; use function assert; use function dirname; @@ -44,6 +47,18 @@ class GracefulLoggingTest extends TestCase { use SemanticLogTreeTrait; + /** + * `FlakyHole::$failureCount` is mutable static state (PHP has no other way to make a + * resource's own onGet() behavior controllable per test) - reset unconditionally so a + * test that leaves it non-zero can never leak into a later, unrelated test. + */ + protected function tearDown(): void + { + FlakyHole::$failureCount = 0; + + parent::tearDown(); + } + public function testCacheWorksWhenLoggingSessionIsMisused(): void { $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); @@ -244,11 +259,15 @@ protected function configure(): void /** * A render that throws must never bake an empty donut template into the store - that - * would serve an empty page to every later visitor (since 1.17.0). The first request's - * write is refused and recorded; a second request is still a cache miss, not a hit - * reading the empty template the bug would have stored. + * would serve an empty page to every later visitor (since 1.17.0). `ResourceDonut::create()` + * renders with the non-swallowing `toString()`, and the hole is wrapped the same way + * (`DonutRequest::__toString()`), so the Throwable travels to the caller as a clean, + * catchable exception - the write is refused (and recorded) as a side effect of nothing + * past the render ever running, not a caught, degraded failure. (Verified by execution: + * this is actually BETTER than the same hole embedded outside `#[DonutCache]`, where the + * raw `AbstractRequest::__toString()` swallows it into a fatal E_USER_ERROR instead.) */ - public function testDonutWriteIsRefusedNotStoredWhenAHoleThrowsDuringRender(): void + public function testDonutWriteLetsAHoleThrowTravelAndStoresNothing(): void { $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); $module->override(new TwigModule([dirname(__DIR__) . '/tests/Fake/fake-app/var/templates'])); @@ -256,44 +275,41 @@ public function testDonutWriteIsRefusedNotStoredWhenAHoleThrowsDuringRender(): v $resource = $injector->getInstance(ResourceInterface::class); $logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class); - set_error_handler(static fn (): bool => true); // the swallowed-render warning and the degrade warning both fire try { - $first = $resource->get('page://self/html/donut-cache-with-throwing-hole'); - $this->assertSame(200, $first->code, 'the request still completes even though nothing is stored'); - } finally { - restore_error_handler(); + $resource->get('page://self/html/donut-cache-with-throwing-hole'); + $this->fail('expected the hole throw to travel to the caller'); + } catch (TwigError $e) { + $this->assertInstanceOf(RuntimeException::class, $e->getPrevious()); + $this->assertSame('the hole blew up mid-render', $e->getPrevious()->getMessage()); } $tree = $this->flushAndValidate($logger); $error = self::eventContextJsonOf($tree, 'cache_error'); - $this->assertNotNull($error, 'the aborted render is recorded, not silently cached'); + $this->assertNotNull($error, 'the aborted render is recorded before it travels'); $this->assertStringContainsString('"operation":"write"', $error); - $this->assertStringContainsString('DonutRenderAborted', $error); // Independent of what a later request happens to do: directly proves nothing was - // stored, rather than inferring it from a second request's cache_miss. + // stored, rather than inferring it from a second request's behavior alone. $resourceStorage = $injector->getInstance(ResourceStorageInterface::class); - $this->assertNull($resourceStorage->getDonut($first->uri), 'nothing was stored after the aborted render'); + $uri = new Uri('page://self/html/donut-cache-with-throwing-hole'); + $this->assertNull($resourceStorage->getDonut($uri), 'nothing was stored after the aborted render'); // If the bug were present, this second request would be a cache HIT serving the - // empty template the first request's write would otherwise have stored. - set_error_handler(static fn (): bool => true); + // empty template the first request's write would otherwise have stored, instead of + // throwing again. try { $resource->get('page://self/html/donut-cache-with-throwing-hole'); - } finally { - restore_error_handler(); + $this->fail('expected the second request to also throw, not read a cached empty template'); + } catch (TwigError $e) { + $this->assertSame('the hole blew up mid-render', $e->getPrevious()?->getMessage()); } - - $tree2 = $this->flushAndValidate($logger); - $this->assertNull(self::closeContextJsonOf($tree2, 'cache_hit'), 'a later request must not be served from a cached empty template'); - $this->assertNotNull(self::closeContextJsonOf($tree2, 'cache_miss'), 'a later request is still a cache miss - nothing was ever stored'); } /** - * The same guard refuses a store when the composing page's own template throws, outside - * any hole - `(string) $ro` in ResourceDonut::create() renders the page itself too. + * The same holds when the composing page's own template throws, outside any hole - + * `$ro->toString()` in `ResourceDonut::create()` renders the page itself too. */ - public function testDonutWriteIsRefusedNotStoredWhenThePageTemplateItselfThrows(): void + public function testDonutWriteLetsAPageTemplateThrowTravelAndStoresNothing(): void { $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); $module->override(new class extends AbstractModule { @@ -306,19 +322,181 @@ protected function configure(): void $resource = $injector->getInstance(ResourceInterface::class); $logger = $injector->getInstance(SemanticLoggerInterface::class, CacheLog::class); - set_error_handler(static fn (): bool => true); try { - $ro = $resource->get('page://self/html/plain-donut-hole'); - $this->assertSame(200, $ro->code, 'the request still completes even though nothing is stored'); - } finally { - restore_error_handler(); + $resource->get('page://self/html/plain-donut-hole'); + $this->fail('expected the page template throw to travel to the caller'); + } catch (FakeTemplateNotFound $e) { + $this->assertSame('template not found: user.html.twig', $e->getMessage()); } $tree = $this->flushAndValidate($logger); $error = self::eventContextJsonOf($tree, 'cache_error'); - $this->assertNotNull($error, 'the aborted render is recorded, not silently cached'); + $this->assertNotNull($error, 'the aborted render is recorded before it travels'); $this->assertStringContainsString('"operation":"write"', $error); - $this->assertStringContainsString('DonutRenderAborted', $error); + + $resourceStorage = $injector->getInstance(ResourceStorageInterface::class); + $uri = new Uri('page://self/html/plain-donut-hole'); + $this->assertNull($resourceStorage->getDonut($uri), 'nothing was stored after the aborted render'); + } + + /** + * The guard never inspects a warning - it just lets `toString()` propagate a genuine + * Throwable unwrapped. A page that merely emits an unrelated warning during render and + * then renders successfully has nothing to propagate, so it is stored normally. + */ + public function testDonutWriteStoresAPageThatEmitsAnUnrelatedWarningButRendersFine(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new class extends AbstractModule { + protected function configure(): void + { + $this->bind(RenderInterface::class)->to(FakeWarningEmittingRenderer::class); + } + }); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + + set_error_handler(static fn (): bool => true); // let the unrelated warning pass quietly + try { + $ro = $resource->get('page://self/html/plain-donut-hole'); + } finally { + restore_error_handler(); + } + + $this->assertSame('rendered-ok', (string) $ro->view); + + $resourceStorage = $injector->getInstance(ResourceStorageInterface::class); + $uri = new Uri('page://self/html/plain-donut-hole'); + $this->assertNotNull($resourceStorage->getDonut($uri), 'a page that renders fine despite an unrelated warning is stored'); + } + + /** + * Fable's CRITICAL finding against the previous (warning-regex) design: an app with a + * warning->exception converter (Whoops, Symfony ErrorHandler, Sentry) turns ANY warning + * during render into a real exception. This design never installs a handler of its own + * and never inspects a warning, so that converted exception is just an ordinary Throwable + * `toString()` propagates - behaving identically to the same render with NO cache + * attribute at all (not merely a different attribute like `#[Cacheable]`), and + * identically on every later request (never "refused forever"). + */ + public function testAWarningToExceptionConverterBehavesIdenticallyWithAndWithoutDonutCache(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new class extends AbstractModule { + protected function configure(): void + { + $this->bind(RenderInterface::class)->to(FakeWarningEmittingRenderer::class); + } + }); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + + $converter = static function (int $errno, string $errstr): bool { + throw new ErrorException($errstr, 0, $errno); + }; + + set_error_handler($converter); + try { + // No cache attribute: $resource->get() alone does not render (onGet() only) - + // the render happens later, the same place HttpResponder::getOutput() triggers + // it (`$ro->toString()`), so that call is what this is compared against. + $resource->get('page://self/html/plain-no-cache-attribute')->toString(); + $this->fail('expected the converted warning to surface for the no-cache-attribute page'); + } catch (ErrorException $e) { + $this->assertSame('an unrelated notice during render', $e->getMessage()); + } finally { + restore_error_handler(); + } + + // Twice, to show the donut page is not treated worse (or better) than the plain + // page, and not treated worse (or better) on a later request than on the first. + for ($i = 0; $i < 2; $i++) { + set_error_handler($converter); + try { + $resource->get('page://self/html/plain-donut-hole'); // #[DonutCache] + $this->fail('expected the converted warning to surface identically for the donut page'); + } catch (ErrorException $e) { + $this->assertSame('an unrelated notice during render', $e->getMessage(), 'identical to the no-#[DonutCache] behavior, every time'); + } finally { + restore_error_handler(); + } + } + } + + /** + * HIT refresh, transient hole failure: `ResourceDonut::refresh()`'s own re-fetch hits a + * hole that fails once, degrades (the reviewed-and-kept CacheStoreFailure conversion), + * and falls back to a full fresh render - which succeeds because the failure already + * consumed itself. The response must be the fresh render's FULL body, not empty/partial. + */ + public function testHitRefreshFallsBackToAFreshRenderWhenAHoleTransientlyFails(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new TwigModule([dirname(__DIR__) . '/tests/Fake/fake-app/var/templates'])); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + + FlakyHole::$failureCount = 0; + $first = $resource->get('page://self/html/donut-cache-with-flaky-hole'); + $this->assertSame(200, $first->code); + $this->assertStringContainsString('healthy', (string) $first->view); + + FlakyHole::$failureCount = 1; + set_error_handler(static fn (): bool => true); // the fallback degrade still warns + try { + $second = $resource->get('page://self/html/donut-cache-with-flaky-hole'); + } finally { + restore_error_handler(); + } + + $this->assertSame(200, $second->code); + $this->assertStringContainsString( + 'healthy', + (string) $second->view, + 'the fresh render\'s full body - not empty, and not the raw AbstractRequest a bare proceed() fallback would leave unrendered', + ); + } + + /** + * HIT refresh, persistent hole failure: both the re-fetch and the fresh-render fallback + * hit a still-broken hole, so the request fails exactly as the hole's own URI does when + * requested directly with no donut composition at all. + */ + public function testHitRefreshFailsTheSameWayAsNoDonutCacheWhenAHoleIsPersistentlyBroken(): void + { + $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); + $module->override(new TwigModule([dirname(__DIR__) . '/tests/Fake/fake-app/var/templates'])); + $injector = new Injector($module, __DIR__ . '/tmp'); + $resource = $injector->getInstance(ResourceInterface::class); + + FlakyHole::$failureCount = 0; + $resource->get('page://self/html/donut-cache-with-flaky-hole'); // caches a good template + + FlakyHole::$failureCount = 1000; // outlasts both the re-fetch and the fallback render + set_error_handler(static fn (): bool => true); // the degraded-read warning still fires + $threw = false; + try { + $resource->get('page://self/html/donut-cache-with-flaky-hole'); + } catch (TwigError $e) { + $threw = true; + $this->assertInstanceOf(RuntimeException::class, $e->getPrevious()); + $this->assertSame('the hole is currently broken', $e->getPrevious()->getMessage()); + } finally { + restore_error_handler(); + } + + $this->assertTrue($threw, 'expected the persistently broken hole to fail the request, same as without the cache attribute'); + + FlakyHole::$failureCount = 1; + $threw = false; + try { + $resource->get('app://self/flaky-hole'); // the hole's own URI, no donut composition + } catch (RuntimeException $e) { + $threw = true; + $this->assertSame('the hole is currently broken', $e->getMessage()); + } + + $this->assertTrue($threw, 'expected the same failure requesting the hole directly'); } public function testAValueEntryIsStoredWithoutRenderingTheResource(): void diff --git a/tests/ResourceDonutTest.php b/tests/ResourceDonutTest.php index 5e3e8d97..586c00a7 100644 --- a/tests/ResourceDonutTest.php +++ b/tests/ResourceDonutTest.php @@ -19,15 +19,13 @@ use Ray\Di\AbstractModule; use Ray\Di\Injector; use RuntimeException; +use Twig\Error\Error as TwigError; use function assert; use function dirname; -use function error_clear_last; -use function error_get_last; use function htmlspecialchars; use function http_build_query; -use const E_USER_WARNING; use const ENT_QUOTES; class ResourceDonutTest extends TestCase @@ -273,18 +271,13 @@ public function options(string $uri, array $query = []): ResourceObject } /** - * `BEAR\Resource\ResourceObject::__toString()` swallows a Throwable from a failed render - * into an E_USER_WARNING and an empty string - a hole's own onGet() propagates here - * uncaught (`DonutRequest::__toString()` has no catch of its own). Storing that empty - * string as the donut template would serve an empty page to every later visitor (since - * 1.17.0). - * - * This also pins the guard's precision through the public API: a regex that matched too - * late in the trace would show up here as a reconstructed message polluted with stray - * `#0 `/`.php(` trace fragments, and a regex that stopped matching at all (BEAR.Resource's - * warning shape drifting) would show up as no exception being thrown. + * A hole's own onGet() propagates uncaught through `DonutRequest::__toString()` + * (issue: storing an empty donut template whose hole threw, since 1.17.0). `create()` + * renders with `$ro->toString()`, which does not swallow, so the ORIGINAL Throwable - + * here wrapped once by Twig as it bubbles through template evaluation - reaches the + * caller unmodified. Nothing past the render call ever runs, so nothing is stored. */ - public function testCreateRefusesToStoreTheTemplateWhenAHoleThrows(): void + public function testCreateLetsAHoleThrowTravelAndStoresNothing(): void { $ro = $this->resource->newInstance('page://self/html/donut-cache-with-throwing-hole'); $resource = $this->resource; @@ -293,31 +286,101 @@ public function testCreateRefusesToStoreTheTemplateWhenAHoleThrows(): void assert($throwingRequest instanceof AbstractRequest); $ro->body = ['secret' => $throwingRequest]; - error_clear_last(); try { ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); - $this->fail('expected the hole throw to refuse the store'); - } catch (CacheStoreFailure $e) { - $this->assertStringStartsWith('Twig\Error\RuntimeError: ', $e->getMessage()); - $this->assertStringContainsString('the hole blew up mid-render', $e->getMessage()); - $this->assertStringNotContainsString('#0 ', $e->getMessage()); - $this->assertStringNotContainsString('.php(', $e->getMessage()); + $this->fail('expected the hole throw to travel'); + } catch (TwigError $e) { + $this->assertInstanceOf(RuntimeException::class, $e->getPrevious()); + $this->assertSame('the hole blew up mid-render', $e->getPrevious()->getMessage()); } + } + + /** + * Unlike `app://self/throwing-hole` (fails inside `($this->request)()`, before + * `DonutRequest::__toString()` ever reaches its own render step), this hole's `onGet()` + * succeeds and its OWN template is what fails - specifically exercising the + * `$executed->toString()` call (not `(string) $executed`, which would swallow this into + * an E_USER_WARNING and an empty placeholder view instead of letting it travel). + */ + public function testCreateLetsAHolesOwnRenderFailureTravelAndStoresNothing(): void + { + $ro = $this->resource->newInstance('page://self/html/donut-cache-with-throwing-hole'); + $resource = $this->resource; + assert($resource instanceof Resource); + $holeRequest = $resource->get->uri('app://self/hole-with-no-template'); + assert($holeRequest instanceof AbstractRequest); + $ro->body = ['secret' => $holeRequest]; - // The handler returns false on a match, so PHP's own handling of the warning still - // runs unsuppressed - error_get_last() is set by the engine regardless of what any - // handler returns, so this proves the original warning was not lost. - $last = error_get_last(); - $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); - $this->assertSame(E_USER_WARNING, $last['type']); - $this->assertStringContainsString('the hole blew up mid-render', $last['message']); + try { + ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); + $this->fail("expected the hole's own render failure to travel"); + } catch (TwigError $e) { + $this->assertStringContainsString('HoleWithNoTemplate', $e->getMessage()); + } } /** - * The same swallow happens when the composing page's OWN template fails, outside any - * hole - `(string) $ro` in create() renders the page itself, not only its holes. + * `app://self/throwing-hole` marks itself unstorable, THEN throws (Kimi LOW: document + * which surfaces). The render exception wins, not a dev-gate exception + * (`UnstorableResponseDetected`): the mark only ever affects a SUCCESSFUL render's + * storability, checked by `UnstorableGateInterface::reason()` after `create()` returns - + * which it never does here, so nothing ever reads the mark at all. The scope the mark + * was filed under is still left correctly despite the throw (DonutRequest::__toString()'s + * own finally), confirmed the same way DonutRequestTest's own throw test does. */ - public function testCreateRefusesToStoreTheTemplateWhenThePageTemplateItselfThrows(): void + public function testCreateLetsAHoleThatMarkedItselfThrowTravelAsTheRenderException(): void + { + $ro = $this->resource->newInstance('page://self/html/donut-cache-with-throwing-hole'); + $resource = $this->resource; + assert($resource instanceof Resource); + $throwingRequest = $resource->get->uri('app://self/throwing-hole'); + assert($throwingRequest instanceof AbstractRequest); + $ro->body = ['secret' => $throwingRequest]; + + try { + ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); + $this->fail('expected the render exception to travel, not any dev-gate exception'); + } catch (TwigError $e) { + // Not UnstorableResponseDetected or any other gate-related exception: the mark + // ThrowingHole made before throwing is simply never read. + $this->assertInstanceOf(RuntimeException::class, $e->getPrevious()); + $this->assertSame('the hole blew up mid-render', $e->getPrevious()->getMessage()); + } + + // The hole's own scope was left (DonutRequest::__toString()'s finally), so a mark + // right after is filed under TOP_LEVEL, not displaced by a leaked hole scope. + $this->mark->mark('after the throw'); + $this->assertTrue($this->mark->isMarkedForCurrentScope()); + } + + /** + * An anonymous exception class (`new class extends RuntimeException {}`) must travel + * exactly like a named one - Kimi's MEDIUM: a class-name-matching guard would silently + * miss this and still store the empty template. This design never inspects the class at + * all, so there is nothing for an anonymous class to evade. + */ + public function testCreateLetsAnAnonymousExceptionHoleThrowTravelAndStoresNothing(): void + { + $ro = $this->resource->newInstance('page://self/html/donut-cache-with-throwing-hole'); + $resource = $this->resource; + assert($resource instanceof Resource); + $throwingRequest = $resource->get->uri('app://self/anonymous-throwing-hole'); + assert($throwingRequest instanceof AbstractRequest); + $ro->body = ['secret' => $throwingRequest]; + + try { + ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $this->mark); + $this->fail('expected the anonymous-class hole throw to travel'); + } catch (TwigError $e) { + $this->assertStringContainsString('anonymous hole blew up', $e->getPrevious()?->getMessage() ?? ''); + } + } + + /** + * The same holds when the composing page's OWN template fails, outside any hole - + * `$ro->toString()` in create() renders the page itself, not only its holes. + */ + public function testCreateLetsAPageTemplateThrowTravelAndStoresNothing(): void { $module = new FakeEtagPoolModule(ModuleFactory::getInstance('FakeVendor\HelloWorld')); $module->override(new class extends AbstractModule { @@ -332,18 +395,12 @@ protected function configure(): void $ro = $resource->newInstance('page://self/html/plain-donut-hole'); $ro->body = ['value' => 'plain']; - error_clear_last(); try { ResourceDonut::create($ro, new DonutRenderer(), new SurrogateKeys($ro->uri), null, false, $mark); - $this->fail('expected the page template throw to refuse the store'); - } catch (CacheStoreFailure $e) { - $this->assertSame('BEAR\QueryRepository\FakeTemplateNotFound: template not found: user.html.twig', $e->getMessage()); + $this->fail('expected the page template throw to travel'); + } catch (FakeTemplateNotFound $e) { + $this->assertSame('template not found: user.html.twig', $e->getMessage()); } - - $last = error_get_last(); - $this->assertNotNull($last, 'the swallowed render warning must still surface, not be suppressed'); - $this->assertSame(E_USER_WARNING, $last['type']); - $this->assertStringContainsString('template not found', $last['message']); } /** From 4143dad730dad32dbf96edb41192e500dba6b905 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 25 Oct 2026 14:04:56 +0900 Subject: [PATCH 4/5] Reword docs/comments for the current toString() design and the transient legacy-placeholder case --- CHANGELOG.md | 4 ++-- src/ResourceDonut.php | 8 +++++--- tests/ResourceDonutTest.php | 16 +++++++++------- 3 files changed, 16 insertions(+), 12 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 024a3853..ddbcac27 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,12 +15,12 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed - Deploy this version with a new `CacheVersionModule` version (an app that binds its own cache adapter rather than this package's `Storage*Module`s must clear its pools instead): entries written by earlier versions may hold per-user content, and an earlier version reading this version's donut cache shows raw `[le2:...]` placeholders during a rolling deploy. - A `#[Cacheable]`/`#[CacheableResponse]` response whose own code sets `Cache-Control` to `private` or `no-store` is no longer stored server-side; its header is kept and CDN headers are removed. A value declared by `#[HttpCache]`/`#[NoHttpCache]` is still stored. -- Upgrading changes the Ray.Aop-woven class name - and so the ETag (`crc32($ro::class . ...)`) - for a `#[CacheableResponse]` class or method that also declares an `#[Embed]`, because it is now woven with a new interceptor (#226); a page with no `#[Embed]` keeps its stock woven class and ETag, and a `#[DonutCache]` page never carries an ETag at all, so neither is affected. This release's own `AbstractDonutCacheInterceptor` fix (see Fixed, below) changes that interceptor's own composition too, so a `#[CacheableResponse]`+`#[Embed]` page's ETag shifts again on this upgrade, verified against a live BeMart run (identical body, different ETag only). +- Upgrading changes the Ray.Aop-woven class name - and so the ETag (`crc32($ro::class . ...)`) - for a `#[CacheableResponse]` class or method that also declares an `#[Embed]`, because it is now woven with a new interceptor (#226); a page with no `#[Embed]` keeps its stock woven class and ETag, and a `#[DonutCache]` page never carries an ETag at all, so neither is affected. - `ResourceDonut::FORMAT` is no longer public; use `ResourceDonut::placeholder()`. `ResourceDonut::refresh()` takes an additional `UncacheableMarkInterface` argument. - Requires `koriym/semantic-logger` `^0.11`. Written logs use its `log` document shape, and diagnostic `kind` is now `code`. - Requires `bear/resource` `^1.22.4`. - `KeepMutationsAndFailures` also keeps a session cut at the record limit (`semantic_logger_truncated`): a `command` past the limit leaves no other trace. -- `ResourceDonut::refresh()`: a hole that throws while an already-cached `#[DonutCache]` page is recomposed (its own `onGet()` or its render) no longer lets that exception reach the caller directly from the refresh. It now degrades the same way a cache-store failure does and falls back to rendering the whole page fresh. A transient failure (the hole recovers on that fresh render) now answers 200 with the full body instead of an error. A persistent failure still fails the request - from the fresh render instead of from the refresh - exactly as the page would without the cache attribute at all (for example a corrupted legacy placeholder's `ParameterException`, previously an uncaught 500 straight from the refresh, is still an uncaught exception, just raised one call later). +- `ResourceDonut::refresh()`: a hole that throws while an already-cached `#[DonutCache]` page is recomposed (its own `onGet()` or its render) no longer lets that exception reach the caller directly from the refresh. It now degrades the same way a cache-store failure does and falls back to rendering the whole page fresh. A transient failure (the hole recovers on that fresh render) now answers 200 with the full body instead of an error - for example a corrupted legacy placeholder's `ParameterException`, previously an uncaught 500 straight from the refresh, now answers 200 on both this request and the next, since the fresh render re-stores the template with a correct `[le2:...]` placeholder. A hole that keeps throwing still fails the request - from the fresh render instead of from the refresh - exactly as the page would without the cache attribute at all. ### Fixed - `LogFileWriter`: two sessions flushed in the same microsecond no longer overwrite each other. The timestamped filename now carries a random suffix, so both survive (#221). diff --git a/src/ResourceDonut.php b/src/ResourceDonut.php index d41ea490..b341030c 100644 --- a/src/ResourceDonut.php +++ b/src/ResourceDonut.php @@ -93,9 +93,11 @@ public function refresh(ResourceInterface $resource, ResourceObject $ro, Uncache $ro = $resource->get($uri); $ro->toString(); } catch (Throwable $e) { - // Unlike create()'s `(string) $ro`, this explicit toString() call does not - // swallow a Throwable into an E_USER_WARNING - it propagates directly, so no - // error-handler guard is needed, only this catch. + // $ro->toString() does not swallow a Throwable (same non-swallowing render + // create() itself now uses) - converted here, deliberately, to + // CacheStoreFailure: unlike create()'s own render, which lets the Throwable + // travel unwrapped, a HIT's re-fetch degrades instead, so the interceptor's + // read path falls back to a full fresh render (reviewed design, kept as-is). throw CacheStoreFailure::from($e); } finally { $mark->leaveHole($uri); diff --git a/tests/ResourceDonutTest.php b/tests/ResourceDonutTest.php index 586c00a7..98340c57 100644 --- a/tests/ResourceDonutTest.php +++ b/tests/ResourceDonutTest.php @@ -404,8 +404,9 @@ protected function configure(): void } /** - * The guard must not refuse a page that renders without error - only the specific - * swallowed-render warning shape triggers it. + * The render must not be disturbed when nothing throws - `$ro->toString()` behaves + * exactly like the magic cast it replaced for the success path, only diverging on a + * Throwable. */ public function testCreateStillStoresTheTemplateWhenNothingThrows(): void { @@ -419,11 +420,12 @@ public function testCreateStillStoresTheTemplateWhenNothingThrows(): void } /** - * Unlike create()'s `(string) $ro`, refresh()'s per-hole `$ro->toString()` (and the - * `$resource->get($uri)` re-fetch that runs the hole's onGet()) does not swallow a - * Throwable - it propagates directly, so this is a plain try/catch, converted to the same - * CacheStoreFailure create() raises, so both paths degrade through the same interceptor - * code. + * refresh()'s per-hole `$ro->toString()` (and the `$resource->get($uri)` re-fetch that + * runs the hole's onGet()) does not swallow a Throwable either - it propagates directly, + * the same non-swallowing render create() itself now uses. Unlike create(), which lets + * it travel unwrapped, this is a plain try/catch converting it to CacheStoreFailure + * deliberately: a HIT's re-fetch degrades through the interceptor's read path instead, + * falling back to a full fresh render (the reviewed design both reviewers said to keep). */ public function testRefreshRefusesToServeWhenAHoleThrows(): void { From dcef1672fefd146d67b861fdd7ee8ee54b714679 Mon Sep 17 00:00:00 2001 From: Akihito Koriyama Date: Sun, 25 Oct 2026 14:08:01 +0900 Subject: [PATCH 5/5] Add a direct storage assertion proving the transient-failure fallback re-stores the template --- tests/GracefulLoggingTest.php | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/tests/GracefulLoggingTest.php b/tests/GracefulLoggingTest.php index 4182e0fc..68a545af 100644 --- a/tests/GracefulLoggingTest.php +++ b/tests/GracefulLoggingTest.php @@ -455,6 +455,20 @@ public function testHitRefreshFallsBackToAFreshRenderWhenAHoleTransientlyFails() (string) $second->view, 'the fresh render\'s full body - not empty, and not the raw AbstractRequest a bare proceed() fallback would leave unrendered', ); + + // Self-heals: the degraded read's fallback render reaches putRecorded(), so the + // template is re-stored - this is what makes a transient failure (including the + // CHANGELOG's corrupted-legacy-placeholder example) answer 200 on every later + // request too, not just this one. Proved two ways: a stored entry now exists at + // all (the earlier bug left the entry untouched - neither healed nor failing), and + // a further HIT refreshes it successfully with no warning needed this time. + $resourceStorage = $injector->getInstance(ResourceStorageInterface::class); + $uri = new Uri('page://self/html/donut-cache-with-flaky-hole'); + $this->assertNotNull($resourceStorage->getDonut($uri), 'the fresh render re-stores the template instead of leaving no entry behind'); + + $third = $resource->get('page://self/html/donut-cache-with-flaky-hole'); + $this->assertSame(200, $third->code); + $this->assertStringContainsString('healthy', (string) $third->view, 'a later request reads the re-stored, healed template directly - no further degrade needed'); } /**