bk commit into 5.0 tree (msvensson:1.2482)

[msvensson]

Below is the list of changes that have just been committed into a local
5.0 repository of msvensson. When msvensson does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet@stripped, 2007-08-03 12:36:32+02:00, msvensson@shellback.(none) +3 -0
  Send output to var/log/mysql-test-run.log to facilitate easier debugging
  of mysql-test-run.pl

  mysql-test/lib/mtr_process.pl@stripped, 2007-08-03 12:36:27+02:00, msvensson@shellback.(none) +11 -10
    Change from "print" to "mtr_debug" to get messages logged to file as well 

  mysql-test/lib/mtr_report.pl@stripped, 2007-08-03 12:36:27+02:00, msvensson@shellback.(none) +44 -11
    - Add "mtr_log_init" function used for opening the log file
    - Change from "print" to "mtr_report" to get the messages logged
    - Make printout functions log to the log file

  mysql-test/mysql-test-run.pl@stripped, 2007-08-03 12:36:27+02:00, msvensson@shellback.(none) +8 -5
    - Open the mysql-test-run log file as soon as var/log has been created
    - Change from "print" to "mtr_report" to get the messgages to log as well

diff -Nrup a/mysql-test/lib/mtr_process.pl b/mysql-test/lib/mtr_process.pl
--- a/mysql-test/lib/mtr_process.pl	2007-06-27 09:21:03 +02:00
+++ b/mysql-test/lib/mtr_process.pl	2007-08-03 12:36:27 +02:00
@@ -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 -Nrup a/mysql-test/lib/mtr_report.pl b/mysql-test/lib/mtr_report.pl
--- a/mysql-test/lib/mtr_report.pl	2007-06-21 16:37:12 +02:00
+++ b/mysql-test/lib/mtr_report.pl	2007-08-03 12:36:27 +02:00
@@ -19,6 +19,7 @@
 # same name.
 
 use strict;
+use warnings;
 
 sub mtr_report_test_name($);
 sub mtr_report_test_passed($);
@@ -97,6 +98,7 @@ sub mtr_show_failed_diff ($) {
 sub mtr_report_test_name ($) {
   my $tinfo= shift;
 
+  _mtr_log("$tinfo->{name}");
   printf "%-30s ", $tinfo->{'name'};
 }
 
@@ -106,15 +108,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 ]");
   }
 }
 
@@ -146,7 +148,7 @@ sub mtr_report_test_passed ($) {
     $timer= sprintf "%12s", $timer;
   }
   $tinfo->{'result'}= 'MTR_RES_PASSED';
-  print "[ pass ]   $timer\n";
+  mtr_report("[ pass ]   $timer");
 }
 
 sub mtr_report_test_failed ($) {
@@ -155,17 +157,17 @@ 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";
+    mtr_report("\nERROR: $tinfo->{'comment'}");
   }
   elsif ( -f $::path_timefile )
   {
@@ -175,7 +177,7 @@ sub mtr_report_test_failed ($) {
   }
   else
   {
-    print "\nUnexpected termination, probably when starting mysqld\n";
+    mtr_report("\nUnexpected termination, probably when starting mysqld");;
   }
 }
 
@@ -243,8 +245,8 @@ sub mtr_report_stats ($) {
 
   if ( $::opt_timer )
   {
-    print
-      "Spent $::glob_tot_real_time seconds actually executing testcases\n"
+    printf("Spent %.3f seconds actually executing testcases\n",
+	   $::glob_tot_real_time);
   }
 
   # ----------------------------------------------------------------------
@@ -397,35 +399,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 -Nrup a/mysql-test/mysql-test-run.pl b/mysql-test/mysql-test-run.pl
--- a/mysql-test/mysql-test-run.pl	2007-06-26 12:26:20 +02:00
+++ b/mysql-test/mysql-test-run.pl	2007-08-03 12:36:27 +02:00
@@ -2891,6 +2891,9 @@ sub initialize_servers () {
     }
   }
   check_running_as_root();
+
+  mtr_log_init("$opt_vardir/log/mysql-test-run.log");
+
 }
 
 sub mysql_install_db () {
@@ -3612,13 +3615,13 @@ sub report_failure_and_restart ($) {
 
     # Restore the snapshot of the installed test db
     restore_installed_db($tinfo->{'name'});
-    print "Resuming Tests\n\n";
+    mtr_report("Resuming Tests\n");
     return;
   }
 
   my $test_mode= join(" ", @::glob_test_mode) || "default";
-  print "Aborting: $tinfo->{'name'} failed in $test_mode mode. ";
-  print "To continue, re-run with '--force'.\n";
+  mtr_report("Aborting: $tinfo->{'name'} failed in $test_mode mode. ");
+  mtr_report("To continue, re-run with '--force'.");
   if ( ! $glob_debugger and
        ! $opt_extern and
        ! $glob_use_embedded_server )
@@ -4076,11 +4079,11 @@ sub mysqld_start ($$$) {
 
 sub stop_all_servers () {
 
-  print  "Stopping All Servers\n";
+  mtr_report("Stopping All Servers");
 
   if ( ! $opt_skip_im )
   {
-    print  "Shutting-down Instance Manager\n";
+    mtr_report("Shutting-down Instance Manager");
     unless (mtr_im_stop($instance_manager, "stop_all_servers"))
     {
       mtr_error("Failed to stop Instance Manager.")