maria-developers team mailing list archive

[knielsen@xxxxxxxxxxxxxxx]

#At lp:maria

 2679 knielsen@xxxxxxxxxxxxxxx	2009-03-12
      BUG#43418: MTR2: does not notice a memory leak occuring at shutdown of mysqld w/ --valgrind
      Partial fix.
      Do a graceful shutdown at end of testsuite instead of kill -9.
      Do a simplified parsing for log errors after final server shutdown.
modified:
  mysql-test/mysql-test-run.pl

=== modified file 'mysql-test/mysql-test-run.pl'
--- a/mysql-test/mysql-test-run.pl	2009-02-19 09:01:25 +0000
+++ b/mysql-test/mysql-test-run.pl	2009-03-12 11:39:00 +0000
@@ -357,7 +357,7 @@ sub main {
   mtr_print_thick_line();
   mtr_print_header();
 
-  my $completed= run_test_server($server, $tests, $opt_parallel);
+  my ($completed, $fail)= run_test_server($server, $tests, $opt_parallel);
 
   # Send Ctrl-C to any children still running
   kill("INT", keys(%children));
@@ -393,6 +393,10 @@ sub main {
     mtr_error("Not all tests completed");
   }
 
+  if ($fail) {
+    mtr_error("Test suite failure.");
+  }
+
   mtr_print_line();
 
   if ( $opt_gcov ) {
@@ -412,6 +416,7 @@ sub run_test_server ($$$) {
   my $num_saved_cores= 0;  # Number of core files saved in vardir/log/ so far.
   my $num_saved_datadir= 0;  # Number of datadirs saved in vardir/log/ so far.
   my $num_failed_test= 0; # Number of tests failed so far
+  my $test_failure= 0;
 
   # Scheduler variables
   my $max_ndb= $childs / 2;
@@ -445,7 +450,7 @@ sub run_test_server ($$$) {
 	  $s->remove($sock);
 	  if (--$childs == 0){
 	    $suite_timeout_proc->kill();
-	    return $completed;
+	    return ($completed, $test_failure);
 	  }
 	  next;
 	}
@@ -509,18 +514,19 @@ sub run_test_server ($$$) {
 	    }
 	    $num_saved_datadir++;
 
+            $test_failure= 1;
 	    if ( !$opt_force ) {
 	      # Test has failed, force is off
 	      $suite_timeout_proc->kill();
 	      push(@$completed, $result);
-	      return $completed;
+	      return ($completed, 1);
 	    }
 	    elsif ($opt_max_test_fail > 0 and
 		   $num_failed_test >= $opt_max_test_fail) {
 	      $suite_timeout_proc->kill();
 	      mtr_report("Too many tests($num_failed_test) failed!",
 			 "Terminating...");
-	      return undef;
+	      return (undef, 1);
 	    }
 	    $num_failed_test++;
 	  }
@@ -571,6 +577,10 @@ sub run_test_server ($$$) {
 	elsif ($line eq 'START'){
 	  ; # Send first test
 	}
+	elsif ($line eq 'WARNINGS'){
+          mtr_report("***Warnings found in log after final shutdown.");
+          $test_failure= 1;
+        }
 	else {
 	  mtr_error("Unknown response: '$line' from client");
 	}
@@ -649,7 +659,7 @@ sub run_test_server ($$$) {
     if ( ! $suite_timeout_proc->wait_one(0) )
     {
       mtr_report("Test suite timeout! Terminating...");
-      return undef;
+      return (undef, 1);
     }
   }
 }
@@ -706,10 +716,11 @@ sub run_worker ($) {
   # Ask server for first test
   print $server "START\n";
 
+  my $test= undef;
   while(my $line= <$server>){
     chomp($line);
     if ($line eq 'TESTCASE'){
-      my $test= My::Test::read_test($server);
+      $test= My::Test::read_test($server);
       #$test->print_test();
 
       # Clear comment and logfile, to avoid
@@ -725,6 +736,22 @@ sub run_worker ($) {
     }
     elsif ($line eq 'BYE'){
       mtr_report("Server said BYE");
+      # We need to gracefully shut down the servers to see any
+      # Valgrind memory leak errors etc. since last server restart.
+      if ($opt_warnings && defined($test)) {
+        # Set marker so we only consider log messages generated during shutdown
+        foreach my $mysqld ( mysqlds() ) {
+          if (defined $mysqld->value('log-error')) {
+            mark_log($mysqld->value('log-error'), "<final shutdown>");
+          }
+        }
+        stop_all_servers(1);
+        if (check_warnings($test)) {
+          # Warnings appeared in log file(s) during final server shutdown.
+          print $server "WARNINGS\n";
+          exit(1);
+        }
+      }
       exit(0);
     }
     else {
@@ -3095,8 +3122,8 @@ sub run_on_all($$)
 
 
 sub mark_log {
-  my ($log, $tinfo)= @_;
-  my $log_msg= "CURRENT_TEST: $tinfo->{name}\n";
+  my ($log, $name)= @_;
+  my $log_msg= "CURRENT_TEST: $name\n";
   mtr_tofile($log, $log_msg);
 }
 
@@ -3247,7 +3274,7 @@ sub run_testcase ($) {
     }
 
     # Write start of testcase to log
-    mark_log($path_current_testlog, $tinfo);
+    mark_log($path_current_testlog, $tinfo->{name});
 
     if (start_servers($tinfo))
     {
@@ -3526,6 +3553,7 @@ sub extract_warning_lines ($) {
      qr/Assertion .* failed/,
     );
 
+  my $match_count= 0;
   foreach my $line ( @lines )
   {
     foreach my $pat ( @patterns )
@@ -3533,12 +3561,14 @@ sub extract_warning_lines ($) {
       if ( $line =~ /$pat/ )
       {
 	print $Fwarn $line;
+        ++$match_count;
 	last;
       }
     }
   }
   $Fwarn = undef; # Close file
 
+  return $match_count;
 }
 
 
@@ -3554,8 +3584,6 @@ sub start_check_warnings ($$) {
 
   my $name= "warnings-".$mysqld->name();
 
-  extract_warning_lines($mysqld->value('log-error'));
-
   my $args;
   mtr_init_args(\$args);
 
@@ -3614,17 +3642,37 @@ sub check_warnings ($) {
   # Start the mysqltest processes in parallel to save time
   # also makes it possible to wait for any process to exit during the check
   my %started;
+  my $total_found= 0;
   foreach my $mysqld ( mysqlds() )
   {
-    if ( defined $mysqld->{'proc'} )
+    my $found= 0;
+    if (defined $mysqld->value('log-error')) {
+      $found= extract_warning_lines($mysqld->value('log-error'));
+    }
+
+    if ( defined $mysqld->{'proc'})
     {
       my $proc= start_check_warnings($tinfo, $mysqld);
       $started{$proc->pid()}= $proc;
     }
+    else
+    {
+      $total_found+= $found;
+    }
   }
 
   # Return immediately if no check proceess was started
-  return 0 unless ( keys %started );
+  unless ( keys %started ) {
+    # When we check warnings after shutdown of mysqld, we cannot use the
+    # SQL implementation of warning checking, so we just use the Perl
+    # checking instead.
+    # (eventually, it would be better to do all the parsing here in Perl).
+    if ($total_found > 0) {
+      return 1;
+    } else {
+      return 0;
+    }
+  }
 
   my $timeout_proc= My::SafeProcess->timer(check_timeout());
 
@@ -4161,12 +4209,14 @@ sub mysqld_start ($$) {
 
 
 sub stop_all_servers () {
+  my ($graceful)= @_;
 
   mtr_verbose("Stopping all servers...");
 
   # Kill all started servers
-  My::SafeProcess::shutdown(0, # shutdown timeout 0 => kill
-			    started(all_servers()));
+  my $timeout = $graceful ?
+    $opt_shutdown_timeout : 0;  # shutdown timeout 0 => kill
+  My::SafeProcess::shutdown($timeout, started(all_servers()));
 
   # Remove pidfiles
   foreach my $server ( all_servers() )
@@ -4426,7 +4476,7 @@ sub start_servers($) {
       # Already started
 
       # Write start of testcase to log file
-      mark_log($mysqld->value('log-error'), $tinfo);
+      mark_log($mysqld->value('log-error'), $tinfo->{name});
 
       next;
     }
@@ -4485,7 +4535,7 @@ sub start_servers($) {
     mkpath($tmpdir) unless -d $tmpdir;
 
     # Write start of testcase to log file
-    mark_log($mysqld->value('log-error'), $tinfo);
+    mark_log($mysqld->value('log-error'), $tinfo->{name});
 
     # Run <tname>-master.sh
     if ($mysqld->option('#!run-master-sh') and