Testing Advanced Log Flushing for Percona Audit

We use Percona’s <A HREF=”https://www.percona.com/doc/percona-server/5.5/management/audit_log_plugin.html”>audit log plugin</A> to keep a record of all our logins. Recently we did one of those tasks that everyone knows they should do, but few ever do: change the application user’s password.

When we change the application password, we add a new application user with the proper permissions and a new password, update the information in our repository and wait a while. Using this procedure, any failures mean the old user is used, and more importantly – failure does not impact the end user.

We check the audit logs to see if there were failures – if the user is still being used – when it is no longer in use, we can drop the user.

For reference, here are our settings:

[mysqlaudit]# grep audit /etc/my.cnf
# Percona audit plugin options
audit_log_format = JSON
audit_log_rotate_on_size = 1073741824 . #1G
audit_log_rotations = 10
audit_log_file = /var/log/mysqlaudit/audit.log
audit_log_buffer_size = 4194304
audit_log_strategy = ASYNCHRONOUS
audit_log_policy = LOGINS

This means that we automatically flush logs >1G, keeping 10 audit logs. The other option is to do manual flushing, but we do not want our log files to get very large, and we don’t need to keep audit logs for a very long time.

The ideal behavio – we update our app to the new user, and then flush the logs. That way we could start a new audit log and only have to search the current audit log for the old user. I’m sure people are thinking, “well, it’s set to rotate by size, not manually, so you just cannot do it.” However, binary logs are set the same way and FLUSH LOGS do indeed rotate logs manually, even when auto rotate by size is set.

The tl;dr is that there is currently no way to do this without restarting MySQL. The audit_log_rotate_on_size variable is not dynamic, so we could not set it to manual without restarting MySQL. Here are some other tests we did to see if we could force an audit log flush while using the auto rotate:

We tried moving the audit logs and flushing:

[ ~]# cd /var/log/mysqlaudit/
[mysqlaudit]# ls -l
total 1459572
-rw-rw—- 1 mysql mysql 420839439 Mar 31 11:04 audit.log
-rw-rw—- 1 mysql mysql 1073749720 Mar 25 08:50 audit.log.01
[mysqlaudit]# mv audit.log.01 audit.log.02
[mysqlaudit]# mv audit.log audit.log.01
[mysqlaudit]# ls
audit.log.01 audit.log.02

Don’t worry, this doesn’t affect writing the file – the inode is still in MySQL and it still writes to the file, now called audit.log.01:
[mysqlaudit]# ls -l
total 1459652
-rw-rw—- 1 mysql mysql 420925253 Mar 31 11:07 audit.log.01
-rw-rw—- 1 mysql mysql 1073749720 Mar 25 08:50 audit.log.02
[mysqlaudit]# ls -l
total 1459652
-rw-rw—- 1 mysql mysql 420925253 Mar 31 11:07 audit.log.01
-rw-rw—- 1 mysql mysql 1073749720 Mar 25 08:50 audit.log.02
[mysqlaudit]# mysql -u sheeri.cabral -p -e “FLUSH LOGS;”
Enter password:
[mysqlaudit]# ls -l
total 1459688
-rw-rw—- 1 mysql mysql 420958983 Mar 31 11:07 audit.log.01
-rw-rw—- 1 mysql mysql 1073749720 Mar 25 08:50 audit.log.02

Note that this also proves that “FLUSH LOGS” does not close and open the audit log.

Can we force it? Let’s try by setting the audit_log_policy to NONE and then to LOGINS (what we have it as by default):

[mysqlaudit]# mysql -u sheeri.cabral -p -e “set global audit_log_policy=NONE; set global audit_log_policy=LOGINS”
Enter password:
[mysqlaudit]# ls -l
total 1459768
-rw-rw—- 1 mysql mysql 421043317 Mar 31 11:10 audit.log.01
-rw-rw—- 1 mysql mysql 1073749720 Mar 25 08:50 audit.log.02

Here’s another failed test – let’s see if we can disable then enable the plugin:
[mysqlaudit]# mysql -u sheeri.cabral -p -e “UNINSTALL PLUGIN audit_log”
Enter password:
[mysqlaudit]# ls -rlth
total 1.4G
-rw-rw—- 1 mysql mysql 1.1G Mar 25 08:50 audit.log.01
-rw-rw—- 1 mysql mysql 403M Mar 31 11:44 audit.log
[mysqlaudit]# mysql -u sheeri.cabral -p -e “INSTALL PLUGIN audit_log SONAME ‘audit_log.so’; ”
Enter password:
ERROR 1125 (HY000) at line 1: Function ‘audit_log’ already exists
[mysqlaudit]# mysql -u sheeri.cabral -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 1375345
Server version: 5.5.51-38.1-log Percona Server (GPL), Release 38.1, Revision b4a63b4

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type ‘help;’ or ‘\h’ for help. Type ‘\c’ to clear the current input statement.

[(none)]> INSTALL PLUGIN audit_log SONAME ‘audit_log.so’;
ERROR 1125 (HY000): Function ‘audit_log’ already exists

So, I ended up needing to restart MySQL if I wanted to re-enable the plugin.

Sometimes the failures are the most illuminating!

[I realize that the plugin probably could not hack FLUSH LOGS but it would be great to get FLUSH AUDIT or something similar…]