diff --git a/mysql-test/include/test_fieldsize.inc b/mysql-test/include/test_fieldsize.inc index cbe63e26318..606bc63779d 100644 --- a/mysql-test/include/test_fieldsize.inc +++ b/mysql-test/include/test_fieldsize.inc @@ -22,7 +22,7 @@ eval $test_insert; connection slave; START SLAVE; -wait_for_slave_to_stop; +--source include/wait_for_slave_sql_to_stop.inc --replace_result $MASTER_MYPORT MASTER_PORT --replace_column 1 # 4 # 7 # 8 # 9 # 16 # 22 # 23 # 33 # 35 # 36 # --query_vertical SHOW SLAVE STATUS diff --git a/mysql-test/suite/binlog/r/binlog_max_extension.result b/mysql-test/suite/binlog/r/binlog_max_extension.result new file mode 100644 index 00000000000..af341db4536 --- /dev/null +++ b/mysql-test/suite/binlog/r/binlog_max_extension.result @@ -0,0 +1,8 @@ +call mtr.add_suppression("Next log extension: 2147483647. Remaining log filename extensions: 0."); +call mtr.add_suppression("Log filename extension number exhausted:"); +call mtr.add_suppression("Can't generate a unique log-filename"); +RESET MASTER; +FLUSH LOGS; +Warnings: +Warning 1098 Can't generate a unique log-filename master-bin.(1-999) + diff --git a/mysql-test/suite/binlog/t/binlog_max_extension.test b/mysql-test/suite/binlog/t/binlog_max_extension.test new file mode 100644 index 00000000000..9f52d195e21 --- /dev/null +++ b/mysql-test/suite/binlog/t/binlog_max_extension.test @@ -0,0 +1,92 @@ +# BUG#40611: MySQL cannot make a binary log after sequential number beyond +# unsigned long. +# +# Problem statement +# ================= +# +# Extension for log file names might be created with negative +# numbers (when counter used would wrap around), causing server +# failure when incrementing -00001 (reaching number 000000 +# extension). +# +# Test +# ==== +# This tests aims at testing the a patch that removes negatives +# numbers from log name extensions and checks that the server +# reports gracefully that the limit has been reached. +# +# It instruments index file to point to a log file close to +# the new maximum and calls flush logs to get warning. +# + +call mtr.add_suppression("Next log extension: 2147483647. Remaining log filename extensions: 0."); +call mtr.add_suppression("Log filename extension number exhausted:"); +call mtr.add_suppression("Can't generate a unique log-filename"); + + +-- source include/have_log_bin.inc +RESET MASTER; + +-- let $MYSQLD_DATADIR= `select @@datadir` + +############################################### +# check hitting maximum file name extension: +############################################### + +########## +# Prepare +########## + +# 1. Stop master server +-- write_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect +wait +EOF +-- shutdown_server 10 +-- source include/wait_until_disconnected.inc + +# 2. Prepare log and index file +-- copy_file $MYSQLD_DATADIR/master-bin.index $MYSQLD_DATADIR/master-bin.index.orig +-- copy_file $MYSQLD_DATADIR/master-bin.000001 $MYSQLD_DATADIR/master-bin.2147483646 +-- append_file $MYSQLD_DATADIR/master-bin.index +master-bin.2147483646 +EOF + +# 3. Restart the server +-- append_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect +restart +EOF +-- enable_reconnect +-- source include/wait_until_connected_again.inc + +########### +# Assertion +########### + +# assertion: should throw warning +FLUSH LOGS; + +############## +# Clean up +############## + +# 1. Stop the server +-- write_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect +wait +EOF +-- shutdown_server 10 +-- source include/wait_until_disconnected.inc + +# 2. Undo changes to index and log files +-- remove_file $MYSQLD_DATADIR/master-bin.index +-- copy_file $MYSQLD_DATADIR/master-bin.index.orig $MYSQLD_DATADIR/master-bin.index +-- remove_file $MYSQLD_DATADIR/master-bin.index.orig + +-- remove_file $MYSQLD_DATADIR/master-bin.2147483646 +-- remove_file $MYSQLD_DATADIR/master-bin.2147483647 + +# 3. Restart the server +-- append_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect +restart +EOF +-- enable_reconnect +-- source include/wait_until_connected_again.inc diff --git a/mysql-test/suite/rpl/r/rpl_empty_master_host.result b/mysql-test/suite/rpl/r/rpl_empty_master_host.result new file mode 100644 index 00000000000..46ef32d415b --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_empty_master_host.result @@ -0,0 +1,16 @@ +stop slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +reset master; +reset slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +start slave; +STOP SLAVE; +Master_Host = '127.0.0.1' (expected '127.0.0.1') +CHANGE MASTER TO MASTER_HOST=""; +ERROR HY000: Incorrect arguments to MASTER_HOST +Master_Host = '127.0.0.1' (expected '127.0.0.1') +CHANGE MASTER TO MASTER_HOST="foo"; +Master_Host = 'foo' (expected 'foo') +CHANGE MASTER TO MASTER_HOST="127.0.0.1"; +Master_Host = '127.0.0.1' (expected '127.0.0.1') +START SLAVE; diff --git a/mysql-test/suite/rpl/r/rpl_slow_query_log.result b/mysql-test/suite/rpl/r/rpl_slow_query_log.result new file mode 100644 index 00000000000..ced357b21e9 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_slow_query_log.result @@ -0,0 +1,47 @@ +stop slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +reset master; +reset slave; +drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; +start slave; +include/stop_slave.inc +SET @old_log_output= @@log_output; +SET GLOBAL log_output= 'TABLE'; +SET @old_long_query_time= @@long_query_time; +SET GLOBAL long_query_time= 2; +TRUNCATE mysql.slow_log; +include/start_slave.inc +CREATE TABLE t1 (a int, b int); +INSERT INTO t1 values(1, 1); +INSERT INTO t1 values(1, sleep(3)); +TRUNCATE mysql.slow_log; +SELECT 1, sleep(3); +1 sleep(3) +1 0 +SELECT 1; +1 +1 +TRUNCATE mysql.slow_log; +SET TIMESTAMP= 1; +SELECT 2, sleep(3); +2 sleep(3) +2 0 +SELECT 2; +2 +2 +TRUNCATE mysql.slow_log; +SET @old_slow_query_log= @@slow_query_log; +SET GLOBAL slow_query_log= 'OFF'; +SELECT 3, sleep(3); +3 sleep(3) +3 0 +SELECT 3; +3 +3 +TRUNCATE mysql.slow_log; +SET GLOBAL slow_query_log= @old_slow_query_log; +DROP TABLE t1; +include/stop_slave.inc +SET GLOBAL long_query_time= @old_long_query_time; +SET GLOBAL log_output= @old_log_output; +include/start_slave.inc diff --git a/mysql-test/suite/rpl/t/rpl_empty_master_host.test b/mysql-test/suite/rpl/t/rpl_empty_master_host.test new file mode 100644 index 00000000000..7d245b1d5d5 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_empty_master_host.test @@ -0,0 +1,51 @@ +# +# BUG +# --- +# BUG#28796: CHANGE MASTER TO MASTER_HOST="" leads to invalid master.info +# +# Description +# ----------- +# +# This test aims at: +# i) verifying that an error is thrown when setting MASTER_HOST='' +# ii) no error is thrown when setting non empty MASTER_HOST +# iii) replication works after setting a correct host name/ip +# +# Implementation is performed by feeding different values (according +# to i), ii) and iii) ) to CHANGE MASTER TO MASTER_HOST= x and checking +# along the way if error/no error is thrown and/or if replication starts +# working when expected. + +--source include/master-slave.inc + +connection slave; +STOP SLAVE; +--source include/wait_for_slave_to_stop.inc + +let $master_host= query_get_value(SHOW SLAVE STATUS, Master_Host, 1); +--echo Master_Host = '$master_host' (expected '127.0.0.1') + +# attempt to change to an empty master host should +# result in error ER_WRONG_ARGUMENTS: "Incorrect arguments to ..." +error ER_WRONG_ARGUMENTS; +CHANGE MASTER TO MASTER_HOST=""; + +# show slave status still holds previous information +let $master_host= query_get_value(SHOW SLAVE STATUS, Master_Host, 1); +--echo Master_Host = '$master_host' (expected '127.0.0.1') + +# changing master to other than empty master host succeeds +CHANGE MASTER TO MASTER_HOST="foo"; + +# show slave status should hold "foo" as master host +let $master_host= query_get_value(SHOW SLAVE STATUS, Master_Host, 1); +--echo Master_Host = '$master_host' (expected 'foo') + +# changing back to localhost +CHANGE MASTER TO MASTER_HOST="127.0.0.1"; +let $master_host= query_get_value(SHOW SLAVE STATUS, Master_Host, 1); +--echo Master_Host = '$master_host' (expected '127.0.0.1') + +# start slave must succeed. +START SLAVE; +--source include/wait_for_slave_to_start.inc diff --git a/mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt b/mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt new file mode 100644 index 00000000000..a27d3a0f5a7 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt @@ -0,0 +1 @@ +--force-restart --log-slow-slave-statements --log-slow-queries diff --git a/mysql-test/suite/rpl/t/rpl_slow_query_log.test b/mysql-test/suite/rpl/t/rpl_slow_query_log.test new file mode 100644 index 00000000000..1d5fcf950f2 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_slow_query_log.test @@ -0,0 +1,187 @@ +# +# BUG#23300: Slow query log on slave does not log slow replicated statements +# +# Description: +# The slave should log slow queries replicated from master when +# --log-slow-slave-statements is used. +# +# Test is implemented as follows: +# i) stop slave +# ii) On slave, set long_query_time to a small value. +# ii) start slave so that long_query_time variable is picked by sql thread +# iii) On master, do one short time query and one long time query, on slave +# and check that slow query is logged to slow query log but fast query +# is not. +# iv) On slave, check that slow queries go into the slow log and fast dont, +# when issued through a regular client connection +# v) On slave, check that slow queries go into the slow log and fast dont +# when we use SET TIMESTAMP= 1 on a regular client connection. +# vi) check that when setting slow_query_log= OFF in a connection 'extra2' +# prevents logging slow queries in a connection 'extra' +# +# OBS: +# This test only runs for statement and mixed binlogging firmat because on +# row format slow queries do not get slow query logged. + +source include/master-slave.inc; +source include/have_binlog_format_mixed_or_statement.inc; + + +# Prepare slave for different long_query_time we need to stop the slave +# and restart it as long_query_time variable is dynamic and, after +# setting it, it only takes effect on new connections. +# +# Reference: +# http://dev.mysql.com/doc/refman/6.0/en/set-option.html +connection slave; + +source include/stop_slave.inc; + +SET @old_log_output= @@log_output; +SET GLOBAL log_output= 'TABLE'; +SET @old_long_query_time= @@long_query_time; +SET GLOBAL long_query_time= 2; +TRUNCATE mysql.slow_log; + +source include/start_slave.inc; + +connection master; +CREATE TABLE t1 (a int, b int); + +# test: +# check that slave logs the slow query to the slow log, but not the fast one. + +let $slow_query= INSERT INTO t1 values(1, sleep(3)); +let $fast_query= INSERT INTO t1 values(1, 1); + +eval $fast_query; +eval $slow_query; +sync_slave_with_master; + +let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`; +let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; + +if ($found_fast_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Fast query FOUND in slow query log. Bailing out!"; +} + +if (!$found_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!"; +} +TRUNCATE mysql.slow_log; + +# regular checks for slow query log (using a new connection - 'extra' - to slave) + +# test: +# when using direct connections to the slave, check that slow query is logged +# but not the fast one. + +connect(extra,127.0.0.1,root,,test,$SLAVE_MYPORT); +connection extra; + +let $fast_query= SELECT 1; +let $slow_query= SELECT 1, sleep(3); + +eval $slow_query; +eval $fast_query; + +let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`; +let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; + +if ($found_fast_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Fast query FOUND in slow query log. Bailing out!"; +} + +if (!$found_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!"; +} +TRUNCATE mysql.slow_log; + +# test: +# when using direct connections to the slave, check that when setting timestamp to 1 the +# slow query is logged but the fast one is not. + +let $fast_query= SELECT 2; +let $slow_query= SELECT 2, sleep(3); + +SET TIMESTAMP= 1; +eval $slow_query; +eval $fast_query; + +let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`; +let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; + +if ($found_fast_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Fast query FOUND in slow query log. Bailing out!"; +} + +if (!$found_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query NOT FOUND in slow query log. Bailing out!"; +} +TRUNCATE mysql.slow_log; + +# test: +# check that when setting the slow_query_log= OFF on connection 'extra2' +# prevents connection 'extra' from logging to slow query log. + +let $fast_query= SELECT 3; +let $slow_query= SELECT 3, sleep(3); + +connect(extra2,127.0.0.1,root,,test,$SLAVE_MYPORT); +connection extra2; + +SET @old_slow_query_log= @@slow_query_log; +SET GLOBAL slow_query_log= 'OFF'; + +connection extra; + +eval $slow_query; +eval $fast_query; + +let $found_fast_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$fast_query'`; +let $found_slow_query= `SELECT count(*) = 1 FROM mysql.slow_log WHERE sql_text like '$slow_query'`; + +if ($found_fast_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Fast query FOUND in slow query log when slow_query_log= OFF. Bailing out!"; +} + +if ($found_slow_query) +{ + SELECT * FROM mysql.slow_log; + die "Assertion failed! Slow query FOUND in slow query log when slow_query_log= OFF. Bailing out!"; +} +TRUNCATE mysql.slow_log; + +# clean up: drop tables, reset the variables back to the previous value, +# disconnect extra connections +connection extra2; + +SET GLOBAL slow_query_log= @old_slow_query_log; + +connection master; +DROP TABLE t1; +sync_slave_with_master; + +source include/stop_slave.inc; + +SET GLOBAL long_query_time= @old_long_query_time; +SET GLOBAL log_output= @old_log_output; + +source include/start_slave.inc; + +disconnect extra; +disconnect extra2; diff --git a/sql/log.cc b/sql/log.cc index 12e57623add..fb8c426b8b5 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -52,7 +52,7 @@ LOGGER logger; MYSQL_BIN_LOG mysql_bin_log(&sync_binlog_period); static bool test_if_number(const char *str, - long *res, bool allow_wildcards); + ulong *res, bool allow_wildcards); static int binlog_init(void *p); static int binlog_close_connection(handlerton *hton, THD *thd); static int binlog_savepoint_set(handlerton *hton, THD *thd, void *sv); @@ -960,6 +960,7 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length, uint user_host_len= 0; ulonglong query_utime, lock_utime; + DBUG_ASSERT(thd->enable_slow_log); /* Print the message to the buffer if we have slow log enabled */ @@ -1833,22 +1834,27 @@ static void setup_windows_event_source() /** Find a unique filename for 'filename.#'. - Set '#' to a number as low as possible. + Set '#' to the number next to the maximum found in the most + recent log file extension. + + This function will return nonzero if: (i) the generated name + exceeds FN_REFLEN; (ii) if the number of extensions is exhausted; + or (iii) some other error happened while examining the filesystem. @return - nonzero if not possible to get unique filename + nonzero if not possible to get unique filename. */ static int find_uniq_filename(char *name) { - long number; uint i; - char buff[FN_REFLEN]; + char buff[FN_REFLEN], ext_buf[FN_REFLEN]; struct st_my_dir *dir_info; reg1 struct fileinfo *file_info; - ulong max_found=0; + ulong max_found= 0, next= 0, number= 0; size_t buf_length, length; char *start, *end; + int error= 0; DBUG_ENTER("find_uniq_filename"); length= dirname_part(buff, name, &buf_length); @@ -1856,15 +1862,15 @@ static int find_uniq_filename(char *name) end= strend(start); *end='.'; - length= (size_t) (end-start+1); + length= (size_t) (end - start + 1); - if (!(dir_info = my_dir(buff,MYF(MY_DONT_SORT)))) + if (!(dir_info= my_dir(buff,MYF(MY_DONT_SORT)))) { // This shouldn't happen strmov(end,".1"); // use name+1 - DBUG_RETURN(0); + DBUG_RETURN(1); } file_info= dir_info->dir_entry; - for (i=dir_info->number_off_files ; i-- ; file_info++) + for (i= dir_info->number_off_files ; i-- ; file_info++) { if (bcmp((uchar*) file_info->name, (uchar*) start, length) == 0 && test_if_number(file_info->name+length, &number,0)) @@ -1874,9 +1880,44 @@ static int find_uniq_filename(char *name) } my_dirend(dir_info); + /* check if reached the maximum possible extension number */ + if ((max_found == MAX_LOG_UNIQUE_FN_EXT)) + { + sql_print_error("Log filename extension number exhausted: %06lu. \ +Please fix this by archiving old logs and \ +updating the index files.", max_found); + error= 1; + goto end; + } + + next= max_found + 1; + sprintf(ext_buf, "%06lu", next); *end++='.'; - sprintf(end,"%06ld",max_found+1); - DBUG_RETURN(0); + + /* + Check if the generated extension size + the file name exceeds the + buffer size used. If one did not check this, then the filename might be + truncated, resulting in error. + */ + if (((strlen(ext_buf) + (end - name)) >= FN_REFLEN)) + { + sql_print_error("Log filename too large: %s%s (%d). \ +Please fix this by archiving old logs and updating the \ +index files.", name, ext_buf, (strlen(ext_buf) + (end - name))); + error= 1; + goto end; + } + + sprintf(end, "%06lu", next); + + /* print warning if reaching the end of available extensions. */ + if ((next > (MAX_LOG_UNIQUE_FN_EXT - LOG_WARN_UNIQUE_FN_EXT_LEFT))) + sql_print_warning("Next log extension: %lu. \ +Remaining log filename extensions: %lu. \ +Please consider archiving some logs.", next, (MAX_LOG_UNIQUE_FN_EXT - next)); + +end: + DBUG_RETURN(error); } @@ -2075,6 +2116,13 @@ int MYSQL_LOG::generate_new_name(char *new_name, const char *log_name) { if (find_uniq_filename(new_name)) { + /* + This should be treated as error once propagation of error further + up in the stack gets proper handling. + */ + push_warning_printf(current_thd, MYSQL_ERROR::WARN_LEVEL_WARN, + ER_NO_UNIQUE_LOGFILE, ER(ER_NO_UNIQUE_LOGFILE), + log_name); sql_print_error(ER(ER_NO_UNIQUE_LOGFILE), log_name); return 1; } @@ -4749,11 +4797,11 @@ void MYSQL_BIN_LOG::set_max_size(ulong max_size_arg) @retval 1 String is a number @retval - 0 Error + 0 String is not a number */ static bool test_if_number(register const char *str, - long *res, bool allow_wildcards) + ulong *res, bool allow_wildcards) { reg2 int flag; const char *start; diff --git a/sql/log.h b/sql/log.h index 53943b649ee..2811ad593d9 100644 --- a/sql/log.h +++ b/sql/log.h @@ -121,6 +121,19 @@ extern TC_LOG_DUMMY tc_log_dummy; #define LOG_CLOSE_TO_BE_OPENED 2 #define LOG_CLOSE_STOP_EVENT 4 +/* + Maximum unique log filename extension. + Note: setting to 0x7FFFFFFF due to atol windows + overflow/truncate. + */ +#define MAX_LOG_UNIQUE_FN_EXT 0x7FFFFFFF + +/* + Number of warnings that will be printed to error log + before extension number is exhausted. +*/ +#define LOG_WARN_UNIQUE_FN_EXT_LEFT 1000 + class Relay_log_info; typedef struct st_log_info diff --git a/sql/mysqld.cc b/sql/mysqld.cc index b8d09fd4e5a..d67c6ca3b1a 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -3829,9 +3829,10 @@ with --log-bin instead."); { if (opt_binlog_format_id != BINLOG_FORMAT_UNSPEC) { - sql_print_error("You need to use --log-bin to make " - "--binlog-format work."); - unireg_abort(1); + sql_print_warning("You need to use --log-bin to make " + "--binlog-format work."); + + global_system_variables.binlog_format= opt_binlog_format_id; } else { @@ -7077,7 +7078,8 @@ static int show_slave_running(THD *thd, SHOW_VAR *var, char *buff) var->type= SHOW_MY_BOOL; pthread_mutex_lock(&LOCK_active_mi); var->value= buff; - *((my_bool *)buff)= (my_bool) (active_mi && active_mi->slave_running && + *((my_bool *)buff)= (my_bool) (active_mi && + active_mi->slave_running == MYSQL_SLAVE_RUN_CONNECT && active_mi->rli.slave_running); pthread_mutex_unlock(&LOCK_active_mi); return 0; diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc index 513b9230c37..d0897646cec 100644 --- a/sql/sql_parse.cc +++ b/sql/sql_parse.cc @@ -1615,9 +1615,9 @@ void log_slow_statement(THD *thd) /* Do not log administrative statements unless the appropriate option is - set; do not log into slow log if reading from backup. + set. */ - if (thd->enable_slow_log && !thd->user_time) + if (thd->enable_slow_log) { ulonglong end_utime_of_query= thd->current_utime(); thd_proc_info(thd, "logging slow query"); diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc index 6295dbb0e79..2d8fbb5f200 100644 --- a/sql/sql_repl.cc +++ b/sql/sql_repl.cc @@ -1150,6 +1150,19 @@ bool change_master(THD* thd, Master_info* mi) thd_proc_info(thd, "Changing master"); LEX_MASTER_INFO* lex_mi= &thd->lex->mi; + /* + We need to check if there is an empty master_host. Otherwise + change master succeeds, a master.info file is created containing + empty master_host string and when issuing: start slave; an error + is thrown stating that the server is not configured as slave. + (See BUG#28796). + */ + if(lex_mi->host && !*lex_mi->host) + { + my_error(ER_WRONG_ARGUMENTS, MYF(0), "MASTER_HOST"); + unlock_slave_threads(mi); + DBUG_RETURN(TRUE); + } // TODO: see if needs re-write if (init_master_info(mi, master_info_file, relay_log_info_file, 0, thread_mask))