This 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 Live MySQL Conference and Expo next week in Santa Clara, California so look for me there. You can checkout the sessions I’ll be leading here.
In my last post, I described a solution for keeping the caches of a MySQL standby server hot using MySQL 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):
- copytruncate – Copies the file to a new name, and then truncates the original file.
- 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:
- Send a HUP signal to the mysqld process.
- 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 MySQL 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 MySQL slow logs temporarily during log rotation.
Putting it all together
Here is a logrotate configuration file for a slow log that illustrates these best practices:
create 660 mysql mysql
/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;'