From cf9038e97973f8bbe387887af9b9f489316b3629 Mon Sep 17 00:00:00 2001 From: unknown Date: Thu, 23 Nov 2006 22:55:36 +0300 Subject: [PATCH] Fix for BUG##24415: Instance manager test im_daemon_life_cycle fails randomly. The problem was that the test case used command line tool (mysql) without specifying connect_timeout argument. In some cases, this lead to hanging of the test case. The fix is to specify --connect_timeout=1 when starting mysql. Also, the patch contains polishing and various cleanups to simplify analyzing of the problems further. The patch affects only test suite, no server codebase has been touched. mysql-test/lib/mtr_im.pl: Remember PID of the IM-spawner -- a process, that is used to fork IM-angel. mysql-test/lib/mtr_io.pl: Trim \n from the PID. mysql-test/lib/mtr_process.pl: Don't complain if it was IM-spawner, who died. mysql-test/r/im_daemon_life_cycle.result: Update the result file. mysql-test/r/im_life_cycle.result: Update the result file. mysql-test/t/im_daemon_life_cycle.imtest: Polishing: add more comments, be more verbose. mysql-test/t/im_life_cycle.imtest: Polishing: be more verbose. mysql-test/t/im_utils.imtest: Polishing: be more verbose. mysql-test/t/kill_n_check.sh: Log messages to the extrenal file so that they can be analyzed if test case failed. mysql-test/t/wait_for_process.sh: Log messages to the extrenal file so that they can be analyzed if test case failed. mysql-test/t/wait_for_socket.sh: Log messages to the extrenal file so that they can be analyzed if test case failed. mysql-test/t/log.sh: Dummy script to facilitate logging from test-scripts. mysql-test/t/utils.sh: A bunch of auxilary functions to facilitate logging. --- mysql-test/lib/mtr_im.pl | 4 +- mysql-test/lib/mtr_io.pl | 1 + mysql-test/lib/mtr_process.pl | 6 ++ mysql-test/r/im_daemon_life_cycle.result | 4 +- mysql-test/r/im_life_cycle.result | 4 +- mysql-test/t/im_daemon_life_cycle.imtest | 73 +++++++++------ mysql-test/t/im_life_cycle.imtest | 10 +-- mysql-test/t/im_utils.imtest | 4 +- mysql-test/t/kill_n_check.sh | 82 +++++++++++------ mysql-test/t/log.sh | 24 +++++ mysql-test/t/utils.sh | 55 ++++++++++++ mysql-test/t/wait_for_process.sh | 108 ++++++++++++++++------- mysql-test/t/wait_for_socket.sh | 60 ++++++++++--- 13 files changed, 327 insertions(+), 108 deletions(-) create mode 100755 mysql-test/t/log.sh create mode 100644 mysql-test/t/utils.sh diff --git a/mysql-test/lib/mtr_im.pl b/mysql-test/lib/mtr_im.pl index ca17516278e..967e92dfcdd 100644 --- a/mysql-test/lib/mtr_im.pl +++ b/mysql-test/lib/mtr_im.pl @@ -582,7 +582,7 @@ sub mtr_im_start($$) { mtr_add_arg($args, $opt); } - $im->{'pid'} = + $im->{'spawner_pid'} = mtr_spawn( $::exe_im, # path to the executable $args, # cmd-line args @@ -593,7 +593,7 @@ sub mtr_im_start($$) { { append_log_file => 1 } # append log files ); - unless ( $im->{'pid'} ) + unless ( $im->{'spawner_pid'} ) { mtr_error('Could not start Instance Manager.') } diff --git a/mysql-test/lib/mtr_io.pl b/mysql-test/lib/mtr_io.pl index 984d834486c..5be1d2ffddb 100644 --- a/mysql-test/lib/mtr_io.pl +++ b/mysql-test/lib/mtr_io.pl @@ -39,6 +39,7 @@ sub mtr_get_pid_from_file ($) { # Read pid number from file my $pid= ; + chomp $pid; close FILE; return $pid if $pid=~ /^(\d+)/; diff --git a/mysql-test/lib/mtr_process.pl b/mysql-test/lib/mtr_process.pl index 9d0c1f601ba..79285de88a7 100644 --- a/mysql-test/lib/mtr_process.pl +++ b/mysql-test/lib/mtr_process.pl @@ -937,6 +937,12 @@ sub check_expected_crash_and_restart($) } } } + + if ($::instance_manager->{'spawner_pid'} eq $ret_pid) + { + return; + } + mtr_warning("check_expected_crash_and_restart couldn't find an entry for pid: $ret_pid"); } diff --git a/mysql-test/r/im_daemon_life_cycle.result b/mysql-test/r/im_daemon_life_cycle.result index b842a5f3bf9..d80a34f8427 100644 --- a/mysql-test/r/im_daemon_life_cycle.result +++ b/mysql-test/r/im_daemon_life_cycle.result @@ -6,7 +6,7 @@ instance_name status mysqld1 online mysqld2 offline Killing the process... -Sleeping... +Waiting... Success: the process was restarted. Success: server is ready to accept connection on socket. @@ -16,7 +16,7 @@ Success: server is ready to accept connection on socket. START INSTANCE mysqld2; Success: the process has been started. Killing the process... -Sleeping... +Waiting... Success: the process was restarted. Success: server is ready to accept connection on socket. SHOW INSTANCE STATUS mysqld1; diff --git a/mysql-test/r/im_life_cycle.result b/mysql-test/r/im_life_cycle.result index 69f6bb5a490..a9ad85d5947 100644 --- a/mysql-test/r/im_life_cycle.result +++ b/mysql-test/r/im_life_cycle.result @@ -39,7 +39,7 @@ ERROR HY000: Bad instance name. Check that the instance with such a name exists -- 1.1.6. -------------------------------------------------------------------- Killing the process... -Sleeping... +Waiting... Success: the process was restarted. SHOW INSTANCES; instance_name status @@ -52,7 +52,7 @@ mysqld2 offline START INSTANCE mysqld2; Success: the process has been started. Killing the process... -Sleeping... +Waiting... Success: the process was killed. -------------------------------------------------------------------- diff --git a/mysql-test/t/im_daemon_life_cycle.imtest b/mysql-test/t/im_daemon_life_cycle.imtest index 65db9dee93f..acd615809f3 100644 --- a/mysql-test/t/im_daemon_life_cycle.imtest +++ b/mysql-test/t/im_daemon_life_cycle.imtest @@ -6,59 +6,73 @@ # ########################################################################### +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle im_daemon_life_cycle.imtest started. + +########################################################################### + --source include/im_check_env.inc -# Turn on reconnect, not on by default anymore +# Turn on reconnect, not on by default anymore. --enable_reconnect ########################################################################### - -# Kill the IM main process and check that the IM Angel will restart the main -# process. - ---exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_PATH_PID restarted 30 - +# +# The main daemon-life-cycle test case -- check that IM-angel will restart +# IM-main if it got killed: +# - kill IM-main and check that IM-angel will restart it; +# - wait for IM-main to start accepting connections before continue test +# case; +# ########################################################################### -# Wait for IM to start accepting connections. +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Main-test: starting... ---exec $MYSQL_TEST_DIR/t/wait_for_socket.sh $EXE_MYSQL $IM_PATH_SOCK $IM_USERNAME $IM_PASSWORD '' 30 +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Killing IM-main... +--exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_PATH_PID restarted 30 im_daemon_life_cycle + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Waiting for IM-main to start accepting connections... +--exec $MYSQL_TEST_DIR/t/wait_for_socket.sh $EXE_MYSQL $IM_PATH_SOCK $IM_USERNAME $IM_PASSWORD '' 30 im_daemon_life_cycle + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Main-test: done. ########################################################################### - # # BUG#12751: Instance Manager: client hangs +# - start nonguarded instance (mysqld2); +# - kill IM-main and get it restarted by IM-angel; +# - check that guarded instance (mysqld1) is accepting connections. +# - check that non-guarded instance (mysqld2) were not stopped. # +########################################################################### --echo --echo -------------------------------------------------------------------- --echo -- Test for BUG#12751 --echo -------------------------------------------------------------------- -# Give some time to begin accepting connections after restart. -# FIXME: race condition here. - ---sleep 3 +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle BUG12751: starting... # 1. Start mysqld; +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: starting... START INSTANCE mysqld2; -# FIXME: START INSTANCE should be synchronous. ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started -# 2. Restart IM-main: kill it and IM-angel will restart it; wait for IM to -# start accepting connections again. +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: waiting to start... +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started im_daemon_life_cycle ---exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_PATH_PID restarted 30 +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: started. ---exec $MYSQL_TEST_DIR/t/wait_for_socket.sh $EXE_MYSQL $IM_PATH_SOCK $IM_USERNAME $IM_PASSWORD '' 30 +# 2. Restart IM-main; + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Killing IM-main... +--exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_PATH_PID restarted 30 im_daemon_life_cycle + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Waiting for IM-main to start accepting connections... +--exec $MYSQL_TEST_DIR/t/wait_for_socket.sh $EXE_MYSQL $IM_PATH_SOCK $IM_USERNAME $IM_PASSWORD '' 30 im_daemon_life_cycle # 3. Issue some statement -- connection should be re-established. -# Give some time to begin accepting connections after restart. -# FIXME: race condition here. - ---sleep 3 +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle Checking that IM-main processing commands... --replace_column 3 VERSION SHOW INSTANCE STATUS mysqld1; @@ -67,6 +81,13 @@ SHOW INSTANCE STATUS mysqld1; # So, if it we do not stop it, it will be stopped by mysql-test-run.pl with # warning. +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: stopping... STOP INSTANCE mysqld2; -# FIXME: STOP INSTANCE should be synchronous. ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: waiting to stop... +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped im_daemon_life_cycle +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle mysqld2: stopped. + +########################################################################### + +--exec $MYSQL_TEST_DIR/t/log.sh im_daemon_life_cycle BUG12751: done. diff --git a/mysql-test/t/im_life_cycle.imtest b/mysql-test/t/im_life_cycle.imtest index ddfb62d312e..3721b92e2b7 100644 --- a/mysql-test/t/im_life_cycle.imtest +++ b/mysql-test/t/im_life_cycle.imtest @@ -25,7 +25,7 @@ START INSTANCE mysqld2; # FIXME: START INSTANCE should be synchronous. ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started im_life_cycle # FIXME: Result of SHOW INSTANCES here is not deterministic unless START # INSTANCE is synchronous. Even waiting for mysqld to start by looking at @@ -58,7 +58,7 @@ SHOW VARIABLES LIKE 'port'; STOP INSTANCE mysqld2; # FIXME: STOP INSTANCE should be synchronous. ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped im_life_cycle # FIXME: Result of SHOW INSTANCES here is not deterministic unless START # INSTANCE is synchronous. Even waiting for mysqld to start by looking at @@ -121,7 +121,7 @@ STOP INSTANCE mysqld3; --echo -- 1.1.6. --echo -------------------------------------------------------------------- ---exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_MYSQLD1_PATH_PID restarted 30 +--exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_MYSQLD1_PATH_PID restarted 30 im_life_cycle # Give some time to IM to detect that mysqld was restarted. It should be # longer than monitoring interval. @@ -143,7 +143,7 @@ SHOW INSTANCES; START INSTANCE mysqld2; # FIXME: START INSTANCE should be synchronous. ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started im_life_cycle # FIXME: Result of SHOW INSTANCES here is not deterministic unless START # INSTANCE is synchronous. Even waiting for mysqld to start by looking at @@ -151,7 +151,7 @@ START INSTANCE mysqld2; # mysqld has started. # SHOW INSTANCES; ---exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_MYSQLD2_PATH_PID killed 10 +--exec $MYSQL_TEST_DIR/t/kill_n_check.sh $IM_MYSQLD2_PATH_PID killed 10 im_life_cycle # FIXME: Result of SHOW INSTANCES here is not deterministic unless START # INSTANCE is synchronous. Even waiting for mysqld to start by looking at diff --git a/mysql-test/t/im_utils.imtest b/mysql-test/t/im_utils.imtest index 52878f6c2b5..0866b87204a 100644 --- a/mysql-test/t/im_utils.imtest +++ b/mysql-test/t/im_utils.imtest @@ -31,10 +31,10 @@ SHOW INSTANCE OPTIONS mysqld2; # START INSTANCE mysqld2; ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 started im_utils STOP INSTANCE mysqld2; ---exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped +--exec $MYSQL_TEST_DIR/t/wait_for_process.sh $IM_MYSQLD2_PATH_PID 30 stopped im_utils # # Check 'SHOW LOG FILES' command: diff --git a/mysql-test/t/kill_n_check.sh b/mysql-test/t/kill_n_check.sh index a54fb6ef8bb..96c402a638c 100755 --- a/mysql-test/t/kill_n_check.sh +++ b/mysql-test/t/kill_n_check.sh @@ -2,74 +2,101 @@ ########################################################################### -# NOTE: this script returns 0 (success) even in case of failure. This is -# because this script is executed under mysql-test-run[.pl] and it's better to -# examine particular problem in log file, than just having said that the test -# case has failed. +# NOTE: this script returns 0 (success) even in case of failure (except for +# usage-error). This is because this script is executed under +# mysql-test-run[.pl] and it's better to examine particular problem in log +# file, than just having said that the test case has failed. + +########################################################################### + +basename=`basename "$0"` +dirname=`dirname "$0"` + +########################################################################### + +. "$dirname/utils.sh" ########################################################################### check_restart() { if [ ! -r "$pid_path" ]; then + log_debug "No '$pid_path' found." user_msg='the process was killed' return 1 fi new_pid=`cat "$pid_path" 2>/dev/null` + err_code=$? - if [ $? -eq 0 -a "$original_pid" = "$new_pid" ]; then + log_debug "err_code: $err_code; original_pid: $original_pid; new_pid: $new_pid." + + if [ $err_code -eq 0 -a "$original_pid" = "$new_pid" ]; then + log_debug "The process was not restarted." user_msg='the process was not restarted' return 1 fi + log_debug "The process was restarted." user_msg='the process was restarted' return 0 } ########################################################################### -if [ $# -ne 3 ]; then - echo "Usage: kill_n_check.sh killed|restarted " - exit 0 +if [ $# -ne 4 ]; then + echo "Usage: $basename killed|restarted " + exit 1 fi pid_path="$1" expected_result="$2" total_timeout="$3" +test_id="$4" +log_file="$MYSQLTEST_VARDIR/log/$test_id.log" + +log_debug "-- $basename: starting --" +log_debug "pid_path: '$pid_path'" +log_debug "expected_result: '$expected_result'" +log_debug "total_timeout: '$total_timeout'" +log_debug "test_id: '$test_id'" +log_debug "log_file: '$log_file'" + +########################################################################### if [ "$expected_result" != 'killed' -a \ "$expected_result" != 'restarted' ]; then - echo "Error: invalid second argument ('killed' or 'restarted' expected)." - exit 0 + log_error "Invalid second argument ($expected_result): 'killed' or 'restarted' expected." + quit 0 fi if [ -z "$pid_path" ]; then - echo "Error: invalid PID path ($pid_path)." - exit 0 + log_error "Invalid PID path ($pid_path)." + quit 0 fi if [ ! -r "$pid_path" ]; then - echo "Error: PID file ($pid_path) does not exist." - exit 0 + log_error "PID file ($pid_path) does not exist." + quit 0 fi if [ -z "$total_timeout" ]; then - echo "Error: timeout is not specified." - exit 0 + log_error "Timeout is not specified." + quit 0 fi ########################################################################### original_pid=`cat "$pid_path"` +log_debug "original_pid: $original_pid." -echo "Killing the process..." +log_info "Killing the process..." kill -9 $original_pid ########################################################################### -echo "Sleeping..." +log_info "Waiting..." if [ "$expected_result" = "restarted" ]; then @@ -79,37 +106,42 @@ if [ "$expected_result" = "restarted" ]; then while true; do + log_debug "cur_attempt: $cur_attempt." + if check_restart; then - echo "Success: $user_msg." - exit 0 + log_info "Success: $user_msg." + quit 0 fi [ $cur_attempt -ge $total_timeout ] && break + log_debug "Sleeping for 1 second..." sleep 1 cur_attempt=`expr $cur_attempt + 1` done - echo "Error: $user_msg." - exit 0 + log_error "$user_msg." + quit 0 else # $expected_result == killed # Here we have to sleep for some long time to ensure that the process will # not be restarted. + log_debug "Sleeping for $total_timeout seconds..." sleep $total_timeout new_pid=`cat "$pid_path" 2>/dev/null` + log_debug "new_pid: $new_pid." if [ "$new_pid" -a "$new_pid" -ne "$original_pid" ]; then - echo "Error: the process was restarted." + log_error "The process was restarted." else - echo "Success: the process was killed." + log_info "Success: the process was killed." fi - exit 0 + quit 0 fi diff --git a/mysql-test/t/log.sh b/mysql-test/t/log.sh new file mode 100755 index 00000000000..20b265087cc --- /dev/null +++ b/mysql-test/t/log.sh @@ -0,0 +1,24 @@ +#!/bin/bash + +########################################################################### + +basename=`basename "$0"` +dirname=`dirname "$0"` + +########################################################################### + +. "$dirname/utils.sh" + +########################################################################### + +if [ $# -lt 2 ]; then + echo "Usage: $basename log message ..." + exit 1 +fi + +test_id="$1" +log_file="$MYSQLTEST_VARDIR/log/$test_id.log" + +shift + +log_debug "$*" diff --git a/mysql-test/t/utils.sh b/mysql-test/t/utils.sh new file mode 100644 index 00000000000..b3f4744947d --- /dev/null +++ b/mysql-test/t/utils.sh @@ -0,0 +1,55 @@ +########################################################################### +# +# This file provides utility functions and is included by other scripts. +# +# The following global variables must be set before calling functions from this +# file: +# - basename -- base name of the calling script (main application); +# - log_file -- where to store log records; +# +########################################################################### + +log() +{ + [ -z "$log_file" ] && return; + + log_level="$1" + log_msg="$2" + ts=`date` + + echo "[$ts] [$basename] [$log_level] $log_msg" >> "$log_file"; +} + +########################################################################### + +log_debug() +{ + log 'DEBUG' "$1" +} + +########################################################################### + +log_info() +{ + log 'INFO' "$1" + echo "$1" +} + +########################################################################### + +log_error() +{ + log 'ERROR' "$1" + echo "Error: $1" +} + +########################################################################### + +quit() +{ + exit_status="$1" + + log_debug "-- $basename: finished (exit_status: $exit_status) --" + + exit $exit_status +} diff --git a/mysql-test/t/wait_for_process.sh b/mysql-test/t/wait_for_process.sh index df0f4a17e3a..4c2d89cfea6 100755 --- a/mysql-test/t/wait_for_process.sh +++ b/mysql-test/t/wait_for_process.sh @@ -2,11 +2,79 @@ ########################################################################### +# NOTE: this script returns 0 (success) even in case of failure (except for +# usage-error). This is because this script is executed under +# mysql-test-run[.pl] and it's better to examine particular problem in log +# file, than just having said that the test case has failed. + +########################################################################### + +basename=`basename "$0"` +dirname=`dirname "$0"` + +########################################################################### + +. "$dirname/utils.sh" + +########################################################################### + +check_started() +{ + if [ ! -r "$pid_path" ]; then + log_debug "No PID-file ($pid_path) found -- not started." + return 1 + fi + + new_pid=`cat "$pid_path" 2>/dev/null` + err_code=$? + + log_debug "err_code: $err_code; new_pid: $new_pid." + + if [ $? -ne 0 -o -z "$new_pid" ]; then + log_debug "The process was not started." + return 1 + fi + + log_debug "The process was started." + return 0 +} + +########################################################################### + +check_stopped() +{ + if [ -r "$pid_path" ]; then + log_debug "PID-file '$pid_path' exists -- not stopped." + return 1 + fi + + log_debug "No PID-file ($pid_path) found -- stopped." + return 0 +} + +########################################################################### + +if [ $# -ne 4 ]; then + echo "Usage: $basename started|stopped " + exit 1 +fi + pid_path="$1" total_attempts="$2" event="$3" +test_id="$4" +log_file="$MYSQLTEST_VARDIR/log/$test_id.log" -case "$3" in +log_debug "-- $basename: starting --" +log_debug "pid_path: '$pid_path'" +log_debug "total_attempts: '$total_attempts'" +log_debug "event: '$event'" +log_debug "test_id: '$test_id'" +log_debug "log_file: '$log_file'" + +########################################################################### + +case "$event" in started) check_fn='check_started'; ;; @@ -16,51 +84,31 @@ case "$3" in ;; *) - echo "Error: invalid third argument ('started' or 'stopped' expected)." - exit 0 + log_error "Invalid third argument ('started' or 'stopped' expected)." + quit 0 esac ########################################################################### -check_started() -{ - [ ! -r "$pid_path" ] && return 1 - - new_pid=`cat "$pid_path" 2>/dev/null` - - [ $? -eq 0 -a "$original_pid" = "$new_pid" ] && return 1 - - return 0 -} - -########################################################################### - -check_stopped() -{ - [ -r "$pid_path" ] && return 1 - - return 0 -} - -########################################################################### - cur_attempt=1 while true; do + log_debug "cur_attempt: $cur_attempt." + if ( eval $check_fn ); then - echo "Success: the process has been $event." - exit 0 + log_info "Success: the process has been $event." + quit 0 fi [ $cur_attempt -ge $total_attempts ] && break + log_debug "Sleeping for 1 second..." sleep 1 cur_attempt=`expr $cur_attempt + 1` done -echo "Error: the process has not been $event in $total_attempts secs." -exit 0 - +log_error "The process has not been $event in $total_attempts secs." +quit 0 diff --git a/mysql-test/t/wait_for_socket.sh b/mysql-test/t/wait_for_socket.sh index 3b900fa2208..1a73dff5244 100755 --- a/mysql-test/t/wait_for_socket.sh +++ b/mysql-test/t/wait_for_socket.sh @@ -2,9 +2,25 @@ ########################################################################### -if [ $# -ne 6 ]; then - echo "Usage: wait_for_socket.sh " - exit 0 +# NOTE: this script returns 0 (success) even in case of failure (except for +# usage-error). This is because this script is executed under +# mysql-test-run[.pl] and it's better to examine particular problem in log +# file, than just having said that the test case has failed. + +########################################################################### + +basename=`basename "$0"` +dirname=`dirname "$0"` + +########################################################################### + +. "$dirname/utils.sh" + +########################################################################### + +if [ $# -ne 7 ]; then + echo "Usage: wait_for_socket.sh " + exit 1 fi client_exe="$1" @@ -13,41 +29,57 @@ username="$3" password="$4" db="$5" total_timeout="$6" +test_id="$7" +log_file="$MYSQLTEST_VARDIR/log/$test_id.log" + +log_debug "-- $basename: starting --" +log_debug "client_exe: '$client_exe'" +log_debug "socket_path: '$socket_path'" +log_debug "username: '$username'" +log_debug "password: '$password'" +log_debug "db: '$db'" +log_debug "total_timeout: '$total_timeout'" +log_debug "test_id: '$test_id'" +log_debug "log_file: '$log_file'" ########################################################################### if [ -z "$client_exe" ]; then - echo "Error: invalid path to client executable ($client_exe)." - exit 0; + log_error "Invalid path to client executable ($client_exe)." + quit 0; fi if [ ! -x "$client_exe" ]; then - echo "Error: client by path '$client_exe' is not available." - exit 0; + log_error "Client by path '$client_exe' is not available." + quit 0; fi if [ -z "$socket_path" ]; then - echo "Error: invalid socket patch." - exit 0 + log_error "Invalid socket patch ($socket_path)." + quit 0 fi ########################################################################### -client_args="--silent --socket=$socket_path " +client_args="--silent --connect_timeout=1 --socket=$socket_path " [ -n "$username" ] && client_args="$client_args --user=$username " [ -n "$password" ] && client_args="$client_args --password=$password " [ -n "$db" ] && client_args="$client_args $db" +log_debug "client_args: '$client_args'" + ########################################################################### cur_attempt=1 while true; do + log_debug "cur_attempt: $cur_attempt." + if ( echo 'quit' | "$client_exe" $client_args >/dev/null 2>&1 ); then - echo "Success: server is ready to accept connection on socket." - exit 0 + log_info "Success: server is ready to accept connection on socket." + quit 0 fi [ $cur_attempt -ge $total_timeout ] && break @@ -58,5 +90,5 @@ while true; do done -echo "Error: server does not accept connections after $total_timeout seconds." -exit 0 +log_error "Server does not accept connections after $total_timeout seconds." +quit 0