diff --git a/ProcessMaker/Http/Kernel.php b/ProcessMaker/Http/Kernel.php index 5fb8432f48..e6ee02c7ee 100644 --- a/ProcessMaker/Http/Kernel.php +++ b/ProcessMaker/Http/Kernel.php @@ -3,6 +3,7 @@ namespace ProcessMaker\Http; use Illuminate\Foundation\Http\Kernel as HttpKernel; +use ProcessMaker\Http\Middleware\ServerTimingMiddleware; class Kernel extends HttpKernel { @@ -20,6 +21,7 @@ class Kernel extends HttpKernel \Illuminate\Foundation\Http\Middleware\ConvertEmptyStringsToNull::class, Middleware\TrustProxies::class, Middleware\BrowserCache::class, + ServerTimingMiddleware::class, ]; /** diff --git a/ProcessMaker/Http/Middleware/ServerTimingMiddleware.php b/ProcessMaker/Http/Middleware/ServerTimingMiddleware.php new file mode 100644 index 0000000000..1c687d4f5d --- /dev/null +++ b/ProcessMaker/Http/Middleware/ServerTimingMiddleware.php @@ -0,0 +1,52 @@ + $timing) { + $time = ($timing['end'] - $timing['start']) * 1000; + + $serverTiming[] = "{$package};dur={$time}"; + } + + // Add Server-Timing headers + $response->headers->set('Server-Timing', $serverTiming); + + return $response; + } +} diff --git a/ProcessMaker/Providers/ProcessMakerServiceProvider.php b/ProcessMaker/Providers/ProcessMakerServiceProvider.php index ce11b8e437..9bb9442cf2 100644 --- a/ProcessMaker/Providers/ProcessMakerServiceProvider.php +++ b/ProcessMaker/Providers/ProcessMakerServiceProvider.php @@ -10,6 +10,7 @@ use Illuminate\Notifications\Events\BroadcastNotificationCreated; use Illuminate\Notifications\Events\NotificationSent; use Illuminate\Support\Facades; +use Illuminate\Support\Facades\DB; use Illuminate\Support\Facades\URL; use Laravel\Dusk\DuskServiceProvider; use Laravel\Horizon\Horizon; @@ -35,8 +36,20 @@ */ class ProcessMakerServiceProvider extends ServiceProvider { + // Track the start time for service providers boot + private static $bootStart; + // Track the boot time for service providers + private static $bootTime; + // Track the boot time for each package + private static $packageBootTiming = []; + // Track the query time for each request + private static $queryTime = 0; + public function boot(): void { + // Track the start time for service providers boot + self::$bootStart = microtime(true); + $this->app->singleton(Menu::class, function ($app) { return new MenuManager(); }); @@ -52,10 +65,18 @@ public function boot(): void $this->setupFactories(); parent::boot(); + + // Hook after service providers boot + self::$bootTime = (microtime(true) - self::$bootStart) * 1000; // Convert to milliseconds } public function register(): void { + // Listen to query events and accumulate query execution time + DB::listen(function ($query) { + self::$queryTime += $query->time; + }); + // Dusk, if env is appropriate // TODO Remove Dusk references and remove from composer dependencies if (!$this->app->environment('production')) { @@ -358,4 +379,61 @@ public static function forceHttps(): void URL::forceScheme('https'); } } + + /** + * Get the boot time for service providers. + * + * @return float|null + */ + public static function getBootTime(): ?float + { + return self::$bootTime; + } + + /** + * Get the query time for the request. + * + * @return float + */ + public static function getQueryTime(): float + { + return self::$queryTime; + } + + /** + * Set the boot time for service providers. + * + * @param float $time + */ + public static function setPackageBootStart(string $package, $time): void + { + $package = ucfirst(\Str::camel(str_replace(['ProcessMaker\Packages\\', '\\'], '', $package))); + + self::$packageBootTiming[$package] = [ + 'start' => $time, + 'end' => null, + ]; + } + + /** + * Set the boot time for service providers. + * + * @param float $time + */ + public static function setPackageBootedTime(string $package, $time): void + { + $package = ucfirst(\Str::camel(str_replace(['ProcessMaker\Packages\\', '\\'], '', $package))); + + self::$packageBootTiming[$package]['end'] = $time; + } + + /** + * Get the boot time for service providers. + * + * @return array + */ + public static function getPackageBootTiming(): array + { + return self::$packageBootTiming; + } } diff --git a/ProcessMaker/Traits/PluginServiceProviderTrait.php b/ProcessMaker/Traits/PluginServiceProviderTrait.php index 2e25a147ec..028409f4a4 100644 --- a/ProcessMaker/Traits/PluginServiceProviderTrait.php +++ b/ProcessMaker/Traits/PluginServiceProviderTrait.php @@ -11,6 +11,7 @@ use ProcessMaker\Managers\IndexManager; use ProcessMaker\Managers\LoginManager; use ProcessMaker\Managers\PackageManager; +use ProcessMaker\Providers\ProcessMakerServiceProvider; /** * Add functionality to control a PM plug-in @@ -21,6 +22,32 @@ trait PluginServiceProviderTrait private $scriptBuilderScripts = []; + private static $bootStart = null; + + private static $bootTime; + + public function __construct($app) + { + parent::__construct($app); + + $this->booting(function () { + self::$bootStart = microtime(true); + + $package = defined('static::name') ? static::name : $this::class; + + ProcessMakerServiceProvider::setPackageBootStart($package, self::$bootStart); + }); + + $this->booted(function () { + self::$bootTime = microtime(true); + + $package = defined('static::name') ? static::name : $this::class; + + ProcessMakerServiceProvider::setPackageBootedTime($package, self::$bootTime); + }); + + } + /** * Boot the PM plug-in. */ diff --git a/tests/Feature/ServerTimingMiddlewareTest.php b/tests/Feature/ServerTimingMiddlewareTest.php new file mode 100644 index 0000000000..d82aed00d8 --- /dev/null +++ b/tests/Feature/ServerTimingMiddlewareTest.php @@ -0,0 +1,137 @@ +headers->all(); + return $headers[$header]; + } + + public function testServerTimingHeaderIncludesAllMetrics() + { + Route::middleware(ServerTimingMiddleware::class)->get('/test', function () { + // Simulate a query + DB::select('SELECT SLEEP(1)'); + + return response()->json(['message' => 'Test endpoint']); + }); + + // Send a GET request + $response = $this->get('/test'); + $response->assertStatus(200); + // Assert the response has the Server-Timing header + $response->assertHeader('Server-Timing'); + + $serverTiming = $this->getHeader($response, 'server-timing'); + $this->assertStringContainsString('provider;dur=', $serverTiming[0]); + $this->assertStringContainsString('controller;dur=', $serverTiming[1]); + $this->assertStringContainsString('db;dur=', $serverTiming[2]); + } + + public function testQueryTimeIsMeasured() + { + // Mock a route with a query + Route::middleware(ServerTimingMiddleware::class)->get('/query-test', function () { + DB::select('SELECT SLEEP(0.2)'); + return response()->json(['message' => 'Query test']); + }); + + // Send a GET request + $response = $this->get('/query-test'); + // Extract the Server-Timing header + $serverTiming = $this->getHeader($response, 'server-timing'); + // Assert the db timing is greater than 200ms (SLEEP simulates query time) + preg_match('/db;dur=([\d.]+)/', $serverTiming[2], $matches); + $dbTime = $matches[1] ?? 0; + + $this->assertGreaterThanOrEqual(200, (float)$dbTime); + } + + public function testServiceProviderTimeIsMeasured() + { + // Mock a route + Route::middleware(ServerTimingMiddleware::class)->get('/providers-test', function () { + return response()->json(['message' => 'Providers test']); + }); + + // Send a GET request + $response = $this->get('/providers-test'); + // Extract the Server-Timing header + $serverTiming = $this->getHeader($response, 'server-timing'); + + // Assert the providers timing is present and greater than or equal to 0 + preg_match('/provider;dur=([\d.]+)/', $serverTiming[0], $matches); + $providersTime = $matches[1] ?? null; + + $this->assertNotNull($providersTime); + $this->assertGreaterThanOrEqual(0, (float)$providersTime); + } + + public function testControllerTimingIsMeasuredCorrectly() + { + // Mock a route + Route::middleware(ServerTimingMiddleware::class)->get('/controller-test', function () { + usleep(300000); // Simulate 300ms delay in the controller + return response()->json(['message' => 'Controller timing test']); + }); + + // Send a GET request + $response = $this->get('/controller-test'); + // Extract the Server-Timing header + $serverTiming = $this->getHeader($response, 'server-timing'); + + // Assert the controller timing is greater than 300ms + preg_match('/controller;dur=([\d.]+)/', $serverTiming[1], $matches); + $controllerTime = $matches[1] ?? 0; + + $this->assertGreaterThanOrEqual(300, (float)$controllerTime); + } + + public function testProvidersTimingIsMeasuredCorrectly() + { + // Mock a route + Route::middleware(ServerTimingMiddleware::class)->get('/providers-test', function () { + return response()->json(['message' => 'Providers timing test']); + }); + + // Send a GET request + $response = $this->get('/providers-test'); + // Extract the Server-Timing header + $serverTiming = $this->getHeader($response, 'server-timing'); + + // Assert the providers timing is present and greater than or equal to 0 + preg_match('/provider;dur=([\d.]+)/', $serverTiming[0], $matches); + $providersTime = $matches[1] ?? null; + + $this->assertNotNull($providersTime); + $this->assertGreaterThanOrEqual(0, (float)$providersTime); + } + + public function testServerTimingOnLogin() + { + $user = User::factory()->create([ + 'username' =>'john', + ]); + $this->actingAs($user, 'web'); + + $response = $this->get('/login'); + $response->assertHeader('Server-Timing'); + + $serverTiming = $this->getHeader($response, 'server-timing'); + $this->assertStringContainsString('provider;dur=', $serverTiming[0]); + $this->assertStringContainsString('controller;dur=', $serverTiming[1]); + $this->assertStringContainsString('db;dur=', $serverTiming[2]); + } +}