feat: hook timings, the bar in wp-admin, multisite (phase 3)

.github/workflows/tests.yml

@@ -27,8 +27,8 @@ jobs:
           extensions: dom, curl, libxml, mbstring, zip, pdo_sqlite
           coverage: none
 
-      - name: Use the unreleased framework (until v13.35.3 is tagged; feature branch until framework#442 is merged)
-        run: composer require --no-update --no-interaction "pollora/framework:dev-feat/debugbar-extension-points as 13.35.3"
+      - name: Use the unreleased framework (release branch until v13.35.3 is tagged)
+        run: composer require --no-update --no-interaction "pollora/framework:dev-release/v13.35.3 as 13.35.3"
 
       - name: Install dependencies
         run: composer update --prefer-stable --prefer-dist --no-interaction
@@ -50,8 +50,8 @@ jobs:
           extensions: dom, curl, libxml, mbstring, zip
           coverage: none
 
-      - name: Use the unreleased framework (until v13.35.3 is tagged; feature branch until framework#442 is merged)
-        run: composer require --no-update --no-interaction "pollora/framework:dev-feat/debugbar-extension-points as 13.35.3"
+      - name: Use the unreleased framework (release branch until v13.35.3 is tagged)
+        run: composer require --no-update --no-interaction "pollora/framework:dev-release/v13.35.3 as 13.35.3"
 
       - name: Install dependencies
         run: composer update --prefer-stable --prefer-dist --no-interaction
@@ -113,11 +113,11 @@ jobs:
             -e 's/^# DB_PASSWORD=.*/DB_PASSWORD=db/' \
             .env
 
-      # Until v13.35.3 is tagged, the framework comes from framework#442's branch.
+      # Until v13.35.3 is tagged, the framework comes from its release branch.
       - name: Install the skeleton with this package checkout
         run: |
           ddev composer config repositories.debugbar '{"type": "path", "url": "packages/debugbar", "options": {"symlink": false, "versions": {"pollora/debugbar": "0.1.0"}}}'
-          ddev composer require "pollora/framework:dev-feat/debugbar-extension-points as 13.35.3" --with-all-dependencies --no-interaction --no-progress --no-scripts
+          ddev composer require "pollora/framework:dev-release/v13.35.3 as 13.35.3" --with-all-dependencies --no-interaction --no-progress --no-scripts
           ddev composer require --dev pollora/debugbar:0.1.0 --with-all-dependencies --no-interaction --no-progress
 
       - name: Generate application key

config/debugbar-pollora.php

@@ -23,9 +23,11 @@
     |--------------------------------------------------------------------------
     |
     | pollora      What answered the request, discovery, modules, theme, async
-    | wp_request   Rewrite rule, query vars, main query, conditionals, templates
+    | wp_request   Rewrite rule, query vars, main query, conditionals, templates,
+    |              admin screen, multisite site and switches
     | wp_queries   $wpdb queries (turns SAVEQUERIES on)
-    | wp_hooks     Hooks that ran and the callbacks Pollora registered
+    | wp_hooks     Hooks that ran and the callbacks Pollora registered; with
+    |              options.wp_hooks.timings, a WP Hook timings tab
     | wp_timeline  WordPress phases on Debugbar's timeline
     | wp_http      HTTP calls made through wp_remote_*
     | wp_cache     Object cache, transients set, OPcache
@@ -54,6 +56,35 @@
         'bridges' => env('DEBUGBAR_POLLORA_COLLECTORS_BRIDGES', true),
     ],
 
+    /*
+    |--------------------------------------------------------------------------
+    | Pages inside an iframe
+    |--------------------------------------------------------------------------
+    |
+    | The Site Editor and the Customizer show the front end in an iframe. Those
+    | requests are still stored (open them from the bar's request list), but
+    | no bar is printed inside the frame unless this is true.
+    |
+    */
+
+    'iframes' => env('DEBUGBAR_POLLORA_IFRAMES', false),
+
+    /*
+    |--------------------------------------------------------------------------
+    | wp-admin
+    |--------------------------------------------------------------------------
+    |
+    | WordPress prints admin pages itself, so Laravel Debugbar never shows
+    | there on its own. The bar is printed with the admin footer scripts,
+    | without Debugbar's tabs about a request Laravel answered.
+    |
+    */
+
+    'admin' => [
+        'enabled' => env('DEBUGBAR_POLLORA_ADMIN', true),
+        'hidden_collectors' => ['route', 'views', 'session', 'livewire', 'inertia'],
+    ],
+
     'options' => [
 
         'wp_queries' => [
@@ -75,6 +106,11 @@
         'wp_hooks' => [
             // Count filters too: an `all` listener runs on every apply_filters()
             'count_filters' => env('DEBUGBAR_POLLORA_WP_HOOKS_COUNT_FILTERS', false),
+            // Time every callback (WP Hook timings tab); wraps each callback
+            // in $wp_filter and adds a timer to every call, so off by default
+            'timings' => env('DEBUGBAR_POLLORA_WP_HOOKS_TIMINGS', false),
+            // How many callbacks the timings tab lists, slowest first
+            'timings_limit' => (int) env('DEBUGBAR_POLLORA_WP_HOOKS_TIMINGS_LIMIT', 200),
         ],
 
         'bridges' => [

src/Activation.php

@@ -6,6 +6,7 @@
 
 use Fruitcake\LaravelDebugbar\LaravelDebugbar;
 use Illuminate\Contracts\Foundation\Application;
+use Illuminate\Http\Request;
 
 /**
  * Whether Pollora's tabs run for this request.
@@ -42,4 +43,17 @@ public static function shouldRun(Application $app): bool
 
         return (bool) ($enabled ?? $config->get('app.debug'));
     }
+
+    /**
+     * Whether the page is loaded inside an iframe: the Site Editor canvas,
+     * the Customizer preview, an embed.
+     *
+     * Browsers say so with `Sec-Fetch-Dest`; `wp_site_preview` covers the
+     * Site Editor in a browser that does not send it.
+     */
+    public static function isFramed(Request $request): bool
+    {
+        return $request->headers->get('Sec-Fetch-Dest') === 'iframe'
+            || $request->query->has('wp_site_preview');
+    }
 }

src/CollectorRegistrar.php

@@ -15,6 +15,7 @@
 use Pollora\Debugbar\Collectors\WpCacheCollector;
 use Pollora\Debugbar\Collectors\WpCapabilitiesCollector;
 use Pollora\Debugbar\Collectors\WpHooksCollector;
+use Pollora\Debugbar\Collectors\WpHookTimingsCollector;
 use Pollora\Debugbar\Collectors\WpHttpCollector;
 use Pollora\Debugbar\Collectors\WpLanguagesCollector;
 use Pollora\Debugbar\Collectors\WpQueriesCollector;
@@ -25,10 +26,12 @@
 use Pollora\Debugbar\Recording\BlockRecorder;
 use Pollora\Debugbar\Recording\CacheRecorder;
 use Pollora\Debugbar\Recording\CapabilityRecorder;
+use Pollora\Debugbar\Recording\HookTimer;
 use Pollora\Debugbar\Recording\HttpRecorder;
 use Pollora\Debugbar\Recording\LanguageRecorder;
 use Pollora\Debugbar\Recording\QueryTracer;
 use Pollora\Debugbar\Recording\RequestRecorder;
+use Pollora\Debugbar\Recording\SiteRecorder;
 use Pollora\Debugbar\Support\Components;
 use Pollora\Hook\Domain\Contract\Action;
 use Pollora\Hook\Domain\Contract\Filter;
@@ -117,7 +120,7 @@ private function builtIns(LaravelDebugbar $debugbar): array
         }
 
         if ($on('wp_request')) {
-            $collectors[] = new WpRequestCollector($this->recorder);
+            $collectors[] = new WpRequestCollector($this->recorder, $this->container->make(SiteRecorder::class), $this->container->make(Components::class));
         }
 
         if ($on('wp_queries')) {
@@ -134,6 +137,14 @@ private function builtIns(LaravelDebugbar $debugbar): array
 
         if ($on('wp_hooks')) {
             $collectors[] = new WpHooksCollector($this->recorder, $this->polloraHookServices());
+
+            if ($config->get('debugbar-pollora.options.wp_hooks.timings', false)) {
+                $collectors[] = new WpHookTimingsCollector(
+                    $this->container->make(HookTimer::class),
+                    $this->container->make(Components::class),
+                    (int) $config->get('debugbar-pollora.options.wp_hooks.timings_limit', 200),
+                );
+            }
         }
 
         $components = $this->container->make(Components::class);

src/Collectors/WpHookTimingsCollector.php

@@ -0,0 +1,104 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Pollora\Debugbar\Collectors;
+
+use Pollora\Debugbar\Collector;
+use Pollora\Debugbar\Origin;
+use Pollora\Debugbar\Recording\HookTimer;
+use Pollora\Debugbar\Support\Components;
+use Pollora\Debugbar\Widget;
+
+/**
+ * The slowest hook callbacks of the request, by their own time: what they
+ * spent outside the hooks they fired in turn. Query Monitor has no such view.
+ */
+final class WpHookTimingsCollector extends Collector
+{
+    public function __construct(
+        private readonly HookTimer $timer,
+        private readonly Components $components,
+        private readonly int $limit = 200,
+    ) {}
+
+    public function getName(): string
+    {
+        return 'wp_hook_timings';
+    }
+
+    public function title(): string
+    {
+        return 'WP Hook timings';
+    }
+
+    public function origin(): string
+    {
+        return Origin::WORDPRESS;
+    }
+
+    public function icon(): string
+    {
+        return 'clock';
+    }
+
+    public function widget(): Widget
+    {
+        return Widget::Table;
+    }
+
+    public function position(): int
+    {
+        return 35;
+    }
+
+    /**
+     * @return array<string, string>
+     */
+    public function columns(): array
+    {
+        return [
+            'self' => 'Own time',
+            'total' => 'Total',
+            'calls' => 'Calls',
+            'hook' => 'Hook',
+            'component' => 'From',
+        ];
+    }
+
+    /**
+     * @return array<string, array{self: string, total: string, calls: int, hook: string, component: string}>
+     */
+    protected function data(): array
+    {
+        $timings = $this->timer->timings();
+
+        usort($timings, static fn (array $a, array $b): int => $b['self'] <=> $a['self']);
+
+        $rows = [];
+
+        foreach (array_slice($timings, 0, max(1, $this->limit)) as $timing) {
+            $key = WpHooksCollector::describe($timing['callback']);
+
+            // The same callback can run on several hooks
+            while (isset($rows[$key])) {
+                $key .= ' ';
+            }
+
+            $rows[$key] = [
+                'self' => self::milliseconds($timing['self']),
+                'total' => self::milliseconds($timing['total']),
+                'calls' => $timing['calls'],
+                'hook' => sprintf('%s @%d', $timing['hook'], $timing['priority']),
+                'component' => $timing['file'] !== '' ? $this->components->of($timing['file']) : 'unknown',
+            ];
+        }
+
+        return $rows;
+    }
+
+    private static function milliseconds(int $nanoseconds): string
+    {
+        return number_format($nanoseconds / 1_000_000, 2).' ms';
+    }
+}

src/Collectors/WpHooksCollector.php

@@ -7,6 +7,7 @@
 use Pollora\Debugbar\Collector;
 use Pollora\Debugbar\Origin;
 use Pollora\Debugbar\Recording\RequestRecorder;
+use Pollora\Debugbar\Recording\TimedCallback;
 use Pollora\Debugbar\Widget;
 
 /**
@@ -76,6 +77,7 @@ public function columns(): array
     public static function describe(mixed $callback): string
     {
         return match (true) {
+            $callback instanceof TimedCallback => self::describe($callback->callback),
             is_string($callback) => $callback,
             is_array($callback) && isset($callback[0], $callback[1]) => (is_object($callback[0]) ? $callback[0]::class : (string) $callback[0]).'::'.(string) $callback[1],
             $callback instanceof \Closure => self::describeClosure($callback),
@@ -123,7 +125,12 @@ protected function data(): array
     private static function describeClosure(\Closure $closure): string
     {
         $reflection = new \ReflectionFunction($closure);
-        $scope = $reflection->getClosureScopeClass()?->getName();
+        $scopeClass = $reflection->getClosureScopeClass();
+
+        // A file included from a method (a mu-plugin WordPress loads from
+        // Pollora's Bootstrap) gives its closures that class's scope: name
+        // the class only when the closure is written in it
+        $scope = $scopeClass !== null && $scopeClass->getFileName() === $reflection->getFileName() ? $scopeClass->getName() : null;
 
         if (! str_contains($reflection->getName(), '{closure')) {
             return $scope !== null ? "{$scope}::{$reflection->getName()}" : $reflection->getName();