From: Andrei Elkin Date: October 28 2011 1:13pm Subject: bzr push into mysql-trunk branch (andrei.elkin:3535) List-Archive: http://lists.mysql.com/commits/141643 Message-Id: <201110281313.p9SDDrS9015754@mysql1000.dsl.inet.fi> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit 3535 Andrei Elkin 2011-10-28 [merge] merge from trunk to local tree. removed: storage/perfschema/table_file_summary.cc storage/perfschema/table_file_summary.h added: storage/perfschema/table_file_summary_by_event_name.cc storage/perfschema/table_file_summary_by_event_name.h storage/perfschema/table_file_summary_by_instance.cc storage/perfschema/table_file_summary_by_instance.h modified: mysql-test/r/mysqld--help-notwin.result mysql-test/r/mysqld--help-win.result mysql-test/suite/opt_trace/r/range_no_prot.result mysql-test/suite/opt_trace/r/range_ps_prot.result mysql-test/suite/perfschema/r/pfs_upgrade.result mysql-test/suite/perfschema/r/relaylog.result mysql-test/suite/perfschema/r/schema.result mysql-test/suite/perfschema/r/start_server_nothing.result mysql-test/suite/perfschema/r/table_schema.result mysql-test/suite/sys_vars/r/sort_buffer_size_basic_32.result* mysql-test/suite/sys_vars/r/sort_buffer_size_basic_64.result scripts/mysql_system_tables.sql sql/sql_const.h sql/sql_select.cc sql/sys_vars.cc storage/innobase/fil/fil0fil.c storage/innobase/fsp/fsp0fsp.c storage/innobase/include/buf0buf.h storage/innobase/include/fil0fil.h storage/innobase/include/fsp0fsp.h storage/innobase/include/sync0rw.ic storage/innobase/lock/lock0lock.c storage/innobase/row/row0umod.c storage/innobase/srv/srv0start.c storage/perfschema/CMakeLists.txt storage/perfschema/pfs.cc storage/perfschema/pfs_engine_table.cc storage/perfschema/pfs_instr.cc storage/perfschema/pfs_instr.h storage/perfschema/pfs_stat.h storage/perfschema/pfs_visitor.cc storage/perfschema/pfs_visitor.h storage/perfschema/table_helper.h storage/perfschema/table_socket_summary_by_instance.cc === modified file 'mysql-test/suite/rpl/r/rpl_checksum.result' --- a/mysql-test/suite/rpl/r/rpl_checksum.result 2011-09-30 13:14:37 +0000 +++ b/mysql-test/suite/rpl/r/rpl_checksum.result 2011-10-27 19:28:15 +0000 @@ -64,7 +64,7 @@ insert into t1 values (1) /* will not be set @@global.debug='d,simulate_slave_unaware_checksum'; start slave; include/wait_for_slave_io_error.inc [errno=1236] -Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'Slave can not handle replication events with the checksum that master is configured to log; the last event was read from 'master-bin.000010' at 114, the last byte read was read from 'master-bin.000010' at 114.'' +Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'Slave can not handle replication events with the checksum that master is configured to log; the last event was read from './master-bin.000010' at 114, the last byte read was read from './master-bin.000010' at 114.'' select count(*) as zero from t1; zero 0 === modified file 'mysql-test/suite/rpl/r/rpl_log_pos.result' --- a/mysql-test/suite/rpl/r/rpl_log_pos.result 2011-09-30 13:14:37 +0000 +++ b/mysql-test/suite/rpl/r/rpl_log_pos.result 2011-10-27 19:28:15 +0000 @@ -9,7 +9,7 @@ change master to master_log_pos=MASTER_L Read_Master_Log_Pos = '75' start slave; include/wait_for_slave_io_error.inc [errno=1236] -Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on master; the last event was read from 'master-bin.000001' at 75, the last byte read was read from 'master-bin.000001' at 94.'' +Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'log event entry exceeded max_allowed_packet; Increase max_allowed_packet on master; the last event was read from './master-bin.000001' at 75, the last byte read was read from './master-bin.000001' at 94.'' include/stop_slave_sql.inc show master status; File Position Binlog_Do_DB Binlog_Ignore_DB === added file 'mysql-test/suite/rpl/r/rpl_rotate_purge_deadlock.result' --- a/mysql-test/suite/rpl/r/rpl_rotate_purge_deadlock.result 1970-01-01 00:00:00 +0000 +++ b/mysql-test/suite/rpl/r/rpl_rotate_purge_deadlock.result 2011-10-27 14:14:41 +0000 @@ -0,0 +1,30 @@ +include/master-slave.inc +[connection master] +show binary logs; +Log_name File_size +master-bin.000001 # +create table t1 (f text) engine=innodb; +SET DEBUG_SYNC = 'at_purge_logs_before_date WAIT_FOR rotated'; +insert into t1 set f=repeat('a', 4096); +*** there must be two logs in the list *** +show binary logs; +Log_name File_size +master-bin.000001 # +master-bin.000002 # +insert into t1 set f=repeat('b', 4096); +*** there must be three logs in the list *** +show binary logs; +Log_name File_size +master-bin.000001 # +master-bin.000002 # +master-bin.000003 # +SET DEBUG_SYNC = 'now SIGNAL rotated'; +SET DEBUG_SYNC = 'RESET'; +SET DEBUG_SYNC = 'RESET'; +SET DEBUG_SYNC = 'at_purge_logs_before_date WAIT_FOR rotated'; +insert into t1 set f=repeat('b', 4096); +SET DEBUG_SYNC = 'now SIGNAL rotated'; +SET DEBUG_SYNC = 'RESET'; +SET DEBUG_SYNC = 'RESET'; +drop table t1; +include/rpl_end.inc === added file 'mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock-master.opt' --- a/mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock-master.opt 1970-01-01 00:00:00 +0000 +++ b/mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock-master.opt 2011-10-27 14:14:41 +0000 @@ -0,0 +1 @@ +--max-binlog-size=4k --expire-logs-days=1 === added file 'mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock.test' --- a/mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock.test 1970-01-01 00:00:00 +0000 +++ b/mysql-test/suite/rpl/t/rpl_rotate_purge_deadlock.test 2011-10-27 14:14:41 +0000 @@ -0,0 +1,92 @@ +# +# Bug#11763573 - 56299: MUTEX DEADLOCK WITH COM_BINLOG_DUMP, BINLOG PURGE, AND PROCESSLIST/KILL +# +source include/master-slave.inc; +source include/have_debug_sync.inc; +source include/have_binlog_format_row.inc; +source include/have_innodb.inc; + +# +# Testing that execution of two concurrent INSERTing connections both +# triggering the binlog rotation is correct even though their execution +# is interleaved. +# The test makes the first connection to complete the rotation part +# and yields control to the second connection that rotates as well and +# gets first on purging. And the fact of interleaving does not create +# any issue. +# + +connection master; +source include/show_binary_logs.inc; +create table t1 (f text) engine=innodb; +SET DEBUG_SYNC = 'at_purge_logs_before_date WAIT_FOR rotated'; +send insert into t1 set f=repeat('a', 4096); + +connection master1; + +let $wait_condition= + SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE STATE like "debug sync point: at_purge_logs_before_date%"; +--source include/wait_condition.inc + +--echo *** there must be two logs in the list *** +source include/show_binary_logs.inc; + +insert into t1 set f=repeat('b', 4096); + +--echo *** there must be three logs in the list *** +source include/show_binary_logs.inc; + +SET DEBUG_SYNC = 'now SIGNAL rotated'; +SET DEBUG_SYNC = 'RESET'; + +# the first connection finally completes its INSERT +connection master; +reap; +SET DEBUG_SYNC = 'RESET'; + +sync_slave_with_master; + + +# +# Testing the reported deadlock involving DUMP, KILL and INSERT threads +# + +connection master; +SET DEBUG_SYNC = 'at_purge_logs_before_date WAIT_FOR rotated'; +send insert into t1 set f=repeat('b', 4096); + +connection master1; + +# make sure INSERT reaches waiting point +let $wait_condition= + SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE STATE like "debug sync point: at_purge_logs_before_date%"; +--source include/wait_condition.inc + +# find and kill DUMP thread +let $_tid= `select id from information_schema.processlist where command = 'Binlog Dump' limit 1`; +--disable_query_log +eval kill query $_tid; +--enable_query_log + +# +# Now the proof is that the new DUMP thread has executed +# a critical section of the deadlock without any regression and is UP +# +let $wait_condition= + SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE command = 'Binlog Dump' and STATE like "Master has sent all binlog to slave%"; +--source include/wait_condition.inc + +SET DEBUG_SYNC = 'now SIGNAL rotated'; +SET DEBUG_SYNC = 'RESET'; + +connection master; +reap; +SET DEBUG_SYNC = 'RESET'; +drop table t1; + +sync_slave_with_master; + +--source include/rpl_end.inc === modified file 'sql/binlog.cc' --- a/sql/binlog.cc 2011-09-23 12:22:58 +0000 +++ b/sql/binlog.cc 2011-10-27 19:28:15 +0000 @@ -23,6 +23,7 @@ #include "sql_plugin.h" #include "rpl_handler.h" #include "rpl_info_factory.h" +#include "debug_sync.h" #define MY_OFF_T_UNDEF (~(my_off_t)0UL) #define FLAGSTR(V,F) ((V)&(F)?#F" ":"") @@ -3739,27 +3740,30 @@ err: DBUG_RETURN(error); } - /** + The method executes rotation when LOCK_log is already acquired + by the caller. + + @param force_rotate caller can request the log rotation + @param check_purge is set to true if rotation took place + @note If rotation fails, for instance the server was unable to create a new log file, we still try to write an incident event to the current log. @retval - nonzero - error + nonzero - error in rotating routine. */ -int MYSQL_BIN_LOG::rotate_and_purge(uint flags) +int MYSQL_BIN_LOG::rotate(bool force_rotate, bool* check_purge) { int error= 0; - DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge"); -#ifdef HAVE_REPLICATION - bool check_purge= false; -#endif - if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)) - mysql_mutex_lock(&LOCK_log); - if ((flags & RP_FORCE_ROTATE) || - (my_b_tell(&log_file) >= (my_off_t) max_size)) + DBUG_ENTER("MYSQL_BIN_LOG::rotate"); + + //todo: fix the macro def and restore safe_mutex_assert_owner(&LOCK_log); + *check_purge= false; + + if (force_rotate || (my_b_tell(&log_file) >= (my_off_t) max_size)) { if ((error= new_file_without_locking())) /** @@ -3774,27 +3778,59 @@ int MYSQL_BIN_LOG::rotate_and_purge(uint if (!write_incident(current_thd, FALSE)) flush_and_sync(0); -#ifdef HAVE_REPLICATION - check_purge= true; -#endif - if (flags & RP_BINLOG_CHECKSUM_ALG_CHANGE) - checksum_alg_reset= BINLOG_CHECKSUM_ALG_UNDEF; // done + *check_purge= true; } - if (!(flags & RP_LOCK_LOG_IS_ALREADY_LOCKED)) - mysql_mutex_unlock(&LOCK_log); + DBUG_RETURN(error); +} + +/** + The method executes logs purging routine. + @retval + nonzero - error in rotating routine. +*/ +void MYSQL_BIN_LOG::purge() +{ #ifdef HAVE_REPLICATION - /* - NOTE: Run purge_logs wo/ holding LOCK_log - as it otherwise will deadlock in ndbcluster_binlog_index_purge_file - */ - if (!error && check_purge && expire_logs_days) + if (expire_logs_days) { + DEBUG_SYNC(current_thd, "at_purge_logs_before_date"); time_t purge_time= my_time(0) - expire_logs_days*24*60*60; if (purge_time >= 0) + { purge_logs_before_date(purge_time); + } } #endif +} + +/** + The method is a shortcut of @c rotate() and @c purge(). + LOCK_log is acquired prior to rotate and is released after it. + + @param force_rotate caller can request the log rotation + + @retval + nonzero - error in rotating routine. +*/ +int MYSQL_BIN_LOG::rotate_and_purge(bool force_rotate) +{ + int error= 0; + DBUG_ENTER("MYSQL_BIN_LOG::rotate_and_purge"); + bool check_purge= false; + + //todo: fix the macro def and restore safe_mutex_assert_not_owner(&LOCK_log); + mysql_mutex_lock(&LOCK_log); + error= rotate(force_rotate, &check_purge); + /* + NOTE: Run purge_logs wo/ holding LOCK_log because it does not need + the mutex. Otherwise causes various deadlocks. + */ + mysql_mutex_unlock(&LOCK_log); + + if (!error && check_purge) + purge(); + DBUG_RETURN(error); } @@ -4105,16 +4141,20 @@ bool MYSQL_BIN_LOG::write_incident(Incid { if (!error && !(error= flush_and_sync(0))) { + bool check_purge= false; signal_update(); - error= rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED | - RP_FORCE_ROTATE); + error= rotate(true, &check_purge); + mysql_mutex_unlock(&LOCK_log); + if (!error && check_purge) + purge(); + } + else + { + mysql_mutex_unlock(&LOCK_log); } - mysql_mutex_unlock(&LOCK_log); } - DBUG_RETURN(error); } - /** Creates an incident event and writes it to the binary log. @@ -4163,11 +4203,13 @@ bool MYSQL_BIN_LOG::write_incident(THD * bool MYSQL_BIN_LOG::write(THD *thd, IO_CACHE *cache, bool incident, bool prepared) { DBUG_ENTER("MYSQL_BIN_LOG::write(THD *, IO_CACHE *, Log_event *)"); - mysql_mutex_lock(&LOCK_log); DBUG_ASSERT(is_open()); if (likely(is_open())) // Should always be true { + bool check_purge; + + mysql_mutex_lock(&LOCK_log); /* We only bother to write to the binary log if there is anything to write. @@ -4224,12 +4266,17 @@ bool MYSQL_BIN_LOG::write(THD *thd, IO_C mysql_mutex_lock(&LOCK_prep_xids); prepared_xids++; mysql_mutex_unlock(&LOCK_prep_xids); + mysql_mutex_unlock(&LOCK_log); } else - if (rotate_and_purge(RP_LOCK_LOG_IS_ALREADY_LOCKED)) + { + if (rotate(false, &check_purge)) goto err; + mysql_mutex_unlock(&LOCK_log); + if (check_purge) + purge(); + } } - mysql_mutex_unlock(&LOCK_log); DBUG_RETURN(0); === modified file 'sql/binlog.h' --- a/sql/binlog.h 2011-08-19 13:04:28 +0000 +++ b/sql/binlog.h 2011-10-27 19:28:15 +0000 @@ -251,7 +251,9 @@ public: void make_log_name(char* buf, const char* log_ident); bool is_active(const char* log_file_name); int remove_logs_from_index(LOG_INFO* linfo, bool need_update_threads); - int rotate_and_purge(uint flags); + int rotate(bool force_rotate, bool* check_purge); + void purge(); + int rotate_and_purge(bool force_rotate); /** Flush binlog cache and synchronize to disk. === modified file 'sql/rpl_master.cc' --- a/sql/rpl_master.cc 2011-10-14 13:37:57 +0000 +++ b/sql/rpl_master.cc 2011-10-27 19:28:15 +0000 @@ -1271,12 +1271,9 @@ err: detailing the fatal error message with coordinates of the last position read. */ - char b_start[FN_REFLEN], b_end[FN_REFLEN]; - fn_format(b_start, coord->file_name, "", "", MY_REPLACE_DIR); - fn_format(b_end, log_file_name, "", "", MY_REPLACE_DIR); my_snprintf(error_text, sizeof(error_text), fmt, errmsg, - b_start, (llstr(coord->pos, llbuff1), llbuff1), - b_end, (llstr(my_b_tell(&log), llbuff2), llbuff2)); + coord->file_name, (llstr(coord->pos, llbuff1), llbuff1), + log_file_name, (llstr(my_b_tell(&log), llbuff2), llbuff2)); } else strcpy(error_text, errmsg); === modified file 'sql/sql_class.h' --- a/sql/sql_class.h 2011-10-27 08:08:46 +0000 +++ b/sql/sql_class.h 2011-10-27 19:28:15 +0000 @@ -182,9 +182,6 @@ typedef struct st_user_var_events bool unsigned_flag; } BINLOG_USER_VAR_EVENT; -#define RP_LOCK_LOG_IS_ALREADY_LOCKED 1 -#define RP_FORCE_ROTATE 2 -#define RP_BINLOG_CHECKSUM_ALG_CHANGE 4 /* The COPY_INFO structure is used by INSERT/REPLACE code. The schema of the row counting by the INSERT/INSERT ... ON DUPLICATE KEY === modified file 'sql/sql_reload.cc' --- a/sql/sql_reload.cc 2011-05-21 08:25:33 +0000 +++ b/sql/sql_reload.cc 2011-10-27 19:28:15 +0000 @@ -142,7 +142,7 @@ bool reload_acl_and_cache(THD *thd, unsi tmp_write_to_binlog= 0; if (mysql_bin_log.is_open()) { - if (mysql_bin_log.rotate_and_purge(RP_FORCE_ROTATE)) + if (mysql_bin_log.rotate_and_purge(true)) *write_to_binlog= -1; } } === modified file 'sql/sys_vars.cc' --- a/sql/sys_vars.cc 2011-10-28 09:18:35 +0000 +++ b/sql/sys_vars.cc 2011-10-28 13:08:51 +0000 @@ -2212,15 +2212,18 @@ static Sys_var_mybool Sys_slave_sql_veri bool Sys_var_enum_binlog_checksum::global_update(THD *thd, set_var *var) { + bool check_purge= false; + mysql_mutex_lock(mysql_bin_log.get_log_lock()); if(mysql_bin_log.is_open()) { - uint flags= RP_FORCE_ROTATE | RP_LOCK_LOG_IS_ALREADY_LOCKED | - (binlog_checksum_options != (uint) var->save_result.ulonglong_value? - RP_BINLOG_CHECKSUM_ALG_CHANGE : 0); - if (flags & RP_BINLOG_CHECKSUM_ALG_CHANGE) + bool alg_changed= + (binlog_checksum_options != (uint) var->save_result.ulonglong_value); + if (alg_changed) mysql_bin_log.checksum_alg_reset= (uint8) var->save_result.ulonglong_value; - mysql_bin_log.rotate_and_purge(flags); + mysql_bin_log.rotate(true, &check_purge); + if (alg_changed) + mysql_bin_log.checksum_alg_reset= BINLOG_CHECKSUM_ALG_UNDEF; // done } else { @@ -2229,6 +2232,10 @@ bool Sys_var_enum_binlog_checksum::globa DBUG_ASSERT((ulong) binlog_checksum_options == var->save_result.ulonglong_value); DBUG_ASSERT(mysql_bin_log.checksum_alg_reset == BINLOG_CHECKSUM_ALG_UNDEF); mysql_mutex_unlock(mysql_bin_log.get_log_lock()); + + if (check_purge) + mysql_bin_log.purge(); + return 0; } No bundle (reason: useless for push emails).