WP CLI Profile package allow use to identify the performance of our WordPress website.
Installation Installation
wp package install wp-cli/profile-command
Syntax Syntax
wp profile stage [<stage>] [--all] [--spotlight] [--url=<url>] [--fields=<fields>] [--format=<format>] [--order=<order>] [--orderby=<orderby>]
Where,
- bootstrap: is where WordPress is setting itself up, loading plugins and the main theme, and firing the init hook.
- main_query: is how WordPress transforms the request into the primary WP_Query.
- template: is where WordPress determines which theme template to render based on the main query, and renders it.
Usage Usage
Simple usage:
$ wp profile stage --url=https://maheshwaghmare.com/
+------------+---------+-------------+------------+
| stage | time | cache_ratio | hook_count |
+------------+---------+-------------+------------+
| bootstrap | 1.0081s | 97.73% | 23076 |
| template | 0.6028s | 96.27% | 6516 |
| main_query | 0.1033s | 81.7% | 180 |
+------------+---------+-------------+------------+
| total (3) | 4.7142s | 91.9% | 29772 |
+------------+---------+-------------+------------+
Here, We can see which stage takes much time when requesting the https://maheshwaghmare.com/ (home page) of our WordPress website.
Profile by Stages Profile by Stages
As we see by default we get the profile of all stages. But, We can debug the profile by providing the specific stage.
E.g.
wp profile stage <stage-name>
We can pass additional parameters as: time, query_time, query_count, cache_ratio, cache_hits, cache_misses, hook_time, hook_count, request_time, request_count
Bootstrap Stage Bootstrap Stage
$ wp profile stage bootstrap --fields=hook,time,cache_ratio --spotlight --orderby=time --order=DESC
+--------------------------+---------+-------------+
| hook | time | cache_ratio |
+--------------------------+---------+-------------+
| init | 3.1252s | 95.38% |
| muplugins_loaded:before | 0.815s | 25% |
| plugins_loaded:before | 0.612s | 85.42% |
| plugins_loaded | 0.189s | 88.46% |
| after_setup_theme:before | 0.08s | 100% |
| wp_loaded:after | 0.034s | |
| after_setup_theme | 0.011s | 84.62% |
| muplugins_loaded | 0s | 50% |
+--------------------------+---------+-------------+
| total (8) | 4.8663s | 75.55% |
+--------------------------+---------+-------------+
Template Stage Template Stage
$ wp profile stage template --fields=hook,time,cache_ratio --spotlight --orderby=time --order=DESC
+-------------------+--------+-------------+
| hook | time | cache_ratio |
+-------------------+--------+-------------+
| wp_head | 0.632s | 96.68% |
| wp_footer | 0.163s | 97.92% |
| template_redirect | 0.034s | 97.67% |
+-------------------+--------+-------------+
| total (3) | 0.829s | 97.42% |
+-------------------+--------+-------------+
Main Query Stage Main Query Stage
$ wp profile stage main_query --fields=hook,time,cache_ratio --spotlight --orderby=time --order=DESC
+----------------------+--------+-------------+
| hook | time | cache_ratio |
+----------------------+--------+-------------+
| wp | 0.077s | 91.53% |
| parse_request:before | 0.033s | 90.91% |
+----------------------+--------+-------------+
| total (2) | 0.11s | 91.22% |
+----------------------+--------+-------------+
Profile by Hooks Profile by Hooks
We can debug the performance by hooks.
E.g.
wp profile hook <hook-name>
We can pass additional parameters as: callback_count, time, query_time, query_count, cache_ratio, cache_hits, cache_misses, request_time, request_count
All Hooks All Hooks
We can debug all hook which is executed while visiting the specific page.
Group by Time Group by Time
$ wp profile hook --fields=hook,callback_count,time --orderby=time
+-------------------------------------------------------------------------------+---------+
| callback | time |
+-------------------------------------------------------------------------------+---------+
| esc_html | 1 | 0.001s |
...
| wp_head | 30 | 0.742s |
| astra_masthead_content | 4 | 0.8751s |
| astra_masthead | 1 | 0.8771s |
| astra_header | 3 | 0.8891s |
| astra_footer | 1 | 0.9611s |
| init | 106 | 4.4243s |
| wp | 37 | 6.9494s |
+------------------------------------------------------------------------------+----------------+----------+
| total (1802) | 1107 | 18.4431s |
+------------------------------------------------------------------------------+----------------+----------+
Profile by URL Profile by URL
$ wp profile hook --fields=hook,callback_count,time --orderby=time --url=http://localhost/dev/portfolio
Group by Callback Count Group by Callback Count
$ wp profile hook --fields=hook,callback_count,time --orderby=callback_count
+-------------------------------------------------------------------------------+---------+
| callback | time |
+-------------------------------------------------------------------------------+---------+
| function(){} | 0s |
| register_block_core_block() | 0.001s |
...
| wp_head | 30 | 0.742s |
| astra_masthead_content | 4 | 0.8751s |
| astra_masthead | 1 | 0.8771s |
| astra_header | 3 | 0.8891s |
| astra_footer | 1 | 0.9611s |
| init | 106 | 4.4243s |
| wp | 37 | 6.9494s |
+------------------------------------------------------------------------------+----------------+----------+
| total (1802) | 1107 | 18.4431s |
+------------------------------------------------------------------------------+----------------+----------+
Single Hook Single Hook
We can debug specific hook. Let’s debug the init
hook group by time and callback count.
Group by Time Group by Time
Lets debug the init hook group by time.
$ wp profile hook init --fields=callback,time --orderby=time
+-------------------------------------------------------------------------------+---------+
| callback | time |
+-------------------------------------------------------------------------------+---------+
| rest_api_init() | 0.001s |
...
| ActionScheduler_DBLogger->init() | 0.001s |
| wp_cron() | 1.0701s |
+-------------------------------------------------------------------------------+---------+
| total (106) | 2.8532s |
+-------------------------------------------------------------------------------+---------+
Group by callback count Group by callback count
Lets debug the init hook group by callback count.
$ wp profile hook init --fields=callback,time --orderby=callback_count
+-------------------------------------------------------------------------------+---------+
| callback | time |
+-------------------------------------------------------------------------------+---------+
| function(){} | 0s |
| register_block_core_block() | 0.001s |
...
| register_block_core_categories() | 0s |
| register_block_core_calendar() | 0s |
+-------------------------------------------------------------------------------+---------+
| total (106) | 1.8471s |
+-------------------------------------------------------------------------------+---------+
Specific Page Specific Page
$ wp profile hook init --fields=callback,time --orderby=time --url=http://localhost/dev/portfolio +-------------------------------------------------------------------------------+---------+ | callback | time | +-------------------------------------------------------------------------------+---------+ | register_block_core_archives() | 0.001s | | rest_api_init() | 0.001s | ... | wp_widgets_init() | 0.157s | | wp_cron() | 1.1221s | +-------------------------------------------------------------------------------+---------+ | total (106) | 3.3182s | +-------------------------------------------------------------------------------+---------+
Spotlight Spotlight
? wp profile hook --fields=hook,time,cache_ratio --spotlight --orderby=time --order=DESC +-----------------------------------+---------+-------------+ | hook | time | cache_ratio | +-----------------------------------+---------+-------------+ | rest_api_init | 1.1056s | 96.76% | ... | elementor/fonts/additional_fonts | 0.0076s | 90% | | muplugins_loaded | 0.0005s | 50% | +-----------------------------------+---------+-------------+ | total (25) | 4.0329s | 94.82% | +-----------------------------------+---------+-------------+
Debug rest_api_init hook
? wp profile hook rest_api_init --fields=callback,time,cache_ratio --spotlight --orderby=time --order=DESC
+-----------------------------------------+---------+-------------+
| callback | time | cache_ratio |
+-----------------------------------------+---------+-------------+
| WC_API->register_rest_routes() | 0.6487s | 95.44% |
| create_initial_rest_routes() | 0.1098s | 100% |
| Envato_Elements\REST->register_routes() | 0.0245s | |
+-----------------------------------------+---------+-------------+
| total (3) | 0.7829s | 97.72% |
+-----------------------------------------+---------+-------------+
Example 2
? wp profile hook init --fields=callback,time,cache_ratio --spotlight --orderby=time --order=DESC +--------------------------------------------+---------+-------------+ | callback | time | cache_ratio | +--------------------------------------------+---------+-------------+ | wp_cron() | 1.103s | 90.48% | | Elementor\Plugin->init() | 0.5867s | 95.38% | ... | WooCommerce->add_image_sizes() | 0.0029s | 85.71% | +--------------------------------------------+---------+-------------+ | total (13) | 1.9125s | 83.66% | +--------------------------------------------+---------+-------------+
Profile by Function Profile by Function
We can also profile the functions.
Normal Function Normal Function
Suppose we have below function:
function my_test_loop() {
for ($i=0; $i < 5000; $i++) {
// Loop for 5000 time.
}
}
Profile function my_test_loop() as below:
? wp profile eval "my_test_loop();"
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| time | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| 0.0005s | 0s | 0 | | 0 | 0 | 0s | 0 |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
Profile wp_remote_get Profile wp_remote_get
? wp profile eval "wp_remote_get( 'https://maheshwaghmare.com/wp-json/wp/v2/posts/' );"
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| time | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| 1.4288s | 0s | 0 | 100% | 2 | 0 | 1.4281s | 1 |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
Profile by File Profile by File
We can debug the performance by file.
? wp profile eval-file my-plugin-file.php +---------+------------+-------------+-------------+------------+--------------+--------------+---------------+ | time | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count | +---------+------------+-------------+-------------+------------+--------------+--------------+---------------+ | 0.1114s | 0s | 0 | 100% | 4 | 0 | 0s | 0 | +---------+------------+-------------+-------------+------------+--------------+--------------+---------------+