Benchmarking WordPress SQL using FirePHP

Building and running a WordPress site is a simple matter. WordPress is a considerably fast CMS system, until you start to add more and more plugins and one day you notice that Worpdress has started to slow down. It may be the case that SQL queries within some plugins are not optimized and are taking an increased amount of time executing them, this can considerably slow down your site. The first thing you can do to rectify the situation is to find out where exactly the bottleneck resides by analyzing the time each SQL query takes to executes. Some inquisitive people among you may also be interested in knowing in what sequence the WordPress SQL queries themselves are being run. Not that all bottlenecks occur due to unoptimized SQL, most are due to poor coding practices. Whatever the reason; the following post will show you how to look inside the SQL query execution of WordPress.

Logging WordPress SQL queries

By default WordPress doesn’t log any queries. But you can instruct WordPress to do so by adding the following configuration option to your WordPress ‘wpconfig.php’ file.

/* wp-config.php */
 
define('SAVEQUERIES', true);

Once that is done you can add the following lines at the end of your WordPress themes ‘footer.php’ file.

/* footer.php */
..
global $wpdb;
print_r($wpdb->queries);
.
.

This will display the SQL statements executed by your WordPress installation in a raw format as shown below. It displays a total of three items – the executed query, the execution time of the query and the function that called the query.

Array
(
    [0] => Array
        (
            [0] => SELECT option_name, option_value FROM wp_options WHERE autoload = 'yes'
            [1] => 0.004619836807251
            [2] => require, require_once, require_once, require_once, is_blog_installed, wp_load_alloptions
        )
 
    [1] => Array
        (
            [0] => SELECT option_value FROM wp_options WHERE option_name = 'sidebars_widgets' LIMIT 1
            [1] => 0.0015749931335449
            [2] => require, require_once, require_once, require_once, do_action, call_user_func_array, wp_widgets_init, register_widget, WP_Widget_Factory->register, WP_Widget_Recent_Comments->WP_Widget_Recent_Comments, is_active_widget, wp_get_sidebars_widgets, get_option
        )
.
.

As you can see the raw information is not interesting to look at and it also clutters the actual site. A better way is to use FireBug and FirePHP to log the SQL queries without interfering with the WordPress output.

Installing FirePHP

Before starting you need to have FirePHP and FireBug installed. FirePHP uses FireBugs console window to output the debug messages. Once you have installed FirePHP and FireBug, you need to install the FirePHP server libraries. Copy the FirePHP server libraries to your WordPress themes directory. For e.g ‘wordpress\wp-content\themes\default\FirePHPCore’.

If you are unfamiliar with FirePHP a nice tutorial can be found at Six Revisions.

Displaying formatted information with FirePHP

Once we are done with the above setup, you can add the following code at the end of your WordPress themes ‘footer.php’ file, replacing the code we previously added.

<?php
 
    /* footer.php */
 
    require_once("FirePHPCore/FirePHP.class.PHP");
 
    global $wpdb;
 
    $query_table[] = array("SQL", "Execution Time", "Calling Function");
    $expensive_query_time = 0;
    $expensive_query = "";
    $total_time = 0;
 
    foreach($wpdb->queries as $query)
    {
        $query_table[] = array($query[0], $query[1], $query[2]);
        /* Get the most expensive query */
        if($query[1] > $expensive_query_time)
        {
            $expensive_query_time = $query[1];
            $expensive_query = $query[0];
            $total_time += $query[1];
        }
    }
 
    $total_queries = count($wpdb->queries);
    $firephp = FirePHP::getInstance(true);
 
    /* Display the queries in a formatted table */
    $firephp->group('Query', array( 'Collapsed' => false,  
                                    'Color' => '#000'));
    $firephp->table($total_queries . " queries took " . 
                    $total_time . " seconds.", $query_table);
 
    /* Display the query summary */
    $firephp->group('Query Summary', array( 'Collapsed' => false,  
                                            'Color' => '#000'));
    $firephp->log($total_queries, 'Total Queries');
    $firephp->log($expensive_query, 'Expensive Query');
    $firephp->log($expensive_query_time, 'Expensive Query Time');
 
?>
</body>
</html>

Refresh your WordPress page and you should see the following output in the FireBug console. Click on the image below to view the complete debug screen. (Some queries have been removed for size.) As you can see FirePHP displays a nicely formatted output than the previous one.

Modifying the query data returned by WordPress

WordPress by default saves and returns the following three parameters for each SQL query:
1. SQL query
2. Query Execution time
3. The method chain that called the query.

The code section where this happens is located in the query() method of the ‘wp-db.php’ file in the WordPress ‘wp-includes’ directory. The following snippet shows that section of code:

/* wp-db.php */
.
.
// Log how the function was called
$this->func_call = "\$db->query(\"$query\")";
 
// Keep track of the last query for debug..
$this->last_query = $query;
 
// Perform the query via std mysql_query function..
if ( defined('SAVEQUERIES') && SAVEQUERIES )
    $this->timer_start();
 
$this->result = @mysql_query($query, $this->dbh);
++$this->num_queries;
 
if ( defined('SAVEQUERIES') && SAVEQUERIES )
    $this->queries[] = array( $query, $this->timer_stop(), 
                              $this->get_caller() );
 
.
.

You can modify the code to add some extra parameters as per your requirements, or modify the format in which it is returned. For example you could add code to save the data to a xml or csv file for latter retrieval and analysis.

Note: Turning on the define(‘SAVEQUERIES’, true) option can slow down your WordPress site, so make sure you disable it after your work is done.