mirror of
https://github.com/MariaDB/server.git
synced 2026-10-23 18:49:29 +03:00
MDEV-41550 MTR doesn't produce core dump or stack trace when a server hangs during startup
Problem: ======== If a server hangs in startup, mtr either waits for its pid file for --start-timeout seconds and gives up with "Failed to start" (or) when the test restarts the server, leaves the waiting to mysqltest, which ends after about 500 seconds with "Server failed to restart". In both cases the hung server is killed with SIGKILL, so no core dump and no stack trace is produced, and it is impossible to find out where the server got stuck. Solution: ========= dump_core_for_hung_server(): Sends SIGABRT to a server that is still alive and waits for it to finish dumping core. The server's fatal signal handler writes the stack trace to the error log. sleep_until_file_created(): call it when the wait for the pid file times out and the process is still alive. This covers the servers that mtr starts and waits for itself. check_expected_crash_and_restart(): when mtr restarts a server on behalf of the test, remember the time by which the server must have created its pid file ($opt_start_timeout) run_testcase() wakes up at that time, and if the server is still alive without a pid file, it dumps core, fails the test with "Failed to restart mysqldN, no pid file after N seconds" and kills mysqltest, instead of waiting for it to give up. mysql_server_wait(): append the server log of the failed server to the failure report, as the other failure paths do. Behavior change: ================ A restart done by the test now has to finish within --start-timeout (180 seconds by default, MTR_START_TIMEOUT), the same as an initial start. Before, only the test's own wait applied, about 500 seconds with restart_mysqld.inc. A slow but healthy restart that needs more than --start-timeout now fails with a core dump. Raise MTR_START_TIMEOUT for such tests. Under a debugger the timeouts are much longer, so nothing changes there. Servers that are only slow, or that mtr has not waited for yet are not aborted before the timeout.
This commit is contained in:
@@ -147,8 +147,23 @@ sub sleep_until_file_created ($$$$$) {
|
||||
|
||||
mtr_warning("Timeout after mysql-test-run waited $timeout seconds " .
|
||||
"for the process $proc to create a pid file.");
|
||||
|
||||
dump_core_for_hung_server($proc);
|
||||
return 0;
|
||||
}
|
||||
|
||||
|
||||
# A server that is alive, but did not finish starting up, is hung.
|
||||
# Make it dump core and write a stack trace to its error log,
|
||||
# to see where it got stuck, instead of just killing it.
|
||||
sub dump_core_for_hung_server {
|
||||
my ($proc)= @_;
|
||||
|
||||
return unless defined $proc and $proc->wait_one(0, 1);
|
||||
mtr_print("Dumping core for $proc, it hung in startup");
|
||||
$proc->dump_core();
|
||||
$proc->wait_one($::opt_dump_core_timeout, 1);
|
||||
}
|
||||
|
||||
|
||||
1;
|
||||
|
||||
@@ -309,6 +309,7 @@ our $opt_testcase_timeout= $ENV{MTR_TESTCASE_TIMEOUT} || 15; # minutes
|
||||
our $opt_suite_timeout = $ENV{MTR_SUITE_TIMEOUT} || 360; # minutes
|
||||
our $opt_shutdown_timeout= $ENV{MTR_SHUTDOWN_TIMEOUT} || 10; # seconds
|
||||
our $opt_start_timeout = $ENV{MTR_START_TIMEOUT} || 180; # seconds
|
||||
our $opt_dump_core_timeout= $ENV{MTR_DUMP_CORE_TIMEOUT} || 120; # seconds
|
||||
|
||||
sub suite_timeout { return $opt_suite_timeout * 60; };
|
||||
|
||||
@@ -2883,7 +2884,8 @@ sub mysql_server_wait {
|
||||
$opt_start_timeout, $mysqld->{'proc'},
|
||||
$warn_seconds))
|
||||
{
|
||||
$tinfo->{comment}= "Failed to start ".$mysqld->name() . "\n";
|
||||
$tinfo->{comment}= "Failed to start ".$mysqld->name() . "\n" .
|
||||
get_log_from_proc($mysqld->{'proc'}, $tinfo->{name});
|
||||
return 1;
|
||||
}
|
||||
|
||||
@@ -4090,7 +4092,13 @@ sub run_testcase ($$) {
|
||||
}
|
||||
if (!%keep_waiting_proc && !$proc)
|
||||
{
|
||||
if ($test_timeout > $print_timeout)
|
||||
# Wake up when a server restarted by the test is overdue
|
||||
my $wait_timeout= $test_timeout;
|
||||
my $restart_deadline= hung_restarted_servers(1);
|
||||
$wait_timeout= $restart_deadline
|
||||
if $restart_deadline && $restart_deadline < $wait_timeout;
|
||||
|
||||
if ($wait_timeout > $print_timeout)
|
||||
{
|
||||
$proc= My::SafeProcess->wait_any_timeout($print_timeout);
|
||||
if ($proc->{timeout})
|
||||
@@ -4104,10 +4112,29 @@ sub run_testcase ($$) {
|
||||
}
|
||||
else
|
||||
{
|
||||
$proc= My::SafeProcess->wait_any_timeout($test_timeout);
|
||||
$proc= My::SafeProcess->wait_any_timeout($wait_timeout);
|
||||
}
|
||||
}
|
||||
|
||||
if ($proc and $proc->{timeout} and !has_expired($test_timeout))
|
||||
{
|
||||
# Not the test case timeout, a restarted server may be hung
|
||||
my @hung= hung_restarted_servers();
|
||||
next unless @hung;
|
||||
|
||||
$tinfo->{comment}= "";
|
||||
foreach my $mysqld (@hung)
|
||||
{
|
||||
dump_core_for_hung_server($mysqld->{proc});
|
||||
$tinfo->{comment}.= "Failed to restart " . $mysqld->name() .
|
||||
", no pid file after $opt_start_timeout seconds\n" .
|
||||
get_log_from_proc($mysqld->{proc}, $tinfo->{name});
|
||||
}
|
||||
$test->kill();
|
||||
report_failure_and_restart($tinfo);
|
||||
return 1;
|
||||
}
|
||||
|
||||
if ($proc and $proc eq $test) # mysqltest itself exited
|
||||
{
|
||||
my $res= $test->exit_status();
|
||||
@@ -4281,7 +4308,7 @@ sub run_testcase ($$) {
|
||||
mtr_print("Trying to dump core for $proc");
|
||||
if ($proc->dump_core())
|
||||
{
|
||||
$proc->wait_one(20);
|
||||
$proc->wait_one($opt_dump_core_timeout);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -4811,6 +4838,33 @@ sub check_warnings_post_shutdown {
|
||||
}
|
||||
}
|
||||
|
||||
# Servers that were restarted by the test, and did not create
|
||||
# their pid file in $opt_start_timeout seconds.
|
||||
# If $first is set, return the earliest deadline of the servers
|
||||
# that are still starting up instead (0 if there is none).
|
||||
sub hung_restarted_servers {
|
||||
my ($first)= @_;
|
||||
my @hung;
|
||||
my $deadline= 0;
|
||||
foreach my $mysqld (mysqlds())
|
||||
{
|
||||
my $d= $mysqld->{'start_deadline'} or next;
|
||||
my $proc= $mysqld->{proc};
|
||||
my $pid_file= $mysqld->if_exist('pid-file');
|
||||
if (!defined $proc || !$proc->wait_one(0, 1) ||
|
||||
(defined $pid_file && -e $pid_file))
|
||||
{
|
||||
# It is up, or it is gone
|
||||
delete $mysqld->{'start_deadline'};
|
||||
next;
|
||||
}
|
||||
push @hung, $mysqld if has_expired($d);
|
||||
$deadline= $d if !$deadline || $d < $deadline;
|
||||
}
|
||||
return $first ? $deadline : @hung;
|
||||
}
|
||||
|
||||
|
||||
#
|
||||
# Check for the file indicating expected crash and restart it.
|
||||
#
|
||||
@@ -4861,7 +4915,11 @@ sub check_expected_crash_and_restart {
|
||||
unlink($expect_file);
|
||||
|
||||
# Start server with same settings as last time
|
||||
return mysqld_start($mysqld, $mysqld->{'started_opts'});
|
||||
my $rc= mysqld_start($mysqld, $mysqld->{'started_opts'});
|
||||
# mtr does not wait for the pid file here, mysqltest does.
|
||||
# Remember when the server must be up, see hung_restarted_servers()
|
||||
$mysqld->{'start_deadline'}= start_timer($opt_start_timeout) if $rc;
|
||||
return $rc;
|
||||
}
|
||||
# Loop ran through: we should keep waiting after a re-check
|
||||
return 2;
|
||||
|
||||
Reference in New Issue
Block a user