Hi Daogang,
Nice work, I have some minor comments!
Dao-Gang.Qu@stripped wrote:
> #At file:///home/daogangq/mysql/bzrwork/bug45214/5.1-bt/ based on
> revid:davi.arnaut@stripped
>
> 2941 Dao-Gang.Qu@stripped 2009-06-25
> Bug #45214 get_master_version_and_clock does not report error when queries
> fail
>
> The "get_master_version_and_clock(...)" function in sql/slave.cc ignores error
>
> and passes directly when queries get a failed response from master because of
> network transient disconnection between master and slave or get a successful
network transient disconnection => transient network problems
Because there could be other problems other than disconnection. Please
also change similar places below.
> response but the result retrieved is NULL.
>
> The "get_master_version_and_clock(...)" function should retry to connect master
>
retry to connect => try to reconnect
and please fix other similar phrases in the patch.
> if the queries get a failed response from master because of network transient
> disconnection between master and slave. And it should report a NULL value error
>
> and stop the slave I/O thread if the queries get a successful response but the
>
> result retrieved from master is NULL.
> @ mysql-test/include/restart_slave_on_disconnection.inc
> Test script for bug #45214
> @ mysql-test/suite/rpl/r/rpl_get_master_version_clock_on_disconnection.result
> Test result for bug #45214
> @ mysql-test/suite/rpl/t/rpl_get_master_version_clock_on_disconnection.test
> Test script for bug #45214
> @ sql/slave.cc
> Update the slave.cc for fixing bug #45214
>
> added:
> mysql-test/include/restart_slave_on_disconnection.inc
> mysql-test/suite/rpl/r/rpl_get_master_version_clock_on_disconnection.result
> mysql-test/suite/rpl/t/rpl_get_master_version_clock_on_disconnection.test
> modified:
> sql/slave.cc
> === added file 'mysql-test/include/restart_slave_on_disconnection.inc'
> --- a/mysql-test/include/restart_slave_on_disconnection.inc 1970-01-01 00:00:00
> +0000
> +++ b/mysql-test/include/restart_slave_on_disconnection.inc 2009-06-25 09:24:23
> +0000
usually only general purpose include files should be put in
mysql-test/include, and I think this file can hardly be such an include
file, so I think it's better to name this
rpl_get_master_version_clock_on_disconnection.test and move it to
mysql-test/extra/rpl_test/, which is the place where we keep rpl test
include files.
> @@ -0,0 +1,55 @@
> +# Restart slave under network disconnection between slave and master
> +
> +connection slave;
> +if (`SELECT '$debug_lock' = ''`)
> +{
> + --die Cannot continue. Please set value for $debug_lock.
> +}
> +
> +# Restart slave
> +--disable_warnings
> +stop slave;
> +source include/wait_for_slave_to_stop.inc;
> +start slave;
> +source include/wait_for_slave_to_start.inc;
> +
> +connection master;
> +# Write file to make mysql-test-run.pl expect the "crash", but don't start
> +# it until it's told to
> +--write_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +wait
> +EOF
> +
> +# Send shutdown to the connected server and give
> +# it 10 seconds to die before zapping it
> +shutdown_server 10;
> +
> +connection slave;
> +eval SELECT RELEASE_LOCK($debug_lock);
> +
> +# Write file to make mysql-test-run.pl start up the server again
> +--append_file $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
> +restart
> +EOF
> +
> +connection master;
> +# Turn on reconnect
> +--enable_reconnect
> +
> +# Call script that will poll the server waiting for it to be back online again
> +--source include/wait_until_connected_again.inc
> +
> +# Turn off reconnect again
> +--disable_reconnect
> +
> +connection slave;
> +source include/wait_for_slave_to_start.inc;
> +
> +# Show slave last IO error
> +let $last_io_errno= query_get_value("show slave status", Last_IO_Errno, 1);
> +let $last_io_error= query_get_value("show slave status", Last_IO_Error, 1);
> +echo Slave_IO_Errno= $last_io_errno;
> +echo Slave_IO_Error= $last_io_error;
> +
> +
> +# End of tests
>
> === added file
> 'mysql-test/suite/rpl/r/rpl_get_master_version_clock_on_disconnection.result'
> ---
> a/mysql-test/suite/rpl/r/rpl_get_master_version_clock_on_disconnection.result 1970-01-01
> 00:00:00 +0000
> +++
> b/mysql-test/suite/rpl/r/rpl_get_master_version_clock_on_disconnection.result 2009-06-25
> 09:24:23 +0000
> @@ -0,0 +1,63 @@
> +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;
> +SELECT IS_FREE_LOCK("debug_lock.before_get_UNIX_TIMESTAMP");
> +IS_FREE_LOCK("debug_lock.before_get_UNIX_TIMESTAMP")
> +1
> +SELECT GET_LOCK("debug_lock.before_get_UNIX_TIMESTAMP", 1000);
> +GET_LOCK("debug_lock.before_get_UNIX_TIMESTAMP", 1000)
> +1
> +set global debug= 'd,debug_lock.before_get_UNIX_TIMESTAMP';
> +stop slave;
> +start slave;
> +SELECT RELEASE_LOCK("debug_lock.before_get_UNIX_TIMESTAMP");
> +RELEASE_LOCK("debug_lock.before_get_UNIX_TIMESTAMP")
> +1
> +Slave_IO_Errno= 2013
> +Slave_IO_Error= error reconnecting to master 'root@stripped:13000' - retry-time: 1
> retries: 10
Please mask out the master user, host, port, retry-time and retries,
because they can vary. Please also fix similar issues below.
> +SELECT IS_FREE_LOCK("debug_lock.before_get_SERVER_ID");
> +IS_FREE_LOCK("debug_lock.before_get_SERVER_ID")
> +1
> +SELECT GET_LOCK("debug_lock.before_get_SERVER_ID", 1000);
> +GET_LOCK("debug_lock.before_get_SERVER_ID", 1000)
> +1
> +set global debug= 'd,debug_lock.before_get_SERVER_ID';
> +stop slave;
> +start slave;
> +SELECT RELEASE_LOCK("debug_lock.before_get_SERVER_ID");
> +RELEASE_LOCK("debug_lock.before_get_SERVER_ID")
> +1
> +Slave_IO_Errno= 2013
> +Slave_IO_Error= error reconnecting to master 'root@stripped:13000' - retry-time: 1
> retries: 10
> +SELECT IS_FREE_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE");
> +IS_FREE_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE")
> +1
> +SELECT GET_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE", 1000);
> +GET_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE", 1000)
> +1
> +set global debug= 'd,debug_lock.before_get_COLLATION_SERVER_VALUE';
> +stop slave;
> +start slave;
> +SELECT RELEASE_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE");
> +RELEASE_LOCK("debug_lock.before_get_COLLATION_SERVER_VALUE")
> +1
> +Slave_IO_Errno= 2013
> +Slave_IO_Error= error reconnecting to master 'root@stripped:13000' - retry-time: 1
> retries: 10
> +SELECT IS_FREE_LOCK("debug_lock.before_get_TIME_ZONE_VALUE");
> +IS_FREE_LOCK("debug_lock.before_get_TIME_ZONE_VALUE")
> +1
> +SELECT GET_LOCK("debug_lock.before_get_TIME_ZONE_VALUE", 1000);
> +GET_LOCK("debug_lock.before_get_TIME_ZONE_VALUE", 1000)
> +1
> +set global debug= 'd,debug_lock.before_get_TIME_ZONE_VALUE';
> +stop slave;
> +start slave;
> +SELECT RELEASE_LOCK("debug_lock.before_get_TIME_ZONE_VALUE");
> +RELEASE_LOCK("debug_lock.before_get_TIME_ZONE_VALUE")
> +1
> +Slave_IO_Errno= 2013
> +Slave_IO_Error= error reconnecting to master 'root@stripped:13000' - retry-time: 1
> retries: 10
> +set global debug= '';
>
> === added file
> 'mysql-test/suite/rpl/t/rpl_get_master_version_clock_on_disconnection.test'
> ---
> a/mysql-test/suite/rpl/t/rpl_get_master_version_clock_on_disconnection.test 1970-01-01
> 00:00:00 +0000
> +++
> b/mysql-test/suite/rpl/t/rpl_get_master_version_clock_on_disconnection.test 2009-06-25
> 09:24:23 +0000
> @@ -0,0 +1,72 @@
> +#
> +# BUG#45214: http://bugs.mysql.com/bug.php?id=45214
> +# This test verifies if the slave I/O tread tries to reconnect to
> +# master when it tries to get the values of the UNIX_TIMESTAMP, SERVER_ID,
> +# COLLATION_SERVER and TIME_ZONE from master under network disconnection.
> +#
> +# Steps:
> +# 1 - Got DBUG_SYNC_POINT lock
> +# 2 - Set DBUG_SYNC_POINT before call mysql_real_query(...) function in
> get_master_version_and_clock(...) function and hang here
> +# 3 - shutdown master server for simulating network disconnecion
typo: disconnection
> +# 4 - Release DBUG_SYNC_POINT lock
> +# 5 - Check if the slave I/O thread tries to reconnect to master.
> +
> +source include/master-slave.inc;
> +
> +#Test case 1: Try to get the value of the UNIX_TIMESTAMP from master under network
> disconnection
> +connection slave;
> +let $debug_saved= `select @@global.debug`;
> +
> +let $debug_lock= "debug_lock.before_get_UNIX_TIMESTAMP";
> +
> +if (`SELECT '$debug_lock' != ''`)
Yes this is not necessary here, and if you want to keep the check, then
it should fail the test if $debug_lock is not set.
I'd suggest to remove all the similar checks in this test file.
> +{
> + eval SELECT IS_FREE_LOCK($debug_lock);
> + eval SELECT GET_LOCK($debug_lock, 1000);
> +}
> +
> +set global debug= 'd,debug_lock.before_get_UNIX_TIMESTAMP';
> +source include/restart_slave_on_disconnection.inc;
> +
> +#Test case 2: Try to get the value of the SERVER_ID from master under network
> disconnection
> +connection slave;
> +let $debug_lock= "debug_lock.before_get_SERVER_ID";
> +
> +if (`SELECT '$debug_lock' != ''`)
> +{
> + eval SELECT IS_FREE_LOCK($debug_lock);
> + eval SELECT GET_LOCK($debug_lock, 1000);
> +}
> +
> +set global debug= 'd,debug_lock.before_get_SERVER_ID';
> +source include/restart_slave_on_disconnection.inc;
> +
> +#Test case 3: Try to get the value of the COLLATION_SERVER from master under network
> disconnection
> +connection slave;
> +let $debug_lock= "debug_lock.before_get_COLLATION_SERVER_VALUE";
> +
> +if (`SELECT '$debug_lock' != ''`)
> +{
> + eval SELECT IS_FREE_LOCK($debug_lock);
> + eval SELECT GET_LOCK($debug_lock, 1000);
> +}
> +
> +set global debug= 'd,debug_lock.before_get_COLLATION_SERVER_VALUE';
> +source include/restart_slave_on_disconnection.inc;
> +
> +#Test case 4: Try to get the value of the TIME_ZONE from master under network
> disconnection
> +connection slave;
> +let $debug_lock= "debug_lock.before_get_TIME_ZONE_VALUE";
> +
> +if (`SELECT '$debug_lock' != ''`)
> +{
> + eval SELECT IS_FREE_LOCK($debug_lock);
> + eval SELECT GET_LOCK($debug_lock, 1000);
> +}
> +
> +set global debug= 'd,debug_lock.before_get_TIME_ZONE_VALUE';
> +source include/restart_slave_on_disconnection.inc;
> +
> +eval set global debug= '$debug_saved';
> +
> +# End of tests
>
> === modified file 'sql/slave.cc'
> --- a/sql/slave.cc 2009-06-09 16:44:26 +0000
> +++ b/sql/slave.cc 2009-06-25 09:24:23 +0000
> @@ -854,6 +854,7 @@ int init_intvar_from_file(int* var, IO_C
> RETURNS
> 0 ok
> 1 error
> + 2 network disconnection, retry to connect.
transient network problem, the caller should try to reconnect
> */
>
> static int get_master_version_and_clock(MYSQL* mysql, Master_info* mi)
> @@ -864,7 +865,7 @@ static int get_master_version_and_clock(
> MYSQL_RES *master_res= 0;
> MYSQL_ROW master_row;
> DBUG_ENTER("get_master_version_and_clock");
> -
> + int query_re= 0;
> /*
> Free old description_event_for_queue (that is needed if we are in
> a reconnection).
> @@ -938,10 +939,22 @@ static int get_master_version_and_clock(
> Compare the master and slave's clock. Do not die if master's clock is
> unavailable (very old master not supporting UNIX_TIMESTAMP()?).
> */
> -
> - if (!mysql_real_query(mysql, STRING_WITH_LEN("SELECT UNIX_TIMESTAMP()"))
> &&
> - (master_res= mysql_store_result(mysql)) &&
> - (master_row= mysql_fetch_row(master_res)))
> + DBUG_SYNC_POINT("debug_lock.before_get_UNIX_TIMESTAMP", 10);
> + query_re= mysql_real_query(mysql, STRING_WITH_LEN("SELECT UNIX_TIMESTAMP()"));
> + if (query_re)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_res= mysql_store_result(mysql);
> + if (!master_res)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + if (master_row= mysql_fetch_row(master_res))
> {
> mi->clock_diff_with_master=
> (long) (time((time_t*) 0) - strtoul(master_row[0], 0, 10));
> @@ -967,26 +980,48 @@ static int get_master_version_and_clock(
> Note: we could have put a @@SERVER_ID in the previous SELECT
> UNIX_TIMESTAMP() instead, but this would not have worked on 3.23 masters.
> */
> - if (!mysql_real_query(mysql,
> - STRING_WITH_LEN("SHOW VARIABLES LIKE 'SERVER_ID'"))
> &&
> - (master_res= mysql_store_result(mysql)))
> - {
> - if ((master_row= mysql_fetch_row(master_res)) &&
> - (::server_id == strtoul(master_row[1], 0, 10)) &&
> - !mi->rli.replicate_same_server_id)
> - {
> - errmsg= "The slave I/O thread stops because master and slave have equal \
> + DBUG_SYNC_POINT("debug_lock.before_get_SERVER_ID", 10);
> + query_re= mysql_real_query(mysql, STRING_WITH_LEN("SHOW VARIABLES LIKE
> 'SERVER_ID'"));
> + if (query_re)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_res= mysql_store_result(mysql);
> + if (!master_res)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_row= mysql_fetch_row(master_res);
> + if (master_row && (::server_id == strtoul(master_row[1], 0, 10))
> &&
> + !mi->rli.replicate_same_server_id)
> + {
> + errmsg= "The slave I/O thread stops because master and slave have equal \
> MySQL server ids; these ids must be different for replication to work (or \
> the --replicate-same-server-id option must be used on slave but this does \
> not always make sense; please check the manual before using it).";
> - err_code= ER_SLAVE_FATAL_ERROR;
> - sprintf(err_buff, ER(err_code), errmsg);
> - }
> - mysql_free_result(master_res);
> - if (errmsg)
> - goto err;
> + err_code= ER_SLAVE_FATAL_ERROR;
> + sprintf(err_buff, ER(err_code), errmsg);
> + }
> + else if (!master_row)
> + {
> + errmsg= "The slave I/O thread stops because the value of \
> +the MySQL server id is not existent on master.";
> + err_code= ER_SLAVE_FATAL_ERROR;
> + sprintf(err_buff, ER(err_code), errmsg);
> + }
> + else
> + {
> + //Do nothing.
> }
The last 'else' clause is not necessary, please remove it.
> + mysql_free_result(master_res);
>
> + if (errmsg)
> + goto err;
> +
> /*
> Check that the master's global character_set_server and ours are the same.
> Not fatal if query fails (old master?).
> @@ -1008,13 +1043,26 @@ not always make sense; please check the
> if (*mysql->server_version == '3')
> goto err;
>
> - if ((*mysql->server_version == '4') &&
> - !mysql_real_query(mysql,
> - STRING_WITH_LEN("SELECT @@GLOBAL.COLLATION_SERVER"))
> &&
> - (master_res= mysql_store_result(mysql)))
> + if (*mysql->server_version == '4')
> {
> - if ((master_row= mysql_fetch_row(master_res)) &&
> - strcmp(master_row[0], global_system_variables.collation_server->name))
> + DBUG_SYNC_POINT("debug_lock.before_get_COLLATION_SERVER_VALUE", 10);
> + query_re= mysql_real_query(mysql, STRING_WITH_LEN("SELECT
> @@GLOBAL.COLLATION_SERVER"));
> + if (query_re)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_res= mysql_store_result(mysql);
> + if (!master_res)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_row= mysql_fetch_row(master_res);
> + if (master_row && strcmp(master_row[0],
> + global_system_variables.collation_server->name))
> {
> errmsg= "The slave I/O thread stops because master and slave have \
> different values for the COLLATION_SERVER global variable. The values must \
> @@ -1022,7 +1070,19 @@ be equal for replication to work";
> err_code= ER_SLAVE_FATAL_ERROR;
> sprintf(err_buff, ER(err_code), errmsg);
> }
> + else if (!master_row)
> + {
> + errmsg= "The slave I/O thread stops because the value of \
> +the COLLATION_SERVER global variable is not existent on master.";
> + err_code= ER_SLAVE_FATAL_ERROR;
> + sprintf(err_buff, ER(err_code), errmsg);
> + }
> + else
> + {
> + //Do nothing.
> + }
Here too, please remove the 'else' clause
> mysql_free_result(master_res);
> +
> if (errmsg)
> goto err;
> }
> @@ -1042,13 +1102,26 @@ be equal for replication to work";
> This check is only necessary for 4.x masters (and < 5.0.4 masters but
> those were alpha).
> */
> - if ((*mysql->server_version == '4') &&
> - !mysql_real_query(mysql, STRING_WITH_LEN("SELECT @@GLOBAL.TIME_ZONE"))
> &&
> - (master_res= mysql_store_result(mysql)))
> - {
> - if ((master_row= mysql_fetch_row(master_res)) &&
> - strcmp(master_row[0],
> - global_system_variables.time_zone->get_name()->ptr()))
> + if (*mysql->server_version == '4')
> + {
> + DBUG_SYNC_POINT("debug_lock.before_get_TIME_ZONE_VALUE", 10);
> + query_re= mysql_real_query(mysql, STRING_WITH_LEN("SELECT
> @@GLOBAL.TIME_ZONE"));
> + if (query_re)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_res= mysql_store_result(mysql);
> + if (!master_res)
> + {
> + /* Network disconnection. Go to retry to connect. */
> + DBUG_RETURN(2);
> + }
> +
> + master_row= mysql_fetch_row(master_res);
> + if (master_row && strcmp(master_row[0],
> +
> global_system_variables.time_zone->get_name()->ptr()))
> {
> errmsg= "The slave I/O thread stops because master and slave have \
> different values for the TIME_ZONE global variable. The values must \
> @@ -1056,6 +1129,17 @@ be equal for replication to work";
> err_code= ER_SLAVE_FATAL_ERROR;
> sprintf(err_buff, ER(err_code), errmsg);
> }
> + else if (!master_row)
> + {
> + errmsg= "The slave I/O thread stops because the value of \
> +the TIME_ZONE global variable is not existent on master.";
> + err_code= ER_SLAVE_FATAL_ERROR;
> + sprintf(err_buff, ER(err_code), errmsg);
> + }
> + else
> + {
> + //Do nothing.
> + }
and here
> mysql_free_result(master_res);
>
> if (errmsg)
> @@ -2372,6 +2456,7 @@ pthread_handler_t handle_slave_io(void *
> char llbuff[22];
> uint retry_count;
> bool suppress_warnings;
> + int get_master_version_and_clock_re;
> #ifndef DBUG_OFF
> uint retry_count_reg= 0, retry_count_dump= 0, retry_count_event= 0;
> #endif
> @@ -2382,7 +2467,7 @@ pthread_handler_t handle_slave_io(void *
> DBUG_ASSERT(mi->inited);
> mysql= NULL ;
> retry_count= 0;
> -
> +
> pthread_mutex_lock(&mi->run_lock);
> /* Inform waiting threads that slave has started */
> mi->slave_run_id++;
> @@ -2451,8 +2536,28 @@ connected:
> mi->slave_running= MYSQL_SLAVE_RUN_CONNECT;
> thd->slave_net = &mysql->net;
> thd_proc_info(thd, "Checking master version");
> - if (get_master_version_and_clock(mysql, mi))
> + get_master_version_and_clock_re= get_master_version_and_clock(mysql, mi);
> + if (get_master_version_and_clock_re == 1)
This variable name is way too long :) just use 'res' or 'ret' or 'error'
is good enough.
> + {
> goto err;
> + }
> + else if (get_master_version_and_clock_re == 2)
> + {
> + //Retry to connect because the error was caused by a transient network problem
> + if (try_to_reconnect(thd, mysql, mi, &retry_count, suppress_warnings,
> + reconnect_messages[SLAVE_RECON_ACT_REG]))
> + {
> + goto err;
> + }
> + else
> + {
> + goto connected;
> + }
> + }
> + else
> + {
> + //Do nothing.
> + }
and here
>
> if (mi->rli.relay_log.description_event_for_queue->binlog_version > 1)
> {
>
