Plugin for simpler performance profiling

Filters vs the rest

How time is spent on a compex page

The two areas where performance problems with WordPress plugins are most common are custom filters/actions and database queries. WP-Profile is a plugin that helps you find such problems.

Actions and filters

WordPress has an intricate system of actions and filters which is used all over the place: to convert : ) into :), to make links clickable and to handle the login procedure are just some examples.

Every action and filter is a hook that allows plugins to call custom functions and easily change or override default behavior. That is very useful.

It also makes it easy to really ruin performance as some common filters are called a hundred times or more for more complex pages, making small inefficiencies add up really quickly.

Unfortunately there are no good ways to keep track of the performance impact of individual filters. It is possible to profile the whole system using for example XDebug and *Cachegrind like I did in an earlier post but it is a lot of work and often overkill during plugin development.

Database queries

Database queries in stock WordPress are highly optimized. So much so that they usually only takes a few percent of total time. It is, however, very easy to change this and even seemingly simple queries can take surprisingly long time. By defining SAVEQUERIES in wp-config.php WordPress will record all queries and how long they took to execute in $wpdb->queries.

WP-Profile

WP-Profile is a small plugin I’ve written to use when developing plugins and modifying WordPress. It keeps track of all calls to actions/filters and presents it in an accessible fashion together with query information collected through SAVEQUERIES. It requires that you are comfortable making minor changes to core WordPress files to set up. It is for testing only. You can download it here.

This is the result on stock WordPress for a rather complex page with a lot of comments. Sort tables by clicking on table header (thanks to JQuery TableSorter):



Time (seconds) % of Total Calls Function Actions / Filters
0.042 12.3% 246 wptexturize
Time (seconds) % of Total Calls Action / Filter
0.022 6.3% 1 the_content
0.008 2.2% 115 the_title
0.007 2.1% 37 comment_text
0.005 1.4% 79 list_cats
<0.001 0.3% 14 bloginfo, link_name, link_description
0.023 6.5% 38 wpautop
Time (seconds) % of Total Calls Action / Filter
0.013 3.7% 1 the_content
0.01 2.9% 37 comment_text
0.017 4.9% 38 convert_smilies
Time (seconds) % of Total Calls Action / Filter
0.009 2.6% 1 the_content
0.008 2.3% 37 comment_text
0.01 3% 167 convert_chars
Time (seconds) % of Total Calls Action / Filter
0.004 1.2% 115 the_title
0.003 0.8% 37 comment_text
0.003 0.8% 1 the_content
<0.001 0.1% 14 link_name, link_description, bloginfo
0.007 2% 1 do_shortcode the_content
0.007 2% 37 make_clickable comment_text
0.006 1.8% 1 WP_Embed :: run_shortcode the_content
0.004 1.2% 1 wp_cron sanitize_comment_cookies
0.002 0.7% 1 wp_widgets_init init
0.002 0.6% 1 profile_enqueue_requirements init
0.002 0.5% 10 wp_filter_kses
Time (seconds) % of Total Calls Action / Filter
0.001 0.3% 5 link_description
0.001 0.3% 5 link_name
0.002 0.5% 1 WP_Widget_Factory :: _register_widgets widgets_init
0.001 0.4% 37 force_balance_tags comment_text
0.001 0.4% 204 _config_wp_home option_home
0.001 0.4% 1 wp_default_scripts wp_default_scripts
0.001 0.2% 1 wp_print_head_scripts wp_head
0.001 0.2% 1 feed_links_extra wp_head
0.001 0.2% 37 kb_filter_avatar get_avatar
0.135s 39.2% 1071


Time (seconds) % of Total Function Query
0.002 0.6% comments_template SELECT * FROM wp_comments WHERE comment_post_ID = 144 AND (comment_approved = ’1′ OR ( user_id = 111 AND comment_approved = ’0′ ) ) ORDER BY comment_date_gmt
0.001 0.4% get_pages SELECT * FROM wp_posts WHERE (post_type = ‘page’ AND post_status = ‘publish’) ORDER BY menu_order, post_title ASC
0.001 0.4% update_meta_cache SELECT post_id, meta_key, meta_value FROM wp_postmeta WHERE post_id IN (144)
0.001 0.2% _fill_user SELECT meta_key, meta_value FROM wp_usermeta WHERE user_id = 111
0.001 0.2% get_bookmarks SELECT * , IF (DATE_ADD(link_updated, INTERVAL 120 MINUTE) >= NOW(), 1,0) as recently_updated FROM wp_links INNER JOIN wp_term_relationships AS tr ON (wp_links.link_id = tr.object_id) INNER JOIN wp_term_taxonomy as tt ON tt.term_taxonomy_id = tr.term_taxonomy_id WHERE 1=1 AND link_visible = ‘Y’ AND ( tt.term_id = 2 ) AND taxonomy = ‘link_category’ ORDER BY link_name ASC
0.01s 2.9%

3 Responses to “Plugin for simpler performance profiling”

  1. Kakel sickan says:

    So what, can this find flaws/bottlenecks in the wp system?

  2. Very interesting tip. Awaited the next tips

  3. Raleigh says:

    I read a lot of interesting posts here. Probably you spend a
    lot of time writing, i know how to save you a lot of work, there is an online
    tool that creates unique, google friendly posts in minutes, just search in google - laranitas
    free content source

Leave a Reply