Merge bk-internal:/home/bk/mysql-5.1-maint

into  pilot.(none):/data/msvensson/mysql/mysql-5.1-new-maint


client/mysql_upgrade.c:
  Auto merged
client/mysqltest.c:
  Auto merged
mysql-test/lib/mtr_report.pl:
  Auto merged
mysql-test/mysql-test-run.pl:
  Auto merged
mysql-test/r/show_check.result:
  Auto merged
mysql-test/t/show_check.test:
  Auto merged

3 files changed, 82 insertions, 77 deletions

diff --git a/mysql-test/lib/mtr_process.pl b/mysql-test/lib/mtr_process.pl
index 69026d2c72f..8fd900330da 100644
--- a/mysql-test/lib/mtr_process.pl
+++ b/mysql-test/lib/mtr_process.pl
@@ -99,25 +99,26 @@ sub spawn_impl ($$$$$$$) {
 
   if ( $::opt_script_debug )
   {
-    print STDERR "\n";
-    print STDERR "#### ", "-" x 78, "\n";
-    print STDERR "#### ", "STDIN  $input\n" if $input;
-    print STDERR "#### ", "STDOUT $output\n" if $output;
-    print STDERR "#### ", "STDERR $error\n" if $error;
-    print STDERR "#### ", "$mode : $path ", join(" ",@$arg_list_t), "\n";
-    print STDERR "#### ", "spawn options:\n";
+    mtr_report("");
+    mtr_debug("-" x 73);
+    mtr_debug("STDIN  $input") if $input;
+    mtr_debug("STDOUT $output") if $output;
+    mtr_debug("STDERR $error") if $error;
+    mtr_debug("$mode: $path ", join(" ",@$arg_list_t));
+    mtr_debug("spawn options:");
     if ($spawn_opts)
     {
       foreach my $key (sort keys %{$spawn_opts})
       {
-        print STDERR "#### ", "  - $key: $spawn_opts->{$key}\n";
+        mtr_debug("  - $key: $spawn_opts->{$key}");
       }
     }
     else
     {
-      print STDERR "#### ", "  none\n";
+      mtr_debug("  none");
     }
-    print STDERR "#### ", "-" x 78, "\n";
+    mtr_debug("-" x 73);
+    mtr_report("");
   }
 
   mtr_error("Can't spawn with empty \"path\"") unless defined $path;
diff --git a/mysql-test/lib/mtr_report.pl b/mysql-test/lib/mtr_report.pl
index 1edace54d30..dcd7d1ec842 100644
--- a/mysql-test/lib/mtr_report.pl
+++ b/mysql-test/lib/mtr_report.pl
@@ -19,6 +19,7 @@
 # same name.
 
 use strict;
+use warnings;
 
 sub mtr_report_test_name($);
 sub mtr_report_test_passed($);
@@ -26,7 +27,6 @@ sub mtr_report_test_failed($);
 sub mtr_report_test_skipped($);
 sub mtr_report_test_not_skipped_though_disabled($);
 
-sub mtr_show_failed_diff ($);
 sub mtr_report_stats ($);
 sub mtr_print_line ();
 sub mtr_print_thick_line ();
@@ -38,6 +38,9 @@ sub mtr_child_error (@);
 sub mtr_debug (@);
 sub mtr_verbose (@);
 
+my $tot_real_time= 0;
+
+
 
 ##############################################################################
 #
@@ -45,43 +48,10 @@ sub mtr_verbose (@);
 #
 ##############################################################################
 
-# We can't use diff -u or diff -a as these are not portable
-
-sub mtr_show_failed_diff ($) {
-  my $tinfo=  shift;
-
-  # The reject and log files have been dumped to
-  # to filenames based on the result_file's name
-  my $base_file= mtr_match_extension($tinfo->{'result_file'},
-				    "result"); # Trim extension
-  my $reject_file=  "$base_file.reject";
-  my $result_file=  "$base_file.result";
-  my $log_file=     "$base_file.log";
-
-  my $diffopts= $::opt_udiff ? "-u" : "-c";
-
-  if ( -f $reject_file )
-  {
-    print "Below are the diffs between actual and expected results:\n";
-    print "-------------------------------------------------------\n";
-    # FIXME check result code?!
-    mtr_run("diff",[$diffopts,$result_file,$reject_file], "", "", "", "");
-    print "-------------------------------------------------------\n";
-    print "Please follow the instructions outlined at\n";
-    print "http://www.mysql.com/doc/en/Reporting_mysqltest_bugs.html\n";
-    print "to find the reason to this problem and how to report this.\n\n";
-  }
-
-  if ( -f $log_file )
-  {
-    print "Result from queries before failure can be found in $log_file\n";
-    # FIXME Maybe a tail -f -n 10 $log_file here
-  }
-}
-
 sub mtr_report_test_name ($) {
   my $tinfo= shift;
 
+  _mtr_log("$tinfo->{name}");
   printf "%-30s ", $tinfo->{'name'};
 }
 
@@ -91,15 +61,15 @@ sub mtr_report_test_skipped ($) {
   $tinfo->{'result'}= 'MTR_RES_SKIPPED';
   if ( $tinfo->{'disable'} )
   {
-    print "[ disabled ]  $tinfo->{'comment'}\n";
+    mtr_report("[ disabled ]  $tinfo->{'comment'}");
   }
   elsif ( $tinfo->{'comment'} )
   {
-    print "[ skipped ]   $tinfo->{'comment'}\n";
+    mtr_report("[ skipped ]   $tinfo->{'comment'}");
   }
   else
   {
-    print "[ skipped ]\n";
+    mtr_report("[ skipped ]");
   }
 }
 
@@ -127,11 +97,11 @@ sub mtr_report_test_passed ($) {
   if ( $::opt_timer and -f "$::opt_vardir/log/timer" )
   {
     $timer= mtr_fromfile("$::opt_vardir/log/timer");
-    $::glob_tot_real_time += ($timer/1000);
+    $tot_real_time += ($timer/1000);
     $timer= sprintf "%12s", $timer;
   }
   $tinfo->{'result'}= 'MTR_RES_PASSED';
-  print "[ pass ]   $timer\n";
+  mtr_report("[ pass ]   $timer");
 }
 
 sub mtr_report_test_failed ($) {
@@ -140,27 +110,34 @@ sub mtr_report_test_failed ($) {
   $tinfo->{'result'}= 'MTR_RES_FAILED';
   if ( defined $tinfo->{'timeout'} )
   {
-    print "[ fail ]  timeout\n";
+    mtr_report("[ fail ]  timeout");
     return;
   }
   else
   {
-    print "[ fail ]\n";
+    mtr_report("[ fail ]");
   }
 
   if ( $tinfo->{'comment'} )
   {
-    print "\nERROR: $tinfo->{'comment'}\n";
+    # The test failure has been detected by mysql-test-run.pl
+    # when starting the servers or due to other error, the reason for
+    # failing the test is saved in "comment"
+    mtr_report("\nERROR: $tinfo->{'comment'}");
   }
   elsif ( -f $::path_timefile )
   {
-    print "\nErrors are (from $::path_timefile) :\n";
+    # Test failure was detected by test tool and it's report
+    # about what failed has been saved to file. Display the report.
+    print "\n";
     print mtr_fromfile($::path_timefile); # FIXME print_file() instead
-    print "\n(the last lines may be the most important ones)\n";
+    print "\n";
   }
   else
   {
-    print "\nUnexpected termination, probably when starting mysqld\n";
+    # Neither this script or the test tool has recorded info
+    # about why the test has failed. Should be debugged.
+    mtr_report("\nUnexpected termination, probably when starting mysqld");;
   }
 }
 
@@ -228,8 +205,10 @@ sub mtr_report_stats ($) {
 
   if ( $::opt_timer )
   {
-    print
-      "Spent $::glob_tot_real_time seconds actually executing testcases\n"
+    use English;
+
+    mtr_report("Spent", sprintf("%.3f", $tot_real_time),"of",
+	       time - $BASETIME, "seconds executing testcases");
   }
 
   # ----------------------------------------------------------------------
@@ -484,35 +463,66 @@ sub mtr_print_header () {
 
 ##############################################################################
 #
-#  Misc
+#  Log and reporting functions
 #
 ##############################################################################
 
+use IO::File;
+
+my $log_file_ref= undef;
+
+sub mtr_log_init ($) {
+  my ($filename)= @_;
+
+  mtr_error("Log is already open") if defined $log_file_ref;
+
+  $log_file_ref= IO::File->new($filename, "a") or
+    mtr_warning("Could not create logfile $filename: $!");
+}
+
+sub _mtr_log (@) {
+  print $log_file_ref join(" ", @_),"\n"
+    if defined $log_file_ref;
+}
+
 sub mtr_report (@) {
+  # Print message to screen and log
+  _mtr_log(@_);
   print join(" ", @_),"\n";
 }
 
 sub mtr_warning (@) {
+  # Print message to screen and log
+  _mtr_log("WARNING: ", @_);
   print STDERR "mysql-test-run: WARNING: ",join(" ", @_),"\n";
 }
 
 sub mtr_error (@) {
+  # Print message to screen and log
+  _mtr_log("ERROR: ", @_);
   print STDERR "mysql-test-run: *** ERROR: ",join(" ", @_),"\n";
   mtr_exit(1);
 }
 
 sub mtr_child_error (@) {
+  # Print message to screen and log
+  _mtr_log("ERROR(child): ", @_);
   print STDERR "mysql-test-run: *** ERROR(child): ",join(" ", @_),"\n";
   exit(1);
 }
 
 sub mtr_debug (@) {
+  # Only print if --script-debug is used
   if ( $::opt_script_debug )
   {
+    _mtr_log("###: ", @_);
     print STDERR "####: ",join(" ", @_),"\n";
   }
 }
+
 sub mtr_verbose (@) {
+  # Always print to log, print to screen only when --verbose is used
+  _mtr_log("> ",@_);
   if ( $::opt_verbose )
   {
     print STDERR "> ",join(" ", @_),"\n";
diff --git a/mysql-test/lib/mtr_timer.pl b/mysql-test/lib/mtr_timer.pl
index 86a9f58514f..d8b6953fb46 100644
--- a/mysql-test/lib/mtr_timer.pl
+++ b/mysql-test/lib/mtr_timer.pl
@@ -52,12 +52,10 @@ sub mtr_init_timers () {
 sub mtr_timer_start($$$) {
   my ($timers,$name,$duration)= @_;
 
-  mtr_verbose("mtr_timer_start: $name, $duration");
-
   if ( exists $timers->{'timers'}->{$name} )
   {
     # We have an old running timer, kill it
-    mtr_verbose("There is an old timer running");
+    mtr_warning("There is an old timer running");
     mtr_timer_stop($timers,$name);
   }
 
@@ -75,22 +73,22 @@ sub mtr_timer_start($$$) {
       }
       else
       {
-        mtr_error("can't fork");
+        mtr_error("can't fork timer, error: $!");
       }
     }
 
     if ( $tpid )
     {
       # Parent, record the information
-      mtr_verbose("timer parent, record info($name, $tpid, $duration)");
+      mtr_verbose("Starting timer for '$name',",
+		  "duration: $duration, pid: $tpid");
       $timers->{'timers'}->{$name}->{'pid'}= $tpid;
       $timers->{'timers'}->{$name}->{'duration'}= $duration;
       $timers->{'pids'}->{$tpid}= $name;
     }
     else
     {
-      # Child, redirect output and exec
-      # FIXME do we need to redirect streams?
+      # Child, install signal handlers and sleep for "duration"
 
       # Don't do the ^C cleanup in the timeout child processes!
       # There is actually a race here, if we get ^C after fork(), but before
@@ -98,13 +96,13 @@ sub mtr_timer_start($$$) {
       $SIG{INT}= 'DEFAULT';
 
       $SIG{TERM}= sub {
-	mtr_verbose("timer woke up, exiting!");
+	mtr_verbose("timer $$ woke up, exiting!");
 	exit(0);
       };
 
       $0= "mtr_timer(timers,$name,$duration)";
       sleep($duration);
-      mtr_verbose("timer expired after $duration seconds");
+      mtr_verbose("timer $$ expired after $duration seconds");
       exit(0);
     }
   }
@@ -114,12 +112,10 @@ sub mtr_timer_start($$$) {
 sub mtr_timer_stop ($$) {
   my ($timers,$name)= @_;
 
-  mtr_verbose("mtr_timer_stop: $name");
-
   if ( exists $timers->{'timers'}->{$name} )
   {
     my $tpid= $timers->{'timers'}->{$name}->{'pid'};
-    mtr_verbose("Stopping timer with pid $tpid");
+    mtr_verbose("Stopping timer for '$name' with pid $tpid");
 
     # FIXME as Cygwin reuses pids fast, maybe check that is
     # the expected process somehow?!
@@ -134,11 +130,8 @@ sub mtr_timer_stop ($$) {
 
     return 1;
   }
-  else
-  {
-    mtr_error("Asked to stop timer \"$name\" not started");
-    return 0;
-  }
+
+  mtr_error("Asked to stop timer '$name' not started");
 }
 
 
@@ -158,7 +151,8 @@ sub mtr_timer_timeout ($$) {
 
   return "" unless exists $timers->{'pids'}->{$pid};
 
-  # We got a timeout, return the name ot the timer
+  # Got a timeout(the process with $pid is recorded as being a timer)
+  # return the name of the timer
   return $timers->{'pids'}->{$pid};
 }