diff --git a/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_loaddata.result b/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_loaddata.result new file mode 100644 index 0000000000000..a876a597aea5d --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_loaddata.result @@ -0,0 +1,38 @@ +include/master-slave.inc +[connection master] +connection master; +SET @save_binlog_stmt_cache_size= @@GLOBAL.binlog_stmt_cache_size; +SET GLOBAL binlog_stmt_cache_size= 4096; +CALL mtr.add_suppression('"No space left on device".*An incident event is written to binary log'); +CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=MyISAM; +FLUSH STATUS; +SHOW STATUS LIKE "binlog_stmt_cache%"; +Variable_name Value +Binlog_stmt_cache_disk_use 0 +Binlog_stmt_cache_use 0 +SET @old_dbug= @@SESSION.debug_dbug; +SET SESSION debug_dbug="+d,load_data_binlog_cache_error"; +LOAD DATA CONCURRENT LOCAL INFILE 'std_data/bug30435_5k.txt' + REPLACE INTO TABLE t1 (a); +ERROR HY000: Error writing file '' (Errcode: 28 "No space left on device") +SET SESSION debug_dbug= @old_dbug; +SHOW STATUS LIKE "binlog_stmt_cache%"; +Variable_name Value +Binlog_stmt_cache_disk_use 1 +Binlog_stmt_cache_use 1 +SELECT IF(COUNT(*) > 0 AND COUNT(*) < 5000, +"ok", +CONCAT("ERROR! Row count ", COUNT(*), " not as expected for partially executed query")) +AS check_result +FROM t1; +check_result +ok +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +SELECT COUNT(*) FROM t1; +COUNT(*) +0 +connection master; +SET GLOBAL binlog_stmt_cache_size= @save_binlog_stmt_cache_size; +DROP TABLE t1; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_row.result b/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_row.result new file mode 100644 index 0000000000000..753fdaa4e6b36 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_binlog_cache_disk_full_row.result @@ -0,0 +1,51 @@ +include/master-slave.inc +[connection master] +connection master; +SET @save_binlog_stmt_cache_size= @@GLOBAL.binlog_stmt_cache_size; +SET GLOBAL binlog_stmt_cache_size= 4096; +CALL mtr.add_suppression('"No space left on device".*An incident event is written to binary log'); +CREATE TABLE t1 (a INT PRIMARY KEY, b VARCHAR(255)) ENGINE=MyISAM; +FLUSH STATUS; +SHOW STATUS LIKE "binlog_stmt_cache%"; +Variable_name Value +Binlog_stmt_cache_disk_use 0 +Binlog_stmt_cache_use 0 +INSERT INTO t1 VALUES (0, CONCAT("?", "-", REPEAT("x", 200))); +INSERT INTO t1 SELECT a+1, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+2, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+4, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+8, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+16, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+32, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+64, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+128, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +SHOW STATUS LIKE "binlog_stmt_cache%"; +Variable_name Value +Binlog_stmt_cache_disk_use 2 +Binlog_stmt_cache_use 9 +SET @old_dbug= @@SESSION.debug_dbug; +SET SESSION debug_dbug="+d,simulate_disk_full_at_flush_pending"; +INSERT INTO t1 SELECT a+256, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +ERROR HY000: Error writing file '' (Errcode: 28 "No space left on device") +SET SESSION debug_dbug= @old_dbug; +SHOW STATUS LIKE "binlog_stmt_cache%"; +Variable_name Value +Binlog_stmt_cache_disk_use 3 +Binlog_stmt_cache_use 10 +SELECT IF(COUNT(*) > 256 AND COUNT(*) < 512, +"ok", +CONCAT("ERROR! Row count ", COUNT(*), " not as expected for partially executed query")) +AS check_result +FROM t1; +check_result +ok +ALTER TABLE t1 COMMENT ''; +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +SELECT COUNT(*) FROM t1; +COUNT(*) +256 +connection master; +SET GLOBAL binlog_stmt_cache_size= @save_binlog_stmt_cache_size; +DROP TABLE t1; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_loaddata.test b/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_loaddata.test new file mode 100644 index 0000000000000..50a6753250133 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_loaddata.test @@ -0,0 +1,47 @@ +--source include/have_binlog_format_statement.inc +--source include/have_debug.inc +--source include/master-slave.inc + +--connection master +# Set minimal cache size so smaller transaction can trigger spill to disk. +SET @save_binlog_stmt_cache_size= @@GLOBAL.binlog_stmt_cache_size; +SET GLOBAL binlog_stmt_cache_size= 4096; + +CALL mtr.add_suppression('"No space left on device".*An incident event is written to binary log'); +CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=MyISAM; + +FLUSH STATUS; +SHOW STATUS LIKE "binlog_stmt_cache%"; +SET @old_dbug= @@SESSION.debug_dbug; +SET SESSION debug_dbug="+d,load_data_binlog_cache_error"; +--replace_regex /Error writing file '[^']+'/Error writing file ''/ +--error 3 +LOAD DATA CONCURRENT LOCAL INFILE 'std_data/bug30435_5k.txt' + REPLACE INTO TABLE t1 (a); +SET SESSION debug_dbug= @old_dbug; +SHOW STATUS LIKE "binlog_stmt_cache%"; +# The actual number of rows left after the disk full error may change as +# binlog event sizes are modified. So here we just test that we get partial +# update from the last INSERT..SELECT that gets disk full error. +SELECT IF(COUNT(*) > 0 AND COUNT(*) < 5000, + "ok", + CONCAT("ERROR! Row count ", COUNT(*), " not as expected for partially executed query")) + AS check_result + FROM t1; + +--save_master_pos + +--connection slave +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--sync_with_master +SELECT COUNT(*) FROM t1; + +# Cleanup + +--connection master +SET GLOBAL binlog_stmt_cache_size= @save_binlog_stmt_cache_size; +DROP TABLE t1; + +--source include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_row.test b/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_row.test new file mode 100644 index 0000000000000..2c5813bb53e19 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_binlog_cache_disk_full_row.test @@ -0,0 +1,61 @@ +--source include/have_binlog_format_row.inc +--source include/have_debug.inc +--source include/master-slave.inc + +--connection master +# Set minimal cache size so smaller transaction can trigger spill to disk. +SET @save_binlog_stmt_cache_size= @@GLOBAL.binlog_stmt_cache_size; +SET GLOBAL binlog_stmt_cache_size= 4096; + +CALL mtr.add_suppression('"No space left on device".*An incident event is written to binary log'); +CREATE TABLE t1 (a INT PRIMARY KEY, b VARCHAR(255)) ENGINE=MyISAM; + +FLUSH STATUS; +SHOW STATUS LIKE "binlog_stmt_cache%"; +INSERT INTO t1 VALUES (0, CONCAT("?", "-", REPEAT("x", 200))); +INSERT INTO t1 SELECT a+1, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+2, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+4, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+8, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+16, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+32, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+64, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +INSERT INTO t1 SELECT a+128, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +SHOW STATUS LIKE "binlog_stmt_cache%"; + +SET @old_dbug= @@SESSION.debug_dbug; +SET SESSION debug_dbug="+d,simulate_disk_full_at_flush_pending"; +--replace_regex /Error writing file '[^']+'/Error writing file ''/ +--error 3 +INSERT INTO t1 SELECT a+256, CONCAT(a, "-", REPEAT("x", 200)) FROM t1; +SET SESSION debug_dbug= @old_dbug; +SHOW STATUS LIKE "binlog_stmt_cache%"; +# The actual number of rows left after the disk full error may change as +# binlog event sizes are modified. So here we just test that we get partial +# update from the last INSERT..SELECT that gets disk full error. +SELECT IF(COUNT(*) > 256 AND COUNT(*) < 512, + "ok", + CONCAT("ERROR! Row count ", COUNT(*), " not as expected for partially executed query")) + AS check_result + FROM t1; + +# A random extra event that helped show the bug that a partial event +# group was binlogged. +ALTER TABLE t1 COMMENT ''; + +--save_master_pos + +--connection slave +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--sync_with_master +SELECT COUNT(*) FROM t1; + +# Cleanup + +--connection master +SET GLOBAL binlog_stmt_cache_size= @save_binlog_stmt_cache_size; +DROP TABLE t1; + +--source include/rpl_end.inc diff --git a/sql/log.cc b/sql/log.cc index e729206474789..59730c3205ae1 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -2228,6 +2228,23 @@ bool MYSQL_BIN_LOG::check_write_error(THD *thd) } +/* + Check if there was an error while writing the statement cache. + If the cache content is corrupt due to an error, we should write an incident + event to the binlog rather than write corrupt data to it. +*/ +bool +MYSQL_BIN_LOG::check_cache_error(THD *thd, binlog_cache_data *cache_data) +{ + if (!cache_data) + return false; + if (check_write_error(thd)) + return true; + if (!cache_data->empty() && cache_data->cache_log.error) + return true; + return false; +} + /** @note How do we handle this (unlikely but legal) case: @@ -5874,7 +5891,7 @@ int THD::binlog_write_table_map(TABLE *table, bool is_transactional, engines, data is written to table but writing to binary log failed. In these scenarios rollback is not possible. Hence report an incident. */ - if (mysql_bin_log.check_write_error(this) && cache_data && + if (mysql_bin_log.check_cache_error(this, cache_data) && lex->stmt_accessed_table(LEX::STMT_WRITES_NON_TRANS_TABLE) && table->current_lock == F_WRLCK) cache_data->set_incident(); @@ -6005,20 +6022,37 @@ MYSQL_BIN_LOG::flush_and_set_pending_rows_event(THD *thd, /* Write pending event to the cache. */ +#ifndef DBUG_OFF + bool clear_dbug= false; +#endif DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending", - {DBUG_SET("+d,simulate_file_write_error");}); + { + if (my_b_tell(&cache_data->cache_log) > 10000) + { + DBUG_SET("+d,simulate_file_write_error"); + clear_dbug= true; + } + }); if (writer.write(pending)) { set_write_error(thd, is_transactional); - if (check_write_error(thd) && cache_data && + if (check_cache_error(thd, cache_data) && stmt_has_updated_non_trans_table(thd)) cache_data->set_incident(); delete pending; cache_data->set_pending(NULL); DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending", - {DBUG_SET("-d,simulate_file_write_error");}); + { + if (clear_dbug) + DBUG_SET("-d,simulate_file_write_error"); + }); DBUG_RETURN(1); } + DBUG_EXECUTE_IF("simulate_disk_full_at_flush_pending", + { + if (clear_dbug) + DBUG_SET("-d,simulate_file_write_error"); + }); delete pending; } @@ -6613,7 +6647,7 @@ bool MYSQL_BIN_LOG::write(Log_event *event_info, my_bool *with_annotate) if (unlikely(error)) { set_write_error(thd, is_trans_cache); - if (check_write_error(thd) && cache_data && + if (check_cache_error(thd, cache_data) && stmt_has_updated_non_trans_table(thd)) cache_data->set_incident(); } @@ -8337,6 +8371,20 @@ MYSQL_BIN_LOG::write_transaction_or_stmt(group_commit_entry *entry, binlog_cache_mngr *mngr= entry->cache_mngr; DBUG_ENTER("MYSQL_BIN_LOG::write_transaction_or_stmt"); + /* + An error in the trx_cache will truncate the cache to the last good + statement, it won't leave a lingering error. Assert that this holds. + */ + DBUG_ASSERT(!(entry->using_trx_cache && !mngr->trx_cache.empty() && + mngr->get_binlog_cache_log(TRUE)->error)); + /* + An error in the stmt_cache would be caught on the higher level and result + in an incident event being written over a (possibly corrupt) cache content. + Assert that this holds. + */ + DBUG_ASSERT(!(entry->using_stmt_cache && !mngr->stmt_cache.empty() && + mngr->get_binlog_cache_log(FALSE)->error)); + if (write_gtid_event(entry->thd, false, entry->using_trx_cache, commit_id)) DBUG_RETURN(ER_ERROR_ON_WRITE); diff --git a/sql/log.h b/sql/log.h index deeb5ca83ba69..48169be0d68e4 100644 --- a/sql/log.h +++ b/sql/log.h @@ -815,6 +815,7 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG int write_cache(THD *thd, IO_CACHE *cache); void set_write_error(THD *thd, bool is_transactional); bool check_write_error(THD *thd); + bool check_cache_error(THD *thd, binlog_cache_data *cache_data); void start_union_events(THD *thd, query_id_t query_id_param); void stop_union_events(THD *thd); diff --git a/sql/sql_load.cc b/sql/sql_load.cc index 8264286a0226f..cc4361b04720c 100644 --- a/sql/sql_load.cc +++ b/sql/sql_load.cc @@ -253,6 +253,10 @@ class READ_INFO: public Load_data_param */ void skip_data_till_eof() { +#ifndef EMBEDDED_LIBRARY + if (mysql_bin_log.is_open()) + cache.read_function= cache.real_read_function; +#endif while (GET != my_b_EOF) ; } diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc index d9b9374219549..0d2e61f7f5919 100644 --- a/sql/sql_repl.cc +++ b/sql/sql_repl.cc @@ -4499,6 +4499,10 @@ int log_loaded_block(IO_CACHE* file, uchar *Buffer, size_t Count) /* buffer contains position where we started last read */ uchar* buffer= (uchar*) my_b_get_buffer_start(file); uint max_event_size= lf_info->thd->variables.max_allowed_packet; + int res; +#ifndef DBUG_OFF + bool did_dbug_inject= false; +#endif if (lf_info->thd->is_current_stmt_binlog_format_row()) goto ret; @@ -4506,6 +4510,19 @@ int log_loaded_block(IO_CACHE* file, uchar *Buffer, size_t Count) lf_info->last_pos_in_file >= my_b_get_pos_in_file(file)) goto ret; + DBUG_EXECUTE_IF("load_data_binlog_cache_error", + { + /* + Simulate "disk full" error in the middle of writing to + the binlog cache. + */ + if (lf_info->last_pos_in_file >= 2*4096) + { + DBUG_SET("+d,simulate_file_write_error"); + did_dbug_inject= true; + } + };); + for (block_len= (uint) (my_b_get_bytes_in_buffer(file)); block_len > 0; buffer += MY_MIN(block_len, max_event_size), block_len -= MY_MIN(block_len, max_event_size)) @@ -4517,7 +4534,10 @@ int log_loaded_block(IO_CACHE* file, uchar *Buffer, size_t Count) MY_MIN(block_len, max_event_size), lf_info->log_delayed); if (mysql_bin_log.write(&a)) - DBUG_RETURN(1); + { + res= 1; + goto err; + } } else { @@ -4526,12 +4546,20 @@ int log_loaded_block(IO_CACHE* file, uchar *Buffer, size_t Count) MY_MIN(block_len, max_event_size), lf_info->log_delayed); if (mysql_bin_log.write(&b)) - DBUG_RETURN(1); + { + res= 1; + goto err; + } lf_info->wrote_create_file= 1; } } ret: - int res= Buffer ? lf_info->real_read_function(file, Buffer, Count) : 0; + res= Buffer ? lf_info->real_read_function(file, Buffer, Count) : 0; +err: +#ifndef DBUG_OFF + if (did_dbug_inject) + DBUG_SET("-d,simulate_file_write_error"); +#endif DBUG_RETURN(res); }