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 |
|
||||||||||||||||||||||||
| 0.023 | 6.5% | 38 | wpautop |
|
||||||||||||||||||||||||
| 0.017 | 4.9% | 38 | convert_smilies |
|
||||||||||||||||||||||||
| 0.01 | 3% | 167 | convert_chars |
|
||||||||||||||||||||||||
| 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 |
|
||||||||||||||||||||||||
| 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% |