diff --git a/.github/workflows/tests.yml b/.github/workflows/tests.yml index 9ed9ef3..66e5254 100644 --- a/.github/workflows/tests.yml +++ b/.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 diff --git a/config/debugbar-pollora.php b/config/debugbar-pollora.php index 3c88cba..c939bb9 100644 --- a/config/debugbar-pollora.php +++ b/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' => [ diff --git a/src/Activation.php b/src/Activation.php index 97d9f7f..913cad0 100644 --- a/src/Activation.php +++ b/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'); + } } diff --git a/src/CollectorRegistrar.php b/src/CollectorRegistrar.php index ca3fe36..1082352 100644 --- a/src/CollectorRegistrar.php +++ b/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); diff --git a/src/Collectors/WpHookTimingsCollector.php b/src/Collectors/WpHookTimingsCollector.php new file mode 100644 index 0000000..8f2975c --- /dev/null +++ b/src/Collectors/WpHookTimingsCollector.php @@ -0,0 +1,104 @@ + + */ + public function columns(): array + { + return [ + 'self' => 'Own time', + 'total' => 'Total', + 'calls' => 'Calls', + 'hook' => 'Hook', + 'component' => 'From', + ]; + } + + /** + * @return array + */ + 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'; + } +} diff --git a/src/Collectors/WpHooksCollector.php b/src/Collectors/WpHooksCollector.php index 310b4b7..6ea7c17 100644 --- a/src/Collectors/WpHooksCollector.php +++ b/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(); diff --git a/src/Collectors/WpRequestCollector.php b/src/Collectors/WpRequestCollector.php index 347bfe0..5338544 100644 --- a/src/Collectors/WpRequestCollector.php +++ b/src/Collectors/WpRequestCollector.php @@ -7,10 +7,13 @@ use Pollora\Debugbar\Collector; use Pollora\Debugbar\Origin; use Pollora\Debugbar\Recording\RequestRecorder; +use Pollora\Debugbar\Recording\SiteRecorder; +use Pollora\Debugbar\Support\Components; /** * How WordPress understood the request: rewrite rule, query, queried object, - * conditionals and the template hierarchy it built. + * conditionals and the template hierarchy it built; in wp-admin, the screen; + * on a multisite, the site and the switches between sites. */ final class WpRequestCollector extends Collector { @@ -30,6 +33,8 @@ final class WpRequestCollector extends Collector public function __construct( private readonly RequestRecorder $recorder, + private readonly ?SiteRecorder $sites = null, + private readonly ?Components $components = null, ) {} public function getName(): string @@ -96,6 +101,79 @@ protected function data(): array $data['Template'] = $this->recorder->template() !== null ? $this->relativePath($this->recorder->template()) : null; $data['Template hierarchy'] = $this->recorder->hierarchies() !== [] ? $this->recorder->hierarchies() : null; + return [...$data, ...$this->adminScreen(), ...$this->multisite()]; + } + + /** + * The admin page and screen, as Query Monitor's Admin panel shows them. + * + * @return array + */ + private function adminScreen(): array + { + global $pagenow, $hook_suffix; + + // $pagenow is set once WordPress has parsed the URL; before that, + // is_admin() has nothing reliable to say + if (! is_string($pagenow) || ! function_exists('is_admin') || ! is_admin() || ! function_exists('get_current_screen')) { + return []; + } + + $screen = get_current_screen(); + + return array_filter([ + 'Admin page' => $pagenow, + 'Hook suffix' => is_string($hook_suffix) && $hook_suffix !== '' ? $hook_suffix : null, + 'Screen' => $screen instanceof \WP_Screen ? array_filter([ + 'id' => $screen->id, + 'base' => $screen->base, + 'post type' => $screen->post_type, + 'taxonomy' => $screen->taxonomy, + 'block editor' => $screen->is_block_editor() ? 'yes' : null, + ], static fn (mixed $value): bool => $value !== '' && $value !== null) : null, + ], static fn (mixed $value): bool => $value !== null); + } + + /** + * The site and network that answered, and each switch between sites. + * + * @return array + */ + private function multisite(): array + { + // ms-settings.php sets the network; a single site never has one + if (! is_object($GLOBALS['current_site'] ?? null) || ! function_exists('is_multisite') || ! is_multisite()) { + return []; + } + + $switched = function_exists('ms_is_switched') && ms_is_switched(); + // While switched, the site that answered is the first one switched away from + $stack = $GLOBALS['_wp_switched_stack'] ?? []; + $site = $switched && is_array($stack) && isset($stack[0]) ? (int) $stack[0] : get_current_blog_id(); + + $data = [ + 'Site' => sprintf('#%d%s', $site, is_main_site($site) ? ' (main site)' : ''), + 'Network' => function_exists('get_current_network_id') ? '#'.get_current_network_id() : null, + ]; + + $switches = []; + + foreach ($this->sites?->switches() ?? [] as $switch) { + $switches[] = sprintf( + '%s #%d → #%d%s', + $switch['context'], + $switch['from'], + $switch['to'], + $this->components instanceof Components && $switch['frames'] !== [] ? ' ('.$this->components->ofTrace($switch['frames']).')' : '', + ); + } + + $data['Site switches'] = $switches !== [] ? $switches : 'none'; + + if ($switched) { + $data['Still switched'] = sprintf('yes, to #%d: restore_current_blog() was not called for every switch_to_blog()', get_current_blog_id()); + } + return $data; } diff --git a/src/DebugbarServiceProvider.php b/src/DebugbarServiceProvider.php index 2028be9..9efec73 100644 --- a/src/DebugbarServiceProvider.php +++ b/src/DebugbarServiceProvider.php @@ -9,16 +9,19 @@ use Illuminate\Support\ServiceProvider; use Pollora\BlockBinding\Domain\Events\BindingResolved; use Pollora\Debugbar\Bridges\MessageBridge; +use Pollora\Debugbar\Http\AdminBarRenderer; use Pollora\Debugbar\Http\DoctorController; use Pollora\Debugbar\Http\WordPressExitResponder; use Pollora\Debugbar\Recording\AsyncRecorder; 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\WordPress\Events\WordPressBooting; @@ -49,6 +52,8 @@ public function register(): void $this->app->singleton(CapabilityRecorder::class, fn ($app): CapabilityRecorder => new CapabilityRecorder((bool) $app->make('config')->get('debugbar-pollora.options.wp_capabilities.backtrace', false))); $this->app->singleton(BlockRecorder::class); $this->app->singleton(AsyncRecorder::class); + $this->app->singleton(HookTimer::class); + $this->app->singleton(SiteRecorder::class); if (! Activation::shouldRun($this->app)) { return; @@ -62,13 +67,34 @@ public function register(): void $on = static fn (string $collector): bool => (bool) $config->get("debugbar-pollora.collectors.{$collector}", true); + $admin = $config->get('debugbar-pollora.admin.enabled', true) && AdminBarRenderer::isAdminPage(); + + $this->app->booting(function () use ($config): void { + // The Site Editor and the Customizer show the front end in an + // iframe: the request is still stored, but a second bar inside + // the canvas would cover the page being edited + if (! $config->get('debugbar-pollora.iframes', false) && $this->app->bound('request') && Activation::isFramed($this->app->make('request'))) { + $config->set('debugbar.inject', false); + } + }); + + if ($admin) { + // Debugbar adds its tabs while it boots; by then every provider has + // registered and its config is merged + $this->app->booting(function () use ($config): void { + foreach ((array) $config->get('debugbar-pollora.admin.hidden_collectors', AdminBarRenderer::LARAVEL_ONLY_COLLECTORS) as $collector) { + $config->set("debugbar.collectors.{$collector}", false); + } + }); + } + if ($on('wp_blocks') && class_exists(BindingResolved::class)) { $this->app->make('events')->listen(BindingResolved::class, function (BindingResolved $binding): void { $this->app->make(BlockRecorder::class)->recordBinding($binding); }); } - $this->app->make('events')->listen(WordPressBooting::class, function () use ($config, $on): void { + $this->app->make('events')->listen(WordPressBooting::class, function () use ($config, $on, $admin): void { $this->app->make(RequestRecorder::class)->install( countAllHooks: (bool) $config->get('debugbar-pollora.options.wp_hooks.count_filters', false), ); @@ -81,6 +107,8 @@ public function register(): void CapabilityRecorder::class => $on('wp_capabilities'), BlockRecorder::class => $on('wp_blocks'), AsyncRecorder::class => $on('pollora'), + HookTimer::class => $on('wp_hooks') && $config->get('debugbar-pollora.options.wp_hooks.timings', false), + SiteRecorder::class => $on('wp_request'), ]; foreach (array_keys(array_filter($recorders)) as $recorder) { @@ -93,16 +121,19 @@ public function register(): void ); } - (new WordPressExitResponder( - $this->collectingDebugbar(...), - function (LaravelDebugbar $debugbar): void { - // WordPress can exit before the booted callbacks that index - // route names have run, and Debugbar's collectors link to - // its own named routes - $this->app->make('router')->getRoutes()->refreshNameLookups(); - $this->app->make(CollectorRegistrar::class)->register($debugbar); - }, - ))->install(); + $prepare = function (LaravelDebugbar $debugbar): void { + // WordPress can exit before the booted callbacks that index + // route names have run, and Debugbar's collectors link to + // its own named routes + $this->app->make('router')->getRoutes()->refreshNameLookups(); + $this->app->make(CollectorRegistrar::class)->register($debugbar); + }; + + (new WordPressExitResponder($this->collectingDebugbar(...), $prepare))->install(); + + if ($admin) { + (new AdminBarRenderer($this->collectingDebugbar(...), $prepare))->install(); + } }); } diff --git a/src/Http/AdminBarRenderer.php b/src/Http/AdminBarRenderer.php new file mode 100644 index 0000000..833407c --- /dev/null +++ b/src/Http/AdminBarRenderer.php @@ -0,0 +1,89 @@ +render(...), PHP_INT_MAX, 0); + } + + public function render(): void + { + if ($this->rendered || ! ($this->isAdminPage ?? self::isAdminPage(...))()) { + return; + } + + $debugbar = ($this->debugbar)(); + + if (! $debugbar instanceof LaravelDebugbar) { + return; + } + + $this->rendered = true; + + // A debugging tool must never break the page it watches + try { + ($this->prepare)($debugbar); + $renderer = $debugbar->getJavascriptRenderer(); + $bar = "\n".$renderer->renderHead().$renderer->render(); + } catch (\Throwable $throwable) { + report($throwable); + + return; + } + + echo $bar; + } +} diff --git a/src/Recording/HookTimer.php b/src/Recording/HookTimer.php new file mode 100644 index 0000000..df3e94e --- /dev/null +++ b/src/Recording/HookTimer.php @@ -0,0 +1,201 @@ + + */ + private array $timings = []; + + /** + * Callback ids already looked at, and whether they can be timed. + * + * @var array + */ + private array $decisions = []; + + /** + * Start time and time spent in nested callbacks, innermost last, in nanoseconds. + * + * @var list + */ + private array $stack = []; + + public function install(): void + { + if ($this->installed || ! function_exists('add_action')) { + return; + } + + $this->installed = true; + + add_action('all', function (mixed $hook): void { + if (is_string($hook)) { + $this->wrap($hook); + } + }, PHP_INT_MIN, 1); + } + + public function isInstalled(): bool + { + return $this->installed; + } + + /** + * Put a timer around every callback of a hook not timed yet. + */ + public function wrap(string $hook): void + { + global $wp_filter; + + $wpHook = is_array($wp_filter) ? ($wp_filter[$hook] ?? null) : null; + + if (! is_object($wpHook) || ! isset($wpHook->callbacks) || ! is_array($wpHook->callbacks)) { + return; + } + + foreach ($wpHook->callbacks as $priority => $callbacks) { + foreach ((array) $callbacks as $id => $entry) { + $callback = $entry['function'] ?? null; + + if ($callback === null || $callback instanceof TimedCallback) { + continue; + } + + $decision = $this->decisions[(string) $id] ??= $this->decide($callback); + + if ($decision === false) { + continue; + } + + $key = $hook.'|'.$priority.'|'.$id; + + $this->timings[$key] ??= [ + 'hook' => $hook, + 'priority' => (int) $priority, + 'callback' => $callback, + 'file' => $decision['file'], + 'calls' => 0, + 'total' => 0, + 'self' => 0, + 'max' => 0, + ]; + + $wpHook->callbacks[$priority][$id]['function'] = new TimedCallback($callback, $this, $key); + } + } + } + + /** + * A callback starts. + */ + public function enter(): void + { + $this->stack[] = [hrtime(true), 0]; + } + + /** + * The callback that started last ends. + */ + public function leave(string $key): void + { + $frame = array_pop($this->stack); + + if ($frame === null) { + return; + } + + $elapsed = hrtime(true) - $frame[0]; + $last = array_key_last($this->stack); + + if ($last !== null) { + $this->stack[$last][1] += $elapsed; + } + + if (! isset($this->timings[$key])) { + return; + } + + $timing = &$this->timings[$key]; + $timing['calls']++; + $timing['total'] += $elapsed; + $timing['self'] += $elapsed - $frame[1]; + $timing['max'] = max($timing['max'], $elapsed); + } + + /** + * The callbacks that ran, times in nanoseconds. + * + * @return list + */ + public function timings(): array + { + return array_values(array_filter($this->timings, static fn (array $timing): bool => $timing['calls'] > 0)); + } + + public function reset(): void + { + $this->timings = []; + $this->stack = []; + } + + /** + * Whether a callback can be timed, and the file it was written in. + * + * @return array{file: string}|false + */ + private function decide(mixed $callback): array|false + { + try { + $reflection = match (true) { + $callback instanceof \Closure => new \ReflectionFunction($callback), + is_string($callback) && str_contains($callback, '::') => new \ReflectionMethod($callback), + is_string($callback) => new \ReflectionFunction($callback), + is_array($callback) && isset($callback[0], $callback[1]) && (is_object($callback[0]) || is_string($callback[0])) && is_string($callback[1]) => new \ReflectionMethod($callback[0], $callback[1]), + is_object($callback) && method_exists($callback, '__invoke') => new \ReflectionMethod($callback, '__invoke'), + default => null, + }; + } catch (\ReflectionException) { + // Not callable yet, or answered by __call(): leave it alone + return false; + } + + if ($reflection === null) { + return false; + } + + foreach ($reflection->getParameters() as $parameter) { + if ($parameter->isPassedByReference()) { + return false; + } + } + + $class = $reflection instanceof \ReflectionMethod ? $reflection->getDeclaringClass()->getName() : $reflection->getClosureScopeClass()?->getName(); + + if ($class !== null && str_starts_with($class, 'Pollora\\Debugbar\\')) { + return false; + } + + return ['file' => (string) $reflection->getFileName()]; + } +} diff --git a/src/Recording/SiteRecorder.php b/src/Recording/SiteRecorder.php new file mode 100644 index 0000000..5eaf574 --- /dev/null +++ b/src/Recording/SiteRecorder.php @@ -0,0 +1,56 @@ +}> + */ + private array $switches = []; + + public function install(): void + { + if ($this->installed || ! function_exists('add_action')) { + return; + } + + $this->installed = true; + + add_action('switch_blog', function (mixed $to, mixed $from, mixed $context = 'switch'): void { + $this->switches[] = [ + 'from' => (int) $from, + 'to' => (int) $to, + 'context' => is_string($context) ? $context : 'switch', + 'frames' => array_values(array_filter( + array_map(static fn (array $frame): array => ['file' => $frame['file'] ?? ''], debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 15)), + static fn (array $frame): bool => $frame['file'] !== '', + )), + ]; + }, PHP_INT_MAX, 3); + } + + /** + * @return list}> + */ + public function switches(): array + { + return $this->switches; + } + + public function reset(): void + { + $this->switches = []; + } +} diff --git a/src/Recording/TimedCallback.php b/src/Recording/TimedCallback.php new file mode 100644 index 0000000..96297f1 --- /dev/null +++ b/src/Recording/TimedCallback.php @@ -0,0 +1,55 @@ + + */ +final class TimedCallback implements \ArrayAccess +{ + public function __construct( + public readonly mixed $callback, + private readonly HookTimer $timer, + private readonly string $key, + ) {} + + public function __invoke(mixed ...$args): mixed + { + $this->timer->enter(); + + try { + return ($this->callback)(...$args); + } finally { + $this->timer->leave($this->key); + } + } + + public function offsetExists(mixed $offset): bool + { + return is_array($this->callback) && isset($this->callback[$offset]); + } + + public function offsetGet(mixed $offset): mixed + { + return is_array($this->callback) ? ($this->callback[$offset] ?? null) : null; + } + + public function offsetSet(mixed $offset, mixed $value): void + { + throw new \LogicException('A timed hook callback cannot be changed.'); + } + + public function offsetUnset(mixed $offset): void + { + throw new \LogicException('A timed hook callback cannot be changed.'); + } +} diff --git a/tests/Feature/ActivationTest.php b/tests/Feature/ActivationTest.php index 34ec564..3caf395 100644 --- a/tests/Feature/ActivationTest.php +++ b/tests/Feature/ActivationTest.php @@ -3,6 +3,7 @@ declare(strict_types=1); use Illuminate\Foundation\Application; +use Illuminate\Http\Request; use Pollora\Debugbar\Activation; /** @@ -49,3 +50,12 @@ function servingTheWeb(Application $app): void expect(Activation::shouldRun($this->app))->toBeFalse(); }); + +it('tells a page loaded in an iframe from a page of its own', function (): void { + $framed = Request::create('/'); + $framed->headers->set('Sec-Fetch-Dest', 'iframe'); + + expect(Activation::isFramed($framed))->toBeTrue() + ->and(Activation::isFramed(Request::create('/?wp_site_preview=1')))->toBeTrue() + ->and(Activation::isFramed(Request::create('/')))->toBeFalse(); +}); diff --git a/tests/Feature/AdminBarRendererTest.php b/tests/Feature/AdminBarRendererTest.php new file mode 100644 index 0000000..ca1dba1 --- /dev/null +++ b/tests/Feature/AdminBarRendererTest.php @@ -0,0 +1,43 @@ +app->make('router'); + $router->get('_debugbar/assets', fn (): string => '')->name('debugbar.assets'); + $router->get('_debugbar/open', fn (): string => '')->name('debugbar.openhandler'); + $router->getRoutes()->refreshNameLookups(); + $debugbar = $this->collectingDebugbar(); + $prepared = 0; + $renderer = new AdminBarRenderer(fn () => $debugbar, function () use (&$prepared): void { + $prepared++; + }, fn (): bool => true); + + ob_start(); + $renderer->render(); + $renderer->render(); + $output = (string) ob_get_clean(); + + expect($prepared)->toBe(1) + ->and(substr_count($output, 'Laravel Debugbar Widget'))->toBe(1) + ->and($debugbar->getStorage()->saved)->toHaveKey($debugbar->getCurrentRequestId()); +}); + +it('prints nothing outside admin pages', function (): void { + $debugbar = $this->collectingDebugbar(); + + ob_start(); + (new AdminBarRenderer(fn () => $debugbar, fn () => null, fn (): bool => false))->render(); + + expect((string) ob_get_clean())->toBe(''); +}); + +it('prints nothing when the bar is not collecting', function (): void { + ob_start(); + (new AdminBarRenderer(fn () => null, fn () => null, fn (): bool => true))->render(); + + expect((string) ob_get_clean())->toBe(''); +}); diff --git a/tests/Fixtures/included-closure.php b/tests/Fixtures/included-closure.php new file mode 100644 index 0000000..0d5ede5 --- /dev/null +++ b/tests/Fixtures/included-closure.php @@ -0,0 +1,6 @@ + null; diff --git a/tests/Unit/Collectors/WpHooksCollectorTest.php b/tests/Unit/Collectors/WpHooksCollectorTest.php index ea7bc07..723e48b 100644 --- a/tests/Unit/Collectors/WpHooksCollectorTest.php +++ b/tests/Unit/Collectors/WpHooksCollectorTest.php @@ -39,9 +39,29 @@ public function all(): array ->and($rows['wp_head']['pollora'])->toBe(''); }); +final class WpHooksClosureOwner +{ + public function closure(): Closure + { + return fn (): null => null; + } +} + it('describes callbacks the way a reader recognises them', function (): void { expect(WpHooksCollector::describe('wp_head'))->toBe('wp_head') ->and(WpHooksCollector::describe(['Acme\\Cart', 'boot']))->toBe('Acme\\Cart::boot') - ->and(WpHooksCollector::describe(fn (): null => null))->toMatch('/^closure in P\\\\Tests\\\\Unit\\\\Collectors\\\\WpHooksCollectorTest\\S* \\(WpHooksCollectorTest\\.php:\\d+\\)$/') + ->and(WpHooksCollector::describe((new WpHooksClosureOwner)->closure()))->toMatch('/^closure in WpHooksClosureOwner \\(WpHooksCollectorTest\\.php:\\d+\\)$/') ->and(WpHooksCollector::describe((new ArrayObject)->count(...)))->toBe('ArrayObject::count'); }); + +it('does not name the class a closure was merely included from', function (): void { + $loader = new class + { + public function load(): Closure + { + return require __DIR__.'/../../Fixtures/included-closure.php'; + } + }; + + expect(WpHooksCollector::describe($loader->load()))->toMatch('/^closure \\(included-closure\\.php:\\d+\\)$/'); +}); diff --git a/tests/Unit/Collectors/WpRequestScreenAndSitesTest.php b/tests/Unit/Collectors/WpRequestScreenAndSitesTest.php new file mode 100644 index 0000000..e9cb71e --- /dev/null +++ b/tests/Unit/Collectors/WpRequestScreenAndSitesTest.php @@ -0,0 +1,82 @@ +setDataFormatter(new DataFormatter) + ->collect()['data']; +} + +afterEach(function (): void { + unset($GLOBALS['pagenow'], $GLOBALS['hook_suffix'], $GLOBALS['current_site'], $GLOBALS['_wp_switched_stack']); +}); + +it('shows the admin page and screen in wp-admin', function (): void { + $GLOBALS['pagenow'] = 'edit.php'; + $GLOBALS['hook_suffix'] = 'edit.php'; + Functions\when('is_admin')->justReturn(true); + Functions\when('get_current_screen')->justReturn(new WP_Screen); + Functions\when('get_queried_object')->justReturn(null); + + $data = requestDataWith(); + + expect($data['Admin page'])->toBe('edit.php') + ->and($data['Screen'])->toContain('edit-post') + ->and($data)->not->toHaveKey('Site'); +}); + +it('shows the site and every switch between sites, and a switch never restored', function (): void { + $switch = null; + Actions\expectAdded('switch_blog')->once()->whenHappen(function (callable $callback) use (&$switch): void { + $switch = $callback; + }); + $sites = new SiteRecorder; + $sites->install(); + $switch(2, 1, 'switch'); + $switch(1, 2, 'restore'); + $switch(3, 1, 'switch'); + + $GLOBALS['current_site'] = (object) ['id' => 1]; + $GLOBALS['_wp_switched_stack'] = [1]; + Functions\when('get_queried_object')->justReturn(null); + Functions\when('is_multisite')->justReturn(true); + Functions\when('get_current_blog_id')->justReturn(3); + Functions\when('is_main_site')->alias(fn (int $site): bool => $site === 1); + Functions\when('get_current_network_id')->justReturn(1); + Functions\when('ms_is_switched')->justReturn(true); + + $data = requestDataWith($sites); + + expect($data['Site'])->toBe('#1 (main site)') + ->and($data['Still switched'])->toStartWith('yes, to #3') + ->and($data['Site switches'])->toContain('switch #1 → #2') + ->and($data['Site switches'])->toContain('restore #2 → #1'); +}); diff --git a/tests/Unit/Recording/HookTimerTest.php b/tests/Unit/Recording/HookTimerTest.php new file mode 100644 index 0000000..91d66dd --- /dev/null +++ b/tests/Unit/Recording/HookTimerTest.php @@ -0,0 +1,141 @@ +> $callbacks Priority => [id => callback] + */ +function hookWith(string $name, array $callbacks): void +{ + $entries = []; + + foreach ($callbacks as $priority => $byId) { + foreach ($byId as $id => $callback) { + $entries[$priority][$id] = ['function' => $callback, 'accepted_args' => 1]; + } + } + + $GLOBALS['wp_filter'][$name] = (object) ['callbacks' => $entries]; +} + +function callbackOf(string $hook, int $priority, string $id): mixed +{ + return $GLOBALS['wp_filter'][$hook]->callbacks[$priority][$id]['function']; +} + +final class HookTimerFixture +{ + public function title(string $title): string + { + return strtoupper($title); + } + + public function byReference(array &$items): void + { + $items[] = 'added'; + } +} + +afterEach(function (): void { + unset($GLOBALS['wp_filter']); +}); + +it('times each callback under the key WordPress gave it, and returns what it returns', function (): void { + hookWith('the_title', [10 => ['fixture_title' => [new HookTimerFixture, 'title']]]); + $timer = new HookTimer; + + $timer->wrap('the_title'); + $callback = callbackOf('the_title', 10, 'fixture_title'); + + expect($callback)->toBeInstanceOf(TimedCallback::class) + ->and($callback('hello'))->toBe('HELLO') + ->and($timer->timings())->toHaveCount(1) + ->and($timer->timings()[0]['calls'])->toBe(1) + ->and($timer->timings()[0]['hook'])->toBe('the_title'); +}); + +it('keeps an array callback readable where code looks inside $wp_filter', function (): void { + $fixture = new HookTimerFixture; + hookWith('the_title', [10 => ['fixture_title' => [$fixture, 'title']]]); + + (new HookTimer)->wrap('the_title'); + $callback = callbackOf('the_title', 10, 'fixture_title'); + + expect($callback[0])->toBe($fixture) + ->and($callback[1])->toBe('title'); +}); + +it('counts the time spent in nested hooks in the total, not in the own time', function (): void { + $timer = new HookTimer; + hookWith('inner', [10 => ['inner_cb' => function (): void { + usleep(6000); + }]]); + hookWith('outer', [10 => ['outer_cb' => function (): void { + usleep(1000); + callbackOf('inner', 10, 'inner_cb')(); + }]]); + + $timer->wrap('inner'); + $timer->wrap('outer'); + callbackOf('outer', 10, 'outer_cb')(); + + $byHook = array_column($timer->timings(), null, 'hook'); + + expect($byHook['outer']['total'])->toBeGreaterThan(6_000_000) + ->and($byHook['outer']['self'])->toBeLessThan(6_000_000) + ->and($byHook['inner']['self'])->toBeGreaterThan(6_000_000); +}); + +it('leaves callbacks taking parameters by reference as they are', function (): void { + $fixture = new HookTimerFixture; + hookWith('collect', [10 => ['by_ref' => [$fixture, 'byReference']]]); + + (new HookTimer)->wrap('collect'); + + expect(callbackOf('collect', 10, 'by_ref'))->toBe([$fixture, 'byReference']); +}); + +it('times a callback added again in the same row', function (): void { + $title = [new HookTimerFixture, 'title']; + hookWith('the_title', [10 => ['fixture_title' => $title]]); + $timer = new HookTimer; + + $timer->wrap('the_title'); + callbackOf('the_title', 10, 'fixture_title')('a'); + + // add_filter() with the same callback writes the raw callback back under its key + $GLOBALS['wp_filter']['the_title']->callbacks[10]['fixture_title']['function'] = $title; + $timer->wrap('the_title'); + callbackOf('the_title', 10, 'fixture_title')('b'); + + expect($timer->timings())->toHaveCount(1) + ->and($timer->timings()[0]['calls'])->toBe(2); +}); + +it('lists the slowest callbacks first, up to the limit', function (): void { + $timer = new HookTimer; + hookWith('fast', [10 => ['fast_cb' => 'strtoupper']]); + hookWith('slow', [5 => ['slow_cb' => function (): void { + usleep(3000); + }]]); + + $timer->wrap('fast'); + $timer->wrap('slow'); + callbackOf('fast', 10, 'fast_cb')('a'); + callbackOf('slow', 5, 'slow_cb')(); + + $rows = (new WpHookTimingsCollector($timer, new Components([]), limit: 1)) + ->setDataFormatter(new DataFormatter) + ->collect()['data']['data']; + + expect($rows)->toHaveCount(1) + ->and(array_values($rows)[0]['hook'])->toBe('slow @5'); +}); diff --git a/tests/e2e/specs/debugbar.spec.ts b/tests/e2e/specs/debugbar.spec.ts index 5fc935a..adcba8d 100644 --- a/tests/e2e/specs/debugbar.spec.ts +++ b/tests/e2e/specs/debugbar.spec.ts @@ -128,3 +128,45 @@ test('runs the doctor on demand from its tab', async ({ page }) => { await expect(panel.locator('tr').first()).toBeVisible(); await expect(panel).toContainText(/\d+ (ok|warning|error)/); }); + +async function logIn(page: Page): Promise { + await page.goto('cms/wp-login.php'); + await page.fill('#user_login', process.env.E2E_ADMIN_USER ?? 'admin'); + await page.fill('#user_pass', process.env.E2E_ADMIN_PASSWORD ?? 'pollora-ci-password'); + await page.click('#wp-submit'); + await page.waitForURL(/wp-admin/); +} + +test('shows the bar on wp-admin pages, with the admin screen and without Laravel-only tabs', async ({ page }) => { + await logIn(page); + await page.goto('cms/wp-admin/edit.php'); + const bar = await debugbar(page); + // The login redirect is stacked before this page's own request + const request = Object.values(bar.datasets).find((dataset) => String(dataset.__meta?.uri ?? '').includes('edit.php'))?.wp_request.data; + + expect(bar.controls).toHaveProperty('wp_request'); + expect(bar.controls).toHaveProperty('wp_queries'); + expect(bar.controls).not.toHaveProperty('route'); + expect(bar.controls).not.toHaveProperty('views'); + expect(request['Admin page']).toBe('edit.php'); + expect(JSON.stringify(request['Screen'])).toContain('edit-post'); +}); + +test('lists the REST calls the block editor makes in the bar of its admin page', async ({ page }) => { + await logIn(page); + await page.goto('cms/wp-admin/post-new.php'); + await debugbar(page); + + await expect.poll(async () => page.evaluate(() => Object.keys((window as any).phpdebugbar.datasets).length), { timeout: 15_000 }) + .toBeGreaterThan(1); +}); + +test('prints no second bar inside the Site Editor canvas', async ({ page }) => { + await logIn(page); + await page.goto('cms/wp-admin/site-editor.php'); + await debugbar(page); + + const canvas = page.frameLocator('iframe[name="editor-canvas"], iframe').first(); + await expect(canvas.locator('body')).toBeVisible({ timeout: 15_000 }); + await expect(canvas.locator('.phpdebugbar')).toHaveCount(0); +});