MySQL Query Logging

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.

Enable Query Logging for Magento 2.2 and higher

  1. Execute in SSH, in the Magento 2 root:
    bin/magento --include-all-queries=true --include-call-stack=true dev:query-log:enable

Enable Query Logging for Magento 2.0 and 2.1

  1. Create a backup of the file app/etc/di.xml
  2. Follow the instructions from https://devdocs.magento.com/guides/v2.1/config-guide/log/log-db.html
    In the rest of this manual we are using the log file debug/pdo_mysql.log instead of log/db.log
  3. Clean the configuration cache:
    bin/magento cache:clean config

Enable query logging in Magento 1

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 ib/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;

Read the log

  1. In Magento 1, the log file is called var/debug/pdo_mysql.log in Magento 2 it is var/debug/db.log
  2. 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.
  3. Delete the log file. 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/db.log
  4. Click once more in the address bar in your browser and push Enter once.
  5. Now we can look at the file in a text editor
    nano var/debug/db.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.

he 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 finished do not forget to carry out the steps below to disable query logging.

Disable Query Logging – Magento 2.2 and higher

  1. Execute in SSH, in the Magento 2 root:
    bin/magento dev:query-log:disable
    rm var/debug/db.log

The next time you want to take a look at the queries again, you will have to begin on top of this manual again.

Disable Query Logging – Magento 2.0 and 2.1

  1. Put back your backup of the file app/etc/di.xml
  2. Clean the configuration cache:
    bin/magento cache:clean config
    rm var/debug/db.log

The next time you want to take a look at the queries again, you will have to begin on top of this manual again.

Disable Query Logging – Magento 1

  1. 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 on top of this manual again.

About the Author
Jeroen Vermeulen
Jeroen acquired his extensive knowledge of hosting, Magento, the technology and all the rest in big-name hosting companies and during vocational training courses. In recent years he has booked considerable success as one of the top Magento programmers in Benelux and is something of a household name in that area of expertise.