[MDEV-9094] SET GLOBAL server_audit_logging=OFF can cause server crash when using audit plugin with MySQL 5.6 Created: 2015-11-06  Updated: 2018-02-07  Resolved: 2017-02-27

Status: Closed
Project: MariaDB Server
Component/s: Plugin - Audit
Affects Version/s: 5.5.46, 10.0.22
Fix Version/s: 5.5.55

Type: Bug Priority: Major
Reporter: Geoff Montee (Inactive) Assignee: Alexey Botchkov
Resolution: Cannot Reproduce Votes: 2
Labels: None

Attachments: File FuncionesUTN.c    

 Description   

When using version 1.3.0 of the audit plugin bundled in MariaDB 5.5.46 and 10.0.22 with MySQL 5.6, the server can crash. This crash was originally experienced with audit plugin version 1.1.8, and we thought it may have been caused by MDEV-7641. However, the crash still happens after upgrading to 1.3.0.

151106 18:20:19 server_audit: MariaDB Audit Plugin version 1.3.0 STARTED.
 
151106 18:22:32 server_audit: Log file name was changed to '/mysqllog/audit/'.
 
151106 18:22:32 server_audit: Log file rotate size was changed to '5000000000'.
 
151106 18:22:32 server_audit: Log file rotations was changed to '5'.
 
151106 18:22:32 server_audit: server_audit_incl_users set to 'toadmin,root,lion_admin,fos_admin'.
 
151106 18:22:55 server_audit: logging started to the file /mysqllog/audit/server_audit.log.
 
18:24:56 UTC - mysqld got signal 11 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
key_buffer_size=33554432
 
read_buffer_size=131072
 
max_used_connections=5
 
max_threads=13100
 
thread_count=4
 
connection_count=2
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8596278 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x2aae0c146020
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 4da860d0 thread_stack 0x40000
 
/opt/mysql/product/mysql/bin/mysqld(my_print_stacktrace+0x35)[0x904cb5]
 
/opt/mysql/product/mysql/bin/mysqld(handle_fatal_signal+0x3e8)[0x6718c8]
 
/lib64/libpthread.so.0[0x306e00ebe0]
 
/opt/mysql/product/mysql/lib/plugin/server_audit.so[0x2aae0b5ddaf5]
 
/opt/mysql/product/mysql/lib/plugin/server_audit.so[0x2aae0b5e0092]
 
/opt/mysql/product/mysql/lib/plugin/server_audit.so[0x2aae0b5e0977]
 
/opt/mysql/product/mysql/lib/plugin/server_audit.so[0x2aae0b5e3769]
 
/opt/mysql/product/mysql/bin/mysqld(_ZN17sys_var_pluginvar13global_updateEP3THDP7set_var+0x5d)[0x6fdffd]
 
/opt/mysql/product/mysql/bin/mysqld(_ZN7sys_var6updateEP3THDP7set_var+0x6a)[0x670baa]
 
/opt/mysql/product/mysql/bin/mysqld(_ZN7set_var6updateEP3THD+0x1a)[0x6710aa]
 
/opt/mysql/product/mysql/bin/mysqld(_Z17sql_set_variablesP3THDP4ListI12set_var_baseE+0x89)[0x670649]
 
/opt/mysql/product/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0x14d9)[0x6f0df9]
 
/opt/mysql/product/mysql/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x318)[0x6f6898]
 
/opt/mysql/product/mysql/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xbcb)[0x6f7c6b]
 
/opt/mysql/product/mysql/bin/mysqld(_Z10do_commandP3THD+0xd7)[0x6f9a67]
 
/opt/mysql/product/mysql/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x116)[0x6c1b26]
 
/opt/mysql/product/mysql/bin/mysqld(handle_one_connection+0x45)[0x6c1c05]
 
/lib64/libpthread.so.0[0x306e00677d]
 
/lib64/libc.so.6(clone+0x6d)[0x306d0d33ed]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (2aae10183900): SET GLOBAL server_audit_logging=OFF
 
Connection ID (thread ID): 2622
 
Status: NOT_KILLED



 Comments   
Comment by Stephen Smith [ 2016-04-20 ]

I've had the exact same problem using version 1.3 and 1.4 of the plugin on Percona Server 5.6.14. It also happens with other global commands in 1.4 , for example:

MYSQL> set global server_audit_file_path='/mysql/logs/logs/audit.log';
ERROR 2013 (HY000): Lost connection to MySQL server during query
ERROR 2006 (HY000): MySQL server has gone away

Comment by Stephen Smith [ 2016-04-26 ]

I did more testing on Percona 5.6.14 and found that if mysql is restarted at least once before issuing the "SET GLOBAL server_audit_logging=OFF", the crash does not happen.

Also, I tested Percona 5.6.29 and found that no crashes happen at all, even if mysql is not restarted before turning the audit plugin off.

Comment by Alexey Botchkov [ 2017-02-27 ]

Can't repeat. Was probably fixed already.

Comment by David Villalobos Cambronero [ 2018-02-07 ]

Hi all,

Days ago I started to develop a custom MariaDB plug-in, and after some research found this report, I am trying to create an MYSQL_AUDIT_PLUGIN and when I try to set a value to a variable the server crashes, if I create a MYSQL_DAEMON_PLUGIN plug-in the process of setting a value works just fine, any clue? FuncionesUTN.c

PD.
The error is present in 10.1.30-MariaDB and 10.2.12-MariaDB-10.2.12+maria~xenial-log

Best regards
David

Comment by David Villalobos Cambronero [ 2018-02-07 ]

Hi all,

I found a solution, if I set the update function everything works fine.

static char *incl_users;
 
static char empty_str[1]= { 0 };
 
 
 
static void update_incl_users(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.",
 
                        NULL, update_incl_users, NULL);
 
static void update_incl_users(MYSQL_THD thd,
 
                              struct st_mysql_sys_var *var  __attribute__((unused)),
 
                              void *var_ptr  __attribute__((unused)), const void *save)
 
{
 
  char *new_users = (*(char **) save) ? *(char **) save : empty_str;
 
  incl_users = new_users;
 
//   if (!maria_55_started || !debug_server_started)
 
//     flogger_mutex_lock(&lock_operations);
 
//   mark_always_logged(thd);
 
//   strncpy(incl_user_buffer, new_users, sizeof(incl_user_buffer));
 
//   incl_user_buffer[sizeof(incl_user_buffer)-1]= 0;
 
//   incl_users= incl_user_buffer;
 
//   user_coll_fill(&incl_user_coll, incl_users, &excl_user_coll, 1);
 
//   error_header();
 
//   fprintf(stderr, "server_audit_incl_users set to '%s'.\n", incl_users);
 
//   if (!maria_55_started || !debug_server_started)
 
//     flogger_mutex_unlock(&lock_operations);
 
 
 
static struct st_mysql_sys_var* vars[] = {
 
  MYSQL_SYSVAR(incl_users),
 
  NULL
 
};
 
}
 
 
 
maria_declare_plugin(UTN)
 
{
 
  MYSQL_AUDIT_PLUGIN,
 
  &utn_plugin_audit_info,
 
  "UTN_Auditoria",
 
  "David Villalobos Cambronero <dvillalobos@utn.ac.cr>",
 
  "Plugin de auditoría para MaríaDB.",
 
  PLUGIN_LICENSE_GPL,
 
  Inicializador_Auditoria,
 
  Finalizador_Auditoria,
 
  0x0100,
 
  NULL,
 
  vars,
 
  "Versión 1",
 
  MariaDB_PLUGIN_MATURITY_STABLE
 
}
 
maria_declare_plugin_end;

Generated at Thu Feb 08 07:32:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.