diff --git a/tests/Feature/ServerTimingMiddlewareTest.php b/tests/Feature/ServerTimingMiddlewareTest.php index 040401d227..9654a44854 100644 --- a/tests/Feature/ServerTimingMiddlewareTest.php +++ b/tests/Feature/ServerTimingMiddlewareTest.php @@ -2,8 +2,11 @@ namespace Tests\Feature; +use Illuminate\Database\Events\QueryExecuted; +use Illuminate\Http\Request; use Illuminate\Support\Facades\DB; use Illuminate\Support\Facades\Route; +use Laravel\Octane\ApplicationGateway; use ProcessMaker\Http\Middleware\ServerTimingMiddleware; use ProcessMaker\Models\User; use ProcessMaker\Providers\ProcessMakerServiceProvider; @@ -15,6 +18,13 @@ class ServerTimingMiddlewareTest extends TestCase { use RequestHelper; + protected function tearDown(): void + { + ProcessMakerServiceProvider::beginRequestTiming(); + + parent::tearDown(); + } + private function getHeader($response, $header) { $headers = $response->headers->all(); @@ -22,6 +32,24 @@ private function getHeader($response, $header) return $headers[$header]; } + private function getMetricDuration($response, string $metric): float + { + $serverTiming = implode(',', $this->getHeader($response, 'server-timing')); + + preg_match('/(?:^|,)\\s*' . preg_quote($metric, '/') . ';dur=([\\d.]+)/', $serverTiming, $matches); + + $this->assertArrayHasKey(1, $matches, "The {$metric} metric was not present in the Server-Timing header."); + + return (float) $matches[1]; + } + + private function recordQueryDuration(float $milliseconds): void + { + $connection = DB::connection(); + + event(new QueryExecuted('SELECT 1', [], $milliseconds, $connection)); + } + public function testServerTimingHeaderIncludesAllMetrics() { Route::middleware(ServerTimingMiddleware::class)->get('/test', function () { @@ -85,6 +113,45 @@ public function testQueryTimeIsMeasured() $this->assertGreaterThanOrEqual(200, (float) $dbTime); } + public function testOctaneGatewayIsolatesQueryTimingAcrossConsecutiveRequests() + { + Route::middleware(ServerTimingMiddleware::class)->get('/octane-query/slow', function () { + $this->recordQueryDuration(5000); + + return response()->json(['request' => 'slow']); + }); + + Route::middleware(ServerTimingMiddleware::class)->get('/octane-query/fast', function () { + $this->recordQueryDuration(10); + + return response()->json(['request' => 'fast']); + }); + + $gateway = new ApplicationGateway($this->app, $this->app); + + $firstRequest = Request::create('/octane-query/slow'); + $firstResponse = $gateway->handle($firstRequest); + $firstRequestQueryTime = $this->getMetricDuration($firstResponse, 'db'); + + $this->assertGreaterThanOrEqual(5000, $firstRequestQueryTime); + + $gateway->terminate($firstRequest, $firstResponse); + + $this->assertSame(0.0, ProcessMakerServiceProvider::getQueryTime()); + + $secondRequest = Request::create('/octane-query/fast'); + $secondResponse = $gateway->handle($secondRequest); + $secondRequestQueryTime = $this->getMetricDuration($secondResponse, 'db'); + + $this->assertGreaterThanOrEqual(10, $secondRequestQueryTime); + $this->assertLessThan(5000, $secondRequestQueryTime); + $this->assertLessThan($firstRequestQueryTime, $secondRequestQueryTime); + + $gateway->terminate($secondRequest, $secondResponse); + + $this->assertSame(0.0, ProcessMakerServiceProvider::getQueryTime()); + } + public function testServiceProviderTimeIsMeasured() { // Mock a route diff --git a/tests/unit/ProcessMaker/Octane/ResetRequestStateTest.php b/tests/unit/ProcessMaker/Octane/ResetRequestStateTest.php index 7895d8519f..22e50f8959 100644 --- a/tests/unit/ProcessMaker/Octane/ResetRequestStateTest.php +++ b/tests/unit/ProcessMaker/Octane/ResetRequestStateTest.php @@ -4,6 +4,7 @@ namespace Tests\Unit\ProcessMaker\Octane; +use Illuminate\Database\Events\QueryExecuted; use Illuminate\Http\Request; use Illuminate\Support\Facades\DB; use Illuminate\Support\Facades\Event; @@ -18,6 +19,20 @@ class ResetRequestStateTest extends TestCase { + protected function tearDown(): void + { + ProcessMakerServiceProvider::beginRequestTiming(); + + parent::tearDown(); + } + + private function recordQueryDuration(float $milliseconds): void + { + $connection = DB::connection(); + + event(new QueryExecuted('SELECT 1', [], $milliseconds, $connection)); + } + public function test_it_clears_request_timing_before_the_next_request(): void { DB::select('SELECT 1'); @@ -49,6 +64,13 @@ public function test_octane_request_termination_automatically_resets_request_sta { Event::fake([RedirectToEvent::class]); + ProcessMakerServiceProvider::beginRequestTiming(); + $this->recordQueryDuration(5000); + + $firstRequestQueryTime = ProcessMakerServiceProvider::getQueryTime(); + + $this->assertSame(5000.0, $firstRequestQueryTime); + $redirectListener = new RedirectStateProbe(); $redirectListener->queue(ProcessRequest::factory()->create()); @@ -59,9 +81,33 @@ public function test_octane_request_termination_automatically_resets_request_sta new Response() )); + $this->assertSame(0.0, ProcessMakerServiceProvider::getQueryTime()); + HandleRedirectListener::sendRedirectToEvent(); Event::assertNotDispatched(RedirectToEvent::class); + + $this->recordQueryDuration(10); + + $nextRequestQueryTime = ProcessMakerServiceProvider::getQueryTime(); + + $this->assertSame(10.0, $nextRequestQueryTime); + } + + public function test_octane_request_termination_resets_timing_after_an_error_response(): void + { + DB::select('SELECT 1'); + + $this->assertGreaterThan(0, ProcessMakerServiceProvider::getQueryTime()); + + event(new RequestTerminated( + $this->app, + $this->app, + Request::create('/failed-request'), + new Response(status: 500) + )); + + $this->assertSame(0.0, ProcessMakerServiceProvider::getQueryTime()); } }