MySQL

Tracking Magento Database Queries

Michael Thessel, , , 1 Comment

Magento is a complex beast and tracking down the source of a database query can be a huge pain. Recently I had to track down the source of a set of queries. I could see the queries in the SQL query logs but wasn’t able to figure out which particular piece of code would execute them because the functionality that triggered these was used all over the place.

I ended up adding the PHP stack trace that executed a SQL query to each query as a comment before the query. That way the full stack trace would show up in the MySQL query logs.
Continue reading “Tracking Magento Database Queries” →

Tracking Magento Database Queries

Percona Toolkit Query Digest

Michael Thessel, , , Leave a comment

When optimizing SQL queries (MySQL) developers often only look at the slow log. The slow log is a good place to get started but only represents the beginning of the optimization process. Depending on what your long_query_time (/et/mysql/my.cnf) is set to the slow log only keeps track of really bad queries. Those are not necessarily the ones that make your application slow.

Lets assume your slow log time is set to 0.5s. You got a query running which gets logged 5 times a day with an execution time of 1s. At the same time you got a query running which finishes in 100ms but runs a million times a day. Query one would show up in the slow log but query two wouldn’t. 100ms sounds fast but is actually quite slow and the second query is worse than the first one for your application’s overall performance.

The guys from Percona developed the amazing Percona Toolkit which helps you to perform various MySQL related tasks. To track down slow queries the Query Digest tool is hugely helpful.

To get a profile for your application you need log all queries for a representative timeframe (depends on your traffic) and then run the Percona Query Digest tool against the generated logfile.

To create a full query dump you need to set the slow log query time to 0. You have 2 options doing so:

  1. Set the long_query_time config option to 0
  2. or execute SET global long_query_time = 0; in the mysql cli

The second option is preferred because you don’t need to restart MySQL. Logging all queries will generate significant disk IO and slow down your site quite a bit. To get realistic data you want to run this on your production site though. If a temporary performance hit is not acceptable you can set up a replicated slave and log the queries there.

Once you logged your queries for a while you can run the pt-query-digest tool against your generated log:

root@michael:/tmp/percona-toolkit-2.1.7/bin# ./pt-query-digest /var/lib/mysql/slow.log > log

The generated log file will contain a ordered list of slow queries and a detailed summary for each individual slow query. If you didn’t truncate your query log before switching the long_query_time to 0 restrict the data analysis using the –since switch.

Note: MySQL ships with a similar tool called: mysqldumpslow but Percona Query Digest is much more refined.

Percona Toolkit Query Digest