Ability to time individual hooks

[johnbillion]

Via @crstauf on #301 (comment):

Possible to add qm/start/qm/stop onto a hook, and if there's no param (function name) provided, assume current_action()?

QM could enable this via a wrapper function such as qm_start() and qm_stop() which would then be used like this:

add_action( 'after_setup_theme', 'qm_start', 0 );
add_action( 'after_setup_theme', 'qm_stop', 999 );

Maybe even only require the start action and QM adds the stop action itself.

[crstauf]

Yep, using $wp_filter, I’ve identified the last priority on a hook, incremented by one, and then added a hook.

Using hooks though makes it difficult to (automatically and simply) make sure the timer starts before other attached hooks... you could do something like add_action( ‘init’, ‘qm_start’, _qm_start( ‘init’ ) ), where _qm_start() returns the integer prior to the earliest priority currently added, but that’s perhaps a bit more complex than desired. Also have thought to use PHP_INT_MIN and PHP_INT_MAX, but that seemed nasty.

I think lapping would be really cool too:

add_action( ‘init’, ‘qm_start’ );
add_action( ‘init’, ‘qm_lap’, 50 );

[crstauf]

Point of clarity: I seem to recall seeing a negative priority on a hook, but don’t recall when or where.

[johnbillion]

Yeah QM makes use of negative integers itself, usually -9999 for early hooks. It doesn't guarantee being the first, but it covers most cases.

The internal timer could maybe check to see if another action is hooked on an earlier priority and warn you. I'll have a play around.

[crstauf]

I've started on a PR for timing hooks. Here's the code I tested with:

add_action( 'temp', 'qm_start',    0 );
add_action( 'temp', 'qm_lap',      9 );
add_action( 'temp', 'qm_lap',     11 );
add_action( 'temp', 'qm_stop',  9999 );

add_action( 'temp', function() { sleep( 2 ); } );
add_action( 'init', function() { do_action( 'temp' ); } );

The result is this:

I can't seem to figure out though, QM_Backtrace, and how to get the component right. I've tried placing the code in different places (another plugin, mu-plugin, theme) and passing different values to QM_Backtrace::ignore() by calling QM_Collector_Timing->start[ current_action() ]->get_trace()->ignore( $x ), but after I get past the Plugin: query-monitor component, its identifies the component as core after that, I think due to the use of do_action.

@johnbillion Can you please advise on how to have QM select and display the correct component?

[crstauf]

Related: #260

[crstauf]

Related: #340