MySQL Bugs: #72515: Audit log plugin generates error when restarting crashed server

Bug #72515	Audit log plugin generates error when restarting crashed server
Submitted:	2 May 2014 15:34	Modified:	4 May 2014 7:07
Reporter:	Nicolas De Rico	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S4 (Feature request)
Version:	5.6	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	audit, Audit plugin, MySQL, server

Description:
When the MySQL server crashes while the audit log plugin is enabled, it may not be able to restart without first rotating or deleting the audit.log file.  This seems to be caused by the plugin validating that the XML content in the existing audit.log is formatted properly, which may not be the case following a crash.

How to repeat:
my.conf:

...
plugin-load = audit_log.so
audit-log                = FORCE_PLUS_PERMANENT
audit_log_format         = NEW
audit_log_rotate_on_size = 64M
audit_log_strategy       = SYNCHRONOUS
...

# service mysql start
# pkill -9 mysqld
# service mysql start

ERROR! (even mysqld_safe cannot help recover from that, off course)

Suggested fix:
1- If the XML tags are not "closed", close them.
2- If (1) fails, rotate the audit.log file to an audit.<timestamp>.bad file and start a new audit.log.

Hello Nicolas,

Thanks for your bug report.  This behavior is consistent with the documentation:

 If the log file exists at open time, the plugin checks whether the file ends with an </AUDIT> tag and truncates it if so before writing any <AUDIT_RECORD> elements. If the log file exists but does not end with </AUDIT> or the </AUDIT> tag cannot be truncated, the plugin considers the file malformed and fails to initialize. This can occur if the server crashes or is killed with the audit log plugin running. No logging occurs until the problem is rectified. Check the error log for diagnostic information:

[ERROR] Plugin 'audit_log' init function returned error.

To deal with this problem, you must either remove or rename the malformed log file and restart the server. 

http://dev.mysql.com/doc/refman/5.5/en/audit-log-plugin-logging-control.html

This exists in part to prevent multiple mysqld instances from writing to the same audit log file.  It does require consideration in a crash recovery scenario, but the error message should provide meaningful diagnostic information when the server does not restart in an automated manner.

Given that this is documented (and intentional) behavior, I don't think this is a bug.  However, perhaps it's a viable feature request to allow configuration of the audit log plugin such that missing XML close tags don't prevent startup.  Do you agree with that approach?

Yes absolutely.  I will change to feature request.