MDEV-7596 audit plugin - record full query / document line length / make buffer configurable.

        The serve_audit_query_log_limit variable implemented.
        Also QUERY_DCL filter added.

3 files changed, 166 insertions, 28 deletions

diff --git a/mysql-test/suite/plugins/r/server_audit.result b/mysql-test/suite/plugins/r/server_audit.result
index d38f194f31b..c9ec79dbafe 100644
--- a/mysql-test/suite/plugins/r/server_audit.result
+++ b/mysql-test/suite/plugins/r/server_audit.result
@@ -11,6 +11,7 @@ server_audit_incl_users
 server_audit_logging	OFF
 server_audit_mode	0
 server_audit_output_type	file
+server_audit_query_log_limit	1024
 server_audit_syslog_facility	LOG_USER
 server_audit_syslog_ident	mysql-server_auditing
 server_audit_syslog_info	
@@ -68,6 +69,7 @@ server_audit_incl_users	odin, root, dva, tri
 server_audit_logging	ON
 server_audit_mode	0
 server_audit_output_type	file
+server_audit_query_log_limit	1024
 server_audit_syslog_facility	LOG_USER
 server_audit_syslog_ident	mysql-server_auditing
 server_audit_syslog_info	
@@ -145,7 +147,40 @@ select 2;
 2
 2
 drop table t1;
+set global server_audit_events='query_dcl';
+create table t1(id int);
+insert into t1 values (1), (2);
+select * from t1;
+id
+1
+2
+CREATE USER u1 IDENTIFIED BY 'pwd-123';
+GRANT ALL ON sa_db TO u2 IDENTIFIED BY "pwd-321";
+SET PASSWORD FOR u1 = PASSWORD('pwd 098');
+CREATE USER u3 IDENTIFIED BY '';
+drop user u1, u2, u3;
+select 2;
+2
+2
+(select 2);
+2
+2
+/*! select 2*/;
+2
+2
+/*comment*/ select 2;
+2
+2
+drop table t1;
 set global server_audit_events='';
+set global server_audit_query_log_limit= 15;
+select (1), (2), (3), (4);
+1	2	3	4
+1	2	3	4
+select 'A', 'B', 'C', 'D';
+A	B	C	D
+A	B	C	D
+set global server_audit_query_log_limit= 1024;
 drop database sa_db;
 set global server_audit_file_path='.';
 show status like 'server_audit_current_log';
@@ -177,6 +212,7 @@ server_audit_incl_users	odin, root, dva, tri
 server_audit_logging	ON
 server_audit_mode	1
 server_audit_output_type	file
+server_audit_query_log_limit	1024
 server_audit_syslog_facility	LOG_USER
 server_audit_syslog_ident	mysql-server_auditing
 server_audit_syslog_info	
@@ -279,7 +315,16 @@ TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'select 2',0
 TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'(select 2)',0
 TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'/*! select 2*/',0
 TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'/*comment*/ select 2',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'CREATE USER u1 IDENTIFIED BY *****',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'GRANT ALL ON sa_db TO u2 IDENTIFIED BY *****',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'SET PASSWORD FOR u1 = PASSWORD(*****)',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'CREATE USER u3 IDENTIFIED BY *****',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'drop user u1, u2, u3',0
 TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'set global server_audit_events=\'\'',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'set global serv',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'select (1), (2)',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'select \'A\', ',0
+TIME,HOSTNAME,root,localhost,ID,ID,QUERY,sa_db,'set global server_audit_query_log_limit= 1024',0
 TIME,HOSTNAME,root,localhost,ID,ID,READ,mysql,proc,
 TIME,HOSTNAME,root,localhost,ID,ID,WRITE,mysql,proc,
 TIME,HOSTNAME,root,localhost,ID,ID,WRITE,mysql,event,
diff --git a/mysql-test/suite/plugins/t/server_audit.test b/mysql-test/suite/plugins/t/server_audit.test
index 8a131ff5f70..3c9544d61f4 100644
--- a/mysql-test/suite/plugins/t/server_audit.test
+++ b/mysql-test/suite/plugins/t/server_audit.test
@@ -95,7 +95,26 @@ select 2;
 /*! select 2*/;
 /*comment*/ select 2;
 drop table t1;
+set global server_audit_events='query_dcl';
+create table t1(id int);
+insert into t1 values (1), (2);
+select * from t1;
+CREATE USER u1 IDENTIFIED BY 'pwd-123';
+GRANT ALL ON sa_db TO u2 IDENTIFIED BY "pwd-321";
+SET PASSWORD FOR u1 = PASSWORD('pwd 098');
+CREATE USER u3 IDENTIFIED BY '';
+drop user u1, u2, u3;
+select 2;
+(select 2);
+/*! select 2*/;
+/*comment*/ select 2;
+drop table t1;
 set global server_audit_events='';
+
+set global server_audit_query_log_limit= 15;
+select (1), (2), (3), (4);
+select 'A', 'B', 'C', 'D';
+set global server_audit_query_log_limit= 1024;
 drop database sa_db;
 
 set global server_audit_file_path='.';
diff --git a/plugin/server_audit/server_audit.c b/plugin/server_audit/server_audit.c
index ce5d5397d9b..a4d726b0c7d 100644
--- a/plugin/server_audit/server_audit.c
+++ b/plugin/server_audit/server_audit.c
@@ -14,8 +14,8 @@
    Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA */
 
 
-#define PLUGIN_VERSION 0x102
-#define PLUGIN_STR_VERSION "1.2.0"
+#define PLUGIN_VERSION 0x103
+#define PLUGIN_STR_VERSION "1.3.0"
 
 #include <my_config.h>
 #include <stdio.h>
@@ -185,6 +185,9 @@ static char logging;
 static int internal_stop_logging= 0;
 static char incl_user_buffer[1024];
 static char excl_user_buffer[1024];
+static char *big_buffer= NULL;
+static size_t big_buffer_alloced= 0;
+static unsigned int query_log_limit= 0;
 
 static char servhost[256];
 static size_t servhost_len;
@@ -227,14 +230,15 @@ static MYSQL_SYSVAR_STR(excl_users, excl_users, PLUGIN_VAR_RQCMDARG,
 /* bits in the event filter. */
 #define EVENT_CONNECT 1
 #define EVENT_QUERY_ALL 2
-#define EVENT_QUERY 26
+#define EVENT_QUERY 58
 #define EVENT_TABLE 4
 #define EVENT_QUERY_DDL 8
 #define EVENT_QUERY_DML 16
+#define EVENT_QUERY_DCL 32
 
 static const char *event_names[]=
 {
-  "CONNECT", "QUERY", "TABLE", "QUERY_DDL", "QUERY_DML",
+  "CONNECT", "QUERY", "TABLE", "QUERY_DDL", "QUERY_DML", "QUERY_DCL",
   NULL
 };
 static TYPELIB events_typelib=
@@ -279,6 +283,9 @@ static MYSQL_SYSVAR_STR(syslog_ident, syslog_ident, PLUGIN_VAR_RQCMDARG,
 static MYSQL_SYSVAR_STR(syslog_info, syslog_info,
        PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_MEMALLOC,
        "The <info> string to be added to the SYSLOG record.", NULL, NULL, "");
+static MYSQL_SYSVAR_UINT(query_log_limit, query_log_limit,
+       PLUGIN_VAR_OPCMDARG, "Limit on the length of the query string in a record.",
+       NULL, NULL, 1024, 0, 0x7FFFFFFF, 1);
 
 static const char *syslog_facility_names[]=
 {
@@ -358,6 +365,7 @@ static struct st_mysql_sys_var* vars[] = {
     MYSQL_SYSVAR(syslog_ident),
     MYSQL_SYSVAR(syslog_facility),
     MYSQL_SYSVAR(syslog_priority),
+    MYSQL_SYSVAR(query_log_limit),
     NULL
 };
 
@@ -382,9 +390,11 @@ static struct st_mysql_show_var audit_status[]=
 static PSI_mutex_key key_LOCK_operations;
 static PSI_mutex_info mutex_key_list[]=
 {{ &key_LOCK_operations, "SERVER_AUDIT_plugin::lock_operations",
+{{ &key_LOCK_bigbuffer, "SERVER_AUDIT_plugin::lock_bigbuffer",
    PSI_FLAG_GLOBAL}};
 #endif
 static mysql_mutex_t lock_operations;
+static mysql_mutex_t lock_bigbuffer;
 
 /* The Percona server and partly MySQL don't support         */
 /* launching client errors in the 'update_variable' methods. */
@@ -617,6 +627,18 @@ struct sa_keyword dml_keywords[]=
 };
 
 
+struct sa_keyword dcl_keywords[]=
+{
+  {6, "CREATE", &user_word, SQLCOM_DCL},
+  {4, "DROP", &user_word, SQLCOM_DCL},
+  {6, "RENAME", &user_word, SQLCOM_DCL},
+  {5, "GRANT", 0, SQLCOM_DCL},
+  {6, "REVOKE", 0, SQLCOM_DCL},
+  {3, "SET", &password_word, SQLCOM_DCL},
+  {0, NULL, 0, SQLCOM_DDL}
+};
+
+
 struct sa_keyword passwd_keywords[]=
 {
   {3, "SET", &password_word, SQLCOM_SET_OPTION},
@@ -1084,11 +1106,15 @@ static size_t escape_string(const char *str, unsigned int len,
       break;
     if (*str == '\'')
     {
+      if (result+1 >= res_end)
+        break;
       *(result++)= '\\';
       *(result++)= '\'';
     }
     else if (*str == '\\')
     {
+      if (result+1 >= res_end)
+        break;
       *(result++)= '\\';
       *(result++)= '\\';
     }
@@ -1173,11 +1199,15 @@ no_password:
       break;
     if (*str == '\'')
     {
+      if (result+1 >= res_end)
+        break;
       *(result++)= '\\';
       *(result++)= '\'';
     }
     else if (*str == '\\')
     {
+      if (result+1 >= res_end)
+        break;
       *(result++)= '\\';
       *(result++)= '\\';
     }
@@ -1307,12 +1337,16 @@ static int log_statement_ex(const struct connection_info *cn,
                             const char *query, unsigned int query_len,
                             int error_code, const char *type)
 {
-  size_t csize, esc_q_len;
-  char message[1024];
-  char uh_buffer[768];
+  size_t csize;
+  char message_loc[1024];
+  char *message= message_loc;
+  size_t message_size= sizeof(message_loc);
+  char *uh_buffer;
+  size_t uh_buffer_size;
   const char *db;
   unsigned int db_length;
   long long query_id;
+  int result;
 
   if ((db= cn->db))
     db_length= cn->db_length;
@@ -1325,14 +1359,6 @@ static int log_statement_ex(const struct connection_info *cn,
   if (!(query_id= cn->query_id))
     query_id= query_counter++;
 
-  csize= log_header(message, sizeof(message)-1, &ev_time,
-                    servhost, servhost_len,
-                    cn->user, cn->user_length,cn->host, cn->host_length,
-                    cn->ip, cn->ip_length, thd_id, query_id, type);
-
-  csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize,
-      ",%.*s", db_length, db);
-
   if (query == 0)
   {
     /* Can happen after the error in mysqld_prepare_stmt() */
@@ -1374,45 +1400,89 @@ static int log_statement_ex(const struct connection_info *cn,
       if (filter_query_type(query, dml_keywords))
         goto do_log_query;
     }
+    if (events & EVENT_QUERY_DCL)
+    {
+      if (filter_query_type(query, dcl_keywords))
+        goto do_log_query;
+    }
 
     return 0;
 do_log_query:
     query= orig_query;
   }
 
+  csize= log_header(message, message_size-1, &ev_time,
+                    servhost, servhost_len,
+                    cn->user, cn->user_length,cn->host, cn->host_length,
+                    cn->ip, cn->ip_length, thd_id, query_id, type);
+
+  csize+= my_snprintf(message+csize, message_size - 1 - csize,
+      ",%.*s,\'", db_length, db);
+
+  if (query_log_limit > 0 && query_len > query_log_limit)
+    query_len= query_log_limit;
+
+  if (query_len > (message_size - csize)/2)
+  {
+    flogger_mutex_lock(&lock_bigbuffer);
+    if (big_buffer_alloced < (query_len * 2 + csize))
+    {
+      big_buffer_alloced= (query_len * 2 + csize + 4095) & ~4095L;
+      big_buffer= realloc(big_buffer, big_buffer_alloced);
+      if (big_buffer == NULL)
+      {
+        big_buffer_alloced= 0;
+        return 0;
+      }
+    }
+
+    memcpy(big_buffer, message, csize);
+    message= big_buffer;
+    message_size= big_buffer_alloced;
+  }
+
+  uh_buffer= message + csize;
+  uh_buffer_size= message_size - csize;
+  if (query_log_limit > 0 && uh_buffer_size > query_log_limit+2)
+    uh_buffer_size= query_log_limit+2;
+
   switch (filter_query_type(query, passwd_keywords))
   {
     case SQLCOM_GRANT:
     case SQLCOM_CREATE_USER:
-      esc_q_len= escape_string_hide_passwords(query, query_len,
-                                           uh_buffer, sizeof(uh_buffer),
+      csize+= escape_string_hide_passwords(query, query_len,
+                                           uh_buffer, uh_buffer_size,
                                            "IDENTIFIED", 10, "BY", 2, 0);
       break;
     case SQLCOM_CHANGE_MASTER:
-      esc_q_len= escape_string_hide_passwords(query, query_len,
-                                           uh_buffer, sizeof(uh_buffer),
+      csize+= escape_string_hide_passwords(query, query_len,
+                                           uh_buffer, uh_buffer_size,
                                            "MASTER_PASSWORD", 15, "=", 1, 0);
       break;
     case SQLCOM_CREATE_SERVER:
     case SQLCOM_ALTER_SERVER:
-      esc_q_len= escape_string_hide_passwords(query, query_len,
-                                           uh_buffer, sizeof(uh_buffer),
+      csize+= escape_string_hide_passwords(query, query_len,
+                                           uh_buffer, uh_buffer_size,
                                            "PASSWORD", 8, NULL, 0, 0);
       break;
     case SQLCOM_SET_OPTION:
-      esc_q_len= escape_string_hide_passwords(query, query_len,
-                                           uh_buffer, sizeof(uh_buffer),
+      csize+= escape_string_hide_passwords(query, query_len,
+                                           uh_buffer, uh_buffer_size,
                                            "=", 1, NULL, 0, 1);
       break;
     default:
-      esc_q_len= escape_string(query, query_len,
-                               uh_buffer, sizeof(uh_buffer)); 
+      csize+= escape_string(query, query_len,
+                               uh_buffer, uh_buffer_size); 
       break;
   }
-  csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize,
-           ",\'%.*s\',%d", esc_q_len, uh_buffer, error_code);
+  csize+= my_snprintf(message+csize, message_size - 1 - csize,
+                      "\',%d", error_code);
   message[csize]= '\n';
-  return write_log(message, csize + 1);
+  result= write_log(message, csize + 1);
+  if (message == big_buffer)
+    flogger_mutex_unlock(&lock_bigbuffer);
+
+  return result;
 }
 
 
@@ -1980,6 +2050,7 @@ static int server_audit_init(void *p __attribute__((unused)))
     PSI_server->register_mutex("server_audit", mutex_key_list, 1);
 #endif
   flogger_mutex_init(key_LOCK_operations, &lock_operations, MY_MUTEX_INIT_FAST);
+  flogger_mutex_init(key_LOCK_operations, &lock_bigbuffer, MY_MUTEX_INIT_FAST);
 
   my_hash_clear(&incl_user_hash);
   my_hash_clear(&excl_user_hash);
@@ -2056,7 +2127,10 @@ static int server_audit_deinit(void *p __attribute__((unused)))
     logger_close(logfile);
   else if (output_type == OUTPUT_SYSLOG)
     closelog();
+
+  (void) free(big_buffer);
   flogger_mutex_destroy(&lock_operations);
+  flogger_mutex_destroy(&lock_bigbuffer);
 
   error_header();
   fprintf(stderr, "STOPPED\n");