From: Bjorn Munch
Date: October 26 2010 7:07am
Subject: bzr push into mysql-trunk-merge branch (bjorn.munch:3299 to 3300)
List-Archive: http://lists.mysql.com/commits/121891
Message-Id: <201010260707.o9Q77MCJ008304@khepri15.norway.sun.com>
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit

 3300 Bjorn Munch	2010-10-26 [merge]
      merge from trunk-mtr

    modified:
      client/mysqltest.cc
      mysql-test/extra/binlog_tests/implicit.test
      mysql-test/extra/rpl_tests/create_recursive_construct.inc
      mysql-test/extra/rpl_tests/rpl_get_master_version_and_clock.test
      mysql-test/extra/rpl_tests/rpl_loaddata.test
      mysql-test/include/check_concurrent_insert.inc
      mysql-test/include/check_no_concurrent_insert.inc
      mysql-test/include/get_relay_log_pos.inc
      mysql-test/include/kill_query.inc
      mysql-test/include/kill_query_and_diff_master_slave.inc
      mysql-test/include/setup_fake_relay_log.inc
      mysql-test/include/show_events.inc
      mysql-test/include/show_rpl_debug_info.inc
      mysql-test/include/wait_for_slave_io_error.inc
      mysql-test/include/wait_for_slave_param.inc
      mysql-test/include/wait_for_slave_sql_error.inc
      mysql-test/include/wait_for_status_var.inc
      mysql-test/lib/mtr_misc.pl
      mysql-test/lib/mtr_process.pl
      mysql-test/mysql-test-run.pl
      mysql-test/suite/binlog/t/binlog_unsafe.test
      mysql-test/suite/rpl/t/rpl_killed_ddl.test
      mysql-test/t/mysqltest.test
      mysql-test/t/server_uuid_embedded.test
      mysql-test/t/wait_timeout.test
 3299 Tor Didriksen	2010-10-26
      Fixed a failing test due to WL1054

    modified:
      mysql-test/suite/perfschema/r/pfs_upgrade_lc2.result
=== modified file 'client/mysqltest.cc'
--- a/client/mysqltest.cc	2010-10-20 21:34:37 +0000
+++ b/client/mysqltest.cc	2010-10-26 06:57:29 +0000
@@ -5887,7 +5887,7 @@ int read_line(char *buf, int size)
       /* Could be a multibyte character */
       /* This code is based on the code in "sql_load.cc" */
 #ifdef USE_MB
-      int charlen = my_mbcharlen(charset_info, c);
+      int charlen = my_mbcharlen(charset_info, (unsigned char) c);
       /* We give up if multibyte character is started but not */
       /* completed before we pass buf_end */
       if ((charlen > 1) && (p + charlen) <= buf_end)
@@ -5899,16 +5899,16 @@ int read_line(char *buf, int size)
 
 	for (i= 1; i < charlen; i++)
 	{
+	  c= my_getc(cur_file->file);
 	  if (feof(cur_file->file))
 	    goto found_eof;
-	  c= my_getc(cur_file->file);
 	  *p++ = c;
 	}
 	if (! my_ismbchar(charset_info, mb_start, p))
 	{
 	  /* It was not a multiline char, push back the characters */
 	  /* We leave first 'c', i.e. pretend it was a normal char */
-	  while (p > mb_start)
+	  while (p-1 > mb_start)
 	    my_ungetc(*--p);
 	}
       }
@@ -9974,6 +9974,7 @@ void free_pointer_array(POINTER_ARRAY *p
 void replace_dynstr_append_mem(DYNAMIC_STRING *ds,
                                const char *val, int len)
 {
+  char lower[512];
 #ifdef __WIN__
   fix_win_paths(val, len);
 #endif
@@ -9981,7 +9982,6 @@ void replace_dynstr_append_mem(DYNAMIC_S
   if (display_result_lower) 
   {
     /* Convert to lower case, and do this first */
-    char lower[512];
     char *c= lower;
     for (const char *v= val;  *v;  v++)
       *c++= my_tolower(charset_info, *v);

=== modified file 'mysql-test/extra/binlog_tests/implicit.test'
--- a/mysql-test/extra/binlog_tests/implicit.test	2009-09-23 11:20:48 +0000
+++ b/mysql-test/extra/binlog_tests/implicit.test	2010-10-21 07:37:10 +0000
@@ -6,7 +6,7 @@ INSERT INTO t1 VALUES (1);
 source include/show_binlog_events.inc;
 eval $statement;
 source include/show_binlog_events.inc;
-if (`select '$cleanup' != ''`) {
+if ($cleanup) {
   eval $cleanup;
 }
 
@@ -22,7 +22,7 @@ INSERT INTO t1 VALUES (3);
 source include/show_binlog_events.inc;
 COMMIT;
 source include/show_binlog_events.inc;
-if (`select '$cleanup' != ''`) {
+if ($cleanup) {
   eval $cleanup;
 }
 

=== modified file 'mysql-test/extra/rpl_tests/create_recursive_construct.inc'
--- a/mysql-test/extra/rpl_tests/create_recursive_construct.inc	2010-08-30 06:11:20 +0000
+++ b/mysql-test/extra/rpl_tests/create_recursive_construct.inc	2010-10-21 12:36:16 +0000
@@ -285,10 +285,10 @@ if (`SELECT $CRC_ARG_type = 7`) {
 }
 
 ######## execute! ########
-if (`SELECT '$CRC_RET_stmt_sidef' != ''`) {
+if ($CRC_RET_stmt_sidef) {
   --echo
   --echo Invoking $CRC_RET_desc.
-  if (`SELECT '$CRC_create' != ''`) {
+  if ($CRC_create) {
     --eval $CRC_create
   }
 
@@ -366,7 +366,7 @@ if (`SELECT '$CRC_RET_stmt_sidef' != ''`
 
 # Invoke created object, discarding the return value. This should not
 # give any warning.
-if (`SELECT '$CRC_RET_sel_retval' != ''`) {
+if ($CRC_RET_sel_retval) {
   --echo * Invoke statement so that return value is dicarded: expect no warning.
   --disable_result_log
   --eval $CRC_RET_sel_retval

=== modified file 'mysql-test/extra/rpl_tests/rpl_get_master_version_and_clock.test'
--- a/mysql-test/extra/rpl_tests/rpl_get_master_version_and_clock.test	2010-07-12 11:55:16 +0000
+++ b/mysql-test/extra/rpl_tests/rpl_get_master_version_and_clock.test	2010-10-21 13:25:40 +0000
@@ -34,7 +34,7 @@
 #
 
 connection slave;
-if (`SELECT $debug_sync_action = ''`)
+if (!$debug_sync_action)
 {
     --die Cannot continue. Please set value for debug_sync_action.
 }

=== modified file 'mysql-test/extra/rpl_tests/rpl_loaddata.test'
--- a/mysql-test/extra/rpl_tests/rpl_loaddata.test	2010-08-04 08:10:38 +0000
+++ b/mysql-test/extra/rpl_tests/rpl_loaddata.test	2010-10-21 13:25:40 +0000
@@ -25,7 +25,7 @@ CALL mtr.add_suppression("Unsafe stateme
 # MTR is not case-sensitive.
 let $lower_stmt_head= load data;
 let $UPPER_STMT_HEAD= LOAD DATA;
-if (`SELECT '$lock_option' <> ''`)
+if ($lock_option)
 {
   #if $lock_option is null, an extra blank is added into the statement,
   #this will change the result of rpl_loaddata test case. so $lock_option

=== modified file 'mysql-test/include/check_concurrent_insert.inc'
--- a/mysql-test/include/check_concurrent_insert.inc	2010-06-17 13:31:51 +0000
+++ b/mysql-test/include/check_concurrent_insert.inc	2010-10-21 13:24:31 +0000
@@ -23,7 +23,7 @@
 # Reset DEBUG_SYNC facility for safety.
 set debug_sync= "RESET";
 
-if (`SELECT '$restore_table' <> ''`)
+if ($restore_table)
 {
 --eval create temporary table t_backup select * from $restore_table;
 }
@@ -82,7 +82,7 @@ connection default;
 
 --eval delete from $table where i = 0;
 
-if (`SELECT '$restore_table' <> ''`)
+if ($restore_table)
 {
 --eval truncate table $restore_table;
 --eval insert into $restore_table select * from t_backup;

=== modified file 'mysql-test/include/check_no_concurrent_insert.inc'
--- a/mysql-test/include/check_no_concurrent_insert.inc	2010-08-06 11:29:37 +0000
+++ b/mysql-test/include/check_no_concurrent_insert.inc	2010-10-21 13:24:31 +0000
@@ -23,7 +23,7 @@
 # Reset DEBUG_SYNC facility for safety.
 set debug_sync= "RESET";
 
-if (`SELECT '$restore_table' <> ''`)
+if ($restore_table)
 {
 --eval create temporary table t_backup select * from $restore_table;
 }
@@ -68,7 +68,7 @@ if (!$success)
 
 --eval delete from $table where i = 0;
 
-if (`SELECT '$restore_table' <> ''`)
+if ($restore_table)
 {
 --eval truncate table $restore_table;
 --eval insert into $restore_table select * from t_backup;

=== modified file 'mysql-test/include/get_relay_log_pos.inc'
--- a/mysql-test/include/get_relay_log_pos.inc	2010-05-26 14:34:25 +0000
+++ b/mysql-test/include/get_relay_log_pos.inc	2010-10-21 07:37:10 +0000
@@ -10,12 +10,12 @@
 #   # at this point, get_relay_log_pos.inc sets $relay_log_pos. echo position
 #   # in $relay_log_file: $relay_log_pos. 
 
-if (`SELECT '$relay_log_file' = ''`)
+if (!$relay_log_file)
 {
   --die 'variable $relay_log_file is null'
 }
 
-if (`SELECT '$master_log_pos' = ''`)
+if (!$master_log_pos)
 {
   --die 'variable $master_log_pos is null'
 }

=== modified file 'mysql-test/include/kill_query.inc'
--- a/mysql-test/include/kill_query.inc	2009-12-10 03:44:19 +0000
+++ b/mysql-test/include/kill_query.inc	2010-10-21 13:24:31 +0000
@@ -44,7 +44,7 @@ connection master;
 # kill the query that is waiting
 eval kill query $connection_id;
 
-if (`SELECT '$debug_lock' != ''`)
+if ($debug_lock)
 {
   # release the lock to allow binlog continue
   eval SELECT RELEASE_LOCK($debug_lock);
@@ -57,7 +57,7 @@ reap;
 
 connection master;
 
-if (`SELECT '$debug_lock' != ''`)
+if ($debug_lock)
 {
   # get lock again to make the next query wait
   eval SELECT GET_LOCK($debug_lock, 10);

=== modified file 'mysql-test/include/kill_query_and_diff_master_slave.inc'
--- a/mysql-test/include/kill_query_and_diff_master_slave.inc	2009-03-27 05:19:50 +0000
+++ b/mysql-test/include/kill_query_and_diff_master_slave.inc	2010-10-21 13:24:31 +0000
@@ -25,7 +25,7 @@ source include/kill_query.inc;
 connection master;
 disable_query_log;
 disable_result_log;
-if (`SELECT '$debug_lock' != ''`)
+if ($debug_lock)
 {
   eval SELECT RELEASE_LOCK($debug_lock);
 }
@@ -36,8 +36,8 @@ source include/diff_master_slave.inc;
 
 # Acquire the debug lock again if used
 connection master;
-disable_query_log; disable_result_log; if (`SELECT '$debug_lock' !=
-''`) { eval SELECT GET_LOCK($debug_lock, 10); } enable_result_log;
-enable_query_log;
+disable_query_log; disable_result_log;
+if ($debug_lock) { eval SELECT GET_LOCK($debug_lock, 10); }
+enable_result_log; enable_query_log;
 
 connection $connection_name;

=== modified file 'mysql-test/include/setup_fake_relay_log.inc'
--- a/mysql-test/include/setup_fake_relay_log.inc	2010-09-20 08:24:39 +0000
+++ b/mysql-test/include/setup_fake_relay_log.inc	2010-10-21 13:25:40 +0000
@@ -56,7 +56,7 @@ if (`SELECT "$_sql_running" = "Yes" OR "
 # Read server variables.
 let $MYSQLD_DATADIR= `SELECT @@datadir`;
 let $_fake_filename= query_get_value(SHOW VARIABLES LIKE 'relay_log', Value, 1);
-if (`SELECT '$_fake_filename' = ''`) {
+if (!$_fake_filename) {
   --echo Badly written test case: relay_log variable is empty. Please use the
   --echo server option --relay-log=FILE.
 }

=== modified file 'mysql-test/include/show_events.inc'
--- a/mysql-test/include/show_events.inc	2010-05-26 14:34:25 +0000
+++ b/mysql-test/include/show_events.inc	2010-10-25 12:07:28 +0000
@@ -18,13 +18,15 @@ if ($is_relay_log)
   --let $_statement=show relaylog events
 }
 
-if (`SELECT '$binlog_file' <> ''`)
+if ($binlog_file)
 {
   --let $_statement= $_statement in '$binlog_file'
 }
 
 --let $_statement= $_statement from $binlog_start
 
+# Cannot use if($binlog_limit) since the variable may begin with a 0
+
 if (`SELECT '$binlog_limit' <> ''`)
 {
   --let $_statement= $_statement limit $binlog_limit

=== modified file 'mysql-test/include/show_rpl_debug_info.inc'
--- a/mysql-test/include/show_rpl_debug_info.inc	2010-05-24 13:54:08 +0000
+++ b/mysql-test/include/show_rpl_debug_info.inc	2010-10-21 13:24:31 +0000
@@ -48,13 +48,13 @@ let $binlog_name= query_get_value("SHOW
 eval SHOW BINLOG EVENTS IN '$binlog_name';
 
 let $_master_con= $master_connection;
-if (`SELECT '$_master_con' = ''`)
+if (!$_master_con)
 {
   if (`SELECT '$_con' = 'slave'`)
   {
     let $_master_con= master;
   }
-  if (`SELECT '$_master_con' = ''`)
+  if (!$_master_con)
   {
     --echo Unable to determine master connection. No debug info printed for master.
     --echo Please fix the test case by setting $master_connection before sourcing
@@ -62,7 +62,7 @@ if (`SELECT '$_master_con' = ''`)
   }
 }
 
-if (`SELECT '$_master_con' != ''`)
+if ($_master_con)
 {
 
   let $master_binlog_name_io= query_get_value("SHOW SLAVE STATUS", Master_Log_File, 1);

=== modified file 'mysql-test/include/wait_for_slave_io_error.inc'
--- a/mysql-test/include/wait_for_slave_io_error.inc	2010-07-12 11:55:16 +0000
+++ b/mysql-test/include/wait_for_slave_io_error.inc	2010-10-21 13:25:40 +0000
@@ -31,7 +31,7 @@
 # $master_connection
 #   See wait_for_slave_param.inc for description.
 
-if (`SELECT '$slave_io_errno' = ''`) {
+if (!$slave_io_errno) {
   --die !!!ERROR IN TEST: you must set \$slave_io_errno before sourcing wait_for_slave_io_error.inc
 }
 

=== modified file 'mysql-test/include/wait_for_slave_param.inc'
--- a/mysql-test/include/wait_for_slave_param.inc	2010-05-26 14:34:25 +0000
+++ b/mysql-test/include/wait_for_slave_param.inc	2010-10-21 13:24:31 +0000
@@ -53,7 +53,7 @@ if (!$_slave_timeout_counter)
 let $slave_tcnt= $_slave_timeout_counter;
 
 let $_slave_param_comparison= $slave_param_comparison;
-if (`SELECT '$_slave_param_comparison' = ''`)
+if (!$_slave_param_comparison)
 {
   let $_slave_param_comparison= =;
 }
@@ -73,7 +73,7 @@ while (`SELECT NOT('$_show_slave_status_
 if (!$_slave_timeout_counter)
 {
   --echo **** ERROR: timeout after $slave_tcnt deci-seconds while waiting for slave parameter $slave_param $_slave_param_comparison $slave_param_value ****
-  if (`SELECT '$slave_error_message' != ''`)
+  if ($slave_error_message)
   {
     --echo Message: $slave_error_message
   }

=== modified file 'mysql-test/include/wait_for_slave_sql_error.inc'
--- a/mysql-test/include/wait_for_slave_sql_error.inc	2010-06-18 11:10:53 +0000
+++ b/mysql-test/include/wait_for_slave_sql_error.inc	2010-10-21 13:25:40 +0000
@@ -31,7 +31,7 @@
 # $master_connection
 #   See wait_for_slave_param.inc for description.
 
-if (`SELECT '$slave_sql_errno' = ''`) {
+if (!$slave_sql_errno) {
   --die !!!ERROR IN TEST: you must set \$slave_sql_errno before sourcing wait_for_slave_sql_error.inc
 }
 

=== modified file 'mysql-test/include/wait_for_status_var.inc'
--- a/mysql-test/include/wait_for_status_var.inc	2010-05-24 13:54:08 +0000
+++ b/mysql-test/include/wait_for_status_var.inc	2010-10-21 13:24:31 +0000
@@ -45,7 +45,7 @@ if (!$_status_timeout_counter)
 }
 
 let $_status_var_comparsion= $status_var_comparsion;
-if (`SELECT '$_status_var_comparsion' = ''`)
+if (!$_status_var_comparsion)
 {
   let $_status_var_comparsion= =;
 }

=== modified file 'mysql-test/lib/mtr_misc.pl'
--- a/mysql-test/lib/mtr_misc.pl	2010-06-07 09:14:56 +0000
+++ b/mysql-test/lib/mtr_misc.pl	2010-10-19 13:05:25 +0000
@@ -33,6 +33,13 @@ sub mtr_exe_maybe_exists(@);
 sub mtr_milli_sleep($);
 sub start_timer($);
 sub has_expired($);
+sub init_timers();
+sub mark_time_used($);
+sub add_total_times($);
+sub print_times_used($$);
+sub print_total_times($);
+
+our $opt_report_times;
 
 ##############################################################################
 #
@@ -205,4 +212,81 @@ sub start_timer ($) { return time + $_[0
 
 sub has_expired ($) { return $_[0] && time gt $_[0]; }
 
+# Below code is for time usage reporting
+
+use Time::HiRes qw(gettimeofday);
+
+my %time_used= (
+  'collect' => 0,
+  'restart' => 0,
+  'check'   => 0,
+  'ch-warn' => 0,
+  'test'    => 0,
+  'init'    => 0,
+);
+
+my %time_text= (
+ 'collect' => "Collecting test cases",
+ 'restart' => "Server stop/start",
+ 'check'   => "Check-testcase",
+ 'ch-warn' => "Check for warnings",
+ 'test'    => "Test execution",
+ 'init'    => "Initialization etc.",
+);
+
+# Counts number of reports from workers
+
+my $time_totals= 0;
+
+my $last_timer_set;
+
+sub init_timers() {
+  $last_timer_set= gettimeofday();
+}
+
+sub mark_time_used($) {
+  my ($name)= @_;
+  return unless $opt_report_times;
+  die "Unknown timer $name" unless exists $time_used{$name};
+
+  my $curr_time= gettimeofday();
+  $time_used{$name}+= int (($curr_time - $last_timer_set) * 1000 + .5);
+  $last_timer_set= $curr_time;
+}
+
+sub add_total_times($) {
+  my ($dummy, $num, @line)= split (" ", $_[0]);
+
+  $time_totals++;
+  foreach my $elem (@line) {
+    my ($name, $spent)= split (":", $elem);
+    $time_used{$name}+= $spent;
+  }
+}
+
+sub print_times_used($$) {
+  my ($server, $num)= @_;
+  return unless $opt_report_times;
+
+  my $output= "SPENT $num";
+  foreach my $name (keys %time_used) {
+    my $spent= $time_used{$name};
+    $output.= " $name:$spent";
+  }
+  print $server $output . "\n";
+}
+
+sub print_total_times($) {
+  # Don't print if we haven't received all worker data
+  return if $time_totals != $_[0];
+
+  foreach my $name (keys %time_used)
+  {
+    my $spent= $time_used{$name}/1000;
+    my $text= $time_text{$name};
+    print ("Spent $spent seconds on $text\n");
+  }
+}
+
+
 1;

=== modified file 'mysql-test/lib/mtr_process.pl'
--- a/mysql-test/lib/mtr_process.pl	2010-06-14 09:31:22 +0000
+++ b/mysql-test/lib/mtr_process.pl	2010-10-12 11:13:23 +0000
@@ -116,18 +116,20 @@ sub sleep_until_file_created ($$$) {
       return 1;
     }
 
+    my $seconds= ($loop * $sleeptime) / 1000;
+
     # Check if it died after the fork() was successful
     if ( defined $proc and ! $proc->wait_one(0) )
     {
-      mtr_warning("Process $proc died");
+      mtr_warning("Process $proc died after mysql-test-run waited $seconds " .
+		  "seconds for $pidfile to be created.");
       return 0;
     }
 
     mtr_debug("Sleep $sleeptime milliseconds waiting for $pidfile");
 
     # Print extra message every 60 seconds
-    my $seconds= ($loop * $sleeptime) / 1000;
-    if ( $seconds > 1 and int($seconds * 10) % 600 == 0 )
+    if ( $seconds > 1 && int($seconds * 10) % 600 == 0 && $seconds < $timeout )
     {
       my $left= $timeout - $seconds;
       mtr_warning("Waited $seconds seconds for $pidfile to be created, " .
@@ -138,6 +140,8 @@ sub sleep_until_file_created ($$$) {
 
   }
 
+  mtr_warning("Timeout after mysql-test-run waited $timeout seconds " .
+	      "for the process $proc to create a pid file.");
   return 0;
 }
 

=== modified file 'mysql-test/mysql-test-run.pl'
--- a/mysql-test/mysql-test-run.pl	2010-10-20 21:15:56 +0000
+++ b/mysql-test/mysql-test-run.pl	2010-10-26 06:57:29 +0000
@@ -201,6 +201,7 @@ sub using_extern { return (keys %opts_ex
 our $opt_fast= 0;
 our $opt_force;
 our $opt_mem= $ENV{'MTR_MEM'};
+our $opt_clean_vardir= $ENV{'MTR_CLEAN_VARDIR'};
 
 our $opt_gcov;
 our $opt_gcov_exe= "gcov";
@@ -241,6 +242,7 @@ my $opt_skip_core;
 our $opt_check_testcases= 1;
 my $opt_mark_progress;
 my $opt_max_connections;
+our $opt_report_times= 0;
 
 my $opt_sleep;
 
@@ -354,8 +356,11 @@ sub main {
     }
   }
 
+  init_timers();
+
   mtr_report("Collecting tests...");
   my $tests= collect_test_cases($opt_reorder, $opt_suites, \@opt_cases, \@opt_skip_test_list);
+  mark_time_used('collect');
 
   if ( $opt_report_features ) {
     # Put "report features" as the first test to run
@@ -424,6 +429,7 @@ sub main {
 	$opt_tmpdir= "$opt_tmpdir/$child_num";
       }
 
+      init_timers();
       run_worker($server_port, $child_num);
       exit(1);
     }
@@ -436,6 +442,8 @@ sub main {
   mtr_print_thick_line();
   mtr_print_header();
 
+  mark_time_used('init');
+
   my $completed= run_test_server($server, $tests, $opt_parallel);
 
   exit(0) if $opt_start_exit;
@@ -481,8 +489,12 @@ sub main {
 		 $opt_gcov_msg, $opt_gcov_err);
   }
 
+  print_total_times($opt_parallel) if $opt_report_times;
+
   mtr_report_stats("Completed", $completed);
 
+  remove_vardir_subs() if $opt_clean_vardir;
+
   exit(0);
 }
 
@@ -613,13 +625,15 @@ sub run_test_server ($$$) {
 	  if ($test_has_failed and $retries <= $opt_retry){
 	    # Test should be run one more time unless it has failed
 	    # too many times already
+	    my $tname= $result->{name};
 	    my $failures= $result->{failures};
 	    if ($opt_retry > 1 and $failures >= $opt_retry_failure){
-	      mtr_report("\nTest has failed $failures times,",
+	      mtr_report("\nTest $tname has failed $failures times,",
 			 "no more retries!\n");
 	    }
 	    else {
-	      mtr_report("\nRetrying test, attempt($retries/$opt_retry)...\n");
+	      mtr_report("\nRetrying test $tname, ".
+			 "attempt($retries/$opt_retry)...\n");
 	      delete($result->{result});
 	      $result->{retries}= $retries+1;
 	      $result->write_test($sock, 'TESTCASE');
@@ -655,6 +669,9 @@ sub run_test_server ($$$) {
 	elsif ($line eq 'START'){
 	  ; # Send first test
 	}
+	elsif ($line =~ /^SPENT/) {
+	  add_total_times($line);
+	}
 	else {
 	  mtr_error("Unknown response: '$line' from client");
 	}
@@ -786,7 +803,9 @@ sub run_worker ($) {
   # Ask server for first test
   print $server "START\n";
 
-  while(my $line= <$server>){
+  mark_time_used('init');
+
+  while (my $line= <$server>){
     chomp($line);
     if ($line eq 'TESTCASE'){
       my $test= My::Test::read_test($server);
@@ -804,16 +823,20 @@ sub run_worker ($) {
       # Send it back, now with results set
       #$test->print_test();
       $test->write_test($server, 'TESTRESULT');
+      mark_time_used('restart');
     }
     elsif ($line eq 'BYE'){
       mtr_report("Server said BYE");
       stop_all_servers($opt_shutdown_timeout);
+      mark_time_used('restart');
       if ($opt_valgrind_mysqld) {
         valgrind_exit_reports();
       }
       if ( $opt_gprof ) {
 	gprof_collect (find_mysqld($basedir), keys %gprof_dirs);
       }
+      mark_time_used('init');
+      print_times_used($server, $thread_num);
       exit(0);
     }
     else {
@@ -954,6 +977,7 @@ sub command_line_setup {
              'tmpdir=s'                 => \$opt_tmpdir,
              'vardir=s'                 => \$opt_vardir,
              'mem'                      => \$opt_mem,
+	     'clean-vardir'             => \$opt_clean_vardir,
              'client-bindir=s'          => \$path_client_bindir,
              'client-libdir=s'          => \$path_client_libdir,
 
@@ -986,6 +1010,7 @@ sub command_line_setup {
 	     'timediff'                 => \&report_option,
 	     'max-connections=i'        => \$opt_max_connections,
 	     'default-myisam!'          => \&collect_option,
+	     'report-times'             => \$opt_report_times,
 
              'help|h'                   => \$opt_usage,
              'list-options'             => \$opt_list_options,
@@ -2256,6 +2281,12 @@ sub environment_setup {
 }
 
 
+sub remove_vardir_subs() {
+  foreach my $sdir ( glob("$opt_vardir/*") ) {
+    mtr_verbose("Removing subdir $sdir");
+    rmtree($sdir);
+  }
+}
 
 #
 # Remove var and any directories in var/ created by previous
@@ -2300,11 +2331,7 @@ sub remove_stale_vardir () {
 	mtr_error("The destination for symlink $opt_vardir does not exist")
 	  if ! -d readlink($opt_vardir);
 
-	foreach my $bin ( glob("$opt_vardir/*") )
-	{
-	  mtr_verbose("Removing bin $bin");
-	  rmtree($bin);
-	}
+	remove_vardir_subs();
       }
     }
     else
@@ -3222,6 +3249,7 @@ sub check_testcase($$)
 
 	if ( keys(%started) == 0){
 	  # All checks completed
+	  mark_time_used('check');
 	  return 0;
 	}
 	# Wait for next process to exit
@@ -3237,7 +3265,8 @@ sub check_testcase($$)
 	    "\nMTR's internal check of the test case '$tname' failed.
 This means that the test case does not preserve the state that existed
 before the test case was executed.  Most likely the test case did not
-do a proper clean-up.
+do a proper clean-up. It could also be caused by the previous test run
+by this thread, if the server wasn't restarted.
 This is the diff of the states of the servers before and after the
 test case was executed:\n";
 	  $tinfo->{check}.= $report;
@@ -3279,6 +3308,11 @@ test case was executed:\n";
     # Kill any check processes still running
     map($_->kill(), values(%started));
 
+    mtr_warning("Check-testcase failed, this could also be caused by the" .
+		" previous test run by this worker thread")
+      if $result > 1 && $mode eq "before";
+    mark_time_used('check');
+
     return $result;
   }
 
@@ -3588,6 +3622,7 @@ sub run_testcase ($) {
       return 1;
     }
   }
+  mark_time_used('restart');
 
   # --------------------------------------------------------------------
   # If --start or --start-dirty given, stop here to let user manually
@@ -3640,6 +3675,8 @@ sub run_testcase ($) {
 
   do_before_run_mysqltest($tinfo);
 
+  mark_time_used('init');
+
   if ( $opt_check_testcases and check_testcase($tinfo, "before") ){
     # Failed to record state of server or server crashed
     report_failure_and_restart($tinfo);
@@ -3686,6 +3723,7 @@ sub run_testcase ($) {
     }
     mtr_verbose("Got $proc");
 
+    mark_time_used('test');
     # ----------------------------------------------------
     # Was it the test program that exited
     # ----------------------------------------------------
@@ -3912,7 +3950,9 @@ sub get_log_from_proc ($$) {
   foreach my $mysqld (mysqlds()) {
     if ($mysqld->{proc} eq $proc) {
       my @srv_lines= extract_server_log($mysqld->value('#log-error'), $name);
-      $srv_log= "\nServer log from this test:\n" . join ("", @srv_lines);
+      $srv_log= "\nServer log from this test:\n" .
+	"----------SERVER LOG START-----------\n". join ("", @srv_lines) .
+	"----------SERVER LOG END-------------\n";
       last;
     }
   }
@@ -4089,6 +4129,7 @@ sub check_warnings ($) {
 
 	if ( keys(%started) == 0){
 	  # All checks completed
+	  mark_time_used('ch-warn');
 	  return $result;
 	}
 	# Wait for next process to exit
@@ -4121,6 +4162,7 @@ sub check_warnings ($) {
     # Kill any check processes still running
     map($_->kill(), values(%started));
 
+    mark_time_used('ch-warn');
     return $result;
   }
 
@@ -5090,6 +5132,8 @@ sub start_mysqltest ($) {
   my $exe= $exe_mysqltest;
   my $args;
 
+  mark_time_used('init');
+
   mtr_init_args(\$args);
 
   mtr_add_arg($args, "--defaults-file=%s", $path_config_file);
@@ -5571,6 +5615,8 @@ Options to control directories to use
                         for tmpfs (/dev/shm)
                         The option can also be set using environment
                         variable MTR_MEM=[DIR]
+  clean-vardir          Clean vardir if tests were successful and if
+                        running in "memory". Otherwise this option is ignored
   client-bindir=PATH    Path to the directory where client binaries are located
   client-libdir=PATH    Path to the directory where client libraries are located
 
@@ -5730,6 +5776,8 @@ Misc options
   default-myisam        Set default storage engine to MyISAM for non-innodb
                         tests. This is needed after switching default storage
                         engine to InnoDB.
+  report-times          Report how much time has been spent on different
+                        phases of test execution.
 HERE
   exit(1);
 

=== modified file 'mysql-test/suite/binlog/t/binlog_unsafe.test'
--- a/mysql-test/suite/binlog/t/binlog_unsafe.test	2010-08-30 06:11:20 +0000
+++ b/mysql-test/suite/binlog/t/binlog_unsafe.test	2010-10-21 12:36:16 +0000
@@ -321,7 +321,7 @@ while (`SELECT $unsafe_type < 9`) {
             --source extra/rpl_tests/create_recursive_construct.inc
 
             # Drop created object.
-            if (`SELECT '$drop_3' != ''`) {
+            if ($drop_3) {
               --eval $drop_3
             }
             --inc $call_type_3
@@ -330,7 +330,7 @@ while (`SELECT $unsafe_type < 9`) {
         } # if (!is_toplevel_2)
 
         # Drop created object.
-        if (`SELECT '$drop_2' != ''`) {
+        if ($drop_2) {
           --eval $drop_2
         }
         --inc $call_type_2
@@ -338,7 +338,7 @@ while (`SELECT $unsafe_type < 9`) {
     } # if (!is_toplevel_1)
 
     # Drop created object.
-    if (`SELECT '$drop_1' != ''`) {
+    if ($drop_1) {
       --eval $drop_1
     }
     --inc $call_type_1

=== modified file 'mysql-test/suite/rpl/t/rpl_killed_ddl.test'
--- a/mysql-test/suite/rpl/t/rpl_killed_ddl.test	2010-02-06 10:28:06 +0000
+++ b/mysql-test/suite/rpl/t/rpl_killed_ddl.test	2010-10-21 13:24:31 +0000
@@ -119,7 +119,7 @@ echo [on master];
 
 # This will block the execution of a statement at the DBUG_SYNC_POINT
 # with given lock name
-if (`SELECT '$debug_lock' != ''`)
+if ($debug_lock)
 {
   disable_query_log;
   disable_result_log;

=== modified file 'mysql-test/t/mysqltest.test'
--- a/mysql-test/t/mysqltest.test	2010-09-28 14:01:36 +0000
+++ b/mysql-test/t/mysqltest.test	2010-10-19 13:05:25 +0000
@@ -331,7 +331,7 @@ eval select $mysql_errno as "after_!errn
 --exec illegal_command
 --cat_file does_not_exist
 --perl
-  exit(1);
+  exit(2);
 EOF
 
 # ----------------------------------------------------------------------------

=== modified file 'mysql-test/t/server_uuid_embedded.test'
--- a/mysql-test/t/server_uuid_embedded.test	2010-07-14 15:04:32 +0000
+++ b/mysql-test/t/server_uuid_embedded.test	2010-10-21 12:36:16 +0000
@@ -25,7 +25,7 @@ SET GLOBAL SERVER_UUID= UUID();
 --echo # SERVER_UUID is not null
 --echo -----------------------------------------------------------------------------
 --let $server_uuid= query_get_value(SELECT @@SERVER_UUID, @@SERVER_UUID, 1)
-if (`SELECT '$server_uuid' = ''`)
+if (!$server_uuid)
 {
   --echo server's UUID is null
 }

=== modified file 'mysql-test/t/wait_timeout.test'
--- a/mysql-test/t/wait_timeout.test	2009-03-06 14:56:17 +0000
+++ b/mysql-test/t/wait_timeout.test	2010-10-19 11:54:28 +0000
@@ -53,7 +53,7 @@ while (!`select @aborted_clients`)
   dec $retries;
   if (!$retries)
   {
-    Failed to detect that client has been aborted;
+    die Failed to detect that client has been aborted;
   }
 }
 --enable_query_log
@@ -108,7 +108,7 @@ while (!`select @aborted_clients`)
   dec $retries;
   if (!$retries)
   {
-    Failed to detect that client has been aborted;
+    die Failed to detect that client has been aborted;
   }
 }
 --enable_query_log

No bundle (reason: useless for push emails).