From dd8f5b92ad35ded33f64479bef6bced5e86a989c Mon Sep 17 00:00:00 2001 From: Alexey Botchkov Date: Fri, 2 May 2025 18:04:49 +0400 Subject: [PATCH] MDEV-34680 Asynchronous and Buffered Logging for Audit Plugin. Buffering with the IO_CACHE added to the file logger. --- include/mysql/plugin.h | 2 +- include/mysql/plugin_audit.h.pp | 12 +- include/mysql/plugin_auth.h.pp | 12 +- include/mysql/plugin_data_type.h.pp | 12 +- include/mysql/plugin_encryption.h.pp | 12 +- include/mysql/plugin_ftparser.h.pp | 12 +- include/mysql/plugin_function.h.pp | 12 +- include/mysql/plugin_password_validation.h.pp | 12 +- include/mysql/service_logger.h | 23 ++- include/service_versions.h | 2 +- mysql-test/include/print_file_line_count.inc | 10 ++ .../suite/plugins/r/server_audit.result | 6 + .../plugins/r/server_audit_buffering.result | 37 ++++ .../plugins/t/server_audit_buffering.test | 85 +++++++++ mysys/file_logger.c | 170 ++++++++++++------ plugin/server_audit/server_audit.c | 100 +++++++---- plugin/sql_errlog/sql_errlog.c | 2 +- sql/sql_plugin_services.inl | 4 +- 18 files changed, 398 insertions(+), 127 deletions(-) create mode 100644 mysql-test/include/print_file_line_count.inc create mode 100644 mysql-test/suite/plugins/r/server_audit_buffering.result create mode 100644 mysql-test/suite/plugins/t/server_audit_buffering.test diff --git a/include/mysql/plugin.h b/include/mysql/plugin.h index 2bf5455cdea..ef70b36f497 100644 --- a/include/mysql/plugin.h +++ b/include/mysql/plugin.h @@ -81,7 +81,7 @@ typedef struct st_mysql_xid MYSQL_XID; */ /** MySQL plugin interface version */ -#define MYSQL_PLUGIN_INTERFACE_VERSION 0x0104 +#define MYSQL_PLUGIN_INTERFACE_VERSION 0x0105 /** MariaDB plugin interface version */ #define MARIA_PLUGIN_INTERFACE_VERSION 0x010f diff --git a/include/mysql/plugin_audit.h.pp b/include/mysql/plugin_audit.h.pp index 93efe24f4a1..adb307050b6 100644 --- a/include/mysql/plugin_audit.h.pp +++ b/include/mysql/plugin_audit.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_auth.h.pp b/include/mysql/plugin_auth.h.pp index 374d9666136..95fc42b7ae7 100644 --- a/include/mysql/plugin_auth.h.pp +++ b/include/mysql/plugin_auth.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_data_type.h.pp b/include/mysql/plugin_data_type.h.pp index 35641802e03..a410c347db0 100644 --- a/include/mysql/plugin_data_type.h.pp +++ b/include/mysql/plugin_data_type.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_encryption.h.pp b/include/mysql/plugin_encryption.h.pp index e8b7f7b3e60..b36e78cbc50 100644 --- a/include/mysql/plugin_encryption.h.pp +++ b/include/mysql/plugin_encryption.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_ftparser.h.pp b/include/mysql/plugin_ftparser.h.pp index 4de3fc3a9e6..55ac7337233 100644 --- a/include/mysql/plugin_ftparser.h.pp +++ b/include/mysql/plugin_ftparser.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_function.h.pp b/include/mysql/plugin_function.h.pp index 63c63cefa10..3e7345e6139 100644 --- a/include/mysql/plugin_function.h.pp +++ b/include/mysql/plugin_function.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/plugin_password_validation.h.pp b/include/mysql/plugin_password_validation.h.pp index 6cc728a8529..aacf98a1541 100644 --- a/include/mysql/plugin_password_validation.h.pp +++ b/include/mysql/plugin_password_validation.h.pp @@ -128,26 +128,30 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) __attribute__((format(printf, 2, 0))); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) __attribute__((format(printf, 2, 3))); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); } extern "C" { extern struct my_md5_service_st { diff --git a/include/mysql/service_logger.h b/include/mysql/service_logger.h index 35c2eb1e3a9..7c46e9b640a 100644 --- a/include/mysql/service_logger.h +++ b/include/mysql/service_logger.h @@ -64,41 +64,48 @@ extern struct logger_service_st { void (*logger_init_mutexes)(); LOGGER_HANDLE* (*open)(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int (*close)(LOGGER_HANDLE *log); int (*vprintf)(LOGGER_HANDLE *log, const char *fmt, va_list argptr) ATTRIBUTE_FORMAT_FPTR(printf, 2, 0); int (*printf)(LOGGER_HANDLE *log, const char *fmt, ...) ATTRIBUTE_FORMAT_FPTR(printf, 2, 3); - int (*write)(LOGGER_HANDLE *log, const char *buffer, size_t size); + int (*write)(LOGGER_HANDLE *log, const void *data, size_t size); int (*rotate)(LOGGER_HANDLE *log); + int (*sync)(LOGGER_HANDLE *log); + int (*resize_buffer)(LOGGER_HANDLE *log, size_t new_buffer_size); } *logger_service; #ifdef MYSQL_DYNAMIC_PLUGIN #define logger_init_mutexes logger_service->logger_init_mutexes -#define logger_open(path, size_limit, rotations) \ - (logger_service->open(path, size_limit, rotations)) +#define logger_open(path, size_limit, rotations, buffer_size) \ + (logger_service->open(path, size_limit, rotations, buffer_size)) #define logger_close(log) (logger_service->close(log)) #define logger_rotate(log) (logger_service->rotate(log)) #define logger_vprintf(log, fmt, argptr) (logger_service->\ vprintf(log, fmt, argptr)) #define logger_printf (*logger_service->printf) -#define logger_write(log, buffer, size) \ - (logger_service->write(log, buffer, size)) +#define logger_write(log, data, size) \ + (logger_service->write(log, data, size)) +#define logger_sync(log) (logger_service->sync(log)) +#define logger_resize_buffer(log, new_buffer_size) \ + (logger_service->resize_buffer(log, new_buffer_size)) #else void logger_init_mutexes(); LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations); + unsigned int rotations, size_t buffer_size); int logger_close(LOGGER_HANDLE *log); int logger_vprintf(LOGGER_HANDLE *log, const char *fmt, va_list argptr) ATTRIBUTE_FORMAT(printf, 2, 0); int logger_printf(LOGGER_HANDLE *log, const char *fmt, ...) ATTRIBUTE_FORMAT(printf, 2, 3); - int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size); + int logger_write(LOGGER_HANDLE *log, const void *data, size_t size); int logger_rotate(LOGGER_HANDLE *log); + int logger_sync(LOGGER_HANDLE *log); + int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size); #endif diff --git a/include/service_versions.h b/include/service_versions.h index 40e668ea843..45cad4d86ae 100644 --- a/include/service_versions.h +++ b/include/service_versions.h @@ -26,7 +26,7 @@ #define VERSION_base64 0x0100 #define VERSION_encryption 0x0300 #define VERSION_encryption_scheme 0x0100 -#define VERSION_logger 0x0200 +#define VERSION_logger 0x0300 #define VERSION_my_crypt 0x0101 #define VERSION_my_md5 0x0100 #define VERSION_my_print_error 0x0200 diff --git a/mysql-test/include/print_file_line_count.inc b/mysql-test/include/print_file_line_count.inc new file mode 100644 index 00000000000..ead5a80a21b --- /dev/null +++ b/mysql-test/include/print_file_line_count.inc @@ -0,0 +1,10 @@ +--perl + my $fname= "$ENV{'SEARCH_FILE'}" or die "SEARCH_FILE not set"; + open (FILE, '<', "$fname") or die("Unable to open '$fname': $!\n"); +# Count lines in the SEARCH_FILE. + my $line_count = 0; + $line_count++ while ; + close(FILE); + + print "$line_count\n" +EOF diff --git a/mysql-test/suite/plugins/r/server_audit.result b/mysql-test/suite/plugins/r/server_audit.result index 73424a19c08..41b9933d9e1 100644 --- a/mysql-test/suite/plugins/r/server_audit.result +++ b/mysql-test/suite/plugins/r/server_audit.result @@ -3,6 +3,7 @@ show variables like 'server_audit%'; Variable_name Value server_audit_events server_audit_excl_users +server_audit_file_buffer_size 0 server_audit_file_path server_audit.log server_audit_file_rotate_now OFF server_audit_file_rotate_size 1000000 @@ -12,6 +13,7 @@ server_audit_logging OFF server_audit_mode 0 server_audit_output_type file server_audit_query_log_limit 1024 +server_audit_sync_log_file OFF server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info @@ -84,6 +86,7 @@ show variables like 'server_audit%'; Variable_name Value server_audit_events CONNECT,QUERY server_audit_excl_users +server_audit_file_buffer_size 0 server_audit_file_path server_audit.log server_audit_file_rotate_now OFF server_audit_file_rotate_size 1000000 @@ -93,6 +96,7 @@ server_audit_logging ON server_audit_mode 0 server_audit_output_type file server_audit_query_log_limit 1024 +server_audit_sync_log_file OFF server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info @@ -307,6 +311,7 @@ show variables like 'server_audit%'; Variable_name Value server_audit_events server_audit_excl_users +server_audit_file_buffer_size 0 server_audit_file_path server_audit_file_rotate_now OFF server_audit_file_rotate_size 1000000 @@ -316,6 +321,7 @@ server_audit_logging ON server_audit_mode 1 server_audit_output_type file server_audit_query_log_limit 1024 +server_audit_sync_log_file OFF server_audit_syslog_facility LOG_USER server_audit_syslog_ident mysql-server_auditing server_audit_syslog_info diff --git a/mysql-test/suite/plugins/r/server_audit_buffering.result b/mysql-test/suite/plugins/r/server_audit_buffering.result new file mode 100644 index 00000000000..dc2217c8f06 --- /dev/null +++ b/mysql-test/suite/plugins/r/server_audit_buffering.result @@ -0,0 +1,37 @@ +install plugin server_audit soname 'server_audit'; +set global server_audit_file_buffer_size=1024; +show variables like 'server_audit%'; +Variable_name Value +server_audit_events +server_audit_excl_users +server_audit_file_buffer_size 1024 +server_audit_file_path server_audit.log +server_audit_file_rotate_now OFF +server_audit_file_rotate_size 1000000 +server_audit_file_rotations 9 +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_sync_log_file OFF +server_audit_syslog_facility LOG_USER +server_audit_syslog_ident mysql-server_auditing +server_audit_syslog_info +server_audit_syslog_priority LOG_INFO +set global server_audit_logging=on; +118 +set global server_audit_sync_log_file=on; +201 +set global server_audit_file_buffer_size=2048; +630 +set global server_audit_sync_log_file=on; +703 +set global server_audit_file_buffer_size=0; +805 +set global server_audit_sync_log_file=on; +806 +set global server_audit_logging=off; +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_buffering.test b/mysql-test/suite/plugins/t/server_audit_buffering.test new file mode 100644 index 00000000000..9e9a659e157 --- /dev/null +++ b/mysql-test/suite/plugins/t/server_audit_buffering.test @@ -0,0 +1,85 @@ +--source include/have_plugin_auth.inc +--source include/not_embedded.inc + +if (!$SERVER_AUDIT_SO) { + skip No SERVER_AUDIT plugin; +} + +--disable_ps2_protocol +# An unfortunate wait for check-testcase.inc to complete disconnect. +let count_sessions= 1; +source include/wait_until_count_sessions.inc; + +let $MYSQLD_DATADIR= `SELECT @@datadir`; +let SEARCH_FILE= $MYSQLD_DATADIR/server_audit.log; + +install plugin server_audit soname 'server_audit'; + +set global server_audit_file_buffer_size=1024; + +show variables like 'server_audit%'; + +set global server_audit_logging=on; + +let $counter=200; +--disable_query_log +--disable_result_log +while ($counter) +{ + eval select $counter; + dec $counter; +} +--enable_result_log +--enable_query_log + +--source include/print_file_line_count.inc + +set global server_audit_sync_log_file=on; + +--source include/print_file_line_count.inc + +set global server_audit_file_buffer_size=2048; + +let $counter=500; +--disable_query_log +--disable_result_log +while ($counter) +{ + eval select $counter; + dec $counter; +} +--enable_result_log +--enable_query_log + +--source include/print_file_line_count.inc + +set global server_audit_sync_log_file=on; + +--source include/print_file_line_count.inc + +set global server_audit_file_buffer_size=0; + +let $counter=100; +--disable_query_log +--disable_result_log +while ($counter) +{ + eval select $counter; + dec $counter; +} +--enable_result_log +--enable_query_log + +--source include/print_file_line_count.inc + +set global server_audit_sync_log_file=on; + +--source include/print_file_line_count.inc + +set global server_audit_logging=off; + +uninstall plugin server_audit; + +remove_file $MYSQLD_DATADIR/server_audit.log; +--enable_ps2_protocol + diff --git a/mysys/file_logger.c b/mysys/file_logger.c index a753c049f68..54c606d4be8 100644 --- a/mysys/file_logger.c +++ b/mysys/file_logger.c @@ -22,13 +22,6 @@ #include #endif /*FLOGGER_SKIP_INCLUDES*/ -#ifndef flogger_mutex_init -#define flogger_mutex_init(A,B,C) mysql_mutex_init(A,B,C) -#define flogger_mutex_destroy(A) mysql_mutex_destroy(A) -#define flogger_mutex_lock(A) mysql_mutex_lock(A) -#define flogger_mutex_unlock(A) mysql_mutex_unlock(A) -#endif /*flogger_mutex_init*/ - #ifdef HAVE_PSI_INTERFACE /* These belong to the service initialization */ static PSI_mutex_key key_LOCK_logger_service; @@ -38,11 +31,13 @@ static PSI_mutex_info mutex_list[]= typedef struct logger_handle_st { File file; + IO_CACHE cache; char path[FN_REFLEN]; unsigned long long size_limit; unsigned int rotations; - size_t path_len; + size_t path_len, buffer_size; mysql_mutex_t lock; + my_off_t filesize; } LSFS; @@ -56,7 +51,7 @@ static unsigned int n_dig(unsigned int i) LOGGER_HANDLE *logger_open(const char *path, unsigned long long size_limit, - unsigned int rotations) + unsigned int rotations, size_t buffer_size) { LOGGER_HANDLE new_log, *l_perm; /* @@ -66,6 +61,12 @@ LOGGER_HANDLE *logger_open(const char *path, if (rotations > 999) return 0; + if (buffer_size > 0 && buffer_size < 1024) + buffer_size= 1024; + + if (rotations > 0 && size_limit < buffer_size) + buffer_size= size_limit; + new_log.rotations= rotations; new_log.size_limit= size_limit; new_log.path_len= strlen(fn_format(new_log.path, path, @@ -92,8 +93,16 @@ LOGGER_HANDLE *logger_open(const char *path, return 0; /* End of memory */ } *l_perm= new_log; - flogger_mutex_init(key_LOCK_logger_service, &l_perm->lock, - MY_MUTEX_INIT_FAST); + mysql_mutex_init(key_LOCK_logger_service, &l_perm->lock, + MY_MUTEX_INIT_FAST); + + l_perm->buffer_size= buffer_size; + l_perm->filesize= my_seek(new_log.file, 0L, MY_SEEK_END, MYF(0)); + + if (l_perm->buffer_size) + init_io_cache(&l_perm->cache, new_log.file, l_perm->buffer_size, + WRITE_CACHE, l_perm->filesize, FALSE, MYF(MY_WME | MY_NABP)); + return l_perm; } @@ -101,7 +110,9 @@ int logger_close(LOGGER_HANDLE *log) { int result; File file= log->file; - flogger_mutex_destroy(&log->lock); + mysql_mutex_destroy(&log->lock); + if (log->buffer_size) + (void) end_io_cache(&log->cache); my_free(log); if ((result= my_close(file, MYF(0)))) errno= my_errno; @@ -140,14 +151,26 @@ static int do_rotate(LOGGER_HANDLE *log) buf_old= buf_new; buf_new= tmp; } + + if (log->buffer_size) + (void) end_io_cache(&log->cache); + if ((result= my_close(log->file, MYF(0)))) goto exit; namebuf[log->path_len]= 0; - result= my_rename(namebuf, logname(log, log->path, 1), MYF(0)); - log->file= my_open(namebuf, LOG_FLAGS, MYF(0)); + if ((result= my_rename(namebuf, logname(log, log->path, 1), MYF(0)))) + goto exit; + + if ((result= (log->file= my_open(namebuf, LOG_FLAGS, MYF(0))) < 0)) + goto exit; + + if (log->buffer_size) + result= init_io_cache(&log->cache, log->file, log->buffer_size, + WRITE_CACHE, 0L, FALSE, MYF(MY_WME | MY_NABP)); + log->filesize= 0; exit: errno= my_errno; - return log->file < 0 || result; + return result; } @@ -155,24 +178,30 @@ exit: Return 1 if we should rotate the log */ -my_bool logger_time_to_rotate(LOGGER_HANDLE *log) +static my_bool logger_time_to_rotate(LOGGER_HANDLE *log) { - my_off_t filesize; - if (log->rotations > 0 && - (filesize= my_tell(log->file, MYF(0))) != (my_off_t) -1 && - ((ulonglong) filesize >= log->size_limit)) - return 1; - return 0; + return log->rotations > 0 && log->filesize >= log->size_limit; } int logger_vprintf(LOGGER_HANDLE *log, const char* fmt, va_list ap) { - int result; char cvtbuf[1024]; size_t n_bytes; - flogger_mutex_lock(&log->lock); + n_bytes= my_vsnprintf(cvtbuf, sizeof(cvtbuf), fmt, ap); + if (n_bytes >= sizeof(cvtbuf)) + n_bytes= sizeof(cvtbuf) - 1; + + return logger_write(log, (uchar *) cvtbuf, n_bytes); +} + + +int logger_write(LOGGER_HANDLE *log, const void *buffer, size_t size) +{ + int result; + + mysql_mutex_lock(&log->lock); if (logger_time_to_rotate(log) && do_rotate(log)) { result= -1; @@ -180,50 +209,79 @@ int logger_vprintf(LOGGER_HANDLE *log, const char* fmt, va_list ap) goto exit; /* Log rotation needed but failed */ } - n_bytes= my_vsnprintf(cvtbuf, sizeof(cvtbuf), fmt, ap); - if (n_bytes >= sizeof(cvtbuf)) - n_bytes= sizeof(cvtbuf) - 1; - - result= (int)my_write(log->file, (uchar *) cvtbuf, n_bytes, MYF(0)); - -exit: - flogger_mutex_unlock(&log->lock); - return result; -} - - -static int logger_write_r(LOGGER_HANDLE *log, my_bool allow_rotations, - const char *buffer, size_t size) -{ - int result; - - flogger_mutex_lock(&log->lock); - if (allow_rotations && logger_time_to_rotate(log) && do_rotate(log)) + if (log->buffer_size) { - result= -1; - errno= my_errno; - goto exit; /* Log rotation needed but failed */ + result= my_b_write(&log->cache, (uchar *) buffer, size) ? 0 : size; } - - result= (int)my_write(log->file, (uchar *) buffer, size, MYF(0)); + else + { + result= (int) my_write(log->file, (uchar *) buffer, size, MYF(0)); + } + + log->filesize+= result; exit: - flogger_mutex_unlock(&log->lock); + mysql_mutex_unlock(&log->lock); return result; } -int logger_write(LOGGER_HANDLE *log, const char *buffer, size_t size) -{ - return logger_write_r(log, TRUE, buffer, size); -} - int logger_rotate(LOGGER_HANDLE *log) { int result; - flogger_mutex_lock(&log->lock); + mysql_mutex_lock(&log->lock); result= do_rotate(log); - flogger_mutex_unlock(&log->lock); + mysql_mutex_unlock(&log->lock); + return result; +} + + + +int logger_sync(LOGGER_HANDLE *log) +{ + int result= 0; + + mysql_mutex_lock(&log->lock); + + if (log->buffer_size == 0) + goto sync_file; + + result= my_b_flush_io_cache(&log->cache, 0); + +sync_file: + if (!result) + result= fsync(log->file); + + mysql_mutex_unlock(&log->lock); + + return result; +} + + +int logger_resize_buffer(LOGGER_HANDLE *log, size_t new_buffer_size) +{ + int result= 0; + + if (new_buffer_size > 0 && new_buffer_size < 1024) + new_buffer_size= 1024; + + if (log->rotations > 0 && log->size_limit < new_buffer_size) + new_buffer_size= log->size_limit; + + + mysql_mutex_lock(&log->lock); + if (log->buffer_size) + { + if (end_io_cache(&log->cache)) + goto exit; + } + + if ((log->buffer_size= new_buffer_size)) + result= init_io_cache(&log->cache, log->file, new_buffer_size, + WRITE_CACHE, log->filesize, FALSE, MYF(MY_WME | MY_NABP)); + +exit: + mysql_mutex_unlock(&log->lock); return result; } diff --git a/plugin/server_audit/server_audit.c b/plugin/server_audit/server_audit.c index 296b2c311b9..77f28a50cae 100644 --- a/plugin/server_audit/server_audit.c +++ b/plugin/server_audit/server_audit.c @@ -109,20 +109,24 @@ static void closelog() {} #define mysql_mutex_real_mutex(A) &(A)->m_mutex #endif -#define flogger_mutex_init(A,B,C) do{}while(0) -#define flogger_mutex_destroy(A) do{}while(0) -#define flogger_mutex_lock(A) do{}while(0) -#define flogger_mutex_unlock(A) do{}while(0) - static char **int_mysql_data_home; static char *default_home= (char *)"."; #define mysql_data_home (*int_mysql_data_home) +#undef mysql_mutex_init +#undef mysql_mutex_destroy +#undef mysql_mutex_lock +#undef mysql_mutex_unlock + +#define mysql_mutex_init(A,B,C) pthread_mutex_init(mysql_mutex_real_mutex(B), C) +#define mysql_mutex_destroy(A) pthread_mutex_destroy(mysql_mutex_real_mutex(A)) +#define mysql_mutex_lock(A) pthread_mutex_lock(mysql_mutex_real_mutex(A)) +#define mysql_mutex_unlock(A) pthread_mutex_unlock(mysql_mutex_real_mutex(A)) + #define FLOGGER_SKIP_INCLUDES #define my_open(A, B, C) loc_open(A, B) #define my_close(A, B) loc_close(A) #define my_rename(A, B, C) loc_rename(A, B) -#define my_tell(A, B) loc_tell(A) #define my_write(A, B, C, D) loc_write(A, B, C) #define my_malloc(A, B, C) malloc(B) #define my_free(A) free(A) @@ -140,7 +144,8 @@ static int loc_file_errno; #define logger_write loc_logger_write #define logger_rotate loc_logger_rotate #define logger_init_mutexts loc_logger_init_mutexts -#define logger_time_to_rotate loc_logger_time_to_rotate +#define logger_sync loc_logger_sync +#define logger_resize_buffer loc_logger_resize_buffer #ifndef HOSTNAME_LENGTH #define HOSTNAME_LENGTH 255 @@ -236,16 +241,6 @@ static int loc_rename(const char *from, const char *to) } -static my_off_t loc_tell(File fd) -{ - os_off_t pos= IF_WIN(_telli64(fd),lseek(fd, 0, SEEK_CUR)); - if (pos == (os_off_t) -1) - { - my_errno= errno; - } - return (my_off_t) pos; -} - #ifdef HAVE_PSI_INTERFACE #undef HAVE_PSI_INTERFACE #include @@ -305,6 +300,8 @@ static ulonglong events; /* mask for events to log */ static unsigned long long file_rotate_size; static unsigned int rotations; static my_bool rotate= TRUE; +static my_bool sync_file= TRUE; +static unsigned int file_buffer_size; static char logging; static volatile int internal_stop_logging= 0; static char incl_user_buffer[1024]; @@ -352,6 +349,8 @@ static void update_file_rotate_size(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); static void update_file_rotations(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); +static void update_file_buffer_size(MYSQL_THD thd, struct st_mysql_sys_var *var, + void *var_ptr, const void *save); static void update_incl_users(MYSQL_THD thd, struct st_mysql_sys_var *var, void *var_ptr, const void *save); static int check_incl_users(MYSQL_THD thd, struct st_mysql_sys_var *var, void *save, @@ -374,6 +373,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 sync_log(MYSQL_THD thd, struct st_mysql_sys_var *var, + void *var_ptr, const void *save); static MYSQL_SYSVAR_STR(incl_users, incl_users, PLUGIN_VAR_RQCMDARG, "Comma separated list of users to monitor", @@ -429,8 +430,13 @@ static MYSQL_SYSVAR_ULONGLONG(file_rotate_size, file_rotate_size, static MYSQL_SYSVAR_UINT(file_rotations, rotations, PLUGIN_VAR_RQCMDARG, "Number of rotations before log is removed", NULL, update_file_rotations, 9, 0, 999, 1); +static MYSQL_SYSVAR_UINT(file_buffer_size, file_buffer_size, + PLUGIN_VAR_RQCMDARG, "Size of file buffer to make logging faster", + NULL, update_file_buffer_size, 0, 0, 65536, 1); static MYSQL_SYSVAR_BOOL(file_rotate_now, rotate, PLUGIN_VAR_OPCMDARG, "Force log rotation now", NULL, rotate_log, FALSE); +static MYSQL_SYSVAR_BOOL(sync_log_file, sync_file, PLUGIN_VAR_OPCMDARG, + "Force sync log file", NULL, sync_log, FALSE); static MYSQL_SYSVAR_BOOL(logging, logging, PLUGIN_VAR_OPCMDARG, "Turn on/off the logging", NULL, update_logging, 0); @@ -516,12 +522,14 @@ static struct st_mysql_sys_var* vars[] = { MYSQL_SYSVAR(excl_users), MYSQL_SYSVAR(events), MYSQL_SYSVAR(output_type), + MYSQL_SYSVAR(file_buffer_size), MYSQL_SYSVAR(file_path), MYSQL_SYSVAR(file_rotate_size), MYSQL_SYSVAR(file_rotations), MYSQL_SYSVAR(file_rotate_now), MYSQL_SYSVAR(logging), MYSQL_SYSVAR(mode), + MYSQL_SYSVAR(sync_log_file), MYSQL_SYSVAR(syslog_info), MYSQL_SYSVAR(syslog_ident), MYSQL_SYSVAR(syslog_facility), @@ -1138,7 +1146,8 @@ static int start_logging() } } - logfile= logger_open(alt_fname, file_rotate_size, rotations); + logfile= logger_open(alt_fname, file_rotate_size, + rotations, file_buffer_size); if (logfile == NULL) { @@ -1404,25 +1413,13 @@ static int write_log(const char *message, size_t len, int take_lock) { int result= 0; if (take_lock) - { - /* Start by taking a read lock */ mysql_prlock_rdlock(&lock_operations); - } if (output_type == OUTPUT_FILE) { if (logfile) { - my_bool allow_rotate= !take_lock; /* Allow rotate if caller write lock */ - if (take_lock && logger_time_to_rotate(logfile)) - { - /* We have to rotate the log, change above read lock to write lock */ - mysql_prlock_unlock(&lock_operations); - mysql_prlock_wrlock(&lock_operations); - allow_rotate= 1; - } - if (!(is_active= (logger_write_r(logfile, allow_rotate, message, len) == - (int) len))) + if (!(is_active= (logger_write(logfile, message, len) == (int) len))) { ++log_write_failures; result= 1; @@ -2794,6 +2791,16 @@ static void rotate_log(MYSQL_THD thd __attribute__((unused)), } +static void sync_log(MYSQL_THD thd __attribute__((unused)), + struct st_mysql_sys_var *var __attribute__((unused)), + void *var_ptr __attribute__((unused)), + const void *save __attribute__((unused))) +{ + if (output_type == OUTPUT_FILE && logfile && *(my_bool*) save) + (void) logger_sync(logfile); +} + + static struct st_mysql_audit mysql_descriptor = { MYSQL_AUDIT_INTERFACE_VERSION, @@ -2969,6 +2976,37 @@ static void update_file_rotate_size(MYSQL_THD thd __attribute__((unused)), } +static void update_file_buffer_size(MYSQL_THD thd __attribute__((unused)), + struct st_mysql_sys_var *var __attribute__((unused)), + void *var_ptr __attribute__((unused)), const void *save) +{ + file_buffer_size= *(unsigned int *) save; + + error_header(); + fprintf(stderr, "Log file buffer size was changed to '%d'.\n", file_buffer_size); + + if (!logging || output_type != OUTPUT_FILE) + return; + + ADD_ATOMIC(internal_stop_logging, 1); + if (!maria_55_started || !debug_server_started) + mysql_prlock_wrlock(&lock_operations); + + if (logger_resize_buffer(logfile, file_buffer_size)) + { + stop_logging(); + error_header(); + fprintf(stderr, "Buffer resize failed. Logging was disabled..\n"); + CLIENT_ERROR(1, "Buffer resize failed. Logging was disabled.", + MYF(ME_WARNING)); + } + + if (!maria_55_started || !debug_server_started) + mysql_prlock_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); +} + + static int check_users(void *save, struct st_mysql_value *value, size_t s, const char *name) { diff --git a/plugin/sql_errlog/sql_errlog.c b/plugin/sql_errlog/sql_errlog.c index cb7efef0ef6..fa3ac70b091 100644 --- a/plugin/sql_errlog/sql_errlog.c +++ b/plugin/sql_errlog/sql_errlog.c @@ -151,7 +151,7 @@ static int sql_error_log_init(void *p __attribute__((unused))) { logger_init_mutexes(); - logfile= logger_open(filename, size_limit, rotations); + logfile= logger_open(filename, size_limit, rotations, 0); if (logfile == NULL) { fprintf(stderr, "Could not create file '%s'\n", filename); diff --git a/sql/sql_plugin_services.inl b/sql/sql_plugin_services.inl index 5d314dcfce8..a7d3d9f81db 100644 --- a/sql/sql_plugin_services.inl +++ b/sql/sql_plugin_services.inl @@ -114,7 +114,9 @@ static struct logger_service_st logger_service_handler= { logger_vprintf, logger_printf, logger_write, - logger_rotate + logger_rotate, + logger_sync, + logger_resize_buffer }; static struct thd_autoinc_service_st thd_autoinc_handler= {