Category Archives: Server Tuning

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

Copyright (c) 2009-2016 Percona LLC and/or its affiliates
Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.

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)]> \P grep -i audit
PAGER set to ‘grep -i audit’
[(none)]> SHOW PLUGINS;
| audit_log | DELETED | AUDIT | audit_log.so | GPL |
41 rows in set (0.00 sec)

[(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…]

Unintentional Googlewhack Leads to MySQL Bug Report

While doing a standard audit for a new client, I recommended a few changes to get better performance. Because I had several changes, I used the documentation at

http://dev.mysql.com/doc/refman/5.0/en/server-system-variables.html

and found that innodb_flush_log_at_trx_commit is a dynamic variable. I was surprised, because most operations dealing with file sizes and operations …

Neighborhoods and Communities

Recently I acquired Sesame Street Volume 1, and on the third DVD in the set I came across one of my favorite Sesame Street songs: “Who are the people in your neighborhood?”

Here’s a sample of one such skit, if you are not familiar with it, or if you want …

Simple MySQL Proxy Failover

mysql-proxy defaults to round-robin load balancing. There are fancy tricks around to get mysql-proxy to balance connections based on how many idle connections there are in a proxy-based connection pool.

But there is no code that I found that would simply load balance based on “always go to …

Does MySQL Send Passwords In the Clear?

I was asked this question recently, and I thought it was a great little tidbit of knowledge to pass along. The short answer is “no”. The slightly longer answer was written up by Jan Kneschke when dealing with a forum post about proxy + connection pooling.

From http://forums.mysql.com/read.php?146,169265,169700

The clear-text …

Hating MySQL for the Wrong Reason

In Spotting the Wolf in Sheep’s Clothing, Frank Mash writes about a specific person who is spreading fear, uncertainty and doubt about MySQL.

Now, this always gets me, especially with MySQL. For how long will MySQL be the bastard stepchild of the database world? Because really, it’s been a …

Saying What You Mean

Ah, the perils of working in a shared, client environment. One client has us using a login that is not exclusive to us. I prefer using bash; the client is set to use zsh. This is not a problem in and of itself.

However, there is a section …

Pop Quiz: MySQL Password Hashing

The answers to the last pop quiz are up: http://www.pythian.com/blogs/868/pop-quiz-mysql-cluster

So here’s another pop quiz. Given the following:

Welcome to the MySQL monitor. Commands end with ; or g.
Your MySQL connection id is 16450949 to server version: 4.1.14-standard-log

Type ‘help;’ or ‘h’ for help. Type ‘c’ to clear the buffer.

mysql> …

Pop Quiz: MySQL Cluster

If you have a 12-server MySQL Cluster with:
1 Management Node
3 SQL Nodes
2 Data Node Groups, 4 Data Nodes per group
And each machine is configured to allocate 1G of memory for its function, how much data (data + indexes) can you store in total in your cluster?
You can guess, but you get bonus points if you […]

Automating To Save Time

This is the first place I am announcing this: The Pythian Group has made me a Team Lead. I am extremely honored and somewhat humbled by this, and I am determined to do a good job. I started officially on Monday, March 3rd, and my first week went pretty well.
On […]