Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ability to time individual hooks #309

Open
johnbillion opened this issue Feb 8, 2018 · 6 comments · May be fixed by #407
Open

Ability to time individual hooks #309

johnbillion opened this issue Feb 8, 2018 · 6 comments · May be fixed by #407

Comments

@johnbillion
Copy link
Owner

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
Copy link
Contributor

crstauf commented Feb 9, 2018

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
Copy link
Contributor

crstauf commented Feb 9, 2018

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

@johnbillion
Copy link
Owner Author

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 added a commit to crstauf/query-monitor that referenced this issue Feb 16, 2019
@crstauf crstauf linked a pull request Feb 16, 2019 that will close this issue
@crstauf
Copy link
Contributor

crstauf commented Feb 16, 2019

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:

screen shot 2019-02-15 at 10 56 12 pm

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
Copy link
Contributor

crstauf commented Feb 16, 2019

Related: #260

@crstauf
Copy link
Contributor

crstauf commented Feb 16, 2019

Related: #340

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants