wp profile v0.3.0: new commands; spotlight mode; intermediate actions

If you like my WordPress work, check out my new plugin, Bylines. Thanks!

wp profile is a premium WP-CLI command to help you quickly identify what’s slow with WordPress. It reports key performance metrics (execution time, query count, cache hit/miss ratio, etc.) for segments of the WordPress execution process to give you easy visibility into what code is the least performant. v0.3.0 is the third significant release.

New commands: eval, eval-file

wp profile v0.3.0 introduces two new commands for profiling arbitrary code execution: wp profile eval and wp profile eval-file. Used creatively, this is an incredibly powerful tool for better understanding your codebase. Spend 15 minutes futzing around with xDebug, or 30 seconds using wp profile.

As an example, profile a WP REST API response by creating a get-posts.php file:

<?php
$request = new WP_REST_Request( 'GET', '/wp/v2/posts' );
$request->set_param( 'per_page', 100 );
$server = rest_get_server();
$server->dispatch( $request );

Then, profile get-posts.php by running wp profile eval-file get-posts.php:

$ wp profile eval-file get-posts.php
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| time    | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| 0.9429s | 0.002s     | 5           | 96.39%      | 7599       | 285          | 0s           | 0             |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+

Holy moly, that’s a lot of cache hits!

Identify the signal from the noise with --spotlight

In a long list of results, it can be difficult to tell the signal from the noise:

$ wp profile stage bootstrap
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| hook                     | callback_count | time    | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| muplugins_loaded:before  |                | 0.2536s | 0.0033s    | 1           | 40%         | 2          | 3            | 0s           | 0             |
| muplugins_loaded         | 2              | 0.0005s | 0s         | 0           | 50%         | 1          | 1            | 0s           | 0             |
| plugins_loaded:before    |                | 0.2955s | 0.0012s    | 6           | 77.63%      | 59         | 17           | 0s           | 0             |
| plugins_loaded           | 14             | 0.1572s | 0s         | 0           | 100%        | 104        | 0            | 0s           | 0             |
| setup_theme:before       |                | 0.0035s | 0s         | 0           | 100%        | 6          | 0            | 0s           | 0             |
| setup_theme              | 1              | 0.0001s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
| after_setup_theme:before |                | 0.0828s | 0s         | 0           | 100%        | 26         | 0            | 0s           | 0             |
| after_setup_theme        | 12             | 0.0038s | 0s         | 0           | 100%        | 4          | 0            | 0s           | 0             |
| init:before              |                | 0.0001s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
| init                     | 82             | 0.2954s | 0.0024s    | 7           | 96.88%      | 155        | 5            | 0s           | 0             |
| wp_loaded:before         |                | 0.0001s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
| wp_loaded                | 3              | 0.0049s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
| wp_loaded:after          |                | 0.0471s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| total (13)               | 114            | 1.1445s | 0.0069s    | 14          | 83.06%      | 357        | 26           | 0s           | 0             |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+

The new --spotlight flag filters out the zero-ish results from the set, to help you focus on the greatest contributing factors:

$ wp profile stage bootstrap --spotlight
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| hook                     | callback_count | time    | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| muplugins_loaded:before  |                | 0.2253s | 0.0025s    | 1           | 40%         | 2          | 3            | 0s           | 0             |
| muplugins_loaded         | 2              | 0.0007s | 0s         | 0           | 50%         | 1          | 1            | 0s           | 0             |
| plugins_loaded:before    |                | 0.2018s | 0.0009s    | 6           | 77.63%      | 59         | 17           | 0s           | 0             |
| plugins_loaded           | 14             | 0.1239s | 0s         | 0           | 100%        | 104        | 0            | 0s           | 0             |
| after_setup_theme:before |                | 0.0598s | 0s         | 0           | 100%        | 26         | 0            | 0s           | 0             |
| init                     | 82             | 0.1751s | 0.0022s    | 7           | 96.88%      | 155        | 5            | 0s           | 0             |
| wp_loaded:after          |                | 0.0273s | 0s         | 0           |             | 0          | 0            | 0s           | 0             |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| total (7)                | 98             | 0.8138s | 0.0056s    | 14          | 77.42%      | 347        | 26           | 0s           | 0             |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+

Profile intermediate actions

In the example immediately above, the primary actions for the stage include ‘muplugins_loaded’, ‘plugins_loaded’, and ‘init’. You can also see some intermediate actions like ‘plugins_loaded:before’ and ‘wp_loaded:after’. These intermediate actions correspond to script execution before (or after) actual WordPress hooks. They’re pseudo hooks in a sense.

Try out wp profile hook plugins_loaded:before to see which plugins take the longest time to load.


wp profile is available to runcommand gold and silver subscribers, or you can purchase a single-seat updates and support subscription for $129 per year. Existing subscribers can download the latest from their account dashboard.

Have a developer seat? You can browse the full list of resolved issues in Github.