As many of you know, WP-CLI is a command-line interface for WordPress supporting many actions you might perform otherwise in the admin like installing plugins, activating/deactivating themes or plugins, updating the core and others.
And the best part is that although it comes with dozens of commands, it can be extended further to cover all sorts of custom commands. That being said, we can use the wp profile command to investigate slow WordPress site and dissect every plugin to their basic hooks.
Let’s do a test run to see how it actually works.
Obviously, first you need to have the WP-CLI installed on the server. The whole process is straight-forward and you won’t have any issues following their official installing guide.
The wp profile command is not available right away, so we need to install this as well. After you have WP-CLI installed, go ahead and run the following command:
wp package install [email protected]:wp-cli/profile-command.gitThis will install the additional package that we need. You should get Success: Package installed at the end to confirm everything is set.
Now before we get into the actual testing, I need to explain something. In the test server, I am logged in as root which leads to using –allow-root at the end of each WP-CLI command. This is a core WP-CLI limitation done for security reasons highlighted in this pull request.
Go ahead and cd into your WordPress directory and run the basic wp profile command
wp profile stage --allow-rootthis will give us similar output
+------------+---------+------------+-------------+-------------+------------+--------------+-----------+------------+--------------+---------------+
| stage | time | query_time | query_count | cache_ratio | cache_hits | cache_misses | hook_time | hook_count | request_time | request_count |
+------------+---------+------------+-------------+-------------+------------+--------------+-----------+------------+--------------+---------------+
| bootstrap | 0.7482s | 0.1383s | 51 | 83.04% | 1533 | 313 | 0.3433s | 6812 | 0s | 0 |
| main_query | 0.0059s | 0.002s | 3 | 97.37% | 74 | 2 | 0.0029s | 160 | 0s | 0 |
| template | 0.3183s | 0.0785s | 177 | 87.78% | 4023 | 560 | 0.2207s | 10347 | 0s | 0 |
+------------+---------+------------+-------------+-------------+------------+--------------+-----------+------------+--------------+---------------+
| total (3) | 1.0723s | 0.2187s | 231 | 89.4% | 5630 | 875 | 0.5669s | 17319 | 0s | 0 |
+------------+---------+------------+-------------+-------------+------------+--------------+-----------+------------+--------------+---------------+
This is the first step of the process. The wp profile stage command breaks the request into 3 stages, like showed in the official doc:
- bootstrap is where WordPress is setting itself up, loading plugins and the main theme, and firing the
inithook. - 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.
So depending on the results we can dig in either stage to find what’s causing the slow times. As you can see our test website is not so bad, but the bootstrap is contributing the most for the load time ( and this is where we can find slow plugins ). Let’s dig deeper with
wp profile stage bootstrap --allow-root
This command outputs further segmented report for the bootstrap stage based on primary actions. In this case we have muplugins_loaded, plugins_loaded, init, setup_theme and wp_loaded. We should examine the time of each hook and decide which one we are going to explore further.
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| hook | callback_count | time | query_time | query_count | cache_ratio | cache_hits | cache_misses | request_time | request_count |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| muplugins_loaded:before | | 0.0948s | 0.0031s | 1 | 0% | 0 | 2 | 0s | 0 |
| muplugins_loaded | 2 | 0.0002s | 0s | 0 | 50% | 1 | 1 | 0s | 0 |
| plugins_loaded:before | | 0.2709s | 0.0028s | 13 | 80.52% | 124 | 30 | 0s | 0 |
| plugins_loaded | 33 | 0.2174s | 0.0905s | 23 | 84.08% | 206 | 39 | 0s | 0 |
| setup_theme:before | | 0.0002s | 0s | 0 | 100% | 4 | 0 | 0s | 0 |
| setup_theme | 0 | 0s | 0s | 0 | | 0 | 0 | 0s | 0 |
| after_setup_theme:before | | 0.0409s | 0.0004s | 2 | 38.21% | 115 | 186 | 0s | 0 |
| after_setup_theme | 8 | 0.009s | 0.0033s | 1 | 96.88% | 31 | 1 | 0s | 0 |
| init:before | | 0s | 0s | 0 | | 0 | 0 | 0s | 0 |
| init | 99 | 0.0666s | 0.002s | 7 | 98.35% | 892 | 15 | 0s | 0 |
| wp_loaded:before | | 0s | 0s | 0 | | 0 | 0 | 0s | 0 |
| wp_loaded | 12 | 0.0432s | 0.0284s | 4 | 80.4% | 160 | 39 | 0s | 0 |
| wp_loaded:after | | 0.0003s | 0s | 0 | | 0 | 0 | 0s | 0 |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+
| total (13) | 154 | 0.7435s | 0.1305s | 51 | 69.83% | 1533 | 313 | 0s | 0 |
+--------------------------+----------------+---------+------------+-------------+-------------+------------+--------------+--------------+---------------+Since we are looking for slow plugins, the important hook is plugins_loaded. And indeed it seems a bit heavy comparing to the others, so let’s output everything related to it. Use the command
wp profile hook plugins_loaded --fields=callback,time,location --allow-root
which will print the following output
+-------------------------------------------------------------------------+---------+--------------------------------------------------------------------------+
| callback | time | location |
+-------------------------------------------------------------------------+---------+--------------------------------------------------------------------------+
| SitePress->plugin_localization() | 0.0001s | sitepress-multilingual-cms/sitepress.class.php:3188 |
| wp_maybe_load_widgets() | 0.0039s | wp-includes/functions.php:3673 |
| wp_maybe_load_embeds() | 0.0001s | wp-includes/embed.php:176 |
| SitePress->init() | 0.0919s | sitepress-multilingual-cms/sitepress.class.php:366 |
| WPML_Compatibility_Gutenberg->load_textdomain_filter() | 0s | sitepress-multilingual-cms/compatibility/gutenberg/wpml-compatibility-gu |
| | | tenberg.php:22 |
| _mc4wp_load_plugin() | 0.0086s | mailchimp-for-wp/mailchimp-for-wp.php:40 |
| _wp_customize_include() | 0s | wp-includes/theme.php:2777 |
| GFForms::loaded() | 0s | gravityforms/gravityforms.php:239 |
| Puc_v4p1_Plugin_UpdateChecker->maybeInitDebugBar() | 0s | admin-menu-editor-pro/plugin-updates/Puc/v4p1/UpdateChecker.php:804 |
| AAL_Main->load_textdomain() | 0.0004s | aryo-activity-log/aryo-activity-log.php:90 |
| wpcf7() | 0.0066s | contact-form-7/settings.php:88 |
| Cookie_Notice->load_textdomain() | 0.0003s | cookie-notice/cookie-notice.php:337 |
| Disable_Comments->register_text_domain() | 0.0003s | disable-comments/disable-comments.php:139 |
| ewww_image_optimizer_preinit() | 0.0004s | ewww-image-optimizer/common.php:427 |
| gap_i18n_init() | 0.0002s | ga-google-analytics/ga-google-analytics.php:47 |
| humanitas_news_load_textdomain() | 0.0002s | humanitas-news/humanitas-news.php:58 |
| WPML_Action_Filter_Loader->deferred_loader() | 0.0004s | sitepress-multilingual-cms/classes/action-filter-loader/class-wpml-actio |
| | | n-filter-loader.php:69 |
| wpml_plugins_integration_setup() | 0.0009s | sitepress-multilingual-cms/inc/plugins-integration.php:12 |
| wpml_check_php_version() | 0.0008s | sitepress-multilingual-cms/sitepress.php:364 |
| wpseo_load_textdomain() | 0.0002s | wordpress-seo/wp-seo-main.php:272 |
| load_yoast_notifications() | 0.0008s | wordpress-seo/wp-seo-main.php:529 |
| dbmanager_textdomain() | 0.0002s | wp-dbmanager/wp-dbmanager.php:34 |
| WPMailSMTP\Core->get_processor() | 0.0004s | wp-mail-smtp/src/Core.php:105 |
| WPMailSMTP\Core->replace_phpmailer() | 0.0037s | wp-mail-smtp/src/Core.php:486 |
| WPMailSMTP\Core->init_notifications() | 0.0013s | wp-mail-smtp/src/Core.php:193 |
| \WPMailSMTP\load_tgm_plugin_activation() | 0s | wp-mail-smtp/src/TGMPA.php:2112 |
| rocket_load_textdomain() | 0.0004s | wp-rocket/wp-rocket.php:93 |
| rocket_init() | 0.0772s | wp-rocket/inc/main.php:14 |
+-------------------------------------------------------------------------+---------+--------------------------------------------------------------------------+
| total (28) | 0.1993s | |
+-------------------------------------------------------------------------+---------+--------------------------------------------------------------------------+
Before we analyze the result, notice that we used --fields=callback,time,location in the command. This is done to restrict the output columns shown in the result, to maintain clean and readable look.
Looking at the results, you can clearly see if you have slow-performing plugin. In this case we have SitePress->init() and rocket_init() are leading the pack with a total of 170ms. That’s not much by itself, but imagine having a website with 30 plugins – surely you will have a single hook exceeding 200ms alone.