From 069fde765016f0c74c61308a0c14d1d3030b7511 Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Mon, 9 Feb 2026 01:44:27 +0530 Subject: [PATCH 1/7] MDEV-18386: Add server_audit_timestamp_format to customize audit log timestamps --- .../suite/plugins/r/server_audit.result | 3 ++ .../plugins/r/server_audit_buffering.result | 1 + .../plugins/r/server_audit_timestamp.result | 26 ++++++++++++++ .../plugins/r/thread_pool_server_audit.result | 3 ++ .../plugins/t/server_audit_timestamp.opt | 4 +++ .../plugins/t/server_audit_timestamp.test | 34 +++++++++++++++++++ plugin/server_audit/server_audit.cc | 24 ++++++++++++- 7 files changed, 94 insertions(+), 1 deletion(-) create mode 100644 mysql-test/suite/plugins/r/server_audit_timestamp.result create mode 100644 mysql-test/suite/plugins/t/server_audit_timestamp.opt create mode 100644 mysql-test/suite/plugins/t/server_audit_timestamp.test diff --git a/mysql-test/suite/plugins/r/server_audit.result b/mysql-test/suite/plugins/r/server_audit.result index 7160789b8e6fb..34a59494929a3 100644 --- a/mysql-test/suite/plugins/r/server_audit.result +++ b/mysql-test/suite/plugins/r/server_audit.result @@ -18,6 +18,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format set global server_audit_file_path=null; set global server_audit_incl_users=null; set global server_audit_file_path='server_audit.log'; @@ -104,6 +105,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format set global server_audit_mode=1; set global server_audit_events=''; create database sa_db; @@ -336,6 +338,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format uninstall plugin server_audit; Warnings: Warning 1620 Plugin is busy and will be uninstalled on shutdown diff --git a/mysql-test/suite/plugins/r/server_audit_buffering.result b/mysql-test/suite/plugins/r/server_audit_buffering.result index 9d4c27a726234..580875d9d6c8a 100644 --- a/mysql-test/suite/plugins/r/server_audit_buffering.result +++ b/mysql-test/suite/plugins/r/server_audit_buffering.result @@ -19,6 +19,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format set global server_audit_logging=on; set global server_audit_sync_log_file=on; Line count in file: 52 diff --git a/mysql-test/suite/plugins/r/server_audit_timestamp.result b/mysql-test/suite/plugins/r/server_audit_timestamp.result new file mode 100644 index 0000000000000..81fa61133ffb8 --- /dev/null +++ b/mysql-test/suite/plugins/r/server_audit_timestamp.result @@ -0,0 +1,26 @@ +set global server_audit_logging=on; +select 1; +1 +1 +set global server_audit_timestamp_format='CUSTOM-DATE %Y-%m-%d'; +select 2; +2 +2 +set global server_audit_timestamp_format='CUSTOM-TZ %H:%M:%S %z'; +select 3; +3 +3 +set global server_audit_timestamp_format=''; +select 4; +4 +4 +set global server_audit_logging=off; +TIMESTAMP,HOSTNAME,root,localhost,4,23,QUERY,test,'set global server_audit_logging=on',0 +TIMESTAMP,HOSTNAME,root,localhost,4,24,QUERY,test,'select 1',0 +CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,4,25,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-DATE %Y-%m-%d\'',0 +CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,4,26,QUERY,test,'select 2',0 +CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,4,27,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-TZ %H:%M:%S %z\'',0 +CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,4,28,QUERY,test,'select 3',0 +TIMESTAMP,HOSTNAME,root,localhost,4,29,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 +TIMESTAMP,HOSTNAME,root,localhost,4,30,QUERY,test,'select 4',0 +TIMESTAMP,HOSTNAME,root,localhost,4,31,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/r/thread_pool_server_audit.result b/mysql-test/suite/plugins/r/thread_pool_server_audit.result index 3b6d7d870010a..42658750b9bfa 100644 --- a/mysql-test/suite/plugins/r/thread_pool_server_audit.result +++ b/mysql-test/suite/plugins/r/thread_pool_server_audit.result @@ -18,6 +18,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format set global server_audit_file_path=null; set global server_audit_incl_users=null; set global server_audit_file_path='server_audit.log'; @@ -89,6 +90,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format set global server_audit_mode=1; set global server_audit_events=''; create database sa_db; @@ -242,6 +244,7 @@ server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info server_audit_syslog_priority LOG_INFO +server_audit_timestamp_format uninstall plugin server_audit; Warnings: Warning 1620 Plugin is busy and will be uninstalled on shutdown diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.opt b/mysql-test/suite/plugins/t/server_audit_timestamp.opt new file mode 100644 index 0000000000000..f42cc19b15a0e --- /dev/null +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.opt @@ -0,0 +1,4 @@ +--plugin-load-add=server_audit +--server_audit_file_path='server_audit_timestamp.log' +--server_audit_output_type=file +--server_audit_events='query' diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.test b/mysql-test/suite/plugins/t/server_audit_timestamp.test new file mode 100644 index 0000000000000..792751a27269f --- /dev/null +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.test @@ -0,0 +1,34 @@ +--source include/not_embedded.inc + +if (!$SERVER_AUDIT_SO) { + skip No SERVER_AUDIT plugin; +} + +# The plugin is loaded via .opt file +let $MYSQLD_DATADIR= `SELECT @@datadir`; +let SEARCH_FILE= $MYSQLD_DATADIR/server_audit_timestamp.log; + +set global server_audit_logging=on; + +# Default format +select 1; + +# Custom format 1: Just date +set global server_audit_timestamp_format='CUSTOM-DATE %Y-%m-%d'; +select 2; + +# Custom format 2: Including timezone (if supported by system strftime) +set global server_audit_timestamp_format='CUSTOM-TZ %H:%M:%S %z'; +select 3; + +# Revert to default +set global server_audit_timestamp_format=''; +select 4; + +set global server_audit_logging=off; + +# We use replace_regex to mask the actual volatile parts but keep our prefixes +--replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),/,HOSTNAME,root,localhost,/ +cat_file $SEARCH_FILE; + +remove_file $SEARCH_FILE; diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index 54c8c3f8dc9be..e3546e554e15f 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -103,7 +103,7 @@ static void closelog() {} const char *(*thd_priv_host_ptr)(MYSQL_THD thd, size_t *length); static char *incl_users, *excl_users, - *file_path, *syslog_info; + *file_path, *syslog_info, *timestamp_format; static char path_buffer[FN_REFLEN]; static unsigned int mode; static ulong output_type; @@ -269,6 +269,10 @@ static MYSQL_SYSVAR_STR(syslog_info, syslog_info, 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 MYSQL_SYSVAR_STR(timestamp_format, timestamp_format, + PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_MEMALLOC, + "The format string the strftime() routine applies with its format argument", + NULL, NULL, ""); char locinfo_ini_value[sizeof(struct connection_info)+4]; @@ -353,6 +357,7 @@ static struct st_mysql_sys_var* vars[] = { MYSQL_SYSVAR(syslog_facility), MYSQL_SYSVAR(syslog_priority), MYSQL_SYSVAR(query_log_limit), + MYSQL_SYSVAR(timestamp_format), MYSQL_SYSVAR(loc_info), NULL }; @@ -1183,6 +1188,23 @@ static size_t log_header(char *message, size_t message_len, connection_id, query_id, operation); (void) localtime_r(ts, &tm_time); + if (timestamp_format && timestamp_format[0]) + { + char ts_buffer[128]; + size_t ts_len= strftime(ts_buffer, sizeof(ts_buffer), + timestamp_format, &tm_time); + if (ts_len) + { + return my_snprintf(message, message_len, + "%s,%.*s,%.*s,%.*s%s,%d,%lld,%s", + ts_buffer, + (int) serverhost_len, serverhost, + username_len, username, + host_len, host, port_str, + connection_id, query_id, operation); + } + } + return my_snprintf(message, message_len, "%04d%02d%02d %02d:%02d:%02d,%.*s,%.*s,%.*s%s,%d,%lld,%s", tm_time.tm_year+1900, tm_time.tm_mon+1, tm_time.tm_mday, From 1d7a2869799609bdc0e84844324228df6ac53e1d Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Mon, 9 Feb 2026 13:31:17 +0530 Subject: [PATCH 2/7] MDEV-18386: Fix server_audit_timestamp tests --- .../plugins/r/server_audit_timestamp.result | 18 +++++++++--------- .../plugins/t/server_audit_timestamp.test | 5 ++++- 2 files changed, 13 insertions(+), 10 deletions(-) diff --git a/mysql-test/suite/plugins/r/server_audit_timestamp.result b/mysql-test/suite/plugins/r/server_audit_timestamp.result index 81fa61133ffb8..c20e69ccd0f23 100644 --- a/mysql-test/suite/plugins/r/server_audit_timestamp.result +++ b/mysql-test/suite/plugins/r/server_audit_timestamp.result @@ -15,12 +15,12 @@ select 4; 4 4 set global server_audit_logging=off; -TIMESTAMP,HOSTNAME,root,localhost,4,23,QUERY,test,'set global server_audit_logging=on',0 -TIMESTAMP,HOSTNAME,root,localhost,4,24,QUERY,test,'select 1',0 -CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,4,25,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-DATE %Y-%m-%d\'',0 -CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,4,26,QUERY,test,'select 2',0 -CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,4,27,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-TZ %H:%M:%S %z\'',0 -CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,4,28,QUERY,test,'select 3',0 -TIMESTAMP,HOSTNAME,root,localhost,4,29,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 -TIMESTAMP,HOSTNAME,root,localhost,4,30,QUERY,test,'select 4',0 -TIMESTAMP,HOSTNAME,root,localhost,4,31,QUERY,test,'set global server_audit_logging=off',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=on',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 1',0 +CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-DATE %Y-%m-%d\'',0 +CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 2',0 +CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-TZ %H:%M:%S %z\'',0 +CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 3',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 4',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.test b/mysql-test/suite/plugins/t/server_audit_timestamp.test index 792751a27269f..7342a62702dcd 100644 --- a/mysql-test/suite/plugins/t/server_audit_timestamp.test +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.test @@ -4,6 +4,9 @@ if (!$SERVER_AUDIT_SO) { skip No SERVER_AUDIT plugin; } +--disable_ps_protocol +--disable_view_protocol + # The plugin is loaded via .opt file let $MYSQLD_DATADIR= `SELECT @@datadir`; let SEARCH_FILE= $MYSQLD_DATADIR/server_audit_timestamp.log; @@ -28,7 +31,7 @@ select 4; set global server_audit_logging=off; # We use replace_regex to mask the actual volatile parts but keep our prefixes ---replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),/,HOSTNAME,root,localhost,/ +--replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ cat_file $SEARCH_FILE; remove_file $SEARCH_FILE; From ab99fdb3af81ad622408dab5bb04f53f7ea4a4a5 Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Wed, 11 Feb 2026 23:37:30 +0530 Subject: [PATCH 3/7] MDEV-18386: Make server_audit_timestamp_format thread-safe and robust --- .../plugins/r/server_audit_timestamp.result | 22 ++++++++ .../plugins/t/server_audit_timestamp.test | 16 +++++- plugin/server_audit/server_audit.cc | 55 +++++++++++++++++-- 3 files changed, 88 insertions(+), 5 deletions(-) diff --git a/mysql-test/suite/plugins/r/server_audit_timestamp.result b/mysql-test/suite/plugins/r/server_audit_timestamp.result index c20e69ccd0f23..0d382f4ae7b97 100644 --- a/mysql-test/suite/plugins/r/server_audit_timestamp.result +++ b/mysql-test/suite/plugins/r/server_audit_timestamp.result @@ -14,7 +14,23 @@ set global server_audit_timestamp_format=''; select 4; 4 4 +# +# Error handling for long timestamp format +# +set global server_audit_timestamp_format='%H:%M:%S'; +show variables like 'server_audit_timestamp_format'; +Variable_name Value +server_audit_timestamp_format %H:%M:%S +# Attempting to set an excessively long format string. +set global server_audit_timestamp_format='AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA'; +Warnings: +Warning 1 server_audit_timestamp_format can't exceed 127 characters. +# Value should still be the old one +show variables like 'server_audit_timestamp_format'; +Variable_name Value +server_audit_timestamp_format %H:%M:%S set global server_audit_logging=off; +set global server_audit_timestamp_format=''; TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=on',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 1',0 CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-DATE %Y-%m-%d\'',0 @@ -23,4 +39,10 @@ CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_ CUSTOM-TZ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 3',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 4',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'%H:%M:%S\'',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'show variables like \'server_audit_timestamp_format\'',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select repeat(\'A\', 130)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\'',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'SHOW WARNINGS',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'show variables like \'server_audit_timestamp_format\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.test b/mysql-test/suite/plugins/t/server_audit_timestamp.test index 7342a62702dcd..a2b10c2c5e593 100644 --- a/mysql-test/suite/plugins/t/server_audit_timestamp.test +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.test @@ -28,10 +28,24 @@ select 3; set global server_audit_timestamp_format=''; select 4; +--echo # +--echo # Error handling for long timestamp format +--echo # +set global server_audit_timestamp_format='%H:%M:%S'; +show variables like 'server_audit_timestamp_format'; + +--echo # Attempting to set an excessively long format string. +let $long_format= `select repeat('A', 130)`; +eval set global server_audit_timestamp_format='$long_format'; + +--echo # Value should still be the old one +show variables like 'server_audit_timestamp_format'; + set global server_audit_logging=off; +set global server_audit_timestamp_format=''; # We use replace_regex to mask the actual volatile parts but keep our prefixes ---replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ +--replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /\d{2}:\d{2}:\d{2}/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ cat_file $SEARCH_FILE; remove_file $SEARCH_FILE; diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index 0209964ab9293..1e82a48287603 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -90,6 +90,9 @@ static void closelog() {} #ifndef USERNAME_CHAR_LENGTH #define USERNAME_CHAR_LENGTH 128 #endif +#ifndef TIMESTAMP_FORMAT_LENGTH +#define TIMESTAMP_FORMAT_LENGTH 128 +#endif #ifndef DBUG_OFF #define PLUGIN_DEBUG_VERSION "-debug" @@ -105,6 +108,7 @@ const char *(*thd_priv_host_ptr)(MYSQL_THD thd, size_t *length); static char *incl_users, *excl_users, *file_path, *syslog_info, *timestamp_format; static char path_buffer[FN_REFLEN]; +static char timestamp_format_buffer[TIMESTAMP_FORMAT_LENGTH]; static unsigned int mode; static ulong output_type; static ulong syslog_facility, syslog_priority; @@ -191,6 +195,8 @@ static void update_syslog_ident(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); static void rotate_log(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); +static void update_timestamp_format(MYSQL_THD thd, struct st_mysql_sys_var *var, + void *var_ptr, const void *save); static void sync_log(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); @@ -270,9 +276,9 @@ 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 MYSQL_SYSVAR_STR(timestamp_format, timestamp_format, - PLUGIN_VAR_RQCMDARG | PLUGIN_VAR_MEMALLOC, + PLUGIN_VAR_RQCMDARG, "The format string the strftime() routine applies with its format argument", - NULL, NULL, ""); + NULL, update_timestamp_format, ""); char locinfo_ini_value[sizeof(struct connection_info)+4]; @@ -1188,22 +1194,26 @@ static size_t log_header(char *message, size_t message_len, connection_id, query_id, operation); (void) localtime_r(ts, &tm_time); + lock_operations.rd_lock(); if (timestamp_format && timestamp_format[0]) { - char ts_buffer[128]; + char ts_buffer[TIMESTAMP_FORMAT_LENGTH]; size_t ts_len= strftime(ts_buffer, sizeof(ts_buffer), timestamp_format, &tm_time); if (ts_len) { - return my_snprintf(message, message_len, + size_t result= my_snprintf(message, message_len, "%s,%.*s,%.*s,%.*s%s,%d,%lld,%s", ts_buffer, (int) serverhost_len, serverhost, username_len, username, host_len, host, port_str, connection_id, query_id, operation); + lock_operations.rd_unlock(); + return result; } } + lock_operations.rd_unlock(); return my_snprintf(message, message_len, "%04d%02d%02d %02d:%02d:%02d,%.*s,%.*s,%.*s%s,%d,%lld,%s", @@ -2133,6 +2143,15 @@ static int server_audit_init(void*) { update_excl_users(NULL, NULL, NULL, &excl_users); } + if (timestamp_format) + { + update_timestamp_format(NULL, NULL, NULL, ×tamp_format); + } + else + { + timestamp_format_buffer[0]= 0; + timestamp_format= timestamp_format_buffer; + } error_header(); fprintf(stderr, "MariaDB Audit Plugin version %s%s STARTED.\n", @@ -2322,6 +2341,34 @@ static void update_file_path(MYSQL_THD thd, st_mysql_sys_var *, void *, } +static void update_timestamp_format(MYSQL_THD thd, st_mysql_sys_var *, void *, + const void *save) +{ + char *new_val= *static_cast(save); + if (!new_val) + new_val= empty_str; + else if (strlen(new_val) >= TIMESTAMP_FORMAT_LENGTH) + { + error_header(); + fprintf(stderr, "server_audit_timestamp_format can't exceed %d characters.\n", + TIMESTAMP_FORMAT_LENGTH - 1); + fprintf(stderr, "Timestamp format remains unchanged '%s'.\n", + timestamp_format); + CLIENT_ERROR(1, "server_audit_timestamp_format can't exceed %d characters.", + MYF(ME_WARNING), TIMESTAMP_FORMAT_LENGTH - 1); + return; + } + + lock_operations.wr_lock(); + internal_stop_logging++; + strncpy(timestamp_format_buffer, new_val, sizeof(timestamp_format_buffer)-1); + timestamp_format_buffer[sizeof(timestamp_format_buffer)-1]= 0; + timestamp_format= timestamp_format_buffer; + internal_stop_logging--; + lock_operations.wr_unlock(); +} + + static void update_file_rotations(MYSQL_THD, st_mysql_sys_var *, void *, const void *save) { From 8b9e22ce66ba951875011b01509745b4bf41235b Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Thu, 12 Feb 2026 01:01:33 +0530 Subject: [PATCH 4/7] MDEV-18386: server_audit: Fix re-entrant deadlock in log_header() --- plugin/server_audit/server_audit.cc | 24 ++++++++++++++---------- 1 file changed, 14 insertions(+), 10 deletions(-) diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index 1e82a48287603..b432846b841c6 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -1160,7 +1160,7 @@ static size_t log_header(char *message, size_t message_len, const char *host, unsigned int host_len, const char *userip, unsigned int userip_len, unsigned int connection_id, unsigned int port, - long long query_id, const char *operation) + long long query_id, const char *operation, int take_lock) { struct tm tm_time; char port_str[16]; @@ -1194,7 +1194,8 @@ static size_t log_header(char *message, size_t message_len, connection_id, query_id, operation); (void) localtime_r(ts, &tm_time); - lock_operations.rd_lock(); + if (take_lock) + lock_operations.rd_lock(); if (timestamp_format && timestamp_format[0]) { char ts_buffer[TIMESTAMP_FORMAT_LENGTH]; @@ -1209,11 +1210,13 @@ static size_t log_header(char *message, size_t message_len, username_len, username, host_len, host, port_str, connection_id, query_id, operation); - lock_operations.rd_unlock(); + if (take_lock) + lock_operations.rd_unlock(); return result; } } - lock_operations.rd_unlock(); + if (take_lock) + lock_operations.rd_unlock(); return my_snprintf(message, message_len, "%04d%02d%02d %02d:%02d:%02d,%.*s,%.*s,%.*s%s,%d,%lld,%s", @@ -1252,7 +1255,7 @@ static int log_proxy(const struct connection_info *cn, cn->host, cn->host_length, cn->ip, cn->ip_length, event->thread_id, event->port, - 0, "PROXY_CONNECT"); + 0, "PROXY_CONNECT", 1); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,`%.*s`@`%.*s`,%d", cn->db_length, cn->db, cn->proxy_length, cn->proxy, @@ -1279,7 +1282,7 @@ static int log_connection(const struct connection_info *cn, cn->user, cn->user_length, cn->host, cn->host_length, cn->ip, cn->ip_length, - event->thread_id, event->port, 0, type); + event->thread_id, event->port, 0, type, 1); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, @@ -1305,7 +1308,7 @@ static int log_connection_event(const struct mysql_event_connection *event, event->user, event->user_length, event->host, event->host_length, event->ip, event->ip_length, - event->thread_id, event->port, 0, type); + event->thread_id, event->port, 0, type, 1); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,%.*s,%d", (int) event->database.length,event->database.str, @@ -1557,7 +1560,8 @@ static int log_statement_ex(struct connection_info *cn, 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, cn->port, query_id, type); + cn->ip, cn->ip_length, thd_id, cn->port, query_id, type, + take_lock); csize+= my_snprintf(message+csize, message_size - 1 - csize, ",%.*s,\'", db_length, db); @@ -1667,7 +1671,7 @@ static int log_table(const struct connection_info *cn, event->user, SAFE_STRLEN_UI(event->user), event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), - event->thread_id, event->port, cn->query_id, type); + event->thread_id, event->port, cn->query_id, type, 1); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,%.*s,", (int) event->database.length, event->database.str, (int) event->table.length, event->table.str); @@ -1690,7 +1694,7 @@ static int log_rename(const struct connection_info *cn, event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), event->thread_id, event->port, - cn->query_id, "RENAME"); + cn->query_id, "RENAME", 1); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,%.*s|%.*s.%.*s,", (int) event->database.length, event->database.str, From 44cf2fbded4bf8d706c96f4218bf405f169c111c Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Fri, 13 Feb 2026 02:32:48 +0530 Subject: [PATCH 5/7] MDEV-18386: Address review comments; implement optimized single-lock audit logging --- .../plugins/r/server_audit_timestamp.result | 11 ++ .../plugins/t/server_audit_timestamp.test | 9 +- plugin/server_audit/server_audit.cc | 178 ++++++++---------- 3 files changed, 100 insertions(+), 98 deletions(-) diff --git a/mysql-test/suite/plugins/r/server_audit_timestamp.result b/mysql-test/suite/plugins/r/server_audit_timestamp.result index 0d382f4ae7b97..0b214de4c82da 100644 --- a/mysql-test/suite/plugins/r/server_audit_timestamp.result +++ b/mysql-test/suite/plugins/r/server_audit_timestamp.result @@ -29,6 +29,14 @@ Warning 1 server_audit_timestamp_format can't exceed 127 characters. show variables like 'server_audit_timestamp_format'; Variable_name Value server_audit_timestamp_format %H:%M:%S +# +# Test large expansion (many %B specifiers) +# +set global server_audit_timestamp_format='EXPAND %B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; +select 5; +5 +5 +set global server_audit_timestamp_format=''; set global server_audit_logging=off; set global server_audit_timestamp_format=''; TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=on',0 @@ -45,4 +53,7 @@ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select repeat(\'A\', 130)',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'SHOW WARNINGS',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'show variables like \'server_audit_timestamp_format\'',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'EXPAND TIMESTAMP,0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 5',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.test b/mysql-test/suite/plugins/t/server_audit_timestamp.test index a2b10c2c5e593..29894fcfe98f3 100644 --- a/mysql-test/suite/plugins/t/server_audit_timestamp.test +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.test @@ -41,11 +41,18 @@ eval set global server_audit_timestamp_format='$long_format'; --echo # Value should still be the old one show variables like 'server_audit_timestamp_format'; +--echo # +--echo # Test large expansion (many %B specifiers) +--echo # +set global server_audit_timestamp_format='EXPAND %B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; +select 5; +set global server_audit_timestamp_format=''; + set global server_audit_logging=off; set global server_audit_timestamp_format=''; # We use replace_regex to mask the actual volatile parts but keep our prefixes ---replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /\d{2}:\d{2}:\d{2}/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ +--replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /EXPAND [^,]+/EXPAND TIMESTAMP/ /\d{2}:\d{2}:\d{2}/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ cat_file $SEARCH_FILE; remove_file $SEARCH_FILE; diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index b432846b841c6..48b94e8decd24 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -93,6 +93,9 @@ static void closelog() {} #ifndef TIMESTAMP_FORMAT_LENGTH #define TIMESTAMP_FORMAT_LENGTH 128 #endif +#ifndef TIMESTAMP_OUTPUT_LENGTH +#define TIMESTAMP_OUTPUT_LENGTH 256 +#endif #ifndef DBUG_OFF #define PLUGIN_DEBUG_VERSION "-debug" @@ -1098,7 +1101,7 @@ static void change_connection(struct connection_info *cn, Write to the log */ -static int write_log(const char *message, size_t len) +static int write_log(const char *message, size_t len, time_t ts) { #if defined _WIN32 || !defined SUX_LOCK_GENERIC DBUG_ASSERT(lock_operations.is_locked_or_waiting()); @@ -1109,7 +1112,25 @@ static int write_log(const char *message, size_t len) { if (logfile) { - if (!(is_active= (logger_write(logfile, message, len) == (int) len))) + struct tm tm_time; + char ts_tmp[TIMESTAMP_OUTPUT_LENGTH]; + (void) localtime_r(&ts, &tm_time); + + size_t ts_len= 0; + if (timestamp_format_buffer[0]) + ts_len= strftime(ts_tmp, sizeof(ts_tmp), timestamp_format_buffer, &tm_time); + + if (ts_len == 0) + ts_len= my_snprintf(ts_tmp, sizeof(ts_tmp), + "%04d%02d%02d %02d:%02d:%02d", + tm_time.tm_year+1900, tm_time.tm_mon+1, + tm_time.tm_mday, tm_time.tm_hour, + tm_time.tm_min, tm_time.tm_sec); + + char *final_message= (char *) message - ts_len; + size_t final_len= len + ts_len; + memcpy(final_message, ts_tmp, ts_len); + if (!(is_active= (logger_write(logfile, final_message, final_len) == (int) final_len))) { ++log_write_failures; result= 1; @@ -1118,9 +1139,10 @@ static int write_log(const char *message, size_t len) } else if (output_type == OUTPUT_SYSLOG) { + /* Syslog doesn't need the audit timestamp. Skip the leading comma. */ syslog(syslog_facility_codes[syslog_facility] | syslog_priority_codes[syslog_priority], - "%s %.*s", syslog_info, (int) len, message); + "%s %.*s", syslog_info, (int) len - 1, message + 1); } return result; @@ -1128,12 +1150,12 @@ static int write_log(const char *message, size_t len) /** Write to the log, acquiring the lock. -*/ + */ -static int write_log_and_lock(const char *message, size_t len) +static int write_log_and_lock(const char *message, size_t len, time_t ts) { lock_operations.rd_lock(); - int result= write_log(message, len); + int result= write_log(message, len, ts); lock_operations.rd_unlock(); return result; } @@ -1143,26 +1165,24 @@ static int write_log_and_lock(const char *message, size_t len) Write to the log @param lock whether the caller did not acquire lock_operations -*/ -static int write_log_maybe_lock(const char *message, size_t len, bool lock) + */ +static int write_log_maybe_lock(const char *message, size_t len, bool lock, time_t ts) { if (unlikely(!lock)) - return write_log(message, len); + return write_log(message, len, ts); else - return write_log_and_lock(message, len); + return write_log_and_lock(message, len, ts); } static size_t log_header(char *message, size_t message_len, - time_t *ts, - const char *serverhost, size_t serverhost_len, - const char *username, unsigned int username_len, - const char *host, unsigned int host_len, - const char *userip, unsigned int userip_len, - unsigned int connection_id, unsigned int port, - long long query_id, const char *operation, int take_lock) + const char *serverhost, size_t serverhost_len, + const char *username, unsigned int username_len, + const char *host, unsigned int host_len, + const char *userip, unsigned int userip_len, + unsigned int connection_id, unsigned int port, + long long query_id, const char *operation) { - struct tm tm_time; char port_str[16]; if (host_len == 0 && userip_len != 0) { @@ -1185,43 +1205,8 @@ static size_t log_header(char *message, size_t message_len, username_len= (unsigned int) strlen(username); } - if (output_type == OUTPUT_SYSLOG) - return my_snprintf(message, message_len, - "%.*s,%.*s,%.*s%s,%d,%lld,%s", - (int) serverhost_len, serverhost, - username_len, username, - host_len, host, port_str, - connection_id, query_id, operation); - - (void) localtime_r(ts, &tm_time); - if (take_lock) - lock_operations.rd_lock(); - if (timestamp_format && timestamp_format[0]) - { - char ts_buffer[TIMESTAMP_FORMAT_LENGTH]; - size_t ts_len= strftime(ts_buffer, sizeof(ts_buffer), - timestamp_format, &tm_time); - if (ts_len) - { - size_t result= my_snprintf(message, message_len, - "%s,%.*s,%.*s,%.*s%s,%d,%lld,%s", - ts_buffer, - (int) serverhost_len, serverhost, - username_len, username, - host_len, host, port_str, - connection_id, query_id, operation); - if (take_lock) - lock_operations.rd_unlock(); - return result; - } - } - if (take_lock) - lock_operations.rd_unlock(); - return my_snprintf(message, message_len, - "%04d%02d%02d %02d:%02d:%02d,%.*s,%.*s,%.*s%s,%d,%lld,%s", - tm_time.tm_year+1900, tm_time.tm_mon+1, tm_time.tm_mday, - tm_time.tm_hour, tm_time.tm_min, tm_time.tm_sec, + ",%.*s,%.*s,%.*s%s,%d,%lld,%s", (int) serverhost_len, serverhost, username_len, username, host_len, host, port_str, @@ -1246,23 +1231,24 @@ static int log_proxy(const struct connection_info *cn, { time_t ctime; size_t csize; - char message[1024]; + char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; (void) time(&ctime); - csize= log_header(message, sizeof(message)-1, &ctime, + csize= log_header(message, 1024-1, servhost, servhost_len, cn->user, cn->user_length, cn->host, cn->host_length, cn->ip, cn->ip_length, event->thread_id, event->port, - 0, "PROXY_CONNECT", 1); - csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, + 0, "PROXY_CONNECT"); + csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,`%.*s`@`%.*s`,%d", cn->db_length, cn->db, cn->proxy_length, cn->proxy, cn->proxy_host_length, cn->proxy_host, event->status); message[csize]= '\n'; - return write_log_and_lock(message, csize + 1); + return write_log_and_lock(message, csize + 1, ctime); } @@ -1272,24 +1258,25 @@ static int log_connection(const struct connection_info *cn, { time_t ctime; size_t csize; - char message[1024]; + char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; char tls_obj[32]; size_t obj_len; (void) time(&ctime); - csize= log_header(message, sizeof(message)-1, &ctime, + csize= log_header(message, 1024-1, servhost, servhost_len, cn->user, cn->user_length, cn->host, cn->host_length, cn->ip, cn->ip_length, - event->thread_id, event->port, 0, type, 1); + event->thread_id, event->port, 0, type); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); - csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, + csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,%.*s,%d", cn->db_length, cn->db, (int) obj_len, tls_obj, event->status); message[csize]= '\n'; - return write_log_and_lock(message, csize + 1); + return write_log_and_lock(message, csize + 1, ctime); } @@ -1298,23 +1285,24 @@ static int log_connection_event(const struct mysql_event_connection *event, { time_t ctime; size_t csize; - char message[1024]; + char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; char tls_obj[32]; size_t obj_len; (void) time(&ctime); - csize= log_header(message, sizeof(message)-1, &ctime, + csize= log_header(message, 1024-1, servhost, servhost_len, event->user, event->user_length, event->host, event->host_length, event->ip, event->ip_length, - event->thread_id, event->port, 0, type, 1); + event->thread_id, event->port, 0, type); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); - csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, + csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,%.*s,%d", (int) event->database.length,event->database.str, (int) obj_len, tls_obj, event->status); message[csize]= '\n'; - return write_log_and_lock(message, csize + 1); + return write_log_and_lock(message, csize + 1, ctime); } @@ -1516,9 +1504,9 @@ static int log_statement_ex(struct connection_info *cn, int error_code, const char *type, int take_lock) { size_t csize; - char message_loc[2048]; - char *message= message_loc; - size_t message_size= sizeof(message_loc); + char raw_message_loc[2048 + TIMESTAMP_OUTPUT_LENGTH]; + char *message= raw_message_loc + TIMESTAMP_OUTPUT_LENGTH; + size_t message_size= 2048; char *uh_buffer; size_t uh_buffer_size; const char *db; @@ -1557,11 +1545,10 @@ static int log_statement_ex(struct connection_info *cn, return 0; } - csize= log_header(message, message_size-1, &ev_time, + csize= log_header(message, message_size-1, servhost, servhost_len, cn->user, cn->user_length,cn->host, cn->host_length, - cn->ip, cn->ip_length, thd_id, cn->port, query_id, type, - take_lock); + cn->ip, cn->ip_length, thd_id, cn->port, query_id, type); csize+= my_snprintf(message+csize, message_size - 1 - csize, ",%.*s,\'", db_length, db); @@ -1571,13 +1558,14 @@ static int log_statement_ex(struct connection_info *cn, if (query_len > (message_size - csize)/2) { - size_t big_buffer_alloced= (query_len * 2 + csize + 4095) & ~4095L; + size_t big_buffer_alloced= (query_len * 2 + csize + 4095 + TIMESTAMP_OUTPUT_LENGTH) & ~4095L; if (!(big_buffer= static_cast(malloc(big_buffer_alloced)))) return 0; - memcpy(big_buffer, message, csize); - message= big_buffer; - message_size= big_buffer_alloced; + char *new_message= big_buffer + TIMESTAMP_OUTPUT_LENGTH; + memcpy(new_message, message, csize); + message= new_message; + message_size= big_buffer_alloced - TIMESTAMP_OUTPUT_LENGTH; } uh_buffer= message + csize; @@ -1622,7 +1610,7 @@ static int log_statement_ex(struct connection_info *cn, csize+= my_snprintf(message+csize, message_size - 1 - csize, "\',%d", error_code); message[csize]= '\n'; - result= write_log_maybe_lock(message, csize + 1, take_lock); + result= write_log_maybe_lock(message, csize + 1, take_lock, ev_time); if (cn->sync_statement && output_type == OUTPUT_FILE && logfile) { @@ -1662,21 +1650,22 @@ static int log_table(const struct connection_info *cn, const struct mysql_event_table *event, const char *type) { size_t csize; - char message[1024]; + char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char *message = raw_message + TIMESTAMP_OUTPUT_LENGTH; time_t ctime; (void) time(&ctime); - csize= log_header(message, sizeof(message)-1, &ctime, + csize= log_header(message, 1024-1, servhost, servhost_len, event->user, SAFE_STRLEN_UI(event->user), event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), - event->thread_id, event->port, cn->query_id, type, 1); - csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,%.*s,", + event->thread_id, event->port, cn->query_id, type); + csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,%.*s,", (int) event->database.length, event->database.str, (int) event->table.length, event->table.str); message[csize]= '\n'; - return write_log_and_lock(message, csize + 1); + return write_log_and_lock(message, csize + 1, ctime); } @@ -1684,17 +1673,18 @@ static int log_rename(const struct connection_info *cn, const struct mysql_event_table *event) { size_t csize; - char message[1024]; + char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; time_t ctime; (void) time(&ctime); - csize= log_header(message, sizeof(message)-1, &ctime, + csize= log_header(message, 1024-1, servhost, servhost_len, event->user, SAFE_STRLEN_UI(event->user), event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), event->thread_id, event->port, - cn->query_id, "RENAME", 1); + cn->query_id, "RENAME"); csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,%.*s|%.*s.%.*s,", (int) event->database.length, event->database.str, @@ -1702,7 +1692,7 @@ static int log_rename(const struct connection_info *cn, (int) event->new_database.length, event->new_database.str, (int) event->new_table.length, event->new_table.str); message[csize]= '\n'; - return write_log_and_lock(message, csize + 1); + return write_log_and_lock(message, csize + 1, ctime); } @@ -2147,15 +2137,11 @@ static int server_audit_init(void*) { update_excl_users(NULL, NULL, NULL, &excl_users); } - if (timestamp_format) + if (timestamp_format && timestamp_format[0]) { update_timestamp_format(NULL, NULL, NULL, ×tamp_format); } - else - { - timestamp_format_buffer[0]= 0; - timestamp_format= timestamp_format_buffer; - } + error_header(); fprintf(stderr, "MariaDB Audit Plugin version %s%s STARTED.\n", @@ -2364,11 +2350,9 @@ static void update_timestamp_format(MYSQL_THD thd, st_mysql_sys_var *, void *, } lock_operations.wr_lock(); - internal_stop_logging++; strncpy(timestamp_format_buffer, new_val, sizeof(timestamp_format_buffer)-1); timestamp_format_buffer[sizeof(timestamp_format_buffer)-1]= 0; timestamp_format= timestamp_format_buffer; - internal_stop_logging--; lock_operations.wr_unlock(); } From 0a98e5819af77e2af3d4f55d5ff873ec314efd1f Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Fri, 13 Feb 2026 12:27:40 +0530 Subject: [PATCH 6/7] MDEV-18386: Fix regressions --- mysql-test/suite/plugins/r/server_audit_timestamp.result | 5 ++--- mysql-test/suite/plugins/t/server_audit_timestamp.test | 5 ++--- plugin/server_audit/server_audit.cc | 2 +- 3 files changed, 5 insertions(+), 7 deletions(-) diff --git a/mysql-test/suite/plugins/r/server_audit_timestamp.result b/mysql-test/suite/plugins/r/server_audit_timestamp.result index 0b214de4c82da..c5d54636fc0d2 100644 --- a/mysql-test/suite/plugins/r/server_audit_timestamp.result +++ b/mysql-test/suite/plugins/r/server_audit_timestamp.result @@ -32,13 +32,12 @@ server_audit_timestamp_format %H:%M:%S # # Test large expansion (many %B specifiers) # -set global server_audit_timestamp_format='EXPAND %B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; +set global server_audit_timestamp_format='%B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; select 5; 5 5 set global server_audit_timestamp_format=''; set global server_audit_logging=off; -set global server_audit_timestamp_format=''; TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=on',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 1',0 CUSTOM-DATE TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'CUSTOM-DATE %Y-%m-%d\'',0 @@ -53,7 +52,7 @@ TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select repeat(\'A\', 130)',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'SHOW WARNINGS',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'show variables like \'server_audit_timestamp_format\'',0 -TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'EXPAND TIMESTAMP,0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'%B %B %B %B %B %B %B %B %B %B %B %B %B %B %B\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'select 5',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_timestamp_format=\'\'',0 TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/t/server_audit_timestamp.test b/mysql-test/suite/plugins/t/server_audit_timestamp.test index 29894fcfe98f3..66661797f8ed8 100644 --- a/mysql-test/suite/plugins/t/server_audit_timestamp.test +++ b/mysql-test/suite/plugins/t/server_audit_timestamp.test @@ -44,15 +44,14 @@ show variables like 'server_audit_timestamp_format'; --echo # --echo # Test large expansion (many %B specifiers) --echo # -set global server_audit_timestamp_format='EXPAND %B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; +set global server_audit_timestamp_format='%B %B %B %B %B %B %B %B %B %B %B %B %B %B %B'; select 5; set global server_audit_timestamp_format=''; set global server_audit_logging=off; -set global server_audit_timestamp_format=''; # We use replace_regex to mask the actual volatile parts but keep our prefixes ---replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /EXPAND [^,]+/EXPAND TIMESTAMP/ /\d{2}:\d{2}:\d{2}/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ +--replace_regex /\d{4}\d{2}\d{2} \d{2}:\d{2}:\d{2}/TIMESTAMP/ /CUSTOM-DATE \d{4}-\d{2}-\d{2}/CUSTOM-DATE TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2} [+-]\d{4}/CUSTOM-TZ TIMESTAMP/ /CUSTOM-TZ \d{2}:\d{2}:\d{2}/CUSTOM-TZ TIMESTAMP/ /([A-Z][a-z]+ ){10,}[A-Z][a-z]+/TIMESTAMP/ /\d{2}:\d{2}:\d{2}/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),(\d+),(\d+),/,HOSTNAME,root,localhost,ID,ID,/ cat_file $SEARCH_FILE; remove_file $SEARCH_FILE; diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index 48b94e8decd24..7420a6bda79ce 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -1685,7 +1685,7 @@ static int log_rename(const struct connection_info *cn, event->ip, SAFE_STRLEN_UI(event->ip), event->thread_id, event->port, cn->query_id, "RENAME"); - csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, + csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,%.*s|%.*s.%.*s,", (int) event->database.length, event->database.str, (int) event->table.length, event->table.str, From 974a559e5f2969c352d4fb2eeaee7a6481d9928d Mon Sep 17 00:00:00 2001 From: Abhishek Bansal Date: Fri, 13 Feb 2026 20:08:36 +0530 Subject: [PATCH 7/7] MDEV-18386: Addressed review comments --- .../plugins/r/server_audit_query_id.result | 56 +++++++------- .../plugins/t/server_audit_query_id.test | 2 +- plugin/server_audit/server_audit.cc | 76 +++++++++++-------- 3 files changed, 73 insertions(+), 61 deletions(-) diff --git a/mysql-test/suite/plugins/r/server_audit_query_id.result b/mysql-test/suite/plugins/r/server_audit_query_id.result index 3d2d9f18cc21d..3c0bf956a21c3 100644 --- a/mysql-test/suite/plugins/r/server_audit_query_id.result +++ b/mysql-test/suite/plugins/r/server_audit_query_id.result @@ -39,31 +39,31 @@ DROP TABLE source, dest, dest_2; set global server_audit_logging=off; # Wait for audit events to be written FOUND 1 /set global server_audit_logging=off/ in server_audit_query_id.log -TIMESTAMP,HOSTNAME,root,localhost,4,0,QUERY,test,'set global server_audit_logging=on',0 -TIMESTAMP,HOSTNAME,root,localhost,4,1,QUERY,test,'USE test',0 -TIMESTAMP,HOSTNAME,root,localhost,4,2,QUERY,test,'CREATE TABLE source (\nid bigint(20) NOT NULL AUTO_INCREMENT,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 -TIMESTAMP,HOSTNAME,root,localhost,4,3,QUERY,test,'CREATE TABLE dest (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 -TIMESTAMP,HOSTNAME,root,localhost,4,4,QUERY,test,'CREATE TABLE dest_2 (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 -TIMESTAMP,HOSTNAME,root,localhost,4,5,QUERY,test,'CREATE TRIGGER test_trigger\nAFTER INSERT ON source\nFOR EACH ROW\nINSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,6,QUERY,test,'CREATE TRIGGER test_trigger_2\nAFTER INSERT ON dest\nFOR EACH ROW\nINSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,7,QUERY,test,'CREATE PROCEDURE test_procedure (IN id bigint(20))\nNOT DETERMINISTIC MODIFIES SQL DATA\nBEGIN\nINSERT INTO source VALUES (id), (NULL);\nEND',0 -TIMESTAMP,HOSTNAME,root,localhost,4,10,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,9,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,8,QUERY,test,'INSERT INTO source VALUES (NULL)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,13,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,12,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,11,QUERY,test,'INSERT INTO source VALUES (NULL)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,16,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,15,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,18,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,17,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,14,QUERY,test,'INSERT INTO source VALUES (NULL), (NULL)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,22,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,21,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,24,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,23,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,20,QUERY,test,'INSERT INTO source VALUES ( NAME_CONST(\'id\',NULL)), (NULL)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,19,QUERY,test,'CALL test_procedure(NULL)',0 -TIMESTAMP,HOSTNAME,root,localhost,4,25,QUERY,test,'DROP PROCEDURE test_procedure',0 -TIMESTAMP,HOSTNAME,root,localhost,4,26,QUERY,test,'DROP TABLE source, dest, dest_2',0 -TIMESTAMP,HOSTNAME,root,localhost,4,27,QUERY,test,'set global server_audit_logging=off',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=on',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'USE test',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE TABLE source (\nid bigint(20) NOT NULL AUTO_INCREMENT,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE TABLE dest (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE TABLE dest_2 (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE TRIGGER test_trigger\nAFTER INSERT ON source\nFOR EACH ROW\nINSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE TRIGGER test_trigger_2\nAFTER INSERT ON dest\nFOR EACH ROW\nINSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CREATE PROCEDURE test_procedure (IN id bigint(20))\nNOT DETERMINISTIC MODIFIES SQL DATA\nBEGIN\nINSERT INTO source VALUES (id), (NULL);\nEND',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO source VALUES (NULL)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO source VALUES (NULL)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO source VALUES (NULL), (NULL)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'INSERT INTO source VALUES ( NAME_CONST(\'id\',NULL)), (NULL)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'CALL test_procedure(NULL)',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'DROP PROCEDURE test_procedure',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'DROP TABLE source, dest, dest_2',0 +TIMESTAMP,HOSTNAME,root,localhost,ID,ID,QUERY,test,'set global server_audit_logging=off',0 diff --git a/mysql-test/suite/plugins/t/server_audit_query_id.test b/mysql-test/suite/plugins/t/server_audit_query_id.test index 950f0a42c0eab..b1b8488db9e62 100644 --- a/mysql-test/suite/plugins/t/server_audit_query_id.test +++ b/mysql-test/suite/plugins/t/server_audit_query_id.test @@ -83,7 +83,7 @@ set global server_audit_logging=off; --exec perl $MYSQL_TEST_DIR/suite/plugins/t/normalize_query_id.pl $SEARCH_FILE # Output the log without heavy replacements so we can see the actual order ---replace_regex /\d\d\d\d\d\d\d\d \d\d:\d\d:\d\d/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),/,HOSTNAME,root,localhost,/ +--replace_regex /\d\d\d\d\d\d\d\d \d\d:\d\d:\d\d/TIMESTAMP/ /,[^,]+,root,(localhost|localhost:[0-9]+),\d+,\d+,/,HOSTNAME,root,localhost,ID,ID,/ cat_file $SEARCH_FILE; remove_file $SEARCH_FILE; diff --git a/plugin/server_audit/server_audit.cc b/plugin/server_audit/server_audit.cc index 7420a6bda79ce..0ec3255be28ed 100644 --- a/plugin/server_audit/server_audit.cc +++ b/plugin/server_audit/server_audit.cc @@ -96,6 +96,12 @@ static void closelog() {} #ifndef TIMESTAMP_OUTPUT_LENGTH #define TIMESTAMP_OUTPUT_LENGTH 256 #endif +#ifndef MAX_AUDIT_PAYLOAD_LENGTH +#define MAX_AUDIT_PAYLOAD_LENGTH 1024 +#endif +#ifndef MAX_AUDIT_QUERY_LENGTH +#define MAX_AUDIT_QUERY_LENGTH 2048 +#endif #ifndef DBUG_OFF #define PLUGIN_DEBUG_VERSION "-debug" @@ -280,7 +286,9 @@ static MYSQL_SYSVAR_UINT(query_log_limit, query_log_limit, NULL, NULL, 1024, 0, 0x7FFFFFFF, 1); static MYSQL_SYSVAR_STR(timestamp_format, timestamp_format, PLUGIN_VAR_RQCMDARG, - "The format string the strftime() routine applies with its format argument", + "A format string used to print the timestamp into the audit log messages " + "The format used is the same as strftime and the default is empty which uses " + "the existing hard-coded format", NULL, update_timestamp_format, ""); char locinfo_ini_value[sizeof(struct connection_info)+4]; @@ -1113,23 +1121,27 @@ static int write_log(const char *message, size_t len, time_t ts) if (logfile) { struct tm tm_time; - char ts_tmp[TIMESTAMP_OUTPUT_LENGTH]; (void) localtime_r(&ts, &tm_time); size_t ts_len= 0; - if (timestamp_format_buffer[0]) - ts_len= strftime(ts_tmp, sizeof(ts_tmp), timestamp_format_buffer, &tm_time); + char *ts_start= (char *) message - TIMESTAMP_OUTPUT_LENGTH; - if (ts_len == 0) - ts_len= my_snprintf(ts_tmp, sizeof(ts_tmp), + if (timestamp_format_buffer[0]) + ts_len= strftime(ts_start, TIMESTAMP_OUTPUT_LENGTH, + timestamp_format_buffer, &tm_time); + else + ts_len= my_snprintf(ts_start, TIMESTAMP_OUTPUT_LENGTH, "%04d%02d%02d %02d:%02d:%02d", tm_time.tm_year+1900, tm_time.tm_mon+1, tm_time.tm_mday, tm_time.tm_hour, tm_time.tm_min, tm_time.tm_sec); + if (ts_len > 0 && ts_len < TIMESTAMP_OUTPUT_LENGTH) + memmove((char *) message - ts_len, ts_start, ts_len); + char *final_message= (char *) message - ts_len; size_t final_len= len + ts_len; - memcpy(final_message, ts_tmp, ts_len); + if (!(is_active= (logger_write(logfile, final_message, final_len) == (int) final_len))) { ++log_write_failures; @@ -1150,7 +1162,7 @@ static int write_log(const char *message, size_t len, time_t ts) /** Write to the log, acquiring the lock. - */ +*/ static int write_log_and_lock(const char *message, size_t len, time_t ts) { @@ -1176,12 +1188,12 @@ static int write_log_maybe_lock(const char *message, size_t len, bool lock, time static size_t log_header(char *message, size_t message_len, - const char *serverhost, size_t serverhost_len, - const char *username, unsigned int username_len, - const char *host, unsigned int host_len, - const char *userip, unsigned int userip_len, - unsigned int connection_id, unsigned int port, - long long query_id, const char *operation) + const char *serverhost, size_t serverhost_len, + const char *username, unsigned int username_len, + const char *host, unsigned int host_len, + const char *userip, unsigned int userip_len, + unsigned int connection_id, unsigned int port, + long long query_id, const char *operation) { char port_str[16]; if (host_len == 0 && userip_len != 0) @@ -1199,7 +1211,7 @@ static size_t log_header(char *message, size_t message_len, That was added to find the possible cause of the MENT-1438. Supposed to be removed after that. */ - if (username_len > 1024) + if (username_len > MAX_AUDIT_PAYLOAD_LENGTH) { username= "unknown_user"; username_len= (unsigned int) strlen(username); @@ -1231,18 +1243,18 @@ static int log_proxy(const struct connection_info *cn, { time_t ctime; size_t csize; - char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message[MAX_AUDIT_PAYLOAD_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; (void) time(&ctime); - csize= log_header(message, 1024-1, + csize= log_header(message, MAX_AUDIT_PAYLOAD_LENGTH - 1, servhost, servhost_len, cn->user, cn->user_length, cn->host, cn->host_length, cn->ip, cn->ip_length, event->thread_id, event->port, 0, "PROXY_CONNECT"); - csize+= my_snprintf(message+csize, 1024 - 1 - csize, + csize+= my_snprintf(message+csize, MAX_AUDIT_PAYLOAD_LENGTH - 1 - csize, ",%.*s,`%.*s`@`%.*s`,%d", cn->db_length, cn->db, cn->proxy_length, cn->proxy, cn->proxy_host_length, cn->proxy_host, @@ -1258,13 +1270,13 @@ static int log_connection(const struct connection_info *cn, { time_t ctime; size_t csize; - char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message[MAX_AUDIT_PAYLOAD_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; char tls_obj[32]; size_t obj_len; (void) time(&ctime); - csize= log_header(message, 1024-1, + csize= log_header(message, MAX_AUDIT_PAYLOAD_LENGTH - 1, servhost, servhost_len, cn->user, cn->user_length, cn->host, cn->host_length, @@ -1272,7 +1284,7 @@ static int log_connection(const struct connection_info *cn, event->thread_id, event->port, 0, type); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); - csize+= my_snprintf(message+csize, 1024 - 1 - csize, + csize+= my_snprintf(message+csize, MAX_AUDIT_PAYLOAD_LENGTH - 1 - csize, ",%.*s,%.*s,%d", cn->db_length, cn->db, (int) obj_len, tls_obj, event->status); message[csize]= '\n'; @@ -1285,20 +1297,20 @@ static int log_connection_event(const struct mysql_event_connection *event, { time_t ctime; size_t csize; - char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message[MAX_AUDIT_PAYLOAD_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; char tls_obj[32]; size_t obj_len; (void) time(&ctime); - csize= log_header(message, 1024-1, + csize= log_header(message, MAX_AUDIT_PAYLOAD_LENGTH - 1, servhost, servhost_len, event->user, event->user_length, event->host, event->host_length, event->ip, event->ip_length, event->thread_id, event->port, 0, type); obj_len= create_tls_obj(event, tls_obj, sizeof(tls_obj)); - csize+= my_snprintf(message+csize, 1024 - 1 - csize, + csize+= my_snprintf(message+csize, MAX_AUDIT_PAYLOAD_LENGTH - 1 - csize, ",%.*s,%.*s,%d", (int) event->database.length,event->database.str, (int) obj_len, tls_obj, event->status); message[csize]= '\n'; @@ -1504,9 +1516,9 @@ static int log_statement_ex(struct connection_info *cn, int error_code, const char *type, int take_lock) { size_t csize; - char raw_message_loc[2048 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message_loc[MAX_AUDIT_QUERY_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message= raw_message_loc + TIMESTAMP_OUTPUT_LENGTH; - size_t message_size= 2048; + size_t message_size= MAX_AUDIT_QUERY_LENGTH; char *uh_buffer; size_t uh_buffer_size; const char *db; @@ -1650,18 +1662,18 @@ static int log_table(const struct connection_info *cn, const struct mysql_event_table *event, const char *type) { size_t csize; - char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message[MAX_AUDIT_PAYLOAD_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message = raw_message + TIMESTAMP_OUTPUT_LENGTH; time_t ctime; (void) time(&ctime); - csize= log_header(message, 1024-1, + csize= log_header(message, MAX_AUDIT_PAYLOAD_LENGTH - 1, servhost, servhost_len, event->user, SAFE_STRLEN_UI(event->user), event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), event->thread_id, event->port, cn->query_id, type); - csize+= my_snprintf(message+csize, 1024 - 1 - csize, ",%.*s,%.*s,", + csize+= my_snprintf(message+csize, MAX_AUDIT_PAYLOAD_LENGTH - 1 - csize, ",%.*s,%.*s,", (int) event->database.length, event->database.str, (int) event->table.length, event->table.str); message[csize]= '\n'; @@ -1673,19 +1685,19 @@ static int log_rename(const struct connection_info *cn, const struct mysql_event_table *event) { size_t csize; - char raw_message[1024 + TIMESTAMP_OUTPUT_LENGTH]; + char raw_message[MAX_AUDIT_PAYLOAD_LENGTH + TIMESTAMP_OUTPUT_LENGTH]; char *message= raw_message + TIMESTAMP_OUTPUT_LENGTH; time_t ctime; (void) time(&ctime); - csize= log_header(message, 1024-1, + csize= log_header(message, MAX_AUDIT_PAYLOAD_LENGTH - 1, servhost, servhost_len, event->user, SAFE_STRLEN_UI(event->user), event->host, SAFE_STRLEN_UI(event->host), event->ip, SAFE_STRLEN_UI(event->ip), event->thread_id, event->port, cn->query_id, "RENAME"); - csize+= my_snprintf(message+csize, 1024 - 1 - csize, + csize+= my_snprintf(message+csize, MAX_AUDIT_PAYLOAD_LENGTH - 1 - csize, ",%.*s,%.*s|%.*s.%.*s,", (int) event->database.length, event->database.str, (int) event->table.length, event->table.str,