Logging Database Queries in Magento

Logging Database Queries in Magento

Apr 15

  • Created: Apr 15, 2011 2:33 PM

Logging Database Queries in Magento
In previous weeks, we’ve covered some debugging tools for both MySQL and PHP that can be very helpful in troubleshooting problems with your LAMP-based web applications. However, there is a little known feature in the Varien library installed with Magento that will automagically log database queries to a file. This feature not only provides a great deal of insight into the behind-the-scenes functionality of Magento, it also helps you to debug slow-running queries and other Model-based performance problems.

To enable this feature, open the file lib/Varien/Db/Adapter/Pdo/Mysql.php in your favorite text editor. Down around line 86, you’ll see the following class variables:

* Write SQL debug data to file<br />
     *<br />
     * @var bool<br />
     */<br />
    protected $_debug               = false;</p>
<p>    /**<br />
     * Minimum query duration time to be logged<br />
     *<br />
     * @var unknown_type<br />
     */<br />
    protected $_logQueryTime        = 0.05; </p>
<p>    /**<br />
     * Log all queries (ignored minimum query duration time)<br />
     *<br />
     * @var bool<br />
     */<br />
    protected $_logAllQueries       = false;</p>
<p>    /**<br />
     * Add to log call stack data (backtrace)<br />
     *<br />
     * @var bool<br />
     */<br />
    protected $_logCallStack        = false;</p>
<p>    /**<br />
     * Path to SQL debug data log<br />
     *<br />
     * @var string<br />
     */<br />
    protected $_debugFile           = 'var/debug/sql.txt';

The documentation does a good job of explaining what these variables do, but I’ll go through them anyway.

protected $_debug               = false;

– This is the switch that turns SQL debugging on or off. Set it to “true” to enable.

protected $_logQueryTime        = 0.05;

– This sets the minimum time in seconds that will determine which queries get logged. This is useful for finding slow queries that could be impacting your store’s performance. 0.05 seconds is a bit low. I recommend setting it to 1.0 seconds if you want to find the really slow queries.

protected $_logAllQueries       = false;

– This variable tells Magento to ignore the previous option and just log everything. Magento does a lot of database work, so turning this option on will generate a great deal of data. If you just want to get a general sense of the database operations going on when loading a specific page, you can enable this option by setting it to “true”.

protected $_logCallStack        = false;

– This option is helpful when debugging custom and third-party modules because in addition to the queries, it logs a backtrace of the methods that called the query. Again, if you’ve turned on the option to log all queries, this option will produce even more data to sift through.

protected $_debugFile           = 'var/debug/sql.txt';

– Finally, you have the option to set the location of the debug file, which is set to (your Magento root)/var/debug/sql.txt by default.

If you decide to enable this feature to debug your Magento store, make sure that you limit access your website by editing the appropriate section of your .htaccess file. Otherwise you will get a mix of queries from users browsing your site.

############################################<br />
## By default allow all access</p>
<p>    #Order allow,deny<br />
    #Allow from all<br />
Order deny,allow<br />
Deny from all<br />
Allow from YOUR.IP.ADDR.ESS

Also, make sure you remember to turn debugging off once you’re finished troubleshooting, or else the size of this log file will become a problem in itself. Hopefully this will help you to figure out that elusive bit of database latency slowing down your site. Happy hunting!

  • http://www.rightwaysolution.com/hire-dedicated-magento-developer.html Magento Developer India

    Thanks Ben for the post. I am new in Magento and this post increased my Magento knowledge!!!

  • Thijs van den Berg

    Hi Ben,

    In my SQL logfiles I see variable names like “:website_id” in the snippet below. Do you know how I can see the actual values instead?

    SELECT `shipping_tablerate`.* FROM `shipping_tablerate` WHERE (website_id = :website_id) AND ((dest_country_id = :country_id …

  • quymv88

    Thanks Ben for your article, it is really useful for me!

  • Gyula Kovats

    awesome! I was tracking a mysql bug for 3 days, and this finally helped me to get to the point! thanks!