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.