Help users start profiling

[szepeviktor]

I'd like to help users to track down culprits.

Copied from the venerable https://github.com/wp-cli/profile-command

qm-profiling.php

<?php

$qm_profiling_stage_hooks = [
    'bootstrap' => [
        'muplugins_loaded',
        'plugins_loaded',
        'setup_theme',
        'after_setup_theme',
        'init',
        'wp_loaded',
    ],
    'main_query' => [
        'parse_request',
        'send_headers',
        // 'pre_get_posts',
        'the_posts',
        'wp',
    ],
    'template' => [
        'template_redirect',
        'template_include',
        'wp_head',
        'loop_start',
        'loop_end',
        'wp_footer',
    ],
];
foreach ($qm_profiling_stage_hooks as $stage => $hooks) {
    foreach ($hooks as $hook) {
        add_filter(
            $hook,
            static function ($value) use ($stage, $hook) {
                do_action('qm/start', sprintf('%s/%s', $stage, $hook));
                return $value;
            },
            PHP_INT_MIN,
            1
        );
        add_filter(
            $hook,
            static function ($value) use ($stage, $hook) {
                do_action('qm/stop', sprintf('%s/%s', $stage, $hook));
                return $value;
            },
            PHP_INT_MAX,
            1
        );
    }
}

How to go on?

[szepeviktor]

Profiling filters in wp-includes/class-wp-hook.php apply_filters method

e.g. the wp_head filter

global $wp_filter;
$_do_debug_filter = ($wp_filter['wp_head'] ?? null) === $this;
if ($_do_debug_filter) do_action('qm/start', 'filter');

    // foreach ( $this->callbacks[ $priority ] as $the_ ) {
    // call_user_func calls ...

if ($_do_debug_filter) do_action('qm/lap', 'filter', QM_Util::populate_callback(['function' => $the_['function']])['name'] ?? 'N/A');

    // }

if ($_do_debug_filter) do_action('qm/stop', 'filter');

[johnbillion]

This is a really interesting topic which I've had various conversations about over the years.

Maaaaany years ago Query Monitor showed the processing time for each hook, but the problem is that timing information for a hook is misleading. For example the init hook will always be the slowest because it always has the greatest number of actions attached to it and those actions typically do a lot of work. That doesn't necessarily mean it's the best place to start debugging or profiling, but the high processing time for init draws your attention there.

A better profiling metric is the processing time for each individual action. You might have ten hooks attached to init but one of them is a lot slower than the others. That's useful information. #260 relates to this and there's some discussion in the comments there. The main problem is the affect this has on processing time and memory usage on an already resource-strained site. I never ended up having time to work on it.