- commits - lists.mariadb.org

[Commits] a2e9e3fbd48: MyRocks: dont show read-Free replication variables
by Sergei Petrunia 20 Jun '19

20 Jun '19

revision-id: a2e9e3fbd485181a4db679a163167b9a833e67ad (mariadb-10.2.25-15-ga2e9e3fbd48) parent(s): 7f845c6653b8ce3d13ab327e1f5feb53c3c47ea1 author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-06-20 15:29:17 +0300 message: MyRocks: dont show read-Free replication variables MariaDB doesn't support Read-Free replication, so showing them only causes confusion. Removed variables: - @@rocksdb_read_free_rpl - @@rocksdb_read_free_rpl_tables --- storage/rocksdb/ha_rocksdb.cc | 21 ++++++++++++++++++++- storage/rocksdb/ha_rocksdb.h | 7 ++++--- .../mysql-test/rocksdb_sys_vars/t/disabled.def | 5 +++++ storage/rocksdb/rdb_datadic.cc | 4 ++++ 4 files changed, 33 insertions(+), 4 deletions(-) diff --git a/storage/rocksdb/ha_rocksdb.cc b/storage/rocksdb/ha_rocksdb.cc index 397f98b46d1..41a83c816d3 100644 --- a/storage/rocksdb/ha_rocksdb.cc +++ b/storage/rocksdb/ha_rocksdb.cc @@ -640,6 +640,8 @@ char *compression_types_val= const_cast<char*>(get_rocksdb_supported_compression_types()); static unsigned long rocksdb_write_policy = rocksdb::TxnDBWritePolicy::WRITE_COMMITTED; + +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported char *rocksdb_read_free_rpl_tables; std::mutex rocksdb_read_free_rpl_tables_mutex; #if defined(HAVE_PSI_INTERFACE) @@ -649,6 +651,8 @@ Regex_list_handler rdb_read_free_regex_handler; #endif enum read_free_rpl_type { OFF = 0, PK_ONLY, PK_SK }; static unsigned long rocksdb_read_free_rpl = read_free_rpl_type::OFF; +#endif + static my_bool rocksdb_error_on_suboptimal_collation = 1; static uint32_t rocksdb_stats_recalc_rate = 0; static uint32_t rocksdb_debug_manual_compaction_delay = 0; @@ -758,12 +762,14 @@ static TYPELIB write_policy_typelib = {array_elements(write_policy_names) - 1, "write_policy_typelib", write_policy_names, nullptr}; +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported /* This array needs to be kept up to date with myrocks::read_free_rpl_type */ static const char *read_free_rpl_names[] = {"OFF", "PK_ONLY", "PK_SK", NullS}; static TYPELIB read_free_rpl_typelib = {array_elements(read_free_rpl_names) - 1, "read_free_rpl_typelib", read_free_rpl_names, nullptr}; +#endif /* This enum needs to be kept up to date with rocksdb::InfoLogLevel */ static const char *info_log_level_names[] = {"debug_level", "info_level", @@ -985,6 +991,8 @@ static MYSQL_THDVAR_BOOL( " Blind delete is disabled if the table has secondary key", nullptr, nullptr, FALSE); +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported + static const char *DEFAULT_READ_FREE_RPL_TABLES = ".*"; static int rocksdb_validate_read_free_rpl_tables( @@ -1059,6 +1067,7 @@ static MYSQL_SYSVAR_ENUM( "primary key. PK_ONLY will enable it on tables where the only key is the " "primary key (i.e. no secondary keys).", nullptr, nullptr, read_free_rpl_type::OFF, &read_free_rpl_typelib); +#endif static MYSQL_THDVAR_BOOL(skip_bloom_filter_on_read, PLUGIN_VAR_RQCMDARG, "Skip using bloom filter for reads", nullptr, nullptr, @@ -1986,8 +1995,10 @@ static struct st_mysql_sys_var *rocksdb_system_variables[] = { MYSQL_SYSVAR(trace_sst_api), MYSQL_SYSVAR(commit_in_the_middle), MYSQL_SYSVAR(blind_delete_primary_key), +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported MYSQL_SYSVAR(read_free_rpl_tables), MYSQL_SYSVAR(read_free_rpl), +#endif MYSQL_SYSVAR(bulk_load_size), MYSQL_SYSVAR(merge_buf_size), MYSQL_SYSVAR(enable_bulk_load_api), @@ -5287,7 +5298,9 @@ static int rocksdb_init_func(void *const p) { rocksdb_db_options->max_open_files = open_files_limit / 2; } +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported rdb_read_free_regex_handler.set_patterns(DEFAULT_READ_FREE_RPL_TABLES); +#endif rocksdb_stats = rocksdb::CreateDBStatistics(); rocksdb_stats->set_stats_level( @@ -14418,9 +14431,11 @@ void ha_rocksdb::rpl_after_update_rows() { DBUG_VOID_RETURN; } +#if 0 bool ha_rocksdb::is_read_free_rpl_table() const { return table->s && m_tbl_def->m_is_read_free_rpl_table; } +#endif /** @brief @@ -14430,10 +14445,11 @@ bool ha_rocksdb::is_read_free_rpl_table() const { bool ha_rocksdb::use_read_free_rpl() const { DBUG_ENTER_FUNC(); - if (!ha_thd()->rli_slave || table->triggers || !is_read_free_rpl_table()) { + if (!ha_thd()->rli_slave || table->triggers || /* !is_read_free_rpl_table()*/ ) { DBUG_RETURN(false); } +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported switch (rocksdb_read_free_rpl) { case read_free_rpl_type::OFF: DBUG_RETURN(false); @@ -14442,6 +14458,9 @@ bool ha_rocksdb::use_read_free_rpl() const { case read_free_rpl_type::PK_SK: DBUG_RETURN(!has_hidden_pk(table)); } +#else + DBUG_RETURN(false); +#endif DBUG_ASSERT(false); DBUG_RETURN(false); diff --git a/storage/rocksdb/ha_rocksdb.h b/storage/rocksdb/ha_rocksdb.h index 98e6b6212d1..437c8667994 100644 --- a/storage/rocksdb/ha_rocksdb.h +++ b/storage/rocksdb/ha_rocksdb.h @@ -91,12 +91,13 @@ enum collations_used { COLLATION_UTF8_BIN = 83 }; - +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported extern char *rocksdb_read_free_rpl_tables; #if defined(HAVE_PSI_INTERFACE) extern PSI_rwlock_key key_rwlock_read_free_rpl_tables; #endif extern Regex_list_handler rdb_read_free_regex_handler; +#endif /** @brief @@ -969,10 +970,10 @@ class ha_rocksdb : public my_core::handler { TABLE *const altered_table, my_core::Alter_inplace_info *const ha_alter_info, bool commit) override; -#ifdef MARIAROCKS_NOT_YET // MDEV-10976 -#endif void set_skip_unique_check_tables(const char *const whitelist); +#ifdef MARIAROCKS_NOT_YET // MDEV-10976 bool is_read_free_rpl_table() const; +#endif #ifdef MARIAROCKS_NOT_YET // MDEV-10976 public: diff --git a/storage/rocksdb/mysql-test/rocksdb_sys_vars/t/disabled.def b/storage/rocksdb/mysql-test/rocksdb_sys_vars/t/disabled.def new file mode 100644 index 00000000000..efa82ff6184 --- /dev/null +++ b/storage/rocksdb/mysql-test/rocksdb_sys_vars/t/disabled.def @@ -0,0 +1,5 @@ +# Disabled tests + +rocksdb_read_free_rpl_basic : MariaDB: Read-Free replication is not supported +rocksdb_read_free_rpl_tables_basic : MariaDB: Read-Free replication is not supported + diff --git a/storage/rocksdb/rdb_datadic.cc b/storage/rocksdb/rdb_datadic.cc index ccff1ee8a28..fee5d24eb66 100644 --- a/storage/rocksdb/rdb_datadic.cc +++ b/storage/rocksdb/rdb_datadic.cc @@ -3654,7 +3654,11 @@ void Rdb_tbl_def::check_if_is_mysql_system_table() { void Rdb_tbl_def::check_and_set_read_free_rpl_table() { m_is_read_free_rpl_table = +#if 0 // MARIAROCKS_NOT_YET : read-free replication is not supported rdb_read_free_regex_handler.matches(base_tablename()); +#else + false; +#endif } void Rdb_tbl_def::set_name(const std::string &name) {

1 0

[Commits] review for MDEV-14564: Support FOR loop in stored aggregate functions
by Alexander Barkov 20 Jun '19

20 Jun '19

Hi Varun, I was recently assigned as a reviewer for this patch: http://lists.askmonty.org/pipermail/commits/2017-December/011777.html I have some suggestions. 1. The MDEV says the proposed syntax is: FOR GROUP ROWS DO and you implemented: FOR GROUP NEXT ROW DO I think the syntax on MDEV looks better. 2. I don't like that you're adding a new uint member sp_instr_agg_cfetch::m_dest An instruction processing a 'FETCH GROUP NEXT ROW' statement does not need it. 3. The generated code: +show function code f1; +Pos Instruction +0 set total at 1 0 +1 jump_if_not 5(5) 1 +2 +3 set total@1 total@1 + a@0 +4 jump 1 +5 freturn int total at 1 does not look nice. - The command at position 2 must have a name. - The command at position 1 looks like a hack. The underlying code is: + if (! it->val_bool() || thd->spcont->forced_error) So it is a conditional jump which never jumps on the condition, i.e. val_bool(). It jumps only on thd->spcont->forced_error. Please create a new class sp_instr_agg_cfetch_or_jump, derive it from sp_instr, and add m_dest to this class. Please implement print() and execute() for it. print() should display: - the name of the command, "agg_cfetch_or_jump". - the label where it jumps to when 'no rows' happens. Note, sp_instr_agg_cfetch_or_jump will have almost nothing to share with the old sp_instr_agg_cfetch. So sp_instr_agg_cfetch_or_jump should derive from sp_instr, not from sp_instr_agg_cfetch. Please perform jump to a proper position on 'no more rows' just inside sp_instr_agg_cfetch_or_jump::execute() So the code should look about like this: Pos Instruction 0 set total at 1 0 1 agg_cfetch_or_jump 4 2 set total@1 total@1 + a@0 3 jump 1 4 freturn int total at 1 4. As discussed on slack, the name for the command sp_instr_agg_cfetch was probably a not good choise. The "c" in other commands like: - sp_instr_copen - sp_instr_cfetch - sp_instr_cclose is an abbreviation for the word "cursor". sp_instr_agg_cfetch does not use any cursors (i.e. sp_cursor instances). Please rename sp_instr_agg_cfetch to sp_instr_fetch_group_row. And the new command can be named something like: sp_instr_fetch_group_row_or_jump, instead of sp_instr_agg_cfetch_or_jump. Greetings.

1 1

[Commits] 8f708679b: Implement CloudEnvImpl::GetThreadList which redirects the call base_env_
by Sergei Petrunia 19 Jun '19

19 Jun '19

revision-id: 8f708679b365476d0018ae37eac93e4d7dc6d8b7 (v5.18.3-6-g8f708679b) parent(s): 40e5e3f07fbb4072b9b5e4f933eb9aecea1bb737 author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-06-19 18:13:44 +0300 message: Implement CloudEnvImpl::GetThreadList which redirects the call base_env_ Without it, CloudEnvImpl uses Env::GetThreadList(), which returns Status::NotSupported. --- cloud/cloud_env_impl.h | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/cloud/cloud_env_impl.h b/cloud/cloud_env_impl.h index 6cad62d99..7b5f6d55a 100644 --- a/cloud/cloud_env_impl.h +++ b/cloud/cloud_env_impl.h @@ -93,6 +93,10 @@ class CloudEnvImpl : public CloudEnv { void TEST_InitEmptyCloudManifest(); void TEST_DisableCloudManifest() { test_disable_cloud_manifest_ = true; } + Status GetThreadList(std::vector<ThreadStatus>* thread_list) override { + return base_env_->GetThreadList(thread_list); + } + protected: // The type of cloud service e.g. AWS, Azure, Google, etc. const CloudType cloud_type_;

1 0

[Commits] 8b545d3d414: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table
by sachin.setiya＠mariadb.com 19 Jun '19

19 Jun '19

revision-id: 8b545d3d41416772203cb98f06243873a4f0d8f7 (mariadb-10.4.5-24-g8b545d3d414) parent(s): e35676f5557d68c7b51ba47aa73dcdf72eafa436 author: Sachin committer: Sachin timestamp: 2019-05-31 12:02:37 +0530 message: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table When RBR is used, add the db name to db Field and table name to Status Field of the "SHOW FULL PROCESSLIST" command for SQL thread. --- mysql-test/suite/rpl/r/rpl_rbr_monitor.result | 57 +++++++++++++++++ mysql-test/suite/rpl/t/rpl_rbr_monitor.test | 86 +++++++++++++++++++++++++ sql/debug_sync.cc | 3 +- sql/log_event.cc | 90 +++++++++++++++++++++------ 4 files changed, 215 insertions(+), 21 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_rbr_monitor.result b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result new file mode 100644 index 00000000000..67e98b80de0 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result @@ -0,0 +1,57 @@ +include/master-slave.inc +[connection master] +connection master; +create table t1(a int primary key); +connection slave; +SET GLOBAL debug_dbug="+d,should_wait_for_mdev7409"; +select * from t1; +a +connection master; +insert into t1(a) values(1); +#monitoring write rows +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table t1"; +db state +test Write_rows_log_event::write_row(-1) on table t1 +set debug_sync="now signal cont"; +#monitoring update rows +connection master; +update t1 set a = a + 4194304 ; +connection slave; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table t1"; +db state +test Update_rows_log_event::find_row(-1) on table t1 +set debug_sync="now signal cont1"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table t1"; +db state +test Update_rows_log_event::unpack_current_row(-1) on table t1 +set debug_sync="now signal cont2"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table t1"; +db state +test Update_rows_log_event::ha_update_row(-1) on table t1 +set debug_sync="now signal cont3"; +set debug_sync="RESET"; +#monitoring delete rows +connection master; +delete from t1 where a>1; +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table t1"; +db state +test Delete_rows_log_event::find_row(-1) on table t1 +set debug_sync="now signal cont1"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table t1"; +db state +test Delete_rows_log_event::ha_delete_row(-1) on table t1 +set debug_sync="now signal cont2"; +set debug_sync="RESET"; +SET GLOBAL debug_dbug=""; +connection master; +drop table t1; +connection slave; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_rbr_monitor.test b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test new file mode 100644 index 00000000000..e9eca2c0047 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test @@ -0,0 +1,86 @@ +--source include/have_innodb.inc +--source include/have_debug.inc +--source include/have_binlog_format_row.inc +--source include/master-slave.inc +--enable_connect_log + +--connection master +create table t1(a int primary key); +--save_master_pos + +--connection slave +--sync_with_master +SET GLOBAL debug_dbug="+d,should_wait_for_mdev7409"; +select * from t1; + +--connection master +insert into t1(a) values(1); +--save_master_pos + +--echo #monitoring write rows +--connection slave + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table t1"; +set debug_sync="now signal cont"; +--sync_with_master + +--echo #monitoring update rows +--connection master +update t1 set a = a + 4194304 ; + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table t1"; +set debug_sync="now signal cont1"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table t1"; +set debug_sync="now signal cont2"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table t1"; +set debug_sync="now signal cont3"; +set debug_sync="RESET"; +--sync_with_master + +--echo #monitoring delete rows +--connection master +delete from t1 where a>1; + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table t1"; +set debug_sync="now signal cont1"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table t1"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table t1"; +set debug_sync="now signal cont2"; +set debug_sync="RESET"; +--sync_with_master +SET GLOBAL debug_dbug=""; + +#CleanUp +--connection master +drop table t1; +--sync_slave_with_master + +--source include/rpl_end.inc diff --git a/sql/debug_sync.cc b/sql/debug_sync.cc index bf721bddb85..7ca8d8a8ecb 100644 --- a/sql/debug_sync.cc +++ b/sql/debug_sync.cc @@ -1360,7 +1360,8 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action) Do this before emitting the signal, so other threads can see it if they awake before we enter_cond() below. */ - if (action->wait_for.length()) + if (action->wait_for.length() && + DBUG_EVALUATE_IF("should_wait_for_mdev7409", 0, 1)) { st_debug_sync_control *ds_control= thd->debug_sync_control; strxnmov(ds_control->ds_proc_info, sizeof(ds_control->ds_proc_info)-1, diff --git a/sql/log_event.cc b/sql/log_event.cc index f25ebd56792..8c944a6e282 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -54,6 +54,7 @@ #include "rpl_constants.h" #include "sql_digest.h" #include "zlib.h" +#include "debug_sync.h" #define my_b_write_string(A, B) my_b_write((A), (uchar*)(B), (uint) (sizeof(B) - 1)) @@ -13693,19 +13694,29 @@ Write_rows_log_event::do_exec_row(rpl_group_info *rgi) { DBUG_ASSERT(m_table != NULL); const char *tmp= thd->get_proc_info(); - const char *message= "Write_rows_log_event::write_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + my_snprintf(msg, sizeof(msg),"Write_rows_log_event::write_row() on table %s", + m_table->s->table_name.str); + thd->set_db(&m_table->s->db); + message= msg; int error; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Write_rows_log_event::write_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Write_rows_log_event::write_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont")); + };); error= write_row(rgi, slave_exec_mode == SLAVE_EXEC_MODE_IDEMPOTENT); thd_proc_info(thd, tmp); + thd->set_db(tmp_db); if (unlikely(error) && unlikely(!thd->is_error())) { @@ -14368,32 +14379,47 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) { int error; const char *tmp= thd->get_proc_info(); - const char *message= "Delete_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::find_row() on table %s", + m_table->s->table_name.str); + thd->set_db(&m_table->s->db); + message= msg; const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; DBUG_ASSERT(m_table != NULL); #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::find_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str) ; message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont1")); + };); if (likely(!(error= find_row(rgi)))) { /* Delete the record found, located in record[0] */ - message= "Delete_rows_log_event::ha_delete_row()"; + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::ha_delete_row() on table %s", + m_table->s->table_name.str); + message= msg; #ifdef WSREP_PROC_INFO snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::ha_delete_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::ha_delete_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str) ; message= thd->wsrep_info; #endif thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont2")); + };); if (invoke_triggers && unlikely(process_triggers(TRG_EVENT_DELETE, TRG_ACTION_BEFORE, FALSE))) @@ -14422,6 +14448,7 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) m_table->file->ha_index_or_rnd_end(); } thd_proc_info(thd, tmp); + thd->set_db(tmp_db); return error; } @@ -14590,17 +14617,27 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; const char *tmp= thd->get_proc_info(); - const char *message= "Update_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; DBUG_ASSERT(m_table != NULL); + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::find_row() on table %s", + m_table->s->table_name.str); + thd->set_db(&m_table->s->db); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::find_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str) ; message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont1")); + };); + int error= find_row(rgi); if (unlikely(error)) { @@ -14611,6 +14648,7 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) if ((m_curr_row= m_curr_row_end)) unpack_current_row(rgi, &m_cols_ai); thd_proc_info(thd, tmp); + thd->db= *tmp_db; return error; } @@ -14628,16 +14666,22 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) store_record(m_table,record[1]); m_curr_row= m_curr_row_end; - message= "Update_rows_log_event::unpack_current_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::unpack_current_row() on table %s", + m_table->s->table_name.str); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::unpack_current_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::unpack_current_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str) ; message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ /* this also updates m_curr_row_end */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont2")); + };); if (unlikely((error= unpack_current_row(rgi, &m_cols_ai)))) goto err; @@ -14655,15 +14699,21 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) DBUG_DUMP("new values", m_table->record[0], m_table->s->reclength); #endif - message= "Update_rows_log_event::ha_update_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::ha_update_row() on table %s", + m_table->s->table_name.str); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::ha_update_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::ha_update_row(%lld) on table %s", + (long long) wsrep_thd_trx_seqno(thd), m_table->s->table_name.str) ; message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont3")); + };); if (invoke_triggers && unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_BEFORE, TRUE))) { @@ -14693,9 +14743,9 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_AFTER, TRUE))) error= HA_ERR_GENERIC; // in case if error is not set yet - thd_proc_info(thd, tmp); - err: + thd_proc_info(thd, tmp); + thd->set_db(tmp_db); m_table->file->ha_index_or_rnd_end(); return error; }

3 2

[Commits] 4d884aeb68f: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table
by sachin.setiya＠mariadb.com 19 Jun '19

19 Jun '19

revision-id: 4d884aeb68fbe600a7738c5c0204a851510adc93 (mariadb-10.4.5-24-g4d884aeb68f) parent(s): e35676f5557d68c7b51ba47aa73dcdf72eafa436 author: Sachin committer: Sachin timestamp: 2019-06-19 15:54:11 +0530 message: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table When RBR is used, add the db name to db Field and table name to Status Field of the "SHOW FULL PROCESSLIST" command for SQL thread. --- mysql-test/suite/rpl/r/rpl_rbr_monitor.result | 57 ++++++++++++++++ mysql-test/suite/rpl/t/rpl_rbr_monitor.test | 86 ++++++++++++++++++++++++ sql/debug_sync.cc | 3 +- sql/log_event.cc | 96 +++++++++++++++++++++------ 4 files changed, 221 insertions(+), 21 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_rbr_monitor.result b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result new file mode 100644 index 00000000000..fd1c737f95e --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result @@ -0,0 +1,57 @@ +include/master-slave.inc +[connection master] +connection master; +create table t1(a int primary key); +connection slave; +SET GLOBAL debug_dbug="+d,should_wait_for_mdev7409"; +select * from t1; +a +connection master; +insert into t1(a) values(1); +#monitoring write rows +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +db state +test Write_rows_log_event::write_row(-1) on table `t1` +set debug_sync="now signal cont"; +#monitoring update rows +connection master; +update t1 set a = a + 4194304 ; +connection slave; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +db state +test Update_rows_log_event::find_row(-1) on table `t1` +set debug_sync="now signal cont1"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table %"; +db state +test Update_rows_log_event::unpack_current_row(-1) on table `t1` +set debug_sync="now signal cont2"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table %"; +db state +test Update_rows_log_event::ha_update_row(-1) on table `t1` +set debug_sync="now signal cont3"; +set debug_sync="RESET"; +#monitoring delete rows +connection master; +delete from t1 where a>1; +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +db state +test Delete_rows_log_event::find_row(-1) on table `t1` +set debug_sync="now signal cont1"; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table %"; +db state +test Delete_rows_log_event::ha_delete_row(-1) on table `t1` +set debug_sync="now signal cont2"; +set debug_sync="RESET"; +SET GLOBAL debug_dbug=""; +connection master; +drop table t1; +connection slave; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_rbr_monitor.test b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test new file mode 100644 index 00000000000..33cd85097fc --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test @@ -0,0 +1,86 @@ +--source include/have_innodb.inc +--source include/have_debug.inc +--source include/have_binlog_format_row.inc +--source include/master-slave.inc +--enable_connect_log + +--connection master +create table t1(a int primary key); +--save_master_pos + +--connection slave +--sync_with_master +SET GLOBAL debug_dbug="+d,should_wait_for_mdev7409"; +select * from t1; + +--connection master +insert into t1(a) values(1); +--save_master_pos + +--echo #monitoring write rows +--connection slave + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +set debug_sync="now signal cont"; +--sync_with_master + +--echo #monitoring update rows +--connection master +update t1 set a = a + 4194304 ; + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +set debug_sync="now signal cont1"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::unpack_current_row(%) on table %"; +set debug_sync="now signal cont2"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::ha_update_row(%) on table %"; +set debug_sync="now signal cont3"; +set debug_sync="RESET"; +--sync_with_master + +--echo #monitoring delete rows +--connection master +delete from t1 where a>1; + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +set debug_sync="now signal cont1"; + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::ha_delete_row(%) on table %"; +set debug_sync="now signal cont2"; +set debug_sync="RESET"; +--sync_with_master +SET GLOBAL debug_dbug=""; + +#CleanUp +--connection master +drop table t1; +--sync_slave_with_master + +--source include/rpl_end.inc diff --git a/sql/debug_sync.cc b/sql/debug_sync.cc index bf721bddb85..7ca8d8a8ecb 100644 --- a/sql/debug_sync.cc +++ b/sql/debug_sync.cc @@ -1360,7 +1360,8 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action) Do this before emitting the signal, so other threads can see it if they awake before we enter_cond() below. */ - if (action->wait_for.length()) + if (action->wait_for.length() && + DBUG_EVALUATE_IF("should_wait_for_mdev7409", 0, 1)) { st_debug_sync_control *ds_control= thd->debug_sync_control; strxnmov(ds_control->ds_proc_info, sizeof(ds_control->ds_proc_info)-1, diff --git a/sql/log_event.cc b/sql/log_event.cc index f25ebd56792..ec3be7a312d 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -54,6 +54,7 @@ #include "rpl_constants.h" #include "sql_digest.h" #include "zlib.h" +#include "debug_sync.h" #define my_b_write_string(A, B) my_b_write((A), (uchar*)(B), (uint) (sizeof(B) - 1)) @@ -13693,19 +13694,31 @@ Write_rows_log_event::do_exec_row(rpl_group_info *rgi) { DBUG_ASSERT(m_table != NULL); const char *tmp= thd->get_proc_info(); - const char *message= "Write_rows_log_event::write_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Write_rows_log_event::write_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; int error; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Write_rows_log_event::write_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Write_rows_log_event::write_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont")); + };); error= write_row(rgi, slave_exec_mode == SLAVE_EXEC_MODE_IDEMPOTENT); thd_proc_info(thd, tmp); + thd->set_db(tmp_db); if (unlikely(error) && unlikely(!thd->is_error())) { @@ -14368,32 +14381,49 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) { int error; const char *tmp= thd->get_proc_info(); - const char *message= "Delete_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; DBUG_ASSERT(m_table != NULL); #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont1")); + };); if (likely(!(error= find_row(rgi)))) { /* Delete the record found, located in record[0] */ - message= "Delete_rows_log_event::ha_delete_row()"; + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::ha_delete_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::ha_delete_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::ha_delete_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont2")); + };); if (invoke_triggers && unlikely(process_triggers(TRG_EVENT_DELETE, TRG_ACTION_BEFORE, FALSE))) @@ -14422,6 +14452,7 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) m_table->file->ha_index_or_rnd_end(); } thd_proc_info(thd, tmp); + thd->set_db(tmp_db); return error; } @@ -14590,17 +14621,29 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; const char *tmp= thd->get_proc_info(); - const char *message= "Update_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); DBUG_ASSERT(m_table != NULL); + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont1")); + };); + int error= find_row(rgi); if (unlikely(error)) { @@ -14611,6 +14654,7 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) if ((m_curr_row= m_curr_row_end)) unpack_current_row(rgi, &m_cols_ai); thd_proc_info(thd, tmp); + thd->db= *tmp_db; return error; } @@ -14628,16 +14672,22 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) store_record(m_table,record[1]); m_curr_row= m_curr_row_end; - message= "Update_rows_log_event::unpack_current_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::unpack_current_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::unpack_current_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::unpack_current_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ /* this also updates m_curr_row_end */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont2")); + };); if (unlikely((error= unpack_current_row(rgi, &m_cols_ai)))) goto err; @@ -14655,15 +14705,21 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) DBUG_DUMP("new values", m_table->record[0], m_table->s->reclength); #endif - message= "Update_rows_log_event::ha_update_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::ha_update_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::ha_update_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::ha_update_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + DBUG_EXECUTE_IF("should_wait_for_mdev7409",{ + debug_sync_set_action + (thd, STRING_WITH_LEN("now WAIT_FOR cont3")); + };); if (invoke_triggers && unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_BEFORE, TRUE))) { @@ -14693,9 +14749,9 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_AFTER, TRUE))) error= HA_ERR_GENERIC; // in case if error is not set yet - thd_proc_info(thd, tmp); - err: + thd_proc_info(thd, tmp); + thd->set_db(tmp_db); m_table->file->ha_index_or_rnd_end(); return error; }

1 0

[Commits] 00a635f4eb0: MDEV-19776: Assertion `to_len >= 8' failed in convert_to_printable with optimizer trace enabled
by Varun 18 Jun '19

18 Jun '19

revision-id: 00a635f4eb0529d2a49a910455930b4bd8b3754d (mariadb-10.4.5-75-g00a635f4eb0) parent(s): 48570eb65cee840be46497c8411a147280e404c5 author: Varun Gupta committer: Varun Gupta timestamp: 2019-06-18 16:36:26 +0530 message: MDEV-19776: Assertion `to_len >= 8' failed in convert_to_printable with optimizer trace enabled Introduced the convert_to_printable_required_length to return the correct length(taking into consideration of dots in the case of error messages) --- mysql-test/main/opt_trace.result | 8 ++++++++ mysql-test/main/opt_trace.test | 10 ++++++++++ sql/sql_string.cc | 6 +++++- sql/sql_string.h | 1 + 4 files changed, 24 insertions(+), 1 deletion(-) diff --git a/mysql-test/main/opt_trace.result b/mysql-test/main/opt_trace.result index c0e0b4807a1..b521447c37c 100644 --- a/mysql-test/main/opt_trace.result +++ b/mysql-test/main/opt_trace.result @@ -6554,4 +6554,12 @@ JSON_DETAILED(JSON_EXTRACT(trace, '$**.analyzing_range_alternatives')) } ] drop table t1, t0, one_k; +# +# MDEV-19776: Assertion `to_len >= 8' failed in convert_to_printable with optimizer trace enabled +# +CREATE TABLE t1 (f VARBINARY(16) NOT NULL, KEY(f)); +INSERT INTO t1 VALUES ('a'),('b'); +SET optimizer_trace = 'enabled=on'; +DELETE FROM t1 WHERE f = 'x'; +DROP TABLE t1; set optimizer_trace='enabled=off'; diff --git a/mysql-test/main/opt_trace.test b/mysql-test/main/opt_trace.test index 916b9313ca6..c1ed050062b 100644 --- a/mysql-test/main/opt_trace.test +++ b/mysql-test/main/opt_trace.test @@ -498,4 +498,14 @@ explain format=json select * from t1 force index(start_date) where start_date >= select JSON_DETAILED(JSON_EXTRACT(trace, '$**.analyzing_range_alternatives')) from INFORMATION_SCHEMA.OPTIMIZER_TRACE; drop table t1, t0, one_k; +--echo # +--echo # MDEV-19776: Assertion `to_len >= 8' failed in convert_to_printable with optimizer trace enabled +--echo # + +CREATE TABLE t1 (f VARBINARY(16) NOT NULL, KEY(f)); +INSERT INTO t1 VALUES ('a'),('b'); +SET optimizer_trace = 'enabled=on'; +DELETE FROM t1 WHERE f = 'x'; +DROP TABLE t1; + set optimizer_trace='enabled=off'; diff --git a/sql/sql_string.cc b/sql/sql_string.cc index 1b567ecb325..c5e0e7e68f5 100644 --- a/sql/sql_string.cc +++ b/sql/sql_string.cc @@ -1197,10 +1197,14 @@ uint convert_to_printable(char *to, size_t to_len, return (uint) (t - to); } +size_t convert_to_printable_required_length(uint len) +{ + return len * 4 + 3/*dots*/ + 1/*trailing \0 */; +} bool String::append_semi_hex(const char *s, uint len, CHARSET_INFO *cs) { - size_t dst_len= len * 4 + 1; //extra length for the '\0' character + size_t dst_len= convert_to_printable_required_length(len); if (reserve(dst_len)) return true; uint nbytes= convert_to_printable(Ptr + str_length, dst_len, s, len, cs); diff --git a/sql/sql_string.h b/sql/sql_string.h index d8edf5e81f0..f21f23e42ef 100644 --- a/sql/sql_string.h +++ b/sql/sql_string.h @@ -126,6 +126,7 @@ size_t my_copy_with_hex_escaping(CHARSET_INFO *cs, uint convert_to_printable(char *to, size_t to_len, const char *from, size_t from_len, CHARSET_INFO *from_cs, size_t nbytes= 0); +size_t convert_to_printable_required_length(uint len); class Charset

1 0

[Commits] 81850491768: MDEV-19716: ASAN use-after-poison in Query_log_event::Query_log_event / THD::log_events_and_free_tmp_shares
by sujatha 18 Jun '19

18 Jun '19

revision-id: 818504917687b6454b91ac0ac16dd35937a3a3ca (mariadb-10.4.5-74-g81850491768) parent(s): e85e4814eeca9123b23c23b40dd776416bfba2ca author: Sujatha committer: Sujatha timestamp: 2019-06-18 13:58:02 +0530 message: MDEV-19716: ASAN use-after-poison in Query_log_event::Query_log_event / THD::log_events_and_free_tmp_shares Analysis: ======== When a given client session ends on a master, the server logs a DROP TEMPORARY TABLE IF EXISTS statement for each temporary table that still exists in the current session. It ensures a proper temporary table cleanup on the slave. In order to write the DROP TEMPORARY TABLE query in binary log a 'Query_log_event' object is created. Within the 'Query_log_event' constructor 'thd->lex->sql_command' is read to identify what type of cache needs to be used to write the query. When the code reaches here as part of THD::cleanup the 'thd->lex->sql_command' will be in an invalid state. The 'thd->lex' could have been cleared or it could be pointing to a statement which was in the middle of execution when the session ended. In such cases ASAN reports use-after-poison error. Fix: === The 'THD::Cleanup' code invokes 'THD::log_events_and_free_tmp_shares' to look for temporary tables and write appropriate DROP TABLE stmts for them. This cleanup code provides a special flag named 'direct=TRUE' to the Query_log_event constructor. Having 'direct=TRUE' means that this query doesn't require any caching. Hence in this scenario the 'Query_log_event' constructor should respect the 'direct' flag and simply skip the logic of deciding the type of cache to be used for the statement. Hence the code will not access the stale lex object. --- .../rpl/r/rpl_drop_temp_table_invaid_lex.result | 8 +++ .../rpl/t/rpl_drop_temp_table_invaid_lex.test | 32 ++++++++++ sql/log_event.cc | 69 +++++++++++----------- 3 files changed, 76 insertions(+), 33 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_drop_temp_table_invaid_lex.result b/mysql-test/suite/rpl/r/rpl_drop_temp_table_invaid_lex.result new file mode 100644 index 00000000000..8e75342c14e --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_drop_temp_table_invaid_lex.result @@ -0,0 +1,8 @@ +include/master-slave.inc +[connection master] +connect con1,localhost,root,,; +CREATE TEMPORARY TABLE tmp (a INT); +CREATE TABLE non_existing_db.t SELECT SLEEP(2) AS b; +disconnect con1; +connection default; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_drop_temp_table_invaid_lex.test b/mysql-test/suite/rpl/t/rpl_drop_temp_table_invaid_lex.test new file mode 100644 index 00000000000..04b2eaa4b4d --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_drop_temp_table_invaid_lex.test @@ -0,0 +1,32 @@ +# ==== Purpose ==== +# +# Test verifies that no ASAN issues are reported at the time of writing DROP +# TEMPORARY TABLE statements to binary log as part of session cleanup. +# +# ==== Implementation ==== +# +# Steps: +# 1 - Create a new connection named 'con1'. +# 2 - Create a temporary table named 'tmp' as part of connection 'con1'. +# 3 - Try to disconnect the current session when a CREATE .. SELECT +# statement is in the middle of execution. +# 4 - Observe that no ASAN issue is reported. +# +# ==== References ==== +# +# MDEV-19716: ASAN use-after-poison in Query_log_event::Query_log_event / +# THD::log_events_and_free_tmp_shares + +--source include/have_log_bin.inc +--source include/master-slave.inc + +--connect (con1,localhost,root,,) + +CREATE TEMPORARY TABLE tmp (a INT); + +--send CREATE TABLE non_existing_db.t SELECT SLEEP(2) AS b +--disconnect con1 + +--connection default + +--source include/rpl_end.inc diff --git a/sql/log_event.cc b/sql/log_event.cc index 731cbf99060..bc125c5c7b9 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -4415,41 +4415,44 @@ Query_log_event::Query_log_event(THD* thd_arg, const char* query_arg, size_t que bool trx_cache= FALSE; cache_type= Log_event::EVENT_INVALID_CACHE; - switch (lex->sql_command) + if (!direct) { - case SQLCOM_DROP_TABLE: - case SQLCOM_DROP_SEQUENCE: - use_cache= (lex->tmp_table() && thd->in_multi_stmt_transaction_mode()); - break; + switch (lex->sql_command) + { + case SQLCOM_DROP_TABLE: + case SQLCOM_DROP_SEQUENCE: + use_cache= (lex->tmp_table() && thd->in_multi_stmt_transaction_mode()); + break; - case SQLCOM_CREATE_TABLE: - case SQLCOM_CREATE_SEQUENCE: - /* - If we are using CREATE ... SELECT or if we are a slave - executing BEGIN...COMMIT (generated by CREATE...SELECT) we - have to use the transactional cache to ensure we don't - calculate any checksum for the CREATE part. - */ - trx_cache= (lex->first_select_lex()->item_list.elements && - thd->is_current_stmt_binlog_format_row()) || - (thd->variables.option_bits & OPTION_GTID_BEGIN); - use_cache= (lex->tmp_table() && - thd->in_multi_stmt_transaction_mode()) || trx_cache; - break; - case SQLCOM_SET_OPTION: - if (lex->autocommit) - use_cache= trx_cache= FALSE; - else - use_cache= TRUE; - break; - case SQLCOM_RELEASE_SAVEPOINT: - case SQLCOM_ROLLBACK_TO_SAVEPOINT: - case SQLCOM_SAVEPOINT: - use_cache= trx_cache= TRUE; - break; - default: - use_cache= sqlcom_can_generate_row_events(thd); - break; + case SQLCOM_CREATE_TABLE: + case SQLCOM_CREATE_SEQUENCE: + /* + If we are using CREATE ... SELECT or if we are a slave + executing BEGIN...COMMIT (generated by CREATE...SELECT) we + have to use the transactional cache to ensure we don't + calculate any checksum for the CREATE part. + */ + trx_cache= (lex->first_select_lex()->item_list.elements && + thd->is_current_stmt_binlog_format_row()) || + (thd->variables.option_bits & OPTION_GTID_BEGIN); + use_cache= (lex->tmp_table() && + thd->in_multi_stmt_transaction_mode()) || trx_cache; + break; + case SQLCOM_SET_OPTION: + if (lex->autocommit) + use_cache= trx_cache= FALSE; + else + use_cache= TRUE; + break; + case SQLCOM_RELEASE_SAVEPOINT: + case SQLCOM_ROLLBACK_TO_SAVEPOINT: + case SQLCOM_SAVEPOINT: + use_cache= trx_cache= TRUE; + break; + default: + use_cache= sqlcom_can_generate_row_events(thd); + break; + } } if (!use_cache || direct)

1 0

[Commits] 167da05: MDEV-19790 Wrong result for query with outer join and IS NOT TRUE predicate
by IgorBabaev 17 Jun '19

17 Jun '19

revision-id: 167da05f554dbe27d16373f6f0b02408ee76dc94 (mariadb-5.5.64-20-g167da05) parent(s): 039b8782d4794f34c5f0219d8a8d21f6e21d74f1 author: Igor Babaev committer: Igor Babaev timestamp: 2019-06-17 14:23:10 -0700 message: MDEV-19790 Wrong result for query with outer join and IS NOT TRUE predicate in where clause The classes Item_func_isnottrue and Item_func_isnotfalse inherited the implementation of the eval_not_null_tables method from the Item_func class. As a result the not_null_tables_cache was set incorrectly for the objects of these classes. It led to improper conversion of outer joins to inner joins when the where clause of the processed query contained IS NOT TRUE or IS NOT FALSE predicates. The coverted query in many cases produced a wrong result set. --- mysql-test/r/join_outer.result | 36 +++++++++++++++++++++++++++++++++++- mysql-test/r/join_outer_jcl6.result | 36 +++++++++++++++++++++++++++++++++++- mysql-test/t/join_outer.test | 25 ++++++++++++++++++++++++- sql/item_cmpfunc.h | 4 ++++ 4 files changed, 98 insertions(+), 3 deletions(-) diff --git a/mysql-test/r/join_outer.result b/mysql-test/r/join_outer.result index d55f11c..c976701 100644 --- a/mysql-test/r/join_outer.result +++ b/mysql-test/r/join_outer.result @@ -2353,7 +2353,7 @@ t1.b1+'0' t2.b2 + '0' 0 0 1 1 DROP TABLE t1, t2; -set @join_cache_level= @save_join_cache_level; +set @@join_cache_level= @save_join_cache_level; # # MDEV-14779: using left join causes incorrect results with materialization and derived tables # @@ -2418,5 +2418,39 @@ WHERE tb1.pk = 40 ORDER BY tb1.i1; v2 DROP TABLE t1,t2; +# +# MDEV-19790 : IS NOT TRUE / IS NOT FALSE predicates over +# inner tables of outer joins +# +create table t1 (a int); +create table t2 (b int); +insert into t1 values (3), (7), (1); +insert into t2 values (7), (4), (3); +select * from t1 left join t2 on a=b; +a b +3 3 +7 7 +1 NULL +select * from t1 left join t2 on a=b where (b > 3) is not true; +a b +3 3 +1 NULL +explain extended select * from t1 left join t2 on a=b where (b > 3) is not true; +id select_type table type possible_keys key key_len ref rows filtered Extra +1 SIMPLE t1 ALL NULL NULL NULL NULL 3 100.00 +1 SIMPLE t2 ALL NULL NULL NULL NULL 3 100.00 Using where +Warnings: +Note 1003 select `test`.`t1`.`a` AS `a`,`test`.`t2`.`b` AS `b` from `test`.`t1` left join `test`.`t2` on((`test`.`t2`.`b` = `test`.`t1`.`a`)) where ((`test`.`t2`.`b` > 3) is not true) +select * from t1 left join t2 on a=b where (b > 3) is not false; +a b +7 7 +1 NULL +explain extended select * from t1 left join t2 on a=b where (b > 3) is not false; +id select_type table type possible_keys key key_len ref rows filtered Extra +1 SIMPLE t1 ALL NULL NULL NULL NULL 3 100.00 +1 SIMPLE t2 ALL NULL NULL NULL NULL 3 100.00 Using where +Warnings: +Note 1003 select `test`.`t1`.`a` AS `a`,`test`.`t2`.`b` AS `b` from `test`.`t1` left join `test`.`t2` on((`test`.`t2`.`b` = `test`.`t1`.`a`)) where ((`test`.`t2`.`b` > 3) is not false) +drop table t1,t2; # end of 5.5 tests SET optimizer_switch=@save_optimizer_switch; diff --git a/mysql-test/r/join_outer_jcl6.result b/mysql-test/r/join_outer_jcl6.result index 8a9b395..5c5581f 100644 --- a/mysql-test/r/join_outer_jcl6.result +++ b/mysql-test/r/join_outer_jcl6.result @@ -2364,7 +2364,7 @@ t1.b1+'0' t2.b2 + '0' 0 0 1 1 DROP TABLE t1, t2; -set @join_cache_level= @save_join_cache_level; +set @@join_cache_level= @save_join_cache_level; # # MDEV-14779: using left join causes incorrect results with materialization and derived tables # @@ -2429,6 +2429,40 @@ WHERE tb1.pk = 40 ORDER BY tb1.i1; v2 DROP TABLE t1,t2; +# +# MDEV-19790 : IS NOT TRUE / IS NOT FALSE predicates over +# inner tables of outer joins +# +create table t1 (a int); +create table t2 (b int); +insert into t1 values (3), (7), (1); +insert into t2 values (7), (4), (3); +select * from t1 left join t2 on a=b; +a b +7 7 +3 3 +1 NULL +select * from t1 left join t2 on a=b where (b > 3) is not true; +a b +3 3 +1 NULL +explain extended select * from t1 left join t2 on a=b where (b > 3) is not true; +id select_type table type possible_keys key key_len ref rows filtered Extra +1 SIMPLE t1 ALL NULL NULL NULL NULL 3 100.00 +1 SIMPLE t2 ALL NULL NULL NULL NULL 3 100.00 Using where; Using join buffer (flat, BNL join) +Warnings: +Note 1003 select `test`.`t1`.`a` AS `a`,`test`.`t2`.`b` AS `b` from `test`.`t1` left join `test`.`t2` on((`test`.`t2`.`b` = `test`.`t1`.`a`)) where ((`test`.`t2`.`b` > 3) is not true) +select * from t1 left join t2 on a=b where (b > 3) is not false; +a b +7 7 +1 NULL +explain extended select * from t1 left join t2 on a=b where (b > 3) is not false; +id select_type table type possible_keys key key_len ref rows filtered Extra +1 SIMPLE t1 ALL NULL NULL NULL NULL 3 100.00 +1 SIMPLE t2 ALL NULL NULL NULL NULL 3 100.00 Using where; Using join buffer (flat, BNL join) +Warnings: +Note 1003 select `test`.`t1`.`a` AS `a`,`test`.`t2`.`b` AS `b` from `test`.`t1` left join `test`.`t2` on((`test`.`t2`.`b` = `test`.`t1`.`a`)) where ((`test`.`t2`.`b` > 3) is not false) +drop table t1,t2; # end of 5.5 tests SET optimizer_switch=@save_optimizer_switch; set join_cache_level=default; diff --git a/mysql-test/t/join_outer.test b/mysql-test/t/join_outer.test index 305421c..bdd6149 100644 --- a/mysql-test/t/join_outer.test +++ b/mysql-test/t/join_outer.test @@ -1895,7 +1895,7 @@ set @save_join_cache_level= @@join_cache_level; SET @@join_cache_level = 3; SELECT t1.b1+'0' , t2.b2 + '0' FROM t1 LEFT JOIN t2 ON b1 = b2; DROP TABLE t1, t2; -set @join_cache_level= @save_join_cache_level; +set @@join_cache_level= @save_join_cache_level; --echo # --echo # MDEV-14779: using left join causes incorrect results with materialization and derived tables @@ -1959,6 +1959,29 @@ ORDER BY tb1.i1; DROP TABLE t1,t2; +--echo # +--echo # MDEV-19790 : IS NOT TRUE / IS NOT FALSE predicates over +--echo # inner tables of outer joins +--echo # + +create table t1 (a int); +create table t2 (b int); +insert into t1 values (3), (7), (1); +insert into t2 values (7), (4), (3); +select * from t1 left join t2 on a=b; + +let $q= +select * from t1 left join t2 on a=b where (b > 3) is not true; +eval $q; +eval explain extended $q; + +let $q= +select * from t1 left join t2 on a=b where (b > 3) is not false; +eval $q; +eval explain extended $q; + +drop table t1,t2; + --echo # end of 5.5 tests SET optimizer_switch=@save_optimizer_switch; diff --git a/sql/item_cmpfunc.h b/sql/item_cmpfunc.h index b10dc2b..2eafa0b 100644 --- a/sql/item_cmpfunc.h +++ b/sql/item_cmpfunc.h @@ -183,6 +183,8 @@ class Item_func_isnottrue : public Item_func_truth Item_func_isnottrue(Item *a) : Item_func_truth(a, true, false) {} ~Item_func_isnottrue() {} virtual const char* func_name() const { return "isnottrue"; } + bool eval_not_null_tables(uchar *opt_arg) + { not_null_tables_cache= 0; return false; } }; @@ -209,6 +211,8 @@ class Item_func_isnotfalse : public Item_func_truth Item_func_isnotfalse(Item *a) : Item_func_truth(a, false, false) {} ~Item_func_isnotfalse() {} virtual const char* func_name() const { return "isnotfalse"; } + bool eval_not_null_tables(uchar *opt_arg) + { not_null_tables_cache= 0; return false; } };

1 0

[Commits] 65e0c9b: MDEV-18661 loading the audit plugin causes performance regression.
by holyfoot＠askmonty.org 14 Jun '19

14 Jun '19

revision-id: 65e0c9b91b46e2dfb4388c8c5c1bc76dd9f8fbd8 (mariadb-10.1.39-62-g65e0c9b) parent(s): 5b65d61d9384a45ea1b8df79694493fbb1a14e4a committer: Alexey Botchkov timestamp: 2019-06-15 01:02:55 +0400 message: MDEV-18661 loading the audit plugin causes performance regression. Plugin fixed to not lock the LOCK_operations when not active. Server fixed to lock the LOCK_plugin less - do it once per thread and then only if a plugin was installed/uninstalled. --- plugin/server_audit/server_audit.c | 112 ++++++++++++++++++++++--------------- sql/sql_audit.cc | 16 ++++++ sql/sql_audit.h | 1 + sql/sql_class.cc | 4 +- sql/sql_class.h | 1 + sql/sql_connect.cc | 3 +- sql/sql_plugin.cc | 3 + sql/sql_plugin.h | 1 + sql/threadpool_common.cc | 3 +- 9 files changed, 97 insertions(+), 47 deletions(-) diff --git a/plugin/server_audit/server_audit.c b/plugin/server_audit/server_audit.c index c9e7e3a..3da5264 100644 --- a/plugin/server_audit/server_audit.c +++ b/plugin/server_audit/server_audit.c @@ -15,7 +15,7 @@ #define PLUGIN_VERSION 0x104 -#define PLUGIN_STR_VERSION "1.4.4" +#define PLUGIN_STR_VERSION "1.4.7" #define _my_thread_var loc_thread_var @@ -295,7 +295,7 @@ static unsigned long long file_rotate_size; static unsigned int rotations; static my_bool rotate= TRUE; static char logging; -static int internal_stop_logging= 0; +static volatile int internal_stop_logging= 0; static char incl_user_buffer[1024]; static char excl_user_buffer[1024]; static char *big_buffer= NULL; @@ -533,16 +533,20 @@ static struct st_mysql_show_var audit_status[]= #if defined(HAVE_PSI_INTERFACE) && !defined(FLOGGER_NO_PSI) /* These belong to the service initialization */ static PSI_mutex_key key_LOCK_operations; +static PSI_mutex_key key_LOCK_atomic; static PSI_mutex_key key_LOCK_bigbuffer; static PSI_mutex_info mutex_key_list[]= { { &key_LOCK_operations, "SERVER_AUDIT_plugin::lock_operations", PSI_FLAG_GLOBAL}, + { &key_LOCK_atomic, "SERVER_AUDIT_plugin::lock_atomic", + PSI_FLAG_GLOBAL}, { &key_LOCK_bigbuffer, "SERVER_AUDIT_plugin::lock_bigbuffer", PSI_FLAG_GLOBAL} }; #endif static mysql_mutex_t lock_operations; +static mysql_mutex_t lock_atomic; static mysql_mutex_t lock_bigbuffer; /* The Percona server and partly MySQL don't support */ @@ -553,6 +557,14 @@ static mysql_mutex_t lock_bigbuffer; /* worths doing. */ #define CLIENT_ERROR if (!started_mysql) my_printf_error +#define ADD_ATOMIC(x, a) \ + do { \ + flogger_mutex_lock(&lock_atomic); \ + x+= a; \ + flogger_mutex_unlock(&lock_atomic); \ + } while (0) + + static uchar *getkey_user(const char *entry, size_t *length, my_bool nu __attribute__((unused)) ) { @@ -731,20 +743,20 @@ static int user_coll_fill(struct user_coll *c, char *users, if (cmp_user && take_over_cmp) { - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); CLIENT_ERROR(1, "User '%.*s' was removed from the" " server_audit_excl_users.", MYF(ME_JUST_WARNING), (int) cmp_length, users); - internal_stop_logging= 0; + ADD_ATOMIC(internal_stop_logging, -1); blank_user(cmp_user); refill_cmp_coll= 1; } else if (cmp_user) { - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); CLIENT_ERROR(1, "User '%.*s' is in the server_audit_incl_users, " "so wasn't added.", MYF(ME_JUST_WARNING), (int) cmp_length, users); - internal_stop_logging= 0; + ADD_ATOMIC(internal_stop_logging, -1); remove_user(users); continue; } @@ -1252,23 +1264,30 @@ static void change_connection(struct connection_info *cn, event->ip, event->ip_length); } -static int write_log(const char *message, int len) +static int write_log(const char *message, size_t len, int take_lock) { + int result= 0; + if (take_lock) + flogger_mutex_lock(&lock_operations); + if (output_type == OUTPUT_FILE) { if (logfile && - (is_active= (logger_write(logfile, message, len) == len))) - return 0; + (is_active= (logger_write(logfile, message, len) == (int) len))) + goto exit; ++log_write_failures; - return 1; + result= 1; } else if (output_type == OUTPUT_SYSLOG) { syslog(syslog_facility_codes[syslog_facility] | syslog_priority_codes[syslog_priority], - "%s %.*s", syslog_info, len, message); + "%s %.*s", syslog_info, (int) len, message); } - return 0; +exit: + if (take_lock) + flogger_mutex_unlock(&lock_operations); + return result; } @@ -1327,7 +1346,7 @@ static int log_connection(const struct connection_info *cn, csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,,%d", cn->db_length, cn->db, event->status); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1348,7 +1367,7 @@ static int log_connection_event(const struct mysql_event_connection *event, csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,,%d", event->database_length, event->database, event->status); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1477,21 +1496,28 @@ static size_t escape_string_hide_passwords(const char *str, unsigned int len, -static int do_log_user(const char *name) +static int do_log_user(const char *name, int take_lock) { size_t len; + int result; if (!name) return 0; len= strlen(name); - if (incl_user_coll.n_users) - return coll_search(&incl_user_coll, name, len) != 0; + if (take_lock) + flogger_mutex_lock(&lock_operations); - if (excl_user_coll.n_users) - return coll_search(&excl_user_coll, name, len) == 0; + if (incl_user_coll.n_users) + result= coll_search(&incl_user_coll, name, len) != 0; + else if (excl_user_coll.n_users) + result= coll_search(&excl_user_coll, name, len) == 0; + else + result= 1; - return 1; + if (take_lock) + flogger_mutex_unlock(&lock_operations); + return result; } @@ -1588,7 +1614,7 @@ static int filter_query_type(const char *query, struct sa_keyword *kwd) static int log_statement_ex(const struct connection_info *cn, time_t ev_time, unsigned long thd_id, const char *query, unsigned int query_len, - int error_code, const char *type) + int error_code, const char *type, int take_lock) { size_t csize; char message_loc[1024]; @@ -1736,7 +1762,7 @@ static int log_statement_ex(const struct connection_info *cn, csize+= my_snprintf(message+csize, message_size - 1 - csize, "\',%d", error_code); message[csize]= '\n'; - result= write_log(message, csize + 1); + result= write_log(message, csize + 1, take_lock); if (message == big_buffer) flogger_mutex_unlock(&lock_bigbuffer); @@ -1750,7 +1776,7 @@ static int log_statement(const struct connection_info *cn, { return log_statement_ex(cn, event->general_time, event->general_thread_id, event->general_query, event->general_query_length, - event->general_error_code, type); + event->general_error_code, type, 1); } @@ -1772,7 +1798,7 @@ static int log_table(const struct connection_info *cn, ",%.*s,%.*s,",event->database_length, event->database, event->table_length, event->table); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1796,7 +1822,7 @@ static int log_rename(const struct connection_info *cn, event->new_database_length, event->new_database, event->new_table_length, event->new_table); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1988,8 +2014,6 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) if (!thd || internal_stop_logging) return; - flogger_mutex_lock(&lock_operations); - if (maria_55_started && debug_server_started && event_class == MYSQL_AUDIT_GENERAL_CLASS) { @@ -2024,7 +2048,7 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) goto exit_func; if (event_class == MYSQL_AUDIT_GENERAL_CLASS && FILTER(EVENT_QUERY) && - cn && do_log_user(cn->user)) + cn && do_log_user(cn->user, 1)) { const struct mysql_event_general *event = (const struct mysql_event_general *) ev; @@ -2043,7 +2067,7 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) { const struct mysql_event_table *event = (const struct mysql_event_table *) ev; - if (do_log_user(event->user)) + if (do_log_user(event->user, 1)) { switch (event->event_subclass) { @@ -2109,7 +2133,6 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) } if (cn) cn->log_always= 0; - flogger_mutex_unlock(&lock_operations); } @@ -2377,6 +2400,7 @@ static int server_audit_init(void *p __attribute__((unused))) PSI_server->register_mutex("server_audit", mutex_key_list, 1); #endif flogger_mutex_init(key_LOCK_operations, &lock_operations, MY_MUTEX_INIT_FAST); + flogger_mutex_init(key_LOCK_operations, &lock_atomic, MY_MUTEX_INIT_FAST); flogger_mutex_init(key_LOCK_operations, &lock_bigbuffer, MY_MUTEX_INIT_FAST); coll_init(&incl_user_coll); @@ -2464,6 +2488,7 @@ static int server_audit_deinit(void *p __attribute__((unused))) (void) free(big_buffer); flogger_mutex_destroy(&lock_operations); + flogger_mutex_destroy(&lock_atomic); flogger_mutex_destroy(&lock_bigbuffer); error_header(); @@ -2553,10 +2578,10 @@ static void log_current_query(MYSQL_THD thd) return; cn= get_loc_info(thd); if (!ci_needs_setup(cn) && cn->query_length && - FILTER(EVENT_QUERY) && do_log_user(cn->user)) + FILTER(EVENT_QUERY) && do_log_user(cn->user, 0)) { log_statement_ex(cn, cn->query_time, thd_get_thread_id(thd), - cn->query, cn->query_length, 0, "QUERY"); + cn->query, cn->query_length, 0, "QUERY", 0); cn->log_always= 1; } } @@ -2568,12 +2593,13 @@ static void update_file_path(MYSQL_THD thd, { char *new_name= (*(char **) save) ? *(char **) save : empty_str; - if (!maria_55_started || !debug_server_started) - flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); error_header(); fprintf(stderr, "Log file name was changed to '%s'.\n", new_name); + if (!maria_55_started || !debug_server_started) + flogger_mutex_lock(&lock_operations); + if (logging) log_current_query(thd); @@ -2582,7 +2608,6 @@ static void update_file_path(MYSQL_THD thd, char *sav_path= file_path; file_path= new_name; - internal_stop_logging= 1; stop_logging(); if (start_logging()) { @@ -2598,16 +2623,15 @@ static void update_file_path(MYSQL_THD thd, } goto exit_func; } - internal_stop_logging= 0; } strncpy(path_buffer, new_name, sizeof(path_buffer)-1); path_buffer[sizeof(path_buffer)-1]= 0; file_path= path_buffer; exit_func: - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2692,8 +2716,8 @@ static void update_output_type(MYSQL_THD thd, if (output_type == new_output_type) return; + ADD_ATOMIC(internal_stop_logging, 1); flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; if (logging) { log_current_query(thd); @@ -2707,8 +2731,8 @@ static void update_output_type(MYSQL_THD thd, if (logging) start_logging(); - internal_stop_logging= 0; flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2756,9 +2780,9 @@ static void update_logging(MYSQL_THD thd, if (new_logging == logging) return; + ADD_ATOMIC(internal_stop_logging, 1); if (!maria_55_started || !debug_server_started) flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; if ((logging= new_logging)) { start_logging(); @@ -2773,9 +2797,9 @@ static void update_logging(MYSQL_THD thd, stop_logging(); } - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2787,16 +2811,16 @@ static void update_mode(MYSQL_THD thd __attribute__((unused)), if (mode_readonly || new_mode == mode) return; + ADD_ATOMIC(internal_stop_logging, 1); if (!maria_55_started || !debug_server_started) flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; mark_always_logged(thd); error_header(); fprintf(stderr, "Logging mode was changed from %d to %d.\n", mode, new_mode); mode= new_mode; - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } diff --git a/sql/sql_audit.cc b/sql/sql_audit.cc index dd98e3c..cee0ac2 100644 --- a/sql/sql_audit.cc +++ b/sql/sql_audit.cc @@ -212,6 +212,7 @@ void mysql_audit_acquire_plugins(THD *thd, ulong *event_class_mask) { plugin_foreach(thd, acquire_plugins, MYSQL_AUDIT_PLUGIN, event_class_mask); add_audit_mask(thd->audit_class_mask, event_class_mask); + thd->audit_plugin_version= global_plugin_version; } DBUG_VOID_RETURN; } @@ -242,6 +243,20 @@ void mysql_audit_notify(THD *thd, uint event_class, uint event_subtype, ...) /** + Check if there were changes in the state of plugins + so we need to do the mysql_audit_release asap. + + @param[in] thd + +*/ + +my_bool mysql_audit_release_required(THD *thd) +{ + return thd && (thd->audit_plugin_version != global_plugin_version); +} + + +/** Release any resources associated with the current thd. @param[in] thd @@ -276,6 +291,7 @@ void mysql_audit_release(THD *thd) /* Reset the state of thread values */ reset_dynamic(&thd->audit_class_plugins); bzero(thd->audit_class_mask, sizeof(thd->audit_class_mask)); + thd->audit_plugin_version= -1; } diff --git a/sql/sql_audit.h b/sql/sql_audit.h index 550b2a5..9a74675 100644 --- a/sql/sql_audit.h +++ b/sql/sql_audit.h @@ -60,6 +60,7 @@ static inline void mysql_audit_notify(THD *thd, uint event_class, #define mysql_audit_connection_enabled() 0 #define mysql_audit_table_enabled() 0 #endif +extern my_bool mysql_audit_release_required(THD *thd); extern void mysql_audit_release(THD *thd); #define MAX_USER_HOST_SIZE 512 diff --git a/sql/sql_class.cc b/sql/sql_class.cc index 8fabcd5..6bcff6d 100644 --- a/sql/sql_class.cc +++ b/sql/sql_class.cc @@ -776,6 +776,9 @@ THD::THD(bool is_wsrep_applier) waiting_on_group_commit(FALSE), has_waiter(FALSE), spcont(NULL), m_parser_state(NULL), +#ifndef EMBEDDED_LIBRARY + audit_plugin_version(-1), +#endif #if defined(ENABLED_DEBUG_SYNC) debug_sync_control(0), #endif /* defined(ENABLED_DEBUG_SYNC) */ @@ -1562,7 +1565,6 @@ THD::~THD() mdl_context.destroy(); ha_close_connection(this); - mysql_audit_release(this); plugin_thdvar_cleanup(this); main_security_ctx.destroy(); diff --git a/sql/sql_class.h b/sql/sql_class.h index 1cb516c..6392394 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -2978,6 +2978,7 @@ class THD :public Statement, added to the list of audit plugins which are currently in use. */ unsigned long audit_class_mask[MYSQL_AUDIT_CLASS_MASK_SIZE]; + int audit_plugin_version; #endif #if defined(ENABLED_DEBUG_SYNC) diff --git a/sql/sql_connect.cc b/sql/sql_connect.cc index 4dbb53f..a6a01b1 100644 --- a/sql/sql_connect.cc +++ b/sql/sql_connect.cc @@ -1326,7 +1326,8 @@ void do_handle_one_connection(THD *thd_arg) while (thd_is_connection_alive(thd)) { - mysql_audit_release(thd); + if (mysql_audit_release_required(thd)) + mysql_audit_release(thd); if (do_command(thd)) break; } diff --git a/sql/sql_plugin.cc b/sql/sql_plugin.cc index 21093e3..48131b1 100644 --- a/sql/sql_plugin.cc +++ b/sql/sql_plugin.cc @@ -228,6 +228,7 @@ static DYNAMIC_ARRAY plugin_array; static HASH plugin_hash[MYSQL_MAX_PLUGIN_TYPE_NUM]; static MEM_ROOT plugin_mem_root; static bool reap_needed= false; +volatile int global_plugin_version= 1; static bool initialized= 0; ulong dlopen_count; @@ -2181,6 +2182,7 @@ bool mysql_install_plugin(THD *thd, const LEX_STRING *name, reap_plugins(); } err: + global_plugin_version++; mysql_mutex_unlock(&LOCK_plugin); if (argv) free_defaults(argv); @@ -2327,6 +2329,7 @@ bool mysql_uninstall_plugin(THD *thd, const LEX_STRING *name, } reap_plugins(); + global_plugin_version++; mysql_mutex_unlock(&LOCK_plugin); DBUG_RETURN(error); diff --git a/sql/sql_plugin.h b/sql/sql_plugin.h index 7f74114..3bde06a 100644 --- a/sql/sql_plugin.h +++ b/sql/sql_plugin.h @@ -37,6 +37,7 @@ enum enum_plugin_load_option { PLUGIN_OFF, PLUGIN_ON, PLUGIN_FORCE, PLUGIN_FORCE_PLUS_PERMANENT }; extern const char *global_plugin_typelib_names[]; +extern volatile int global_plugin_version; extern ulong dlopen_count; #include <my_sys.h> diff --git a/sql/threadpool_common.cc b/sql/threadpool_common.cc index b4066bd..b8be708 100644 --- a/sql/threadpool_common.cc +++ b/sql/threadpool_common.cc @@ -266,7 +266,8 @@ int threadpool_process_request(THD *thd) { Vio *vio; thd->net.reading_or_writing= 0; - mysql_audit_release(thd); + if (mysql_audit_release_required(thd)) + mysql_audit_release(thd); if ((retval= do_command(thd)) != 0) goto end;

1 0

[Commits] 2762e16: MDEV-18661 loading the audit plugin causes performance regression.
by holyfoot＠askmonty.org 14 Jun '19

14 Jun '19

revision-id: 2762e165083c35b1ae70069200372aec95f6fd79 (mariadb-10.1.39-62-g2762e16) parent(s): 5b65d61d9384a45ea1b8df79694493fbb1a14e4a committer: Alexey Botchkov timestamp: 2019-06-14 11:32:30 +0400 message: MDEV-18661 loading the audit plugin causes performance regression. Plugin fixed to not lock the LOCK_operations when not active. Server fixed to lock the LOCK_plugin less - do it once per thread and then only if a plugin was installed/uninstalled. --- plugin/server_audit/server_audit.c | 112 ++++++++++++++++++++++--------------- sql/sql_audit.cc | 16 ++++++ sql/sql_audit.h | 1 + sql/sql_class.cc | 4 +- sql/sql_class.h | 1 + sql/sql_connect.cc | 3 +- sql/sql_plugin.cc | 3 + sql/sql_plugin.h | 1 + sql/threadpool_common.cc | 3 +- 9 files changed, 97 insertions(+), 47 deletions(-) diff --git a/plugin/server_audit/server_audit.c b/plugin/server_audit/server_audit.c index c9e7e3a..3da5264 100644 --- a/plugin/server_audit/server_audit.c +++ b/plugin/server_audit/server_audit.c @@ -15,7 +15,7 @@ #define PLUGIN_VERSION 0x104 -#define PLUGIN_STR_VERSION "1.4.4" +#define PLUGIN_STR_VERSION "1.4.7" #define _my_thread_var loc_thread_var @@ -295,7 +295,7 @@ static unsigned long long file_rotate_size; static unsigned int rotations; static my_bool rotate= TRUE; static char logging; -static int internal_stop_logging= 0; +static volatile int internal_stop_logging= 0; static char incl_user_buffer[1024]; static char excl_user_buffer[1024]; static char *big_buffer= NULL; @@ -533,16 +533,20 @@ static struct st_mysql_show_var audit_status[]= #if defined(HAVE_PSI_INTERFACE) && !defined(FLOGGER_NO_PSI) /* These belong to the service initialization */ static PSI_mutex_key key_LOCK_operations; +static PSI_mutex_key key_LOCK_atomic; static PSI_mutex_key key_LOCK_bigbuffer; static PSI_mutex_info mutex_key_list[]= { { &key_LOCK_operations, "SERVER_AUDIT_plugin::lock_operations", PSI_FLAG_GLOBAL}, + { &key_LOCK_atomic, "SERVER_AUDIT_plugin::lock_atomic", + PSI_FLAG_GLOBAL}, { &key_LOCK_bigbuffer, "SERVER_AUDIT_plugin::lock_bigbuffer", PSI_FLAG_GLOBAL} }; #endif static mysql_mutex_t lock_operations; +static mysql_mutex_t lock_atomic; static mysql_mutex_t lock_bigbuffer; /* The Percona server and partly MySQL don't support */ @@ -553,6 +557,14 @@ static mysql_mutex_t lock_bigbuffer; /* worths doing. */ #define CLIENT_ERROR if (!started_mysql) my_printf_error +#define ADD_ATOMIC(x, a) \ + do { \ + flogger_mutex_lock(&lock_atomic); \ + x+= a; \ + flogger_mutex_unlock(&lock_atomic); \ + } while (0) + + static uchar *getkey_user(const char *entry, size_t *length, my_bool nu __attribute__((unused)) ) { @@ -731,20 +743,20 @@ static int user_coll_fill(struct user_coll *c, char *users, if (cmp_user && take_over_cmp) { - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); CLIENT_ERROR(1, "User '%.*s' was removed from the" " server_audit_excl_users.", MYF(ME_JUST_WARNING), (int) cmp_length, users); - internal_stop_logging= 0; + ADD_ATOMIC(internal_stop_logging, -1); blank_user(cmp_user); refill_cmp_coll= 1; } else if (cmp_user) { - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); CLIENT_ERROR(1, "User '%.*s' is in the server_audit_incl_users, " "so wasn't added.", MYF(ME_JUST_WARNING), (int) cmp_length, users); - internal_stop_logging= 0; + ADD_ATOMIC(internal_stop_logging, -1); remove_user(users); continue; } @@ -1252,23 +1264,30 @@ static void change_connection(struct connection_info *cn, event->ip, event->ip_length); } -static int write_log(const char *message, int len) +static int write_log(const char *message, size_t len, int take_lock) { + int result= 0; + if (take_lock) + flogger_mutex_lock(&lock_operations); + if (output_type == OUTPUT_FILE) { if (logfile && - (is_active= (logger_write(logfile, message, len) == len))) - return 0; + (is_active= (logger_write(logfile, message, len) == (int) len))) + goto exit; ++log_write_failures; - return 1; + result= 1; } else if (output_type == OUTPUT_SYSLOG) { syslog(syslog_facility_codes[syslog_facility] | syslog_priority_codes[syslog_priority], - "%s %.*s", syslog_info, len, message); + "%s %.*s", syslog_info, (int) len, message); } - return 0; +exit: + if (take_lock) + flogger_mutex_unlock(&lock_operations); + return result; } @@ -1327,7 +1346,7 @@ static int log_connection(const struct connection_info *cn, csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,,%d", cn->db_length, cn->db, event->status); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1348,7 +1367,7 @@ static int log_connection_event(const struct mysql_event_connection *event, csize+= my_snprintf(message+csize, sizeof(message) - 1 - csize, ",%.*s,,%d", event->database_length, event->database, event->status); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1477,21 +1496,28 @@ static size_t escape_string_hide_passwords(const char *str, unsigned int len, -static int do_log_user(const char *name) +static int do_log_user(const char *name, int take_lock) { size_t len; + int result; if (!name) return 0; len= strlen(name); - if (incl_user_coll.n_users) - return coll_search(&incl_user_coll, name, len) != 0; + if (take_lock) + flogger_mutex_lock(&lock_operations); - if (excl_user_coll.n_users) - return coll_search(&excl_user_coll, name, len) == 0; + if (incl_user_coll.n_users) + result= coll_search(&incl_user_coll, name, len) != 0; + else if (excl_user_coll.n_users) + result= coll_search(&excl_user_coll, name, len) == 0; + else + result= 1; - return 1; + if (take_lock) + flogger_mutex_unlock(&lock_operations); + return result; } @@ -1588,7 +1614,7 @@ static int filter_query_type(const char *query, struct sa_keyword *kwd) static int log_statement_ex(const struct connection_info *cn, time_t ev_time, unsigned long thd_id, const char *query, unsigned int query_len, - int error_code, const char *type) + int error_code, const char *type, int take_lock) { size_t csize; char message_loc[1024]; @@ -1736,7 +1762,7 @@ static int log_statement_ex(const struct connection_info *cn, csize+= my_snprintf(message+csize, message_size - 1 - csize, "\',%d", error_code); message[csize]= '\n'; - result= write_log(message, csize + 1); + result= write_log(message, csize + 1, take_lock); if (message == big_buffer) flogger_mutex_unlock(&lock_bigbuffer); @@ -1750,7 +1776,7 @@ static int log_statement(const struct connection_info *cn, { return log_statement_ex(cn, event->general_time, event->general_thread_id, event->general_query, event->general_query_length, - event->general_error_code, type); + event->general_error_code, type, 1); } @@ -1772,7 +1798,7 @@ static int log_table(const struct connection_info *cn, ",%.*s,%.*s,",event->database_length, event->database, event->table_length, event->table); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1796,7 +1822,7 @@ static int log_rename(const struct connection_info *cn, event->new_database_length, event->new_database, event->new_table_length, event->new_table); message[csize]= '\n'; - return write_log(message, csize + 1); + return write_log(message, csize + 1, 1); } @@ -1988,8 +2014,6 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) if (!thd || internal_stop_logging) return; - flogger_mutex_lock(&lock_operations); - if (maria_55_started && debug_server_started && event_class == MYSQL_AUDIT_GENERAL_CLASS) { @@ -2024,7 +2048,7 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) goto exit_func; if (event_class == MYSQL_AUDIT_GENERAL_CLASS && FILTER(EVENT_QUERY) && - cn && do_log_user(cn->user)) + cn && do_log_user(cn->user, 1)) { const struct mysql_event_general *event = (const struct mysql_event_general *) ev; @@ -2043,7 +2067,7 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) { const struct mysql_event_table *event = (const struct mysql_event_table *) ev; - if (do_log_user(event->user)) + if (do_log_user(event->user, 1)) { switch (event->event_subclass) { @@ -2109,7 +2133,6 @@ void auditing(MYSQL_THD thd, unsigned int event_class, const void *ev) } if (cn) cn->log_always= 0; - flogger_mutex_unlock(&lock_operations); } @@ -2377,6 +2400,7 @@ static int server_audit_init(void *p __attribute__((unused))) PSI_server->register_mutex("server_audit", mutex_key_list, 1); #endif flogger_mutex_init(key_LOCK_operations, &lock_operations, MY_MUTEX_INIT_FAST); + flogger_mutex_init(key_LOCK_operations, &lock_atomic, MY_MUTEX_INIT_FAST); flogger_mutex_init(key_LOCK_operations, &lock_bigbuffer, MY_MUTEX_INIT_FAST); coll_init(&incl_user_coll); @@ -2464,6 +2488,7 @@ static int server_audit_deinit(void *p __attribute__((unused))) (void) free(big_buffer); flogger_mutex_destroy(&lock_operations); + flogger_mutex_destroy(&lock_atomic); flogger_mutex_destroy(&lock_bigbuffer); error_header(); @@ -2553,10 +2578,10 @@ static void log_current_query(MYSQL_THD thd) return; cn= get_loc_info(thd); if (!ci_needs_setup(cn) && cn->query_length && - FILTER(EVENT_QUERY) && do_log_user(cn->user)) + FILTER(EVENT_QUERY) && do_log_user(cn->user, 0)) { log_statement_ex(cn, cn->query_time, thd_get_thread_id(thd), - cn->query, cn->query_length, 0, "QUERY"); + cn->query, cn->query_length, 0, "QUERY", 0); cn->log_always= 1; } } @@ -2568,12 +2593,13 @@ static void update_file_path(MYSQL_THD thd, { char *new_name= (*(char **) save) ? *(char **) save : empty_str; - if (!maria_55_started || !debug_server_started) - flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; + ADD_ATOMIC(internal_stop_logging, 1); error_header(); fprintf(stderr, "Log file name was changed to '%s'.\n", new_name); + if (!maria_55_started || !debug_server_started) + flogger_mutex_lock(&lock_operations); + if (logging) log_current_query(thd); @@ -2582,7 +2608,6 @@ static void update_file_path(MYSQL_THD thd, char *sav_path= file_path; file_path= new_name; - internal_stop_logging= 1; stop_logging(); if (start_logging()) { @@ -2598,16 +2623,15 @@ static void update_file_path(MYSQL_THD thd, } goto exit_func; } - internal_stop_logging= 0; } strncpy(path_buffer, new_name, sizeof(path_buffer)-1); path_buffer[sizeof(path_buffer)-1]= 0; file_path= path_buffer; exit_func: - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2692,8 +2716,8 @@ static void update_output_type(MYSQL_THD thd, if (output_type == new_output_type) return; + ADD_ATOMIC(internal_stop_logging, 1); flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; if (logging) { log_current_query(thd); @@ -2707,8 +2731,8 @@ static void update_output_type(MYSQL_THD thd, if (logging) start_logging(); - internal_stop_logging= 0; flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2756,9 +2780,9 @@ static void update_logging(MYSQL_THD thd, if (new_logging == logging) return; + ADD_ATOMIC(internal_stop_logging, 1); if (!maria_55_started || !debug_server_started) flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; if ((logging= new_logging)) { start_logging(); @@ -2773,9 +2797,9 @@ static void update_logging(MYSQL_THD thd, stop_logging(); } - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } @@ -2787,16 +2811,16 @@ static void update_mode(MYSQL_THD thd __attribute__((unused)), if (mode_readonly || new_mode == mode) return; + ADD_ATOMIC(internal_stop_logging, 1); if (!maria_55_started || !debug_server_started) flogger_mutex_lock(&lock_operations); - internal_stop_logging= 1; mark_always_logged(thd); error_header(); fprintf(stderr, "Logging mode was changed from %d to %d.\n", mode, new_mode); mode= new_mode; - internal_stop_logging= 0; if (!maria_55_started || !debug_server_started) flogger_mutex_unlock(&lock_operations); + ADD_ATOMIC(internal_stop_logging, -1); } diff --git a/sql/sql_audit.cc b/sql/sql_audit.cc index dd98e3c..cee0ac2 100644 --- a/sql/sql_audit.cc +++ b/sql/sql_audit.cc @@ -212,6 +212,7 @@ void mysql_audit_acquire_plugins(THD *thd, ulong *event_class_mask) { plugin_foreach(thd, acquire_plugins, MYSQL_AUDIT_PLUGIN, event_class_mask); add_audit_mask(thd->audit_class_mask, event_class_mask); + thd->audit_plugin_version= global_plugin_version; } DBUG_VOID_RETURN; } @@ -242,6 +243,20 @@ void mysql_audit_notify(THD *thd, uint event_class, uint event_subtype, ...) /** + Check if there were changes in the state of plugins + so we need to do the mysql_audit_release asap. + + @param[in] thd + +*/ + +my_bool mysql_audit_release_required(THD *thd) +{ + return thd && (thd->audit_plugin_version != global_plugin_version); +} + + +/** Release any resources associated with the current thd. @param[in] thd @@ -276,6 +291,7 @@ void mysql_audit_release(THD *thd) /* Reset the state of thread values */ reset_dynamic(&thd->audit_class_plugins); bzero(thd->audit_class_mask, sizeof(thd->audit_class_mask)); + thd->audit_plugin_version= -1; } diff --git a/sql/sql_audit.h b/sql/sql_audit.h index 550b2a5..9a74675 100644 --- a/sql/sql_audit.h +++ b/sql/sql_audit.h @@ -60,6 +60,7 @@ static inline void mysql_audit_notify(THD *thd, uint event_class, #define mysql_audit_connection_enabled() 0 #define mysql_audit_table_enabled() 0 #endif +extern my_bool mysql_audit_release_required(THD *thd); extern void mysql_audit_release(THD *thd); #define MAX_USER_HOST_SIZE 512 diff --git a/sql/sql_class.cc b/sql/sql_class.cc index 8fabcd5..6bcff6d 100644 --- a/sql/sql_class.cc +++ b/sql/sql_class.cc @@ -776,6 +776,9 @@ THD::THD(bool is_wsrep_applier) waiting_on_group_commit(FALSE), has_waiter(FALSE), spcont(NULL), m_parser_state(NULL), +#ifndef EMBEDDED_LIBRARY + audit_plugin_version(-1), +#endif #if defined(ENABLED_DEBUG_SYNC) debug_sync_control(0), #endif /* defined(ENABLED_DEBUG_SYNC) */ @@ -1562,7 +1565,6 @@ THD::~THD() mdl_context.destroy(); ha_close_connection(this); - mysql_audit_release(this); plugin_thdvar_cleanup(this); main_security_ctx.destroy(); diff --git a/sql/sql_class.h b/sql/sql_class.h index 1cb516c..6392394 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -2978,6 +2978,7 @@ class THD :public Statement, added to the list of audit plugins which are currently in use. */ unsigned long audit_class_mask[MYSQL_AUDIT_CLASS_MASK_SIZE]; + int audit_plugin_version; #endif #if defined(ENABLED_DEBUG_SYNC) diff --git a/sql/sql_connect.cc b/sql/sql_connect.cc index 4dbb53f..a6a01b1 100644 --- a/sql/sql_connect.cc +++ b/sql/sql_connect.cc @@ -1326,7 +1326,8 @@ void do_handle_one_connection(THD *thd_arg) while (thd_is_connection_alive(thd)) { - mysql_audit_release(thd); + if (mysql_audit_release_required(thd)) + mysql_audit_release(thd); if (do_command(thd)) break; } diff --git a/sql/sql_plugin.cc b/sql/sql_plugin.cc index 21093e3..48131b1 100644 --- a/sql/sql_plugin.cc +++ b/sql/sql_plugin.cc @@ -228,6 +228,7 @@ static DYNAMIC_ARRAY plugin_array; static HASH plugin_hash[MYSQL_MAX_PLUGIN_TYPE_NUM]; static MEM_ROOT plugin_mem_root; static bool reap_needed= false; +volatile int global_plugin_version= 1; static bool initialized= 0; ulong dlopen_count; @@ -2181,6 +2182,7 @@ bool mysql_install_plugin(THD *thd, const LEX_STRING *name, reap_plugins(); } err: + global_plugin_version++; mysql_mutex_unlock(&LOCK_plugin); if (argv) free_defaults(argv); @@ -2327,6 +2329,7 @@ bool mysql_uninstall_plugin(THD *thd, const LEX_STRING *name, } reap_plugins(); + global_plugin_version++; mysql_mutex_unlock(&LOCK_plugin); DBUG_RETURN(error); diff --git a/sql/sql_plugin.h b/sql/sql_plugin.h index 7f74114..3bde06a 100644 --- a/sql/sql_plugin.h +++ b/sql/sql_plugin.h @@ -37,6 +37,7 @@ enum enum_plugin_load_option { PLUGIN_OFF, PLUGIN_ON, PLUGIN_FORCE, PLUGIN_FORCE_PLUS_PERMANENT }; extern const char *global_plugin_typelib_names[]; +extern volatile int global_plugin_version; extern ulong dlopen_count; #include <my_sys.h> diff --git a/sql/threadpool_common.cc b/sql/threadpool_common.cc index b4066bd..b8be708 100644 --- a/sql/threadpool_common.cc +++ b/sql/threadpool_common.cc @@ -266,7 +266,8 @@ int threadpool_process_request(THD *thd) { Vio *vio; thd->net.reading_or_writing= 0; - mysql_audit_release(thd); + if (mysql_audit_release_required(thd)) + mysql_audit_release(thd); if ((retval= do_command(thd)) != 0) goto end;

1 0