Profile

Advertisement

WP CLI Profile package allow use to identify the performance of our WordPress website.

Installation Installation

wp package install wp-cli/profile-command

Top ↑

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.

Top ↑

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%      |
+--------------------------+---------+-------------+

Top ↑

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%      |
+-------------------+--------+-------------+

Top ↑

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%      |
+----------------------+--------+-------------+

Top ↑

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

Top ↑

All Hooks All Hooks

We can debug all hook which is executed while visiting the specific page.

Top ↑

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 |
+------------------------------------------------------------------------------+----------------+----------+

Top ↑

Profile by URL Profile by URL

$ wp profile hook --fields=hook,callback_count,time --orderby=time --url=http://localhost/dev/portfolio

Top ↑

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 |
+------------------------------------------------------------------------------+----------------+----------+

Top ↑

Single Hook Single Hook

We can debug specific hook. Let’s debug the init hook group by time and callback count.

Top ↑

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 |
+-------------------------------------------------------------------------------+---------+

Top ↑

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 |
+-------------------------------------------------------------------------------+---------+

Top ↑

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聽|
+-------------------------------------------------------------------------------+---------+

Top ↑

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%聽聽聽聽聽聽|聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽聽
+--------------------------------------------+---------+-------------+

Top ↑

Profile by Function Profile by Function

We can also profile the functions.

Top ↑

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             |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+

Top ↑

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             |
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+

Top ↑

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聽聽聽聽聽聽聽聽聽聽聽聽聽|
+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
%d bloggers like this: