Tracking MySQL slow queries with syslog-ng


Like me, you may have experiencied slow-down on your PHP/MySQL website, especially when using a crappy CMS (who said Joomla ? ;-)) and have been told “hey, the linux guy, please fix this”.
To be honest, I won’t fix anything as I’m neither a DBA or a developer, however, in this article we will set up an automatic e-mail reporting of slow queries processed by your MySQL server.

First, you’ll have to remove your old syslog server and replace it with something powerful (I mean: syslog-ng):

The default Debian configuration doesn’t log mail system messages into syslog (unlike default rsyslogd), I suggest fixing this first:
In /etc/syslog-ng/syslog-ng.conf, find the line

And add this one:

We need to ask MySQL to log slow queries (queries for which processing took more than NN seconds).
Edit /etc/mysql/my.cnf and uncomment the following lines:

We started investigating with long_query_time set to 5 seconds, but 1 is a decent value. I haven’t tried yet to use something lower than 1 sec but I guess that should work.

Restart mysql server.

Open /etc/syslog-ng/syslog-ng.conf again and add the following piece of configuration:

A little explanation:
First we define a new source of log file. MySQL has its own way of logging and doesn’t rely on syslog, so we need to track its own log file and ask our syslog to merge this logs.
Then we create a new destination similar to the default d_syslog (aka /var/log/syslog file) but with text refactoring (just to make it look like a real syslog entry).
After that, another destination: pipe into an homemade script that will send the lines by email (and text refactoring again).
Finally, associate the sources with the two destinations.

So, yes, we need to create that “mailing” script. Create a new file named /etc/syslog-ng/mail-alert-mysql-slow-query and fill it with:

I stole this script somewhere on syslog-ng’s mailing list and tweaked it a bit.
This script is a lot better because it handles a timeout before sending the email (see 0.1 in last line).
A full “slow query log” is written on several line. Thanks to this genius piece of Python script, only one email containing all of them will be send!

Set this file +x (chmod 755) and restart syslog-ng. Run tail -f /var/log/syslog and start a slow mysql query.
You should see something like this:


*UPDATE* 2012-10-22

After using this setup for a while, we discovered that most of alert sent during the night were irrelevant.
So here a quick patch to disable it from midnight to 8am:

*UPDATE* 2015-11-19

I made a slightly better version for another issue at work:

Also, in this case I decided to filter out messages within syslog-ng, which would probably be a lot more efficient than using re module in Python script.

Here is my configuration file: