↑ Return to Technical tips

MySQL Query Logging

When there has been quite some developing to a web shop and/or several extensions are been installed, chances are that the Magento front end doesn’t react as fast as it did before. The reason can often be found in useless MySQL queries.

When the PHP code and Magento templates have been set up optimally, many HTML blocks can be cached. When a visitor requests a page, many blocks can be obtained from the cache. Requests in the MySQL database are not necessary for blocks from the cache. So that makes a difference in the amount of load on the database server, and the page will load much faster.
A mistake that is often made is that the menu navigation doesn’t come from the cache, while rather heavy MySQL queries are needed to built this navigation.

We are going to explain here how you can find out what MySQL queries are being executed to build one page. For this purpose, you need an environment where there are no other visitors, a staging environment for instance. We do this by turning on the query log temporarily.

We show the commands as Linux shell commands, but you can of course do it also using your own tools. We assume you start from the Magento root directory.

Preparation if you want to execute the commands in Ubuntu or Debian Linux (you can skip this if you use your own tools):

  apt-get install  nano dos2unix

Now execute these steps gradually:

  1. Create the directory app/code/local/Varien/Db/Adapter/Pdo
      mkdir -p  app/code/local/Varien/Db/Adapter/Pdo
  2. Copy the file lib/Varien/Db/Adapter/Pdo/Mysql.php to that directory
      cp  lib/Varien/Db/Adapter/Pdo/Mysql.php  app/code/local/Varien/Db/Adapter/Pdo/
  3. Open the copy of the file in a text editor
      nano  app/code/local/Varien/Db/Adapter/Pdo/Mysql.php
  4. Adapt the following lines, in the upper part of the file.
      protected $_debug               = true;
      protected $_logAllQueries       = true;
      protected $_logCallStack        = true;
  5. In your browser, go to a shop page in this (staging) environment that is slow, refresh the page to be sure by clicking in the browser’s URL bar and by pushing Enter. Don’t close your browser.
  6. Delete the file var/debug/pdo_mysql.log. Now that the page has been loaded once, and a lot of blocks should be cached now, we are going to start with a clean query log.
      rm  var/debug/pdo_mysql.log
  7. Click once more in the address bar in your browser and push Enter once.
  8. Because of the fact that different line breaks are used in the file, many text editors do not understand the file; that is why we are going to make all line breaks the same
      dos2unix  var/debug/pdo_mysql.log
  9. Now we can look at the file in a text editor
      nano  var/debug/pdo_mysql.log

In the file you will find blocks with always this information:

## 201X-XX-XX XX:XX:XX  = The date and time of the query
## 3890 ## QUERY
TIME: 0.1234 = The time that was necessary to execute this query, in seconds.
TRACE: #1 Varien_Db_.. = Where in the code this query was executed, several lines.

The first few blocks deal with connecting to the MySQL server; this should last no longer than a couple of hundreds of seconds.
Then it gets more interesting. First aim on the block for which the required time is high, more than a second for instance. The TRACE is in reverse order. The last trace line of the block is the startup of Magento, and from the bottom to the top you enter the code deeper and deeper. The first two lines of the TRACE are of the Database Adapter that effectively executes the query. At the end of the trace lines are always the file name and the line number. From bottom to top, a new file or function is requested. Try to find out why the query is executed and what you should do in order to prevent that, like improving the block caching for instance. Some SQL queries can be completely needless, or are done by extensions that are unnecessary in that location.

When you improved something, execute step 5 to 9 again, and look if you see any difference.

When you’re ready with your investigations to the SQL queries, delete the adapted PHP file and the log:

  rm  app/code/local/Varien/Db/Adapter/Pdo/Mysql.php
  rm  var/debug/pdo_mysql.log

The next time you want to take a look at the queries again, you will have to begin at step 1 again.