PS-269 (Initial Percona Server 8.0 tree) - audit_log

1. (Mostly) fix the audit log plugin:
- set correct flags for PFS memory instrumentation;
- fix undefined behavior in make_argv;
- fix plugin declaration having swapped deinit and check-deinit
  function pointers;
- fix an include in filter.cc;
- re-record some testcases.

2. Fix audit log plugin command filtering.

The initial 8.0 port dropped the lowercasing of passed filter strings
by mistake. Fix by restoring it. At the same time notice that MySQL
collations charsets are not interesting for command names, which are
7-bit ASCII, and so replace collation_unordered_set uses with simpler
malloc_unordered_set.

3. audit_log testcases under 8.0 tend to produce control characters more
often, due to CREATE USER ... IDENTIFIED AS hashes containing
them. There is no good handling option for them in XML 1.0, thus
1) as a lesser evil, print them as numeric sequences anyway, and
replace \0 with ?;
2) patch testcases not to produce control characters if the output is
to be consumed by an XML parser.

4. Avoid undefined behavior in audit_log_update_thd_local by avoiding
passing NULL as source pointer to memcpy, even with zero length.

The UBSan report fixed is

/usr/include/x86_64-linux-gnu/bits/string3.h:53:71: runtime error: null pointer passed as argument 2, which is declared to never be null
    #0 0x7fe5aad56fb1 in memcpy /usr/include/x86_64-linux-gnu/bits/string3.h:53
    #1 0x7fe5aad56fb1 in audit_log_update_thd_local plugin/audit_log/audit_log.cc:987
    #2 0x7fe5aad56fb1 in audit_log_notify plugin/audit_log/audit_log.cc:1105
    #3 0x1ecac37 in plugins_dispatch sql/sql_audit.cc:1284
    #4 0x1ecac37 in event_class_dispatch sql/sql_audit.cc:1322
    #5 0x1ecb311 in event_class_dispatch_error sql/sql_audit.cc:1340
    #6 0x1ed21b1 in mysql_audit_notify(THD*, mysql_event_connection_subclass_t, char const*, int) sql/sql_audit.cc:438
    #7 0x1350071 in check_connection sql/sql_connect.cc:868
    #8 0x1350071 in login_connection sql/sql_connect.cc:929
    #9 0x1357881 in thd_prepare_connection(THD*, bool) sql/sql_connect.cc:1084
    #10 0x1e66347 in handle_connection sql/conn_handler/connection_handler_per_thread.cc:313
    #11 0xb1913a3 in pfs_spawn_thread storage/perfschema/pfs.cc:2836
    #12 0x7fe5d352f6b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
    percona#13 0x7fe5d0bd741c in clone (/lib/x86_64-linux-gnu/libc.so.6+0x10741c)

plugin/audit_log/audit_log.cc

@@ -87,17 +87,17 @@ PSI_memory_key key_memory_audit_log_commands;
 
 static PSI_memory_info all_audit_log_memory[] = {
     {&key_memory_audit_log_logger_handle, "audit_log_logger_handle",
-     PSI_FLAG_SINGLETON, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
-    {&key_memory_audit_log_handler, "audit_log_handler", PSI_FLAG_SINGLETON,
-     PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
-    {&key_memory_audit_log_buffer, "audit_log_buffer", PSI_FLAG_SINGLETON,
-     PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
-    {&key_memory_audit_log_accounts, "audit_log_accounts", PSI_FLAG_SINGLETON,
-     PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
-    {&key_memory_audit_log_databases, "audit_log_databases", PSI_FLAG_SINGLETON,
-     PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
-    {&key_memory_audit_log_commands, "audit_log_commands", PSI_FLAG_SINGLETON,
-     PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+    {&key_memory_audit_log_handler, "audit_log_handler",
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+    {&key_memory_audit_log_buffer, "audit_log_buffer",
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+    {&key_memory_audit_log_accounts, "audit_log_accounts",
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+    {&key_memory_audit_log_databases, "audit_log_databases",
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
+    {&key_memory_audit_log_commands, "audit_log_commands",
+     PSI_FLAG_ONLY_GLOBAL_STAT, PSI_VOLATILITY_UNKNOWN, PSI_DOCUMENT_ME},
 };
 
 static const int audit_log_syslog_facility_codes[] = {
@@ -207,18 +207,20 @@ static void escape_buf(const char *in, size_t *inlen, char *out, size_t *outlen,
 
 static void xml_escape(const char *in, size_t *inlen, char *out,
                        size_t *outlen) noexcept {
-  // Most control sequences aren't supported before XML 1.1, and most
-  // tools only support 1.0. Our output is 1.0. Escaping them wouldn't make
-  // the output more valid.
+  // Although most control sequences aren't supported in XML 1.0, we are better
+  // off printing them anyway instead of the original control characters
   static const escape_rule_t control_rules[] = {
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {'\t', 5, "	"},  {'\n', 6, "
"}, {0, 0, nullptr},
-      {0, 0, nullptr}, {'\r', 6, "
"}, {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
-      {0, 0, nullptr}, {0, 0, nullptr},    {0, 0, nullptr},    {0, 0, nullptr},
+      {0, 1, "?"},       {1, 4, ""},     {2, 4, ""},
+      {3, 4, ""},    {4, 4, ""},     {5, 4, ""},
+      {6, 4, ""},    {7, 4, ""},     {8, 4, ""},
+      {'\t', 4, "	"}, {'\n', 5, "
"}, {11, 5, ""},
+      {12, 5, ""},  {'\r', 5, "
"}, {14, 5, ""},
+      {15, 5, ""},  {16, 5, ""},   {17, 5, ""},
+      {18, 5, ""},  {19, 5, ""},   {20, 5, ""},
+      {21, 5, ""},  {22, 5, ""},   {23, 5, ""},
+      {24, 5, ""},  {25, 5, ""},   {26, 5, ""},
+      {27, 5, ""},  {28, 5, ""},   {29, 5, ""},
+      {30, 5, ""},  {31, 5, ""},
   };
   static const escape_rule_t other_rules[] = {{'<', 4, "&lt;"},
                                               {'>', 4, "&gt;"},
@@ -368,8 +370,12 @@ static char *make_argv(char *buf, size_t len, int argc, char **argv) noexcept {
   size_t left = len;
 
   buf[0] = 0;
-  while (argc > 0 && left > 0) {
-    left -= snprintf(buf + len - left, left, "%s%c", *argv, argc > 1 ? ' ' : 0);
+  while (argc > 0 || left > 0) {
+    const int ret =
+        snprintf(buf + len - left, left, "%s%c", *argv, argc > 1 ? ' ' : 0);
+    DBUG_ASSERT(ret > 0);
+    if (ret < 0 || static_cast<size_t>(ret) >= left) break;
+    left -= ret;
     argc--;
     argv++;
   }
@@ -977,8 +983,9 @@ static bool audit_log_update_thd_local(MYSQL_THD thd,
     if (event_connection->status == 0) {
       /* track default DB change */
       DBUG_ASSERT(event_connection->database.length <= sizeof(local->db));
-      memcpy(local->db, event_connection->database.str,
-             event_connection->database.length);
+      if (event_connection->database.str != nullptr)
+        memcpy(local->db, event_connection->database.str,
+               event_connection->database.length);
       local->db[event_connection->database.length] = 0;
     }
   } else if (event_class == MYSQL_AUDIT_GENERAL_CLASS) {
@@ -1717,9 +1724,9 @@ mysql_declare_plugin(audit_log){
     "Percona LLC and/or its affiliates.", /* author                          */
     "Audit log",                          /* description                     */
     PLUGIN_LICENSE_GPL,
-    audit_log_plugin_init,   /* init function (when loaded)     */
-    audit_log_plugin_deinit, /* deinit function (when unloaded) */
+    audit_log_plugin_init, /* init function (when loaded)     */
     nullptr,
+    audit_log_plugin_deinit,    /* deinit function (when unloaded) */
     PLUGIN_VERSION,             /* version                         */
     audit_log_status_variables, /* status variables                */
     audit_log_system_variables, /* system variables                */

plugin/audit_log/filter.cc

@@ -16,12 +16,13 @@
 
 #include "filter.h"
 
+#include <algorithm>
 #include "audit_log.h"
 #include "m_ctype.h"
 #include "map_helpers.h"
 #include "my_sys.h"
 #include "my_user.h"
-#include "mysql/components/services/mysql_rwlock.h"
+#include "mysql/psi/mysql_rwlock.h"
 #include "mysql_com.h"
 
 static std::string make_account_string(const char *user, size_t user_length,
@@ -36,7 +37,7 @@ static std::string make_account_string(const char *user, size_t user_length,
 
 static std::string make_command_string(const char *name, size_t length) {
   std::string result(name, length);
-  my_casedn_str(&my_charset_utf8_general_ci, const_cast<char *>(result.data()));
+  std::transform(result.begin(), result.end(), result.begin(), ::tolower);
   result.shrink_to_fit();
   return result;
 }
@@ -51,7 +52,7 @@ using db_set_t = collation_unordered_set<std::string>;
 static db_set_t *include_databases;
 static db_set_t *exclude_databases;
 
-using command_set_t = collation_unordered_set<std::string>;
+using command_set_t = malloc_unordered_set<std::string>;
 
 static command_set_t *include_commands;
 static command_set_t *exclude_commands;
@@ -175,20 +176,22 @@ static void database_list_from_string(db_set_t *db_set, const char *string) {
 */
 static void command_list_from_string(command_set_t *command_set,
                                      const char *string) {
-  const char *entry = string;
+  std::string lcase_str(string);
+  std::transform(lcase_str.begin(), lcase_str.end(), lcase_str.begin(),
+                 ::tolower);
 
   command_set->clear();
 
-  while (*entry) {
-    size_t len = 0;
-
-    while (*entry == ' ' || *entry == ',') entry++;
-
-    while (entry[len] != ' ' && entry[len] != ',' && entry[len] != 0) len++;
-
-    if (len > 0) command_set->emplace(entry, len);
-
-    entry += len;
+  auto it = lcase_str.cbegin();
+  while (it != lcase_str.cend()) {
+    std::string::size_type len = 0;
+    while (it != lcase_str.cend() && (*it == ' ' || *it == ',')) it++;
+    while (it + len != lcase_str.cend() && it[len] != ' ' && it[len] != ',')
+      len++;
+    if (len > 0) {
+      command_set->emplace(&(*it), len);
+      it += len;
+    }
   }
 }
 
@@ -215,11 +218,9 @@ void audit_log_filter_init() {
   exclude_databases =
       new db_set_t(&my_charset_bin, key_memory_audit_log_databases);
 
-  include_commands =
-      new command_set_t(&my_charset_bin, key_memory_audit_log_commands);
+  include_commands = new command_set_t(key_memory_audit_log_commands);
 
-  exclude_commands =
-      new command_set_t(&my_charset_bin, key_memory_audit_log_commands);
+  exclude_commands = new command_set_t(key_memory_audit_log_commands);
 }
 
 void audit_log_filter_destroy() noexcept {

plugin/audit_log/tests/mtr/audit_log_charset.result

@@ -9,19 +9,21 @@ Warnings:
 Warning	1300	Invalid utf8mb4 character string: '\xF0\xA6\x89\x98\xF0\xA6...'
 SHOW DATABASES;
 Database
-information_schema
 ???
-ฐานข้อมูล
+information_schema
 mtr
 mysql
 performance_schema
 sys
 test
+ฐานข้อมูล
 use 𦉘𦟌𦧲;
 Warnings:
 Warning	1300	Invalid utf8mb4 character string: '\xF0\xA6\x89\x98\xF0\xA6...'
 use ฐานข้อมูล;
 SET NAMES utf8;
+Warnings:
+Warning	3719	'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
 SELECT * FROM t WHERE txt LIKE 'ขุนนาง%';
 txt
 ขุนนางใช่พ่อแม่ หินแง่ใช่ตายาย
@@ -59,6 +61,7 @@ set global audit_log_flush= ON;
 "Query","<ID>","<DATETIME>","change_db","<CONN_ID>",0,"use 𦉘𦟌𦧲","root[root] @ localhost []","localhost","","","???"
 "Query","<ID>","<DATETIME>","show_warnings","<CONN_ID>",0,"SHOW WARNINGS","root[root] @ localhost []","localhost","","","???"
 "Query","<ID>","<DATETIME>","change_db","<CONN_ID>",0,"use ฐานข้อมูล","root[root] @ localhost []","localhost","","","ฐานข้อมูล"
+"Query","<ID>","<DATETIME>","show_warnings","<CONN_ID>",0,"SHOW WARNINGS","root[root] @ localhost []","localhost","","","ฐานข้อมูล"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM t WHERE txt LIKE 'ขุนนาง%'","root[root] @ localhost []","localhost","","","ฐานข้อมูล"
 "Query","<ID>","<DATETIME>","change_db","<CONN_ID>",0,"use test","root[root] @ localhost []","localhost","","","test"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM ฐานข้อมูล.t LIMIT 1","root[root] @ localhost []","localhost","","","test"

plugin/audit_log/tests/mtr/audit_log_csv.result

@@ -90,14 +90,7 @@ create table sa_t1(id int);
 insert into sa_t1 values (1), (2);
 drop table sa_t1;
 drop database sa_db;
-create user 'jeffrey'@'localhost' IDENTIFIED BY 'mypass';
-drop user 'jeffrey'@'localhost';
 select '&;&&&""""<><<>>>>';
 &;&&&""""<><<>>>>
 &;&&&""""<><<>>>>
-select ' 	
-/"\\';
-/"\
- 	
-/"\
 set global audit_log_flush= ON;

plugin/audit_log/tests/mtr/audit_log_default_db.result

@@ -1,4 +1,6 @@
 set names utf8;
+Warnings:
+Warning	3719	'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
 CREATE USER 'user1'@'%' IDENTIFIED BY '111';
 CREATE USER 'user2'@'%' IDENTIFIED BY '111';
 CREATE DATABASE db1;
@@ -7,6 +9,8 @@ CREATE DATABASE `ąžąžąžą`;
 CREATE TABLE db1.t (a VARCHAR(100));
 CREATE TABLE db2.t (a VARCHAR(100));
 CREATE TABLE ąžąžąžą.t (a VARCHAR(100)) charset=utf8;
+Warnings:
+Warning	3719	'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
 INSERT INTO db1.t VALUES ('db1');
 INSERT INTO db2.t VALUES ('db2');
 INSERT INTO ąžąžąžą.t VALUES ('ąžąžąžą');
@@ -31,6 +35,8 @@ ERROR 28000: Access denied for user 'user2'@'localhost' (using password: YES)
 connect(localhost,user3,111,db2,MASTER_MYPORT,MASTER_MYSOCK);
 ERROR 28000: Access denied for user 'user3'@'localhost' (using password: YES)
 set names utf8;
+Warnings:
+Warning	3719	'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
 SELECT * FROM t;
 a
 db2
@@ -40,6 +46,8 @@ SELECT * FROM t;
 a
 db2
 set names utf8;
+Warnings:
+Warning	3719	'utf8' is currently an alias for the character set UTF8MB3, but will be an alias for UTF8MB4 in a future release. Please consider using UTF8MB4 in order to be unambiguous.
 SELECT * FROM t;
 a
 db1
@@ -67,11 +75,13 @@ set global audit_log_flush= ON;
 "Connect","<ID>","<DATETIME>","<CONN_ID>",1045,"user3","","","","localhost","",""
 "Connect","<ID>","<DATETIME>","<CONN_ID>",0,"user2","user2","","","localhost","","db2"
 "Query","<ID>","<DATETIME>","set_option","<CONN_ID>",0,"set names utf8","user2[user2] @ localhost []","localhost","","","db2"
+"Query","<ID>","<DATETIME>","show_warnings","<CONN_ID>",0,"SHOW WARNINGS","user2[user2] @ localhost []","localhost","","","db2"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM t","user2[user2] @ localhost []","localhost","","","db2"
 "Query","<ID>","<DATETIME>","change_db","<CONN_ID>",1044,"use    	`db1`","user2[user2] @ localhost []","localhost","","","db2"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM t","user2[user2] @ localhost []","localhost","","","db2"
 "Change user","<ID>","<DATETIME>","<CONN_ID>",0,"user1","user1","","","localhost","","db1"
 "Query","<ID>","<DATETIME>","set_option","<CONN_ID>",0,"set names utf8","user1[user1] @ localhost []","localhost","","","db1"
+"Query","<ID>","<DATETIME>","show_warnings","<CONN_ID>",0,"SHOW WARNINGS","user1[user1] @ localhost []","localhost","","","db1"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM t","user1[user1] @ localhost []","localhost","","","db1"
 "Query","<ID>","<DATETIME>","change_db","<CONN_ID>",0,"use `db2`","user1[user1] @ localhost []","localhost","","","db2"
 "Query","<ID>","<DATETIME>","select","<CONN_ID>",0,"SELECT * FROM t","user1[user1] @ localhost []","localhost","","","db2"

plugin/audit_log/tests/mtr/audit_log_events.inc

@@ -88,10 +88,15 @@ insert into sa_t1 values (1), (2);
 drop table sa_t1;
 drop database sa_db;
 connection default;
-create user 'jeffrey'@'localhost' IDENTIFIED BY 'mypass';
-drop user 'jeffrey'@'localhost';
+# IDENTIFIED BY will be logged as IDENTIFIED ... AS, containing control chars
+if ($test_control_chars) {
+  create user 'jeffrey'@'localhost' IDENTIFIED BY 'mypass';
+  drop user 'jeffrey'@'localhost';
+}
 select '&;&&&""""<><<>>>>';
-let $str=`SELECT x'2009080c0a0d2f225c5c'`;
-eval select '$str';
+if ($test_control_chars) {
+  let $str=`SELECT x'2009080c0a0d2f225c5c'`;
+  eval select '$str';
+}
 disconnect con1;
 --source include/wait_until_count_sessions.inc