From 7cf996223d12dc4049ebccb9ccc80df7ece9e091 Mon Sep 17 00:00:00 2001 From: Luis Soares Date: Tue, 29 Sep 2009 15:09:01 +0100 Subject: [PATCH 1/5] BUG#23300: Slow query log on slave does not log slow replicated statements NOTE: this is the backport to next-mr. When using replication, the slave will not log any slow query logs queries replicated from the master, even if the option "--log-slow-slave-statements" is set and these take more than "log_query_time" to execute. In order to log slow queries in replicated thread one needs to set the --log-slow-slave-statements, so that the SQL thread is initialized with the correct switch. Although setting this flag correctly configures the slave thread option to log slow queries, there is an issue with the condition that is used to check whether to log the slow query or not. When replaying binlog events the statement contains the SET TIMESTAMP clause which will force the slow logging condition check to fail. Consequently, the slow query logging will not take place. This patch addresses this issue by removing the second condition from the log_slow_statements as it prevents slow queries to be binlogged and seems to be deprecated. --- .../suite/rpl/r/rpl_slow_query_log.result | 47 +++++ .../suite/rpl/t/rpl_slow_query_log-slave.opt | 1 + .../suite/rpl/t/rpl_slow_query_log.test | 187 ++++++++++++++++++ sql/log.cc | 1 + sql/sql_parse.cc | 4 +- 5 files changed, 238 insertions(+), 2 deletions(-) create mode 100644 mysql-test/suite/rpl/r/rpl_slow_query_log.result create mode 100644 mysql-test/suite/rpl/t/rpl_slow_query_log-slave.opt create mode 100644 mysql-test/suite/rpl/t/rpl_slow_query_log.test 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_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 1af2f3a4ddc..5c25d30bad0 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -961,6 +961,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 */ 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"); From 19ac26274b390b722fffac18f2eb67bbe984f2a8 Mon Sep 17 00:00:00 2001 From: Luis Soares Date: Tue, 29 Sep 2009 15:09:46 +0100 Subject: [PATCH 2/5] BUG#28796: CHANGE MASTER TO MASTER_HOST="" leads to invalid master.info NOTE: this is the backport to next-mr. This patch addresses the bug reported by checking wether host argument is an empty string or not. If empty, an error is reported to the client, otherwise continue normally. This commit is based on the originally proposed patch and adds a test case as requested during review as well as refines comments, and makes test case result file less verbose (compared to previous patch). --- .../suite/rpl/r/rpl_empty_master_host.result | 16 ++++++ .../suite/rpl/t/rpl_empty_master_host.test | 51 +++++++++++++++++++ sql/sql_repl.cc | 13 +++++ 3 files changed, 80 insertions(+) create mode 100644 mysql-test/suite/rpl/r/rpl_empty_master_host.result create mode 100644 mysql-test/suite/rpl/t/rpl_empty_master_host.test 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/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/sql/sql_repl.cc b/sql/sql_repl.cc index 4d9b7410b88..1cc21162022 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)) From ca151daf85f1e5e8af957157855e9c6de20555e3 Mon Sep 17 00:00:00 2001 From: Luis Soares Date: Tue, 29 Sep 2009 15:10:37 +0100 Subject: [PATCH 3/5] Bug #30703 SHOW STATUS LIKE 'Slave_running' is not compatible with `SHOW SLAVE STATUS' NOTE: this is the backport to next-mr. SHOW SHOW STATUS LIKE 'Slave_running' command believes that if active_mi->slave_running != 0, then io thread is running normally. But it isn't so in fact. When some errors happen to make io thread try to reconnect master, then it will become transitional status (MYSQL_SLAVE_RUN_NOT_CONNECT == 1), which also doesn't equal 0. Yet, "SHOW SLAVE STATUS" believes that only if active_mi->slave_running == MYSQL_SLAVE_RUN_CONNECT, then io thread is running. So "SHOW SLAVE STATUS" can get the correct result. Fixed to make SHOW SHOW STATUS LIKE 'Slave_running' command have the same check condition with "SHOW SLAVE STATUS". It only believe that the io thread is running when active_mi->slave_running == MYSQL_SLAVE_RUN_CONNECT. --- mysql-test/include/test_fieldsize.inc | 2 +- sql/mysqld.cc | 3 ++- 2 files changed, 3 insertions(+), 2 deletions(-) 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/sql/mysqld.cc b/sql/mysqld.cc index 9b70096eb73..9ae3db4762b 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -7043,7 +7043,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; From bdacc5622ece6bc5a32e66e4d88b2ecb6fd60e72 Mon Sep 17 00:00:00 2001 From: Luis Soares Date: Tue, 29 Sep 2009 15:12:07 +0100 Subject: [PATCH 4/5] BUG#40611: MySQL cannot make a binary log after sequential number beyond unsigned long. BUG#44779: binlog.binlog_max_extension may be causing failure on next test in PB NOTE1: this is the backport to next-mr. NOTE2: already includes patch for BUG#44779. Binlog file extensions would turn into negative numbers once the variable used to hold the value reached maximum for signed long. Consequently, incrementing value to the next (negative) number would lead to .000000 extension, causing the server to fail. This patch addresses this issue by not allowing negative extensions and by returning an error on find_uniq_filename, when the limit is reached. Additionally, warnings are printed to the error log when the limit is approaching. FLUSH LOGS will also report warnings to the user, if the extension number has reached the limit. The limit has been set to 0x7FFFFFFF as the maximum. --- .../binlog/r/binlog_max_extension.result | 8 ++ .../suite/binlog/t/binlog_max_extension.test | 92 +++++++++++++++++++ sql/log.cc | 75 ++++++++++++--- sql/log.h | 13 +++ 4 files changed, 174 insertions(+), 14 deletions(-) create mode 100644 mysql-test/suite/binlog/r/binlog_max_extension.result create mode 100644 mysql-test/suite/binlog/t/binlog_max_extension.test 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/sql/log.cc b/sql/log.cc index 5c25d30bad0..19b26fcf5ab 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -53,7 +53,7 @@ MYSQL_BIN_LOG mysql_bin_log; ulong sync_binlog_counter= 0; 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); @@ -1835,22 +1835,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); @@ -1858,15 +1863,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)) @@ -1876,9 +1881,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); } @@ -2077,6 +2117,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; } @@ -4739,11 +4786,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 d306d6f7182..3c2ccc521cc 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 From a11e2137c241a3e5e588c4f48659d3f7a856f51e Mon Sep 17 00:00:00 2001 From: Luis Soares Date: Tue, 29 Sep 2009 15:12:43 +0100 Subject: [PATCH 5/5] BUG#42928: binlog-format setting prevents server from start if binary logging is disabled NOTE: this is the backport to next-mr. If one sets binlog-format but does NOT enable binary log, server refuses to start up. The following messages appears in the error log: 090217 12:47:14 [ERROR] You need to use --log-bin to make --binlog-format work. 090217 12:47:14 [ERROR] Aborting This patch addresses this by making the server not to bail out if the binlog-format is set without the log-bin option. Additionally, the specified binlog-format is stored, in the global system variable "binlog_format", and a warning is printed instead of an error. --- sql/mysqld.cc | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/sql/mysqld.cc b/sql/mysqld.cc index 9ae3db4762b..513302b6aec 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -3827,9 +3827,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 {