Merge pull request #7830 from ProcessMaker/epic/FOUR-20327

FOUR-20327 [EPIC] Implement Baseline Server Timing Headers

Author: ryancooley

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,
     ];
 
     /**

ProcessMaker/Http/Middleware/ServerTimingMiddleware.php

@@ -0,0 +1,71 @@
+<?php
+
+namespace ProcessMaker\Http\Middleware;
+
+use Closure;
+use Illuminate\Http\Request;
+use ProcessMaker\Providers\ProcessMakerServiceProvider;
+use Symfony\Component\HttpFoundation\Response;
+
+class ServerTimingMiddleware
+{
+    // Minimum time in ms to include a package in the Server-Timing header
+    private static $minPackageTime;
+
+    public function __construct()
+    {
+        self::$minPackageTime = config('app.server_timing.min_package_time');
+    }
+    /**
+     * Handle an incoming request.
+     *
+     * @param  \Closure(\Illuminate\Http\Request): (\Symfony\Component\HttpFoundation\Response)  $next
+     */
+    public function handle(Request $request, Closure $next): Response
+    {
+        if (!config('app.server_timing.enabled')) {
+            return $next($request);
+        }
+
+        // Start time for controller execution
+        $startController = microtime(true);
+
+        // Process the request
+        $response = $next($request);
+
+        // Calculate execution times
+        $controllerTime = (microtime(true) - $startController) * 1000; // Convert to ms
+        // Fetch service provider boot time
+        $serviceProviderTime = ProcessMakerServiceProvider::getBootTime() ?? 0;
+        // Fetch query time
+        $queryTime = ProcessMakerServiceProvider::getQueryTime() ?? 0;
+
+        $serverTiming = [
+            "provider;dur={$serviceProviderTime}",
+            "controller;dur={$controllerTime}",
+            "db;dur={$queryTime}",
+        ];
+
+        $hasLaravelStart = defined('LARAVEL_START');
+        if ($hasLaravelStart) {
+            $bootTiming = ($startController - \LARAVEL_START) * 1000; // Convert to ms
+            array_unshift($serverTiming, "boot;dur={$bootTiming}");
+        }
+
+        $packageTimes = ProcessMakerServiceProvider::getPackageBootTiming();
+
+        foreach ($packageTimes as $package => $timing) {
+            $time = ($timing['end'] - $timing['start']) * 1000;
+
+            // Only include packages that took more than MIN_PACKAGE_TIME ms
+            if ($time > self::$minPackageTime) {
+                $serverTiming[] = "{$package};dur={$time}";
+            }
+        }
+
+        // Add Server-Timing headers
+        $response->headers->set('Server-Timing', $serverTiming);
+
+        return $response;
+    }
+}

ProcessMaker/Providers/ProcessMakerServiceProvider.php

@@ -10,6 +10,8 @@
 use Illuminate\Notifications\Events\BroadcastNotificationCreated;
 use Illuminate\Notifications\Events\NotificationSent;
 use Illuminate\Support\Facades;
+use Illuminate\Support\Facades\DB;
+use Illuminate\Support\Facades\Log;
 use Illuminate\Support\Facades\URL;
 use Laravel\Dusk\DuskServiceProvider;
 use Laravel\Horizon\Horizon;
@@ -35,8 +37,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 +66,20 @@ 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
     {
+        if (config('app.server_timing.enabled')) {
+            // 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 +382,71 @@ 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 string $package
+     * @param float $time
+     */
+    public static function setPackageBootStart(string $package, float $time): void
+    {
+        if ($time < 0) {
+            Log::info("Server Timing: Invalid boot time for package: {$package}, time: {$time}");
+
+            $time = 0;
+        }
+
+        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
+    {
+        if (!isset(self::$packageBootTiming[$package]) || $time < 0) {
+            Log::info("Server Timing: Invalid booted time for package: {$package}, time: {$time}");
+
+            return;
+        }
+
+        self::$packageBootTiming[$package]['end'] = $time;
+    }
+
+    /**
+     * Get the boot time for service providers.
+     *
+     * @return array
+     */
+    public static function getPackageBootTiming(): array
+    {
+        return self::$packageBootTiming;
+    }
 }

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,58 @@ trait PluginServiceProviderTrait
 
     private $scriptBuilderScripts = [];
 
+    private static $bootStart = null;
+
+    private static $bootTime;
+
+    public function __construct($app)
+    {
+        parent::__construct($app);
+
+        $this->bootServerTiming();
+    }
+
+    /**
+     * The `bootServerTiming` function sets up timing measurements for the booting and booted events of the packages
+     *
+     * @return void If the condition `config('app.server_timing.enabled')` is false, nothing is being returned as the
+     * function will exit early.
+     */
+    protected function bootServerTiming(): void
+    {
+        if (!config('app.server_timing.enabled')) {
+            return;
+        }
+
+        $package = $this->getPackageName();
+
+        $this->booting(function () use ($package) {
+            self::$bootStart = microtime(true);
+
+            ProcessMakerServiceProvider::setPackageBootStart($package, self::$bootStart);
+        });
+
+        $this->booted(function () use ($package) {
+            self::$bootTime = microtime(true);
+
+            ProcessMakerServiceProvider::setPackageBootedTime($package, self::$bootTime);
+        });
+    }
+
+    /**
+     * Get the package name for the Server Timing header
+     *
+     * @return string
+     */
+    protected function getPackageName(): string
+    {
+        if (defined('static::name')) {
+            return ucfirst(\Str::camel(static::name));
+        }
+
+        return substr(static::class, strrpos(static::class, '\\') + 1);
+    }
+
     /**
      * Boot the PM plug-in.
      */

config/app.php

@@ -246,7 +246,7 @@
     // Process Request security log rate limit: 1 per day (86400 seconds)
     'process_request_errors_rate_limit' => env('PROCESS_REQUEST_ERRORS_RATE_LIMIT', 1),
     'process_request_errors_rate_limit_duration' => env('PROCESS_REQUEST_ERRORS_RATE_LIMIT_DURATION', 86400),
-    
+
     'default_colors' => [
         'primary' => '#2773F3',
         'secondary' => '#728092',
@@ -266,4 +266,9 @@
         'vault_token' => env('ENCRYPTED_DATA_VAULT_TOKEN', ''),
         'vault_transit_key' => env('ENCRYPTED_DATA_VAULT_TRANSIT_KEY', ''),
     ],
+
+    'server_timing' => [
+        'enabled' => env('SERVER_TIMING_ENABLED', true),
+        'min_package_time' => env('SERVER_TIMING_MIN_PACKAGE_TIME', 5), // Minimum time in milliseconds
+    ],
 ];