Rotating MySQL Slow Logs Safely

at April 18th, 2013

This blog post is part two of two. The first part is here.

In my last post, I described a solution for keeping the caches of a MySQL standby server hot using slow logs with long_query_time set to 0. Here are a some lessons we learned when logging a high volume of queries to the slow log.

Do not use copytruncate

Logrotate offers two techniques for log rotation (your log rotation scheme likely offers similar options with a different name):

  1. copytruncate – Copies the file to a new name, and then truncates the original file.
  2. no copytruncate – Uses the rename() system call to move the file to a new name, and then expects the daemon to be signaled to reopen its log file.

MySQL has a mutex for slow log writes. Truncation can block MySQL because the OS serializes access to the inode during the truncate operation. This problem is particularly evident when using the ext3 file system (instead of xfs).

Use FLUSH LOGS instead of sending SIGHUP

When copytruncate is disabled, MySQL must be told to reopen the slow log file. There are two options for signaling:

  1. Send a HUP signal to the mysqld process.
  2. Use the mysql console or mysqladmin utility to FLUSH LOGS;

These options should be equivalent, but MySQL bug 65481 explains that the HUP signal also flushes tables in addition to logs. Flushing tables can impact running queries.

Disable slow logs during rotation

Flushing logs takes time. Meanwhile, queries are still being executed. To prevent MySQL from filling the slow log buffer, we disable the slow logs temporarily during log rotation.

Update: In standard MySQL, long_query_time is a session variable. If your application has a connection pool of persistent connections, you may have a problem changing long_query_time. Percona Server offers a solution; set slow_query_log_use_global_control to make long_query_time a global variable. Thanks Martin Arrieta for mentioning this!

slow_query_log_use_global_control = long_query_time,log_slow_filter,log_slow_rate_limit,log_slow_verbosity

Putting it all together

Here is a logrotate configuration file for a slow log that illustrates these best practices:

/var/mysql/slow_query.log {
    create 660 mysql mysql
    size 1G
       /usr/local/bin/mysql -e 'select @@global.long_query_time into @lqt_save; set global long_query_time=2000; select sleep(2); FLUSH LOGS; select sleep(2); set global long_query_time=@lqt_save;'
    rotate 150

Update: In MySQL 5.5+, you may prefer to use the more specific FLUSH /*!50503 SLOW */ LOGS.

This post has been cross-posted to the MySQL Performance Blog. I am looking for MySQL experts to join our team at Groupon. Drop me a line if you are interested!

No Tags

5 thoughts on “Rotating MySQL Slow Logs Safely

  1. Hello, since this is a cross-post, I thought that it would be useful to make a coss-comment :D One important thing to check is if you are using persistent-connections. The global variable long_query_time is checked when the connection is created, so if you are using a connection pool or persistent connections this will not be useful because it will not affect to the connections that were already opened. There is a Percona Server feature to solve this issue. You can set the “slow_query_log_use_global_control” in 5.5 or “use_global_log_slow_control” in 5.1 in 1 and the server will use the global variable long_query_time instead the local one. PS 5.1 PS 5.5 Martin @martinarrietac

    by Martin Arrieta on April 18, 2013 at 9:01 am
  2. Thanks, Martin. Indeed, we use slow_query_log_use_global_control=long_query_time,log_slow_filter,log_slow_rate_limit,log_slow_verbosity in our configs. I should have mentioned that!

    by Kyle O on April 18, 2013 at 10:20 am
  3. It seem's that the cross posted url has change to (notice the day change and the end / character)

    by shakaran on April 18, 2013 at 9:52 pm
  4. Thanks. I updated the link.

    by Kyle O on April 19, 2013 at 11:51 am
  5. [...] blog post is part two of two. Like part one, published Wednesday, this is a cross-post from Groupon’s engineering blog. Thanks again to Kyle Oppenheim at Groupon. And one more reminder that I’ll be at the Percona [...]

    pingback by Rotating MySQL slow logs safely on May 28, 2014 at 1:36 pm

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>