audit_log: malformed record could be written after audit_log_flush=ON in ASYNC and PERFORMANCE modes

[Sergei Glushchenko]

Parser reporting

not well-formed (invalid token) at line 639, column 12, byte 20241 at /usr/lib/x86_64-linux-gnu/perl5/5.20/XML/Parser.pm line 187.

but in my testing environment the log file is only 18919 bytes and 577 lines.

We need to add the code to print the entire file in case of parser error to diagnose the issue.

[Sergei Glushchenko (sergei.glushchenko)]

Malformed record appears at the end of the file and it looks like:

<AUDIT_RECORD
  NAME=</AUDIT>
"Query"
  RECORD="40_2016-08-25T14:07:40"
  TIMESTAMP="2016-08-25T14:07:40 UTC"
  COMMAND_CLASS="select"
  CONNECTION_ID="122"
  STATUS="0"
  SQLTEXT="select '&amp;;&amp;&amp;&amp;&quot;&quot;&quot;&quot;&lt;&gt;&lt;&lt;&gt;&gt;&gt;&gt;'"
  USER="root[root] @ localhost []"
  HOST="localhost"
  OS_USER=""
  IP=""
  DB="test"
/>

Note that </AUDIT> is written in the middle of <AUDIT_RECORD>. Probably footer (which is written by logger_close) interferes with the usual record written by flush thread.

[Sergei Glushchenko (sergei.glushchenko)]

https://github.com/percona/percona-server/pull/923
https://github.com/percona/percona-server/pull/924

[Laurynas Biveinis (laurynas-biveinis)]

Sergei, please edit the title of the bug for the underlying issue, this will need a proper release notes entry

[Sergei Glushchenko (sergei.glushchenko)]

https://github.com/percona/percona-server/pull/925

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-996