From 170b0ab78037fd92b1b363f705289741e28236e1 Mon Sep 17 00:00:00 2001 From: Greg Bowler Date: Sat, 9 May 2026 15:41:15 +0100 Subject: [PATCH 1/4] feature: log order of logic execution closes #695 --- src/Dispatch/Dispatcher.php | 66 +++++++++++++++++++----- test/phpunit/Dispatch/DispatcherTest.php | 15 ++++-- 2 files changed, 66 insertions(+), 15 deletions(-) diff --git a/src/Dispatch/Dispatcher.php b/src/Dispatch/Dispatcher.php index fdd222b0..662e9d35 100644 --- a/src/Dispatch/Dispatcher.php +++ b/src/Dispatch/Dispatcher.php @@ -54,6 +54,8 @@ * @SuppressWarnings("PHPMD.ExcessiveClassComplexity") */ class Dispatcher { + private const LOGIC_EXECUTION_HEADER = "X-Logic-Execution"; + private Config $config; private Request $request; /** @var array>> */ @@ -80,6 +82,8 @@ class Dispatcher { private HeaderManager $headerManager; private Closure $viewInitCb; private bool $redirectPrepared = false; + /** @var array */ + private array $logicExecutionOrder = []; /** * @param array>> $globals @@ -369,9 +373,8 @@ private function handleLogicExecution( $extraArgs[$legacyElementClass] = $component; } - foreach($this->logicExecutor->invoke($logicAssembly, "go_before", $extraArgs) as $file) { - // Force generator execution even when debug output is disabled. - continue; + foreach($this->logicExecutor->invoke($logicAssembly, "go_before", $extraArgs) as $functionReference) { + $this->recordLogicExecution($functionReference); } // TODO: No need to have the whole Input class. Just pass a nullable string in called $doMethod, from $input->getString("do") @@ -383,21 +386,18 @@ function(InputData $data)use($logicAssembly, $extraArgs) { $data->getString("do"), ); - foreach($this->logicExecutor->invoke($logicAssembly, $doName, $extraArgs) as $file) { - // Force generator execution even when debug output is disabled. - continue; + foreach($this->logicExecutor->invoke($logicAssembly, $doName, $extraArgs) as $functionReference) { + $this->recordLogicExecution($functionReference); } } ); - foreach($this->logicExecutor->invoke($logicAssembly, "go", $extraArgs) as $file) { - // Force generator execution even when debug output is disabled. - continue; + foreach($this->logicExecutor->invoke($logicAssembly, "go", $extraArgs) as $functionReference) { + $this->recordLogicExecution($functionReference); } - foreach($this->logicExecutor->invoke($logicAssembly, "go_after", $extraArgs) as $file) { - // Force generator execution even when debug output is disabled. - continue; + foreach($this->logicExecutor->invoke($logicAssembly, "go_after", $extraArgs) as $functionReference) { + $this->recordLogicExecution($functionReference); } } @@ -408,6 +408,7 @@ function(InputData $data)use($logicAssembly, $extraArgs) { public function processResponse( ?Throwable $errorThrowable = null, ):void { + $this->logicExecutionOrder = []; $dynamicPath = $this->serviceContainer->get(DynamicPath::class); $this->viewModelProcessor?->processDynamicPath( @@ -460,6 +461,13 @@ public function processResponse( } } + if($this->logicExecutionOrder) { + $this->response = $this->response->withHeader( + self::LOGIC_EXECUTION_HEADER, + implode(";", $this->logicExecutionOrder), + ); + } + if($responseWithHeader = $this->headerManager->applyWithHeader( $this->response->getResponseHeaders(), $this->response->withHeader(...) @@ -476,6 +484,40 @@ public function processResponse( } // phpcs:enable Generic.Metrics.CyclomaticComplexity.TooHigh + private function recordLogicExecution(string $functionReference):void { + $referenceWithoutAttributes = explode("#", $functionReference, 2)[0]; + $separatorPosition = strrpos($referenceWithoutAttributes, "::"); + if($separatorPosition === false) { + return; + } + + $file = substr($referenceWithoutAttributes, 0, $separatorPosition); + $function = substr($referenceWithoutAttributes, $separatorPosition + 2); + $function = preg_replace('/\(\)$/', '', $function); + if($function === null || $function === "") { + return; + } + + $this->logicExecutionOrder[] = sprintf( + "%s:%s", + $this->normaliseLogicExecutionFile($file), + $function, + ); + } + + private function normaliseLogicExecutionFile(string $file):string { + $cwd = getcwd(); + if($cwd && str_starts_with($file, $cwd . DIRECTORY_SEPARATOR)) { + $file = substr($file, strlen($cwd) + 1); + } + + if(str_ends_with($file, ".php")) { + $file = substr($file, 0, -4); + } + + return $file; + } + private function verifyCsrfRequest(string $method, InputData $inputData):void { if($method !== "POST" || $this->isIgnoredCsrfPath()) { return; diff --git a/test/phpunit/Dispatch/DispatcherTest.php b/test/phpunit/Dispatch/DispatcherTest.php index 080fb3c8..6bf36f3c 100644 --- a/test/phpunit/Dispatch/DispatcherTest.php +++ b/test/phpunit/Dispatch/DispatcherTest.php @@ -174,9 +174,7 @@ public function testGenerateResponse_executesComponentAndPageLogicAndAppliesHead "name" => $name, "extraArgs" => $extraArgs, ]; - if(false) { - yield "never"; - } + yield ($assembly === $componentAssembly ? "/tmp/component.php" : "/tmp/page.php") . "::$name()"; }); $headerManager = $this->createMock(HeaderManager::class); @@ -210,6 +208,17 @@ public function testGenerateResponse_executesComponentAndPageLogicAndAppliesHead self::assertSame(StatusCode::OK, $response->getStatusCode()); self::assertSame("applied", $response->getHeaderLine("X-Test")); + self::assertSame( + "/tmp/component:go_before;" + . "/tmp/component:do_save_item;" + . "/tmp/component:go;" + . "/tmp/component:go_after;" + . "/tmp/page:go_before;" + . "/tmp/page:do_save_item;" + . "/tmp/page:go;" + . "/tmp/page:go_after", + $response->getHeaderLine("X-Logic-Execution"), + ); self::assertSame([ ["assembly" => "component", "name" => "go_before"], ["assembly" => "component", "name" => "do_save_item"], From 1c7ef4d198b71769b8234b7cc9cd33467caa0f51 Mon Sep 17 00:00:00 2001 From: Greg Bowler Date: Mon, 25 May 2026 16:10:19 +0100 Subject: [PATCH 2/4] tidy: fix indentation --- test/phpunit/ApplicationTest.php | 68 ++++++++++++++++---------------- 1 file changed, 34 insertions(+), 34 deletions(-) diff --git a/test/phpunit/ApplicationTest.php b/test/phpunit/ApplicationTest.php index 4b45e512..571e325a 100644 --- a/test/phpunit/ApplicationTest.php +++ b/test/phpunit/ApplicationTest.php @@ -40,29 +40,29 @@ public function testStart_callsRedirectExecute():void { ->method("execute") ->willReturn(null); - $globalProtection = self::createStub(Protection::class); - $serverRequest = self::createStub(ServerRequest::class); - $serverRequest->method("getUri") - ->willReturn(self::createStub(Uri::class)); - $serverRequest->method("getHeaderLine") - ->willReturnCallback( - fn(string $name):string => strtolower($name) === "accept" ? "*/*" : "" - ); + $globalProtection = self::createStub(Protection::class); + $serverRequest = self::createStub(ServerRequest::class); + $serverRequest->method("getUri") + ->willReturn(self::createStub(Uri::class)); + $serverRequest->method("getHeaderLine") + ->willReturnCallback( + fn(string $name):string => strtolower($name) === "accept" ? "*/*" : "" + ); $serverRequest->method("getMethod") ->willReturn("GET"); - $requestFactory = self::createStub(RequestFactory::class); - $requestFactory->method("createServerRequestFromGlobalState") - ->willReturn($serverRequest); - $dispatcher = self::createStub(Dispatcher::class); + $requestFactory = self::createStub(RequestFactory::class); + $requestFactory->method("createServerRequestFromGlobalState") + ->willReturn($serverRequest); + $dispatcher = self::createStub(Dispatcher::class); - $response = self::createStub(Response::class); + $response = self::createStub(Response::class); $response->method('getStatusCode')->willReturn(200); $response->method('getHeaders')->willReturn(['Content-Type' => ['text/html']]); $response->method('getBody')->willReturn(new \GT\Http\Stream()); $dispatcher->method('generateResponse')->willReturn($response); - $dispatcherFactory = self::createStub(DispatcherFactory::class); - $dispatcherFactory->method('create')->willReturn($dispatcher); + $dispatcherFactory = self::createStub(DispatcherFactory::class); + $dispatcherFactory->method('create')->willReturn($dispatcher); // Avoid warnings by ensuring server params contain REMOTE_ADDR $serverRequest->method('getServerParams')->willReturn(['REMOTE_ADDR' => '127.0.0.1']); @@ -85,23 +85,23 @@ public function testStart_callsTimerFunctions():void { $timer->expects(self::once()) ->method("logDelta"); - $dispatcher = self::createStub(Dispatcher::class); - $response = self::createStub(Response::class); + $dispatcher = self::createStub(Dispatcher::class); + $response = self::createStub(Response::class); $response->method('getStatusCode')->willReturn(200); $response->method('getHeaders')->willReturn(['Content-Type' => ['text/html']]); $response->method('getBody')->willReturn(new \GT\Http\Stream()); $dispatcher->method('generateResponse')->willReturn($response); - $dispatcherFactory = self::createStub(DispatcherFactory::class); - $dispatcherFactory->method('create')->willReturn($dispatcher); - - $requestFactory = self::createStub(RequestFactory::class); - $serverRequest = self::createStub(ServerRequest::class); - $serverRequest->method('getServerParams')->willReturn(['REMOTE_ADDR' => '127.0.0.1']); - $serverRequest->method('getUri')->willReturn(self::createStub(Uri::class)); - $serverRequest->method('getHeaderLine') - ->willReturnCallback( - fn(string $name):string => strtolower($name) === "accept" ? "*/*" : "" - ); + $dispatcherFactory = self::createStub(DispatcherFactory::class); + $dispatcherFactory->method('create')->willReturn($dispatcher); + + $requestFactory = self::createStub(RequestFactory::class); + $serverRequest = self::createStub(ServerRequest::class); + $serverRequest->method('getServerParams')->willReturn(['REMOTE_ADDR' => '127.0.0.1']); + $serverRequest->method('getUri')->willReturn(self::createStub(Uri::class)); + $serverRequest->method('getHeaderLine') + ->willReturnCallback( + fn(string $name):string => strtolower($name) === "accept" ? "*/*" : "" + ); $serverRequest->method('getMethod')->willReturn('GET'); $requestFactory->method('createServerRequestFromGlobalState')->willReturn($serverRequest); @@ -250,7 +250,7 @@ public function testStart_callErrorScriptOnThrowable():void { $output = ob_get_clean(); ob_end_clean(); - self::assertStringContainsString("exception message is testing", $output); + self::assertStringContainsString("exception message is testing", $output); } public function testStart_protectsGlobalsUsingConfiguredWhitelists():void { @@ -363,7 +363,7 @@ public function testStart_rebuildsDispatcherWithErrorStatusAndSessionInit():void Closure $finishCallback, ?int $errorStatus = null, ?SessionInit $passedSessionInit = null, - )use($config, $request, $sessionInit, &$createCalls, $firstDispatcher, $secondDispatcher) { + ) use ($config, $request, $sessionInit, &$createCalls, $firstDispatcher, $secondDispatcher) { $createCalls[] = [ "config" => $passedConfig, "request" => $passedRequest, @@ -1080,22 +1080,22 @@ private function createTestConfig(array $mockedValues):Config { $configContents = parse_ini_file($configFile, true); $map = []; - foreach ($configContents as $section => $kvp) { - foreach ($kvp as $key => $value) { + foreach($configContents as $section => $kvp) { + foreach($kvp as $key => $value) { $map["$section.$key"] = $value; } } $map = array_merge($map, $mockedValues); - $config->method(self::anything())->willReturnCallback(function ($key) use ($map) { + $config->method(self::anything())->willReturnCallback(function($key) use ($map) { $type = null; $bt = debug_backtrace(); if(isset($bt[1]) && ($bt[1]["args"][0] ?? null) instanceof Invocation) { $type = strtolower(substr($bt[1]["args"][0]->methodName(), 3)); } - return match($type) { + return match ($type) { "bool" => (bool)$map[$key], "int" => (int)$map[$key], "float" => (float)$map[$key], From 0ca6539211aadd80004fb643b2a0fc4bfd670898 Mon Sep 17 00:00:00 2001 From: Greg Bowler Date: Mon, 25 May 2026 16:10:31 +0100 Subject: [PATCH 3/4] tweak: check for output buffer being open before closing --- src/Debug/OutputBuffer.php | 11 ++++++++++- test/phpunit/Debug/OutputBufferTest.php | 3 ++- 2 files changed, 12 insertions(+), 2 deletions(-) diff --git a/src/Debug/OutputBuffer.php b/src/Debug/OutputBuffer.php index 339b0250..83a94ada 100644 --- a/src/Debug/OutputBuffer.php +++ b/src/Debug/OutputBuffer.php @@ -15,6 +15,7 @@ class OutputBuffer { private Closure $obStartHandler; private Closure $obGetCleanHandler; private string $buffer = ""; + private bool $bufferOpen = false; public function __construct( private bool $debugToJavaScript, @@ -33,11 +34,19 @@ private function fillBuffer(string $buffer):string { public function start():void { $this->cleanBuffer(); ($this->obStartHandler)(); + $this->bufferOpen = true; } public function cleanBuffer():void { + if(!$this->bufferOpen) { + return; + } + + $buffer = ($this->obGetCleanHandler)(); + $this->bufferOpen = false; + // ob_get_clean can return false; normalise to empty string. - $this->fillBuffer(($this->obGetCleanHandler)() ?? ""); + $this->fillBuffer($buffer ?: ""); } public function debugOutput():?string { diff --git a/test/phpunit/Debug/OutputBufferTest.php b/test/phpunit/Debug/OutputBufferTest.php index a16e8bea..912a2444 100644 --- a/test/phpunit/Debug/OutputBufferTest.php +++ b/test/phpunit/Debug/OutputBufferTest.php @@ -52,9 +52,10 @@ public function testCleanBuffer_accumulatesAndNormalisesNull(): void { $obGetClean = function() use (&$sequence) { return array_shift($sequence); }; $sut = new OutputBuffer(true, $obStart, $obGetClean); $sut->start(); - // Manually accumulate twice, then let debugOutput() call a final clean $sut->cleanBuffer(); // "one" + $sut->start(); $sut->cleanBuffer(); // null -> "" + $sut->start(); $html = $sut->debugOutput(); // "two" + emit script self::assertNotNull($html); self::assertStringContainsString('onetwo', $html); From 3a0951cfaa9b09d59951a14dcd15294635aeabe7 Mon Sep 17 00:00:00 2001 From: Greg Bowler Date: Mon, 25 May 2026 16:12:10 +0100 Subject: [PATCH 4/4] tweak: shorten variable name --- src/Dispatch/Dispatcher.php | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/Dispatch/Dispatcher.php b/src/Dispatch/Dispatcher.php index 662e9d35..09b59bcc 100644 --- a/src/Dispatch/Dispatcher.php +++ b/src/Dispatch/Dispatcher.php @@ -485,14 +485,14 @@ public function processResponse( // phpcs:enable Generic.Metrics.CyclomaticComplexity.TooHigh private function recordLogicExecution(string $functionReference):void { - $referenceWithoutAttributes = explode("#", $functionReference, 2)[0]; - $separatorPosition = strrpos($referenceWithoutAttributes, "::"); + $refWithoutAttributes = explode("#", $functionReference, 2)[0]; + $separatorPosition = strrpos($refWithoutAttributes, "::"); if($separatorPosition === false) { return; } - $file = substr($referenceWithoutAttributes, 0, $separatorPosition); - $function = substr($referenceWithoutAttributes, $separatorPosition + 2); + $file = substr($refWithoutAttributes, 0, $separatorPosition); + $function = substr($refWithoutAttributes, $separatorPosition + 2); $function = preg_replace('/\(\)$/', '', $function); if($function === null || $function === "") { return;