From: Date: July 21 2008 12:23pm Subject: bzr commit into mysql-6.0-backup branch (azundris:2731) Bug#23921 List-Archive: http://lists.mysql.com/commits/50109 X-Bug: 23921 Message-Id: <20080721102355.358B342E73AC@noir.koehntopp.de> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit #At file:///misc/mysql/forest/23921/60/ 2731 Tatiana A. Nurnberg 2008-07-21 [merge] Bug#23921: random failure of user_limits.test mysqltest disconnect/connect-combo could be so quick that connect would hit the server before it had processed the disconnect. Since that resulted in one more concurrent connection than we meant to have, global or per-user max-user-connections could be exceeded. This could lead to "random" failures in tests that set those limits. modified: client/mysqltest.c mysql-test/r/mysqltest.result mysql-test/t/disabled.def mysql-test/t/mysqltest.test per-file messages: client/mysqltest.c Retry max-connect-retries times if connect in connect_n_handle_errors() unexpectedly fails on connection-limit as this could be a race. Break out code that checks for expected --errors into its own function. mysql-test/r/mysqltest.result show that we throw a warning if test expects a SQL-state from a command (diff_files, ...) that clearly can't produce one. mysql-test/t/disabled.def re-enable user_limits mysql-test/t/mysqltest.test show that we throw a warning if test expects a SQL-state from a command (diff_files, ...) that clearly can't produce one. === modified file 'client/mysqltest.c' --- a/client/mysqltest.c 2008-07-14 14:56:49 +0000 +++ b/client/mysqltest.c 2008-07-21 10:23:44 +0000 @@ -171,6 +171,8 @@ static ulonglong timer_now(void); static ulonglong progress_start= 0; +static ulong connection_retry_sleep= 100000; /* Microseconds */ + /* Precompiled re's */ static my_regex_t ps_re; /* the query can be run using PS protocol */ static my_regex_t sp_re; /* the query can be run as a SP */ @@ -483,6 +485,9 @@ void replace_dynstr_append(DYNAMIC_STRIN void replace_dynstr_append_uint(DYNAMIC_STRING *ds, uint val); void dynstr_append_sorted(DYNAMIC_STRING* ds, DYNAMIC_STRING* ds_input); +static int match_expected_error(struct st_command *command, + unsigned int err_errno, + const char *err_sqlstate); void handle_error(struct st_command*, unsigned int err_errno, const char *err_error, const char *err_sqlstate, DYNAMIC_STRING *ds); @@ -836,29 +841,25 @@ void check_command_args(struct st_comman DBUG_VOID_RETURN; } - void handle_command_error(struct st_command *command, uint error) { DBUG_ENTER("handle_command_error"); DBUG_PRINT("enter", ("error: %d", error)); if (error != 0) { - uint i; + int i; if (command->abort_on_error) die("command \"%.*s\" failed with error %d", command->first_word_len, command->query, error); - for (i= 0; i < command->expected_errors.count; i++) + + i= match_expected_error(command, error, NULL); + + if (i >= 0) { - DBUG_PRINT("info", ("expected error: %d", - command->expected_errors.err[i].code.errnum)); - if ((command->expected_errors.err[i].type == ERR_ERRNO) && - (command->expected_errors.err[i].code.errnum == error)) - { - DBUG_PRINT("info", ("command \"%.*s\" failed with expected error: %d", - command->first_word_len, command->query, error)); - DBUG_VOID_RETURN; - } + DBUG_PRINT("info", ("command \"%.*s\" failed with expected error: %d", + command->first_word_len, command->query, error)); + DBUG_VOID_RETURN; } die("command \"%.*s\" failed with wrong error: %d", command->first_word_len, command->query, error); @@ -2461,8 +2462,8 @@ void do_exec(struct st_command *command) error= pclose(res_file); if (error > 0) { - uint status= WEXITSTATUS(error), i; - my_bool ok= 0; + uint status= WEXITSTATUS(error); + int i; if (command->abort_on_error) { @@ -2474,19 +2475,13 @@ void do_exec(struct st_command *command) DBUG_PRINT("info", ("error: %d, status: %d", error, status)); - for (i= 0; i < command->expected_errors.count; i++) - { - DBUG_PRINT("info", ("expected error: %d", - command->expected_errors.err[i].code.errnum)); - if ((command->expected_errors.err[i].type == ERR_ERRNO) && - (command->expected_errors.err[i].code.errnum == status)) - { - ok= 1; - DBUG_PRINT("info", ("command \"%s\" failed with expected error: %d", - command->first_argument, status)); - } - } - if (!ok) + + i= match_expected_error(command, status, NULL); + + if (i >= 0) + DBUG_PRINT("info", ("command \"%s\" failed with expected error: %d", + command->first_argument, status)); + else { dynstr_free(&ds_cmd); die("command \"%s\" failed with wrong error: %d", @@ -4249,7 +4244,6 @@ void safe_connect(MYSQL* mysql, const ch int port, const char *sock) { int failed_attempts= 0; - static ulong connection_retry_sleep= 100000; /* Microseconds */ DBUG_ENTER("safe_connect"); while(!mysql_real_connect(mysql, host,user, pass, db, port, sock, @@ -4316,6 +4310,7 @@ int connect_n_handle_errors(struct st_co const char* db, int port, const char* sock) { DYNAMIC_STRING *ds; + int failed_attempts= 0; ds= &ds_res; @@ -4344,9 +4339,41 @@ int connect_n_handle_errors(struct st_co dynstr_append_mem(ds, delimiter, delimiter_length); dynstr_append_mem(ds, "\n", 1); } - if (!mysql_real_connect(con, host, user, pass, db, port, sock ? sock: 0, + while (!mysql_real_connect(con, host, user, pass, db, port, sock ? sock: 0, CLIENT_MULTI_STATEMENTS)) { + /* + If we have used up all our connections check whether this + is expected (by --error). If so, handle the error right away. + Otherwise, give it some extra time to rule out race-conditions. + If extra-time doesn't help, we have an unexpected error and + must abort -- just proceeding to handle_error() when second + and third chances are used up will handle that for us. + + There are various user-limits of which only max_user_connections + and max_connections_per_hour apply at connect time. For the + the second to create a race in our logic, we'd need a limits + test that runs without a FLUSH for longer than an hour, so we'll + stay clear of trying to work out which exact user-limit was + exceeded. + */ + + if (((mysql_errno(con) == ER_TOO_MANY_USER_CONNECTIONS) || + (mysql_errno(con) == ER_USER_LIMIT_REACHED)) && + (failed_attempts++ < opt_max_connect_retries)) + { + int i; + + i= match_expected_error(command, mysql_errno(con), mysql_sqlstate(con)); + + if (i >= 0) + goto do_handle_error; /* expected error, handle */ + + my_sleep(connection_retry_sleep); /* unexpected error, wait */ + continue; /* and give it 1 more chance */ + } + +do_handle_error: var_set_errno(mysql_errno(con)); handle_error(command, mysql_errno(con), mysql_error(con), mysql_sqlstate(con), ds); @@ -6109,6 +6136,56 @@ end: /* + Check whether given error is in list of expected errors + + SYNOPSIS + match_expected_error() + + PARAMETERS + command the current command (and its expect-list) + err_errno error number of the error that actually occurred + err_sqlstate SQL-state that was thrown, or NULL for impossible + (file-ops, diff, etc.) + + RETURNS + -1 for not in list, index in list of expected errors otherwise + + NOTE + If caller needs to know whether the list was empty, they should + check command->expected_errors.count. +*/ + +static int match_expected_error(struct st_command *command, + unsigned int err_errno, + const char *err_sqlstate) +{ + uint i; + + for (i= 0 ; (uint) i < command->expected_errors.count ; i++) + { + if ((command->expected_errors.err[i].type == ERR_ERRNO) && + (command->expected_errors.err[i].code.errnum == err_errno)) + return i; + + if (command->expected_errors.err[i].type == ERR_SQLSTATE) + { + /* + NULL is quite likely, but not in conjunction with a SQL-state expect! + */ + if (unlikely(err_sqlstate == NULL)) + die("expecting a SQL-state (%s) from query '%s' which cannot produce one...", + command->expected_errors.err[i].code.sqlstate, command->query); + + if (strncmp(command->expected_errors.err[i].code.sqlstate, + err_sqlstate, SQLSTATE_LENGTH) == 0) + return i; + } + } + return -1; +} + + +/* Handle errors which occurred during execution SYNOPSIS @@ -6128,7 +6205,7 @@ void handle_error(struct st_command *com unsigned int err_errno, const char *err_error, const char *err_sqlstate, DYNAMIC_STRING *ds) { - uint i; + int i; DBUG_ENTER("handle_error"); @@ -6154,34 +6231,30 @@ void handle_error(struct st_command *com DBUG_PRINT("info", ("expected_errors.count: %d", command->expected_errors.count)); - for (i= 0 ; (uint) i < command->expected_errors.count ; i++) + + i= match_expected_error(command, err_errno, err_sqlstate); + + if (i >= 0) { - if (((command->expected_errors.err[i].type == ERR_ERRNO) && - (command->expected_errors.err[i].code.errnum == err_errno)) || - ((command->expected_errors.err[i].type == ERR_SQLSTATE) && - (strncmp(command->expected_errors.err[i].code.sqlstate, - err_sqlstate, SQLSTATE_LENGTH) == 0))) + if (!disable_result_log) { - if (!disable_result_log) + if (command->expected_errors.count == 1) { - if (command->expected_errors.count == 1) - { - /* Only log error if there is one possible error */ - dynstr_append_mem(ds, "ERROR ", 6); - replace_dynstr_append(ds, err_sqlstate); - dynstr_append_mem(ds, ": ", 2); - replace_dynstr_append(ds, err_error); - dynstr_append_mem(ds,"\n",1); - } - /* Don't log error if we may not get an error */ - else if (command->expected_errors.err[0].type == ERR_SQLSTATE || - (command->expected_errors.err[0].type == ERR_ERRNO && - command->expected_errors.err[0].code.errnum != 0)) - dynstr_append(ds,"Got one of the listed errors\n"); + /* Only log error if there is one possible error */ + dynstr_append_mem(ds, "ERROR ", 6); + replace_dynstr_append(ds, err_sqlstate); + dynstr_append_mem(ds, ": ", 2); + replace_dynstr_append(ds, err_error); + dynstr_append_mem(ds,"\n",1); } - /* OK */ - DBUG_VOID_RETURN; + /* Don't log error if we may not get an error */ + else if (command->expected_errors.err[0].type == ERR_SQLSTATE || + (command->expected_errors.err[0].type == ERR_ERRNO && + command->expected_errors.err[0].code.errnum != 0)) + dynstr_append(ds,"Got one of the listed errors\n"); } + /* OK */ + DBUG_VOID_RETURN; } DBUG_PRINT("info",("i: %d expected_errors: %d", i, @@ -6196,7 +6269,7 @@ void handle_error(struct st_command *com dynstr_append_mem(ds, "\n", 1); } - if (i) + if (command->expected_errors.count > 0) { if (command->expected_errors.err[0].type == ERR_ERRNO) die("query '%s' failed with wrong errno %d: '%s', instead of %d...", === modified file 'mysql-test/r/mysqltest.result' --- a/mysql-test/r/mysqltest.result 2008-07-09 11:19:04 +0000 +++ b/mysql-test/r/mysqltest.result 2008-07-21 10:23:44 +0000 @@ -14,6 +14,7 @@ select otto from (select 1 as otto) as t otto 1 mysqltest: At line 1: query 'select otto from (select 1 as otto) as t1' succeeded - should have failed with sqlstate 42S22... +mysqltest: At line 1: expecting a SQL-state (00000) from query 'remove_file MYSQLTEST_VARDIR/tmp/test_nonexistent.tmp' which cannot produce one... select friedrich from (select 1 as otto) as t1; ERROR 42S22: Unknown column 'friedrich' in 'field list' mysqltest: At line 1: query 'select friedrich from (select 1 as otto) as t1' failed with wrong sqlstate 42S22: 'Unknown column 'friedrich' in 'field list'', instead of 00000... === modified file 'mysql-test/t/disabled.def' --- a/mysql-test/t/disabled.def 2008-07-16 08:43:42 +0000 +++ b/mysql-test/t/disabled.def 2008-07-21 10:23:44 +0000 @@ -16,7 +16,6 @@ show_check : Bug #32682 Test sho lowercase_table3 : Bug#32667 lowercase_table3.test reports to error log rpl_log_pos : Bug#8693 Test 'rpl_log_pos' fails sometimes ctype_create : Bug#32965 main.ctype_create fails -user_limits : Bug#23921 2007-12-16 random failure of user_limits.test backup_no_engine : Bug#36021 2008-04-13 rsomla server crashes when openning table with unknown storage engine backup_tablespace : Bug #36973 backup_tablespace.test fails in pushbuild csv_alter_table : Bug#33696 2008-01-21 pcrews no .result file - bug allows NULL columns in CSV tables @@ -25,7 +24,6 @@ query_cache_wlock_invalidate_func: Bug#3 thread_cache_size_func: BUG#35988, BUG#36733 Due to not deterministic results cast : Bug#35594 2008-03-27 main.cast fails on Windows2003-64 subselect_notembedded : Bug#35803, Bug#33506 2008-Apr-03 subselect_notembedded crashes the server -user_limits : Bug#23921 random failure of user_limits.test status : Bug#37481 status.test fails randomly maria-preload : Bug#35107 crashes key_buffer_size_basic_64 : Bug #36522: Some tests of system variables have diffs on 64bit platorms === modified file 'mysql-test/t/mysqltest.test' --- a/mysql-test/t/mysqltest.test 2008-07-09 16:18:28 +0000 +++ b/mysql-test/t/mysqltest.test 2008-07-21 10:23:44 +0000 @@ -91,6 +91,10 @@ select otto from (select 1 as otto) as t --error 1 --exec echo "error S42S22; select otto from (select 1 as otto) as t1;" | $MYSQL_TEST 2>&1 +# expecting a SQL-state for a command that can't give one should fail +--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR +--error 1 +--exec echo "error S00000; remove_file $MYSQLTEST_VARDIR/tmp/test_nonexistent.tmp;" | $MYSQL_TEST 2>&1 # ----------------------------------------------------------------------------