Merge lp:~sergei.glushchenko/percona-xtrabackup/BT30559-kill-long-selects into lp:percona-xtrabackup/2.1

[Sergei Glushchenko]

      Blueprint https://blueprints.launchpad.net/percona-xtrabackup/+spec/safe-ftwrl
      Try to catch the moment when no long queries are running.
      Try to kill all the queries which block the global lock.
      To determine a good moment, innobackupex analyses
      SHOW FULL PROCESSLIST output, particularly looking into
      Time field. If there is no process with Time greater than
      specified threshold, the moment is considered to be good.
      If no good moment been chatched during specified time,
      innobackupex bail out.
      After the global lock issued, spawn child process to kill
      the queries which bloc the global lock.

There is a lot of Jenkins failures, most of them are unrelated.
There are potential issues with test case as it rely heavily on timings. Suggestions to improve are welcome.

http://jenkins.percona.com/view/XtraBackup/job/percona-xtrabackup-2.1-param/315/

[Alexey Kopytov (akopytov)]

Sergei,

There are conflicts in innobackupex. Please also re-run Jenkins tests with exactly the same branch as has been submitted for reviews.

review: Needs Fixing

[Sergei Glushchenko (sergei.glushchenko)]

Conflicts resolved.
Jenkins build: http://jenkins.percona.com/view/XtraBackup/job/percona-xtrabackup-2.1-param/320/

[Alexey Kopytov (akopytov)]

Sergei,

Thanks. I would like the following things in user-visible text to be fixed before it is merged. Otherwise approved.

   - s/enales/enables/
   - s/"before start "FLUSH TABLE WITH READ LOCK"/before FLUSH TABLES
     WITH READ LOCK is started by innobackupex/
   - s/time in seconds to wait moment when there are no.../time in
     seconds to wait until there are no.../
   - s/This option specifies number of seconds innobackupex will wait
     after it issued the global lock and before it start to kill
     queries/This option specifies the number of seconds innobackupex
     waits between starting FLUSH TABLES WITH READ LOCK and killing
     those queries that block it./
   - s/which means no query killing/which means innobackupex will not
     attempt to kill any queries/
   - s/If value is not 0, innobackupex will wait not longer than
     specified amount of seconds for a good moment to issue the global
     lock. If no good moment being catched, innobackupex will bail out./
     This option specifies time in seconds that innobackupex should
     wait for queries that would block FTWRL before running it. If
     there are still such queries when the timeout expires,
     innobackupex terminates with an error.
   - s/Default is 0 which means no waiting for a good moment, just issue
     the global lock mandatory./Default is 0, in which case
     innobackupex does not wait for queries to complete and starts FTWRL
     immediately./
   - s/This option specifes the minimum age of a query to be considered as
     "long running" and potentially a blocker of the global lock. Such a
     queries will prevent the global lock from being issued (see
     --lock-wait-timeout).This option does not have any meaning if
     --lock-wait-timeout=0./
      This option specifies the query run time threshold which is used by
     innobackupex to detect long-running queries with a non-zero value
     of --lock-wait-timeout. FTWRL is not started until such
     long-running queries exist. This option has no effect if
     --lock-wait-timeout is 0.

review: Approve

[Sergei Glushchenko (sergei.glushchenko)]

Alexey,

I made required changes. Also I removed two documentation items, which turned out to be a garbage.

 =item --ftwrl-wait
and
 =item --ftwrl-wait-timeout=SECONDS

I run test locally and, re-pushed the branch, but did not start Jenkins build.

Thanks,
Sergei.

[Alexey Kopytov (akopytov)]

review: Approve

=== modified file 'innobackupex'
--- innobackupex	2013-05-22 10:25:21 +0000
+++ innobackupex	2013-05-26 07:22:28 +0000
@@ -202,6 +202,26 @@
 # process id of ibbackup program (runs as a child process of this script)
 my $ibbackup_pid = '';
 
+# process id of long queries killer
+my $query_killer_pid;
+
+# set kill long queries timeout in seconds
+my $option_kill_long_queries_timeout = 0;
+
+# waiting for an appropriate time to start FTWRL timeout
+my $option_lock_wait_timeout = 0;
+
+# how old should be query to be waited for
+my $option_lock_wait_threshold = 60;
+
+# which type of queries we are waiting for during the pre-FTWRL phase
+# possible values are "update" and "all"
+my $option_lock_wait_query_type = "all";
+
+# which type of queries wa are waiting when clearing the way for FTWRL
+# by killing; possible values are "select" and "all"
+my $option_kill_long_query_type = "all";
+
 # a counter for numbering mysql connection checks
 my $hello_id = 0;
 
@@ -277,7 +297,7 @@
                         if ($mysql{dbh}) {
                             print STDERR "Connected successfully\n";
                             $option_ibbackup_binary = set_xtrabackup_version();
-                            mysql_close();
+                            mysql_close(\%mysql);
                         } else {
      		            die "Failed to connect to MySQL server to detect version.\nYou must set xtrabackup version to use with --ibbackup option.\nPossible values are xtrabackup_55 (for MySQL 5.5), xtrabackup_56 (for MySQL or Percona Server 5.6, or xtrabackup (for MySQL 5.1 with InnoDB plugin or Percona Server)\n";
                         }
@@ -1417,6 +1437,7 @@
 #
 # mysql_query subroutine send a query to MySQL server child process.
 # Parameters:
+#    con       mysql connection
 #    query     query to execute
 #
 sub mysql_query {
@@ -1439,6 +1460,10 @@
       } elsif ($query eq 'SHOW SLAVE STATUS') {
           $con->{slave_status} =
               $con->{dbh}->selectrow_hashref("SHOW SLAVE STATUS");
+      } elsif ($query eq 'SHOW PROCESSLIST' or
+               $query eq "SHOW FULL PROCESSLIST") {
+          $con->{processlist} =
+              $con->{dbh}->selectall_hashref($query, "Id");
       } else {
           $con->{dbh}->do($query);
       }
@@ -1602,16 +1627,183 @@
     $mysql_slave_position = "master host '$master', filename '$filename', position $position";
 }
 
+sub eat_sql_whitespace {
+    my ($query) = @_;
+
+    while (1) {
+        if ($query =~ m/^\/\*/) {
+            $query =~ s/^\/\*.*?\*\///s;
+        } elsif ($query =~ m/^[ \t\n\r]/s) {
+            $query =~ s/^[ \t\n\r]+//s;
+        } elsif ($query =~ m/^\(/) {
+            $query =~ s/^\(//;
+        } else {
+            return $query;
+        }
+    }
+
+}
+
+
+sub is_query {
+    my ($query) = @_;
+
+    $query = eat_sql_whitespace($query);
+    if ($query =~
+        m/^(insert|update|delete|replace|alter|load|select|do|handler|call|execute|begin)/i) {
+        return 1;
+    }
+
+    return 0;
+}
+
+
+sub is_select_query {
+    my ($query) = @_;
+
+    $query = eat_sql_whitespace($query);
+    if ($query =~ m/^select/i) {
+        return 1;
+    }
+
+    return 0;
+}
+
+
+sub is_update_query {
+    my ($query) = @_;
+
+    $query = eat_sql_whitespace($query);
+    if ($query =~ m/^(insert|update|delete|replace|alter|load)/i) {
+        return 1;
+    }
+
+    return 0;
+}
+
+
+sub have_queries_to_wait_for {
+    my ($con, $threshold) = @_;
+
+    $now = current_time();
+
+    mysql_query($con, "SHOW FULL PROCESSLIST");
+
+    my $processlist = $con->{processlist};
+
+    while (my ($id, $process) = each %$processlist) {
+        if (defined($process->{Info}) &&
+            $process->{Time} >= $threshold &&
+            (($option_lock_wait_query_type eq "all" &&
+             is_query($process->{Info})) ||
+             is_update_query($process->{Info}))) {
+            print STDERR "\n$now  $prefix Waiting for query $id (duration " .
+                            "$process->{Time} sec): $process->{Info}\n";
+            return 1;
+        }
+    }
+
+    return 0;
+}
+
+
+sub kill_long_queries {
+    my ($con, $timeout) = @_;
+
+    $now = current_time();
+
+    mysql_query($con, "SHOW FULL PROCESSLIST");
+
+    my $processlist = $con->{processlist};
+
+    while (my ($id, $process) = each %$processlist) {
+        if (defined($process->{Info}) &&
+            $process->{Time} >= $timeout &&
+            (($option_kill_long_query_type eq "all" &&
+              is_query($process->{Info})) ||
+             is_select_query($process->{Info}))) {
+            print STDERR "\n$now  $prefix Killing query $id (duration " .
+                           "$process->{Time} sec): $process->{Info}\n";
+            mysql_query($con, "KILL $id");
+        }
+    }
+}
+
+
+sub wait_for_no_updates {
+    my ($con, $timeout, $threshold) = @_;
+    my $start_time = time();
+
+    while (time() <= $start_time + $timeout) {
+        if (!(have_queries_to_wait_for($con, $threshold))) {
+            return;
+        }
+        sleep(1);
+    }
+
+    Die "Unable to obtain lock. Please try again.";
+}
+
+
+sub start_query_killer {
+
+    my ($kill_timeout, $pcon) = @_;
+    my $start_time = time();
+    my $pid = fork();
+
+    if ($pid) {
+        # parent process
+        $query_killer_pid = $pid;
+    } else {
+        # child process
+        my $end = 0;
+        local $SIG{HUP} = sub { $end = 1 };
+
+        $pcon->{dbh}->{InactiveDestroy} = 1;
+
+        sleep($kill_timeout);
+
+        my %con = mysql_connect(abort_on_error => 1, keepalives => 0);
+
+        while (!$end) {
+            kill_long_queries(\%con, time() - $start_time);
+            sleep(1);
+        }
+
+        mysql_close(\%con);
+
+        exit(0);
+    }
+}
+
+sub stop_query_killer {
+    if (defined($query_killer_pid)) {
+        kill 'HUP' => $query_killer_pid;
+        waitpid($query_killer_pid, 0);
+        print STDERR "Query killing process is finished\n";
+    }
+}
+
 
 #
 # mysql_lockall subroutine puts a read lock on all tables in all databases.
 # 
 sub mysql_lockall {
     my $con = shift;
+    my $queries_hash_ref;
+
+    if ($option_lock_wait_timeout) {
+        wait_for_no_updates($con, $option_lock_wait_timeout,
+                            $option_lock_wait_threshold);
+    }
 
     $now = current_time();
     print STDERR "$now  $prefix Starting to lock all tables...\n";
 
+    # start query killer process
+    if ($option_kill_long_queries_timeout) {
+        start_query_killer($option_kill_long_queries_timeout, $con);
+    }
     if (compare_versions($mysql_server_version, '4.0.22') == 0
         || compare_versions($mysql_server_version, '4.1.7') == 0) {
         # MySQL server version is 4.0.22 or 4.1.7
@@ -1622,9 +1814,12 @@
         mysql_query($con, "FLUSH TABLES WITH READ LOCK");
         mysql_query($con, "COMMIT");
     }
+    # stop query killer process
+    if ($option_kill_long_queries_timeout) {
+        stop_query_killer();
+    }
     write_binlog_info($con);
     write_galera_info($con) if $option_galera_info;
-	
     $now = current_time();
     print STDERR "$now  $prefix All tables locked and flushed to disk\n";
 }
@@ -1657,6 +1852,7 @@
         kill($kill_signal, $ibbackup_pid);
         $ibbackup_pid = '';
     }
+    stop_query_killer();
 }
 
 
@@ -1996,7 +2192,15 @@
                         'rebuild-indexes' => \$option_rebuild_indexes,
                         'rebuild-threads=i' => \$option_rebuild_threads,
                         'debug-sleep-before-unlock=i' =>
-                        \$option_debug_sleep_before_unlock
+                        \$option_debug_sleep_before_unlock,
+                        'kill-long-queries-timeout=i' =>
+                        \$option_kill_long_queries_timeout,
+                        'kill-long-query-type=s' =>
+                        \$option_kill_long_query_type,
+                        'lock-wait-timeout=i' => \$option_lock_wait_timeout,
+                        'lock-wait-threshold=i' => \$option_lock_wait_threshold,
+                        'lock-wait-query-type=s' =>
+                        \$option_lock_wait_query_type
     );
                         
     if (!$rcode) {
@@ -2036,6 +2240,18 @@
         $option_compress = 0;
     }
 
+    # validate lock-wait-query-type and kill-long-query-type values
+    if (!(grep {$_ eq $option_lock_wait_query_type} qw/all update/)) {
+        Die "Wrong value of lock-wait-query-type. ".
+            "Possible values are all|update, but $option_lock_wait_query_type ".
+            "is specified.";
+    }
+    if (!(grep {$_ eq $option_kill_long_query_type} qw/all select/)) {
+        Die "Wrong value of kill-long-query-type. ".
+            "Possible values are all|select, but $option_kill_long_query_type ".
+            "is specified.";
+    }
+
     if ($option_stream eq 'tar') {
       $stream_cmd = 'tar chf -';
     } elsif ($option_stream eq 'xbstream') {
@@ -3148,6 +3364,27 @@
 
 This option specifies the log sequence number (LSN) to use for the incremental backup.  The option accepts a string argument. It is used with the --incremental option. It is used instead of specifying --incremental-basedir. For databases created by MySQL and Percona Server 5.0-series versions, specify the LSN as two 32-bit integers in high:low format. For databases created in 5.1 and later, specify the LSN as a single 64-bit integer.
 
+=item --kill-long-queries-timeout=SECONDS
+
+This option specifies the number of seconds innobackupex waits between starting FLUSH TABLES WITH READ LOCK and killing those queries that block it. Default is 0 seconds, which means innobackupex will not attempt to kill any queries.
+
+=item --kill-long-query-type=all|update
+
+This option specifies which types of queries should be killed to unblock the global lock. Default is "all".
+
+=item --lock-wait-timeout=SECONDS
+
+This option specifies time in seconds that innobackupex should wait for queries that would block FTWRL before running it. If there are still such queries when the timeout expires, innobackupex terminates with an error.
+Default is 0, in which case innobackupex does not wait for queries to complete and starts FTWRL immediately.
+
+=item --lock-wait-threshold=SECONDS
+
+This option specifies the query run time threshold which is used by innobackupex to detect long-running queries with a non-zero value of --lock-wait-timeout. FTWRL is not started until such long-running queries exist. This option has no effect if --lock-wait-timeout is 0. Default value is 60 seconds.
+
+=item --lock-wait-query-type=all|update
+
+This option specifies which types of queries are allowed to complete before innobackuped will issue the global lock. Default is all.
+
 =item --move-back
 
 Move all the files in a previously made backup from the backup directory to the actual datadir location. Use with caution, as it removes backup files.

=== added file 'test/t/kill_long_selects.sh'
--- test/t/kill_long_selects.sh	1970-01-01 00:00:00 +0000
+++ test/t/kill_long_selects.sh	2013-05-26 07:22:28 +0000
@@ -0,0 +1,181 @@
+############################################################################
+# Test kill-long-queries and kill-long-queries-timeout optins
+############################################################################
+
+. inc/common.sh
+
+function bg_run()
+{
+    local varname=$1
+
+    shift
+
+    ( for cmd in "$@"
+      do
+        eval "$cmd"
+      done ) &
+
+    local pid=$!
+
+    eval "$varname=$pid"
+
+}
+
+function mysql_select()
+{
+    vlog "Run select query with duration $1 seconds"
+    ${MYSQL} ${MYSQL_ARGS} -c test  2> /dev/null <<EOF
+        /* Run background /*SELECT*\  */
+        (
+         SELECT SLEEP($1) FROM t1 FOR UPDATE
+        ) UNION ALL
+        (
+         SELECT 1
+        );
+EOF
+}
+
+function mysql_update()
+{
+    vlog "Run update query with duration $1 seconds"
+    ${MYSQL} ${MYSQL_ARGS} -c test 2> /dev/null <<EOF
+        /* This is not SELECT but rather an /*UPDATE*\
+        query  */
+        UPDATE t1 SET a = SLEEP($1);
+EOF
+}
+
+
+function bg_kill_ok()
+{
+    vlog "Killing $1, expecting it is alive"
+    run_cmd kill $1
+}
+
+
+function bg_wait_ok()
+{
+    vlog "Waiting for $1, expecting it's success"
+    run_cmd wait $1
+}
+
+
+function bg_wait_fail()
+{
+    vlog "Waiting for $1, expecting it would fail"
+    run_cmd_expect_failure wait $1
+}
+
+function kill_all_queries()
+{
+  run_cmd $MYSQL $MYSQL_ARGS test <<EOF
+  select concat('KILL ',id,';') from information_schema.processlist
+  where user='root' and time > 2 into outfile '$MYSQLD_TMPDIR/killall.sql';
+  source $MYSQLD_TMPDIR/killall.sql;
+EOF
+  rm -f $MYSQLD_TMPDIR/killall.sql
+}
+
+start_server --innodb_file_per_table
+
+run_cmd $MYSQL $MYSQL_ARGS test <<EOF
+CREATE TABLE t1(a INT) ENGINE=InnoDB;
+INSERT INTO t1 VALUES (1);
+EOF
+
+mkdir $topdir/full
+
+# ==============================================================
+vlog "===================== case 1 ====================="
+bg_run bg_select_pid "mysql_select 3"
+bg_run bg_update_pid "sleep 1" "mysql_update 3"
+
+innobackupex $topdir/full --kill-long-queries-timeout=5 \
+                          --kill-long-query-type=all
+
+bg_wait_ok $bg_select_pid
+bg_wait_ok $bg_update_pid
+kill_all_queries
+
+
+# ==============================================================
+vlog "===================== case 2 ====================="
+bg_run bg_select_pid "mysql_select 200"
+bg_run bg_update_pid "sleep 1" "mysql_update 5"
+
+innobackupex $topdir/full --kill-long-queries-timeout=3 \
+                          --kill-long-query-type=select
+
+bg_wait_fail $bg_select_pid
+bg_wait_ok $bg_update_pid
+kill_all_queries
+
+
+# ==============================================================
+vlog "===================== case 3 ====================="
+bg_run bg_select_pid "mysql_select 200"
+bg_run bg_update_pid "mysql_update 200"
+
+innobackupex $topdir/full --kill-long-queries-timeout=3 \
+                          --kill-long-query-type=all
+
+bg_wait_fail $bg_select_pid
+bg_wait_fail $bg_update_pid
+kill_all_queries
+
+
+# ==============================================================
+vlog "===================== case 4 ====================="
+bg_run bg_select_pid "mysql_select 200"
+bg_run bg_update_pid "mysql_update 200"
+
+sleep 1
+
+run_cmd_expect_failure ${IB_BIN} ${IB_ARGS} $topdir/full \
+                          --lock-wait-timeout=3 \
+                          --lock-wait-query-type=all \
+                          --lock-wait-threshold=1 \
+                          --kill-long-queries-timeout=1 \
+                          --kill-long-query-type=all
+
+bg_kill_ok $bg_select_pid
+bg_kill_ok $bg_update_pid
+kill_all_queries
+
+
+# ==============================================================
+vlog "===================== case 5 ====================="
+bg_run bg_select_pid "mysql_select 200"
+bg_run bg_update_pid "mysql_update 200"
+
+sleep 2
+
+run_cmd_expect_failure ${IB_BIN} ${IB_ARGS} $topdir/full \
+                          --lock-wait-timeout=3 \
+                          --lock-wait-query-type=update \
+                          --lock-wait-threshold=2 \
+                          --kill-long-queries-timeout=1 \
+                          --kill-long-query-type=all
+
+bg_kill_ok $bg_select_pid
+bg_kill_ok $bg_update_pid
+kill_all_queries
+
+
+# ==============================================================
+vlog "===================== case 6 ====================="
+bg_run bg_update_pid "mysql_update 5"
+bg_run bg_select_pid "sleep 1" "mysql_select 200"
+
+sleep 2
+
+innobackupex $topdir/full \
+                          --lock-wait-timeout=6 \
+                          --lock-wait-query-type=update \
+                          --lock-wait-threshold=2 \
+                          --kill-long-queries-timeout=1 \
+                          --kill-long-query-type=all
+
+bg_wait_fail $bg_select_pid
+bg_wait_ok $bg_update_pid
+kill_all_queries