From: Date: July 15 2008 1:43pm Subject: bzr commit into mysql-5.1 branch (azundris:2662) Bug#23921 List-Archive: http://lists.mysql.com/commits/49751 X-Bug: 23921 Message-Id: <20080715114303.C819342E73AF@noir.koehntopp.de> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit #At file:///misc/mysql/forest/23921/51-23921/ 2662 Tatiana A. Nurnberg 2008-07-15 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-05-06 13:37:36 +0000 +++ b/client/mysqltest.c 2008-07-15 11:42:21 +0000 @@ -163,6 +163,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 */ @@ -482,6 +484,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); @@ -835,29 +840,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); @@ -2452,8 +2453,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) { @@ -2465,19 +2466,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", @@ -4157,7 +4152,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, @@ -4224,6 +4218,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; @@ -4252,9 +4247,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); @@ -6016,6 +6043,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 @@ -6035,7 +6112,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"); @@ -6061,34 +6138,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, @@ -6103,7 +6176,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-04-29 16:08:52 +0000 +++ b/mysql-test/r/mysqltest.result 2008-07-15 11:42:21 +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 /misc/mysql/forest/23921/51-23921/mysql-test/var/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-05-23 16:42:54 +0000 +++ b/mysql-test/t/disabled.def 2008-07-15 11:42:21 +0000 @@ -11,7 +11,6 @@ ############################################################################## federated_transactions : Bug#29523 Transactions do not work csv_alter_table : Bug#33696 2008-01-21 pcrews no .result file - bug allows NULL columns in CSV tables -user_limits : Bug#23921 random failure of user_limits.test thread_cache_size_func : Bug#36733 main.thread_cache_size_func fails randomly binlog_cache_size_basic_32 : Bug #36522: Some tests of system variables have diffs on 64bit platorms bulk_insert_buffer_size_basic_32 : 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-04-29 16:08:52 +0000 +++ b/mysql-test/t/mysqltest.test 2008-07-15 11:42:21 +0000 @@ -91,6 +91,8 @@ 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 +--error 1 +--exec echo "error S00000; remove_file $MYSQLTEST_VARDIR/tmp/test_nonexistent.tmp;" | $MYSQL_TEST 2>&1 # ----------------------------------------------------------------------------