#!/usr/bin/perl

# This is mysql-query-profiler, a program to analyze MySQL workload.
# 
# This program is copyright (c) 2007 Baron Schwartz.
# Feedback and improvements are welcome.
#
# THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
# WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
# MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.
#
# This program is free software; you can redistribute it and/or modify it under
# the terms of the GNU General Public License as published by the Free Software
# Foundation, version 2; OR the Perl Artistic License.  On UNIX and similar
# systems, you can issue `man perlgpl' or `man perlartistic' to read these
# licenses.
#
# You should have received a copy of the GNU General Public License along with
# this program; if not, write to the Free Software Foundation, Inc., 59 Temple
# Place, Suite 330, Boston, MA  02111-1307  USA.

use strict;
use warnings FATAL => 'all';

use DBI;
use English qw(-no_match_vars);
use Getopt::Long;
use List::Util qw(sum min max first);
use Term::ReadKey;
use Time::HiRes qw(time);

our $VERSION = '1.1.5';
our $DISTRIB = '1053';
our $SVN_REV = sprintf("%d", q$Revision: 871 $ =~ m/(\d+)/g);

$OUTPUT_AUTOFLUSH = 1;

use constant MAX_ULONG => 4294967295; # 2^32-1

# ############################################################################
# Get configuration information.
# ############################################################################

my @opt_spec = (
   { s => 'allowcache|a',  d => 'Enable query cache (default is disabled)' },
   { s => 'askpass',       d => 'Prompt for password for connection' },
   { s => 'calibrate|c!',  d => "Try to compensate for SHOW STATUS (default)" },
   { s => 'database|D=s',  d => 'Database to use' },
   { s => 'defaults-file|F=s', d => 'Only read default options from the given file' },
   { s => 'external|e',    d => 'Calibrate, then pause while an external program runs' },
   { s => 'flush|f+',      d => 'Flush tables.  Specify twice to do between every query' },
   { s => 'help',          d => 'Show this help message' },
   { s => 'host|h=s',      d => 'Connect to host' },
   { s => 'innodb|i!',     d => "Show InnoDB statistics (default)" },
   { s => 'only|n=s',      d => "Only print separate stats for these queries (e.g. 1,5,7)" },
   { s => 'password|p=s',  d => 'Password to use when connecting' },
   { s => 'port|P=i',      d => 'Port number to use for connection' },
   { s => 'separate|s',    d => 'Print stats separately for each query' },
   { s => 'socket|S=s',    d => 'Socket file to use for connection' },
   { s => 'tab|t',         d => 'Print tab-separated values (for a spreadsheet)' },
   { s => 'user|u=s',      d => 'User for login if not current user' },
   { s => 'verbose|v+',    d => 'Verbosity (specify multiple times for more detail)' },
   { s => 'verify|r',      d => 'Verify nothing else is accessing the server' },
   { s => 'version',       d => 'Output version information and exit' },
);

my %opts = (
   n => '',
   v => 0,
   c => 1,
);
# Post-process...
my %opt_seen;
foreach my $spec ( @opt_spec ) {
   my ( $long, $short ) = $spec->{s} =~ m/^([\w-]+)(?:\|([^!+=]*))?/;
   $spec->{k} = $short || $long;
   $spec->{l} = $long;
   $spec->{t} = $short;
   $spec->{n} = $spec->{s} =~ m/!/;
   $opts{$spec->{k}} = undef unless defined $opts{$spec->{k}};
   die "Duplicate option $spec->{k}" if $opt_seen{$spec->{k}}++;
}

Getopt::Long::Configure('no_ignore_case', 'bundling');
GetOptions( map { $_->{s} => \$opts{$_->{k}} } @opt_spec) or $opts{help} = 1;

if ( $opts{version} ) {
   print "mysql-query-profiler  Ver $VERSION Distrib $DISTRIB Changeset $SVN_REV\n";
   exit(0);
}

$opts{n} = [ split(/,/, $opts{n} || '' ) ];
$opts{v} = min(2, $opts{v});

if ( $opts{help} || (!@ARGV && !$opts{e} )) {
   print "Usage: mysql-query-profiler <options> [FILE]...\n\n";
   my $maxw = max(map { length($_->{l}) + ($_->{n} ? 4 : 0)} @opt_spec);
   foreach my $spec ( sort { $a->{l} cmp $b->{l} } @opt_spec ) {
      my $long  = $spec->{n} ? "[no]$spec->{l}" : $spec->{l};
      my $short = $spec->{t} ? "-$spec->{t}" : '';
      printf("  --%-${maxw}s %-4s %s\n", $long, $short, $spec->{d});
   }
   print <<USAGE;

mysql-query-profiler reads and executes queries, and prints statistics about
MySQL server load.  Connection options are read from MySQL option files.

If FILE is given, queries are read and executed from the file(s).  With no FILE,
or when FILE is -, read standard input.  If --external is specified, lines in
FILE are executed by the shell.  You must specify - if no FILE and you want
--external to read and execute from standard input.

Queries in FILE must be terminated with a semicolon and separated by a blank
line.

For more details, please read the documentation:

   perldoc mysql-query-profiler

USAGE
   exit(0);
}

# ############################################################################
# Get ready to do the main work.
# ############################################################################
my %conn = (
   F => 'mysql_read_default_file',
   h => 'host',
   P => 'port',
   S => 'mysql_socket'
);

# Connect to the database
if ( !$opts{p} && $opts{askpass} ) {
   print "Enter password: ";
   ReadMode('noecho');
   chomp($opts{p} = <STDIN>);
   ReadMode('normal');
   print "\n";
}

my $dsn = 'DBI:mysql:' . ( $opts{D} || '' ) . ';'
   . join(';', map  { "$conn{$_}=$opts{$_}" } grep { defined $opts{$_} } qw(F h P S))
   . ';mysql_read_default_group=mysql';
my $dbh = DBI->connect($dsn, @opts{qw(u p)}, { AutoCommit => 1, RaiseError => 1, PrintError => 0 } );

my $variables    = get_variables($dbh);
my $have_innodb  = !$opts{i} && $variables->{have_innodb} eq 'YES' ? 1 : 0;
my $have_session = version_ge($dbh, '5.0.2'); # SESSION status and InnoDB status values.
my $have_rowlock = version_ge($dbh, '5.0.3') && $have_innodb; # InnoDB row lock status.
my $have_last    = version_ge($dbh, '5.0.1') && !$opts{e};    # Last query cost according to optimizer.

# Configure the query cache
my $have_qcache = 0;
if ( $variables->{query_cache_size} ) {
   if ( $opts{a} || $opts{e} ) {
      $have_qcache = 1;
   }
   else {
      $dbh->do("SET SESSION query_cache_type = OFF");
   }
}

# Depending on the level of verbosity and the server version, summary and
# separate printouts will include different formats.
my $formats_for = {
   0 => [
      $have_last    ? qw( OPT_COST ) : qw(),
                      qw( TBL_IDX ),
      $have_qcache  ? qw( QCACHE )   : qw(),
   ],
   1 => [
      $have_last    ? qw( OPT_COST )       : qw(),
                      qw( TBL_IDX ),
      $have_qcache  ? qw( QCACHE )         : qw(),
      $have_innodb  ? qw( ROW_OPS_INNODB ) : qw( ROW_OPS ),
   ],
   2 => [
      $have_last    ? qw( OPT_COST )                         : qw(),
                      qw( TBL_IDX ),
      $have_qcache  ? qw( QCACHE )                           : qw(),
      $have_innodb  ? qw( ROW_OPS_INNODB )                   : qw( ROW_OPS ),
      $have_rowlock ? qw( ROW_LOCKS )                        : qw(),
      $have_innodb  ? qw( IO_OPS IO_INNODB INNODB_DATA_OPS ) : qw( IO_OPS ),
   ],
};

# Globals that'll get set by subroutines.  Used in formats, which is why they
# must be global.
my $ch                 = {};
my $qcost              = 0;
my $qcost_total        = 0;
my $qtime_total        = 0;
my $bytes_in_total     = 0;
my $bytes_out_total    = 0;
my $which_query        = 0;
my $query_time         = 0;
my $query_text         = '';
my $qcache_inval       = 0;
my $qcache_inval_total = 0;
my $hdr_type           = '';

# ############################################################################
# Get a baseline for how much SHOW STATUS costs.
# ############################################################################

# Every status variable this script cares about
my @important_vars = qw(
   Bytes_received Bytes_sent
   Com_commit Com_delete Com_delete_multi Com_insert Com_insert_select
   Com_replace Com_replace_select Com_select Com_update Com_update_multi
   Created_tmp_disk_tables Created_tmp_files Created_tmp_tables Handler_commit
   Handler_delete Handler_read_first Handler_read_key Handler_read_next
   Handler_read_prev Handler_read_rnd Handler_read_rnd_next Handler_update
   Handler_write Innodb_buffer_pool_pages_flushed
   Innodb_buffer_pool_read_ahead_rnd Innodb_buffer_pool_read_ahead_seq
   Innodb_buffer_pool_read_requests Innodb_buffer_pool_reads
   Innodb_buffer_pool_wait_free Innodb_buffer_pool_write_requests
   Innodb_data_fsyncs Innodb_data_read Innodb_data_reads Innodb_data_writes
   Innodb_data_written Innodb_dblwr_pages_written Innodb_dblwr_writes
   Innodb_log_waits Innodb_log_write_requests Innodb_log_writes
   Innodb_os_log_fsyncs Innodb_os_log_written Innodb_pages_created
   Innodb_pages_read Innodb_pages_written Innodb_row_lock_time
   Innodb_row_lock_waits Innodb_rows_deleted Innodb_rows_inserted
   Innodb_rows_read Innodb_rows_updated Key_read_requests Key_reads
   Key_write_requests Key_writes Last_query_cost Qcache_hits Qcache_inserts
   Qcache_lowmem_prunes Qcache_queries_in_cache Questions Select_full_join
   Select_full_range_join Select_range Select_range_check Select_scan
   Sort_merge_passes Sort_range Sort_rows Sort_scan Table_locks_immediate
   );

# SESSION status variables this script cares about.
my @session_vars
   = $have_session
   ? qw(
      Bytes_received Bytes_sent Com_commit
      Com_delete Com_delete_multi Com_insert Com_insert_select
      Com_replace Com_replace_select Com_select Com_update Com_update_multi
      Created_tmp_disk_tables Created_tmp_tables Handler_commit Handler_delete
      Handler_read_first Handler_read_key Handler_read_next Handler_read_prev
      Handler_read_rnd Handler_read_rnd_next Handler_update Handler_write
      Last_query_cost Select_full_join Select_full_range_join Select_range
      Select_range_check Select_scan Sort_merge_passes Sort_range Sort_rows
      Sort_scan
      )
   : qw();

# Status variables that may decrease (if monotonically increasing variables
# decrease, it means they wrapped over the max size of a ulong).
my %non_monotonic_vars = (
   Qcache_queries_in_cache => 1,
   Last_query_cost         => 1,
);

get_status_info($dbh); # Throwaway to prime caches after FLUSH
my $status_0 = get_status_info($dbh);
my $status_1 = get_status_info($dbh);

my $base = $opts{c}
   ? ( { map { $_ => $status_1->{$_} - $status_0->{$_} } @important_vars } )
   : ( { map { $_ => 0 } @important_vars } );

if ( $opts{r} ) {
   my $base_2 = $opts{c} ? $base
      : ( { map { $_ => $status_1->{$_} - $status_0->{$_} } @important_vars } );

   sleep(1);
   my $status_2 = get_status_info($dbh);
   my $base_3
      = { map { $_ => $status_2->{$_} - $status_1->{$_} } @session_vars };
   foreach my $key ( @session_vars ) {
      if ( $base_3->{$key} != $base_2->{$key} ) {
         print "Cost of observation changed: $key $base_3->{$key} $base_2->{$key}\n";
      }
   }
}

# ############################################################################
# The main work happens now.
# ############################################################################

# Get a baseline status.
my $sql_status_0 = get_status_info($dbh);
my @queries;

# ############################################################################
# Do the profiling.
# ############################################################################
my $have_flushed_tables = 0;

if ( $opts{e} ) { # An external process will issue queries
   if ( !@ARGV ) { # Don't read files or STDIN
      flush_tables($have_flushed_tables++);
      my $start = time();
      print "Press <ENTER> when the external program is finished";
      <STDIN>;
      my $end = time();
      # Hack the @queries variable by stuffing the external program's data in as a
      # hash reference just as though it had been a query in a file.
      push @queries, {
         text   => '[External program]',
         start  => $start,
         end    => $end,
         status => get_status_info($dbh),
      };
   }
   else {
      while ( my $line = <> ) { # Read from STDIN, or files named on cmdline
         chomp $line;
         next unless $line;

         flush_tables($have_flushed_tables++);
         my $start = time();
         print `$line`;
         my $end = time();
         push @queries, {
            text   => $line,
            start  => $start,
            end    => $end,
            status => get_status_info($dbh),
         };
      }
   }
}
else {
   local $INPUT_RECORD_SEPARATOR = ''; # read a paragraph at a time
   while ( my $line = <> ) { # Read from STDIN, or files named on cmdline
      chomp $line;
      next unless $line;
      $line =~ s/;\s*\z//xms; # Remove trailing whitespace/semicolon

      flush_tables($have_flushed_tables++);
      my $query = {
         text  => $line,
         start => time(),
      };
      # It appears to me that this actually fetches all the data over the wire,
      # which is what I want for purposes of counting bytes in and bytes out.
      $dbh->do( $line );
      $query->{end}    = time();
      $query->{status} = get_status_info($dbh);
      push @queries, $query;
   }
}

# ############################################################################
# Tab-separated output for a spreadsheet.
# ############################################################################
if ( $opts{t} ) {

   # Get a list of all the SHOW STATUS measurements.
   my @statuses = (
      $sql_status_0,
      ( map { $_->{status} } @queries ),
      get_status_info($dbh),
   );

   # Decide which variables to output.  If verbosity is 0, output only those
   # whose values are non-zero across the board.  If verbosity is greater,
   # output everything.
   my @variables = sort keys %$sql_status_0;
   if ( !$opts{v} ) {
      @variables = grep {
         # Discover whether there is a true value in any set.  A 'true' value
         # is one where the value isn't the same as the value for the same key
         # in the previous set.  The first (before) and last (calibrate) set
         # are excluded.
         my $var = $_;
         first { # first() terminates early, unlike grep()
            defined $statuses[$_]->{$var}
             && defined $statuses[$_ - 1]->{$var}
             && $statuses[$_]->{$var} != $statuses[$_ - 1]->{$var}
         } ( 1 .. $#statuses - 1 );
      } @variables;
   }

   # Print headers.
   print
      join("\t",
         'Variable_name',
         'Before',
         ( map { "After$_" } ( 1 ..  $#statuses - 1 ) ),
         'Calibration',
      ),
      "\n";

   # Print each variable in tab-separated values.
   foreach my $key ( @variables ) {
      print
         join("\t", $key, map { defined($_->{$key}) ? $_->{$key} : '' } @statuses),
         "\n";
   }
}

# ############################################################################
# Tabular layout for human readability.
# ############################################################################
else {
   # Print the separate results and accumulate global totals.
   foreach my $i ( 0 .. $#queries ) {
      my $query     = $queries[$i];
      my $before    = $i ? $queries[ $i - 1 ]->{status} : $sql_status_0;
      my $after     = $query->{status};

      # Accumulate some globals
      $qcost_total += $after->{Last_query_cost};
      $qtime_total += $query->{end} - $query->{start};
      $which_query = $i + 1;
      $query_time  = $query->{end} - $query->{start};
      $ch          = get_changes( $before, $after, 1 );

      # Accumulate query cache invalidations
      $qcache_inval
         = ($ch->{Qcache_inserts} > 0 && $ch->{Qcache_queries_in_cache} == 0)
            || $ch->{Qcache_queries_in_cache} < 0
         ? -$ch->{Qcache_queries_in_cache} - $ch->{Qcache_lowmem_prunes}
         : 0;
      $qcache_inval_total += $qcache_inval;
      $bytes_in_total     += $ch->{Bytes_received};
      $bytes_out_total    += $ch->{Bytes_sent};

      # Print separate stats
      if ( $opts{s} && @queries > 1
         && (!@{$opts{n}} || grep { $i + 1 == $_ } @{$opts{n}} ))
      {
         $qcost        = $after->{Last_query_cost};
         ( $query_text = $query->{text} ) =~ s/\s+/ /g;
         $FORMAT_NAME  = $opts{e} ? 'SUMMARY'  : 'QUERY';
         $hdr_type     = $opts{e} ? 'EXTERNAL' : 'QUERY';
         write;
         foreach my $format_name ( @{$formats_for->{$opts{v}}}) {
            $FORMAT_NAME = $format_name;
            write;
         }
      }
   }

   # Print summary stats
   $ch           = get_changes( $sql_status_0, $queries[-1]->{status}, scalar(@queries) );
   $qcache_inval = $qcache_inval_total;
   $qcost        = $qcost_total;
   $FORMAT_NAME  = "SUMMARY";
   write;
   foreach my $format_name ( @{$formats_for->{$opts{v}}}) {
      $FORMAT_NAME = $format_name;
      write;
   }
   if ( !$have_session ) {
      if ( $queries[-1]->{Questions} - $sql_status_0->{Questions}
         > (@queries * 2) + 1 )
      {
         print STDERR "WARNING: Something else accessed the database at "
            . "the same time you were trying to profile this batch!  These "
            . "numbers are not correct!\n";
      }
      else {
         print STDERR "WARNING: These statistics could be wrong if "
            . "anything else was accessing the database at the same time.\n";
      }
   }
}

$dbh->disconnect;

# ############################################################################
# Subroutines
# ############################################################################

sub flush_tables {
   my ($have_flushed) = @_;
   return if !$opts{f}
      || ( $opts{f} == 1 && $have_flushed );
   eval { $dbh->do("FLUSH TABLES") };
   if ( $EVAL_ERROR ) {
      print STDERR "Warning: can't FLUSH TABLES because $EVAL_ERROR\n";
   }
}

sub get_changes {
   my ( $before, $after, $num_base ) = @_;
   $num_base ||= 1;
   return { map {
      $after->{$_}  ||= 0;
      $before->{$_} ||= 0;
      my $val = $after->{$_} - $before->{$_} - ( $num_base * $base->{$_} );
      if ( $val < 0 && !defined($non_monotonic_vars{$_}) ) {
         # Handle when a ulong wraps over the 32-bit boundary
         $val += MAX_ULONG;
      }
      $_ => $val;
   } @important_vars };
}

sub get_status_info {
   my $dbh = shift;
   my $res = $dbh->selectall_arrayref(
      $have_session
         ? ($opts{e} ? 'SHOW GLOBAL STATUS' : 'SHOW SESSION STATUS')
         : 'SHOW STATUS' );
   my %result = map { @{$_} } @$res;
   return { map { $_ => $result{$_} || 0 } @important_vars };
}

sub get_variables {
   my $dbh = shift;
   my $res = $dbh->selectall_arrayref('SHOW VARIABLES');
   return { map { @{$_} } @$res };
}

# Compares versions like 5.0.27 and 4.1.15-standard-log
sub version_ge {
   my ( $dbh, $target ) = @_;
   my $version = sprintf('%03d%03d%03d', $dbh->{mysql_serverinfo} =~ m/(\d+)/g);
   return $version ge sprintf('%03d%03d%03d', $target =~ m/(\d+)/g);
}

sub get_file {
   my $filename = shift;
   open my $file, "<", "$filename" or die "Can't open $filename: $OS_ERROR";
   my $file_contents = do { local $INPUT_RECORD_SEPARATOR; <$file>; };
   close $file;
   return $file_contents;
}

# ############################################################################
# Formats
# ############################################################################

format SUMMARY =

+----------------------------------------------------------+
| @||||||||||||||||||||||||||||||||||||||||||||||||||||||| |
sprintf("$hdr_type %d (%.4f sec)", $which_query, $query_time)
+----------------------------------------------------------+

__ Overall stats _______________________ Value _____________
   Total elapsed time              @##########.###
$qtime_total
   Questions                       @##########
$ch->{Questions}
     COMMIT                        @##########
$ch->{Com_commit}
     DELETE                        @##########
$ch->{Com_delete}
     DELETE MULTI                  @##########
$ch->{Com_delete_multi}
     INSERT                        @##########
$ch->{Com_insert}
     INSERT SELECT                 @##########
$ch->{Com_insert_select}
     REPLACE                       @##########
$ch->{Com_replace}
     REPLACE SELECT                @##########
$ch->{Com_replace_select}
     SELECT                        @##########
$ch->{Com_select}
     UPDATE                        @##########
$ch->{Com_update}
     UPDATE MULTI                  @##########
$ch->{Com_update_multi}
   Data into server                @##########
$bytes_in_total
   Data out of server              @##########
$bytes_out_total
.

format TBL_IDX =

__ Table and index accesses ____________ Value _____________
   Table locks acquired            @##########
$ch->{Table_locks_immediate}
   Table scans                     @##########
$ch->{Select_scan} + $ch->{Select_full_join}
     Join                          @##########
$ch->{Select_full_join}
   Index range scans               @##########
{
   $ch->{Select_range} + $ch->{Select_full_range_join}
   + $ch->{Select_range_check}
}
     Join without check            @##########
$ch->{Select_full_range_join}
     Join with check               @##########
$ch->{Select_range_check}
   Rows sorted                     @##########
$ch->{Sort_rows}
     Range sorts                   @##########
$ch->{Sort_range}
     Merge passes                  @##########
$ch->{Sort_merge_passes}
     Table scans                   @##########
$ch->{Sort_scan}
     Potential filesorts           @##########
min($ch->{Sort_scan}, $ch->{Created_tmp_tables})
.

format QCACHE =
   Query cache
     Hits                          @##########
$ch->{Qcache_hits}
     Inserts                       @##########
$ch->{Qcache_inserts}
     Invalidations                 @##########
$qcache_inval
.

format ROW_OPS_INNODB =

__ Row operations ____________________ Handler ______ InnoDB
   Reads                           @##########   @##########
{
   $ch->{Handler_read_rnd}
   + $ch->{Handler_read_rnd_next}
   + $ch->{Handler_read_key}
   + $ch->{Handler_read_first}
   + $ch->{Handler_read_next}
   + $ch->{Handler_read_prev},
   $ch->{Innodb_rows_read} || 0
}
     Fixed pos (might be sort)     @##########
$ch->{Handler_read_rnd}
     Next row (table scan)         @##########
$ch->{Handler_read_rnd_next}
     Bookmark lookup               @##########
$ch->{Handler_read_key}
     First in index (full scan?)   @##########
$ch->{Handler_read_first}
     Next in index                 @##########
$ch->{Handler_read_next}
     Prev in index                 @##########
$ch->{Handler_read_prev}
   Writes
     Delete                        @##########   @##########
$ch->{Handler_delete}, $ch->{Innodb_rows_deleted}
     Update                        @##########   @##########
$ch->{Handler_update}, $ch->{Innodb_rows_updated}
     Insert                        @##########   @##########
$ch->{Handler_write}, $ch->{Innodb_rows_inserted}
     Commit                        @##########
$ch->{Handler_commit}
.

format ROW_OPS =

__ Row operations ____________________ Handler _____________
   Reads                           @##########
{
   $ch->{Handler_read_rnd}
   + $ch->{Handler_read_rnd_next}
   + $ch->{Handler_read_key}
   + $ch->{Handler_read_first}
   + $ch->{Handler_read_next}
   + $ch->{Handler_read_prev}
}
     Fixed pos (might be sort)     @##########
$ch->{Handler_read_rnd}
     Next row (table scan)         @##########
$ch->{Handler_read_rnd_next}
     Bookmark lookup               @##########
$ch->{Handler_read_key}
     First in index (full scan?)   @##########
$ch->{Handler_read_first}
     Next in index                 @##########
$ch->{Handler_read_next}
     Prev in index                 @##########
$ch->{Handler_read_prev}
   Writes
     Delete                        @##########
$ch->{Handler_delete}
     Update                        @##########
$ch->{Handler_update}
     Insert                        @##########
$ch->{Handler_write}
     Commit                        @##########
$ch->{Handler_commit}
.

format ROW_LOCKS =
   InnoDB row locks
     Number of locks waited for                  @##########
$ch->{Innodb_row_lock_waits}
     Total ms spent acquiring locks              @##########
$ch->{Innodb_row_lock_time}
.

format IO_OPS =

__ I/O Operations _____________________ Memory ________ Disk
   Key cache
     Key reads                     @##########    @#########
$ch->{Key_read_requests}, $ch->{Key_reads}
     Key writes                    @##########    @#########
$ch->{Key_write_requests}, $ch->{Key_writes}
   Temp tables                     @##########    @#########
$ch->{Created_tmp_tables}, $ch->{Created_tmp_disk_tables}
   Temp files                                     @#########
$ch->{Created_tmp_files}
.

format IO_INNODB =
   InnoDB buffer pool
     Reads                         @##########    @#########
$ch->{Innodb_buffer_pool_read_requests}, $ch->{Innodb_buffer_pool_reads}
     Random read-aheads            @##########
$ch->{Innodb_buffer_pool_read_ahead_rnd}
     Sequential read-aheads        @##########
$ch->{Innodb_buffer_pool_read_ahead_seq}
     Write requests                @##########    @#########
$ch->{Innodb_buffer_pool_write_requests}, $ch->{Innodb_buffer_pool_pages_flushed}
     Reads/creates blocked by flushes             @#########
$ch->{Innodb_buffer_pool_wait_free}
   InnoDB log operations
     Log writes                    @##########    @#########
$ch->{Innodb_log_write_requests}, $ch->{Innodb_log_writes}
     Log writes blocked by flushes                @#########
$ch->{Innodb_log_waits}
.

format INNODB_DATA_OPS =

__ InnoDB Data Operations ____ Pages _____ Ops _______ Bytes
   Reads                   @######## @########    @#########
$ch->{Innodb_pages_read}, $ch->{Innodb_data_reads}, $ch->{Innodb_data_read}
   Writes                  @######## @########    @#########
$ch->{Innodb_pages_written}, $ch->{Innodb_data_writes}, $ch->{Innodb_data_written}
   Doublewrites            @######## @########
$ch->{Innodb_dblwr_pages_written}, $ch->{Innodb_dblwr_writes}
   Creates                 @########
$ch->{Innodb_pages_created}
   Fsyncs                            @########
$ch->{Innodb_data_fsyncs}
   OS fsyncs                         @########    @#########
$ch->{Innodb_os_log_fsyncs}, $ch->{Innodb_os_log_written}
.

format QUERY =

+----------------------------------------------------------+
| @||||||||||||||||||||||||||||||||||||||||||||||||||||||| |
sprintf("QUERY %d (%.4f sec)", $which_query, $query_time)
+----------------------------------------------------------+
^<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<...
$query_text

__ Overall stats _______________________ Value _____________
   Elapsed time                    @##########.###
$query_time
   Data into server                @##########
$ch->{Bytes_received}
   Data out of server              @##########
$ch->{Bytes_sent}
.

format OPT_COST =
   Optimizer cost                  @##########.###
$qcost
.

# ############################################################################
# Documentation
# ############################################################################

=pod

=head1 NAME

mysql-query-profiler - Execute SQL statements and print statistics, or measure
activity caused by other processes.

=head1 SYNOPSIS

mysql-query-profiler can profile the (semicolon-terminated, blank-line
separated) queries in a file:

   mysql-query-profiler queries.sql
   cat queries.sql | mysql-query-profiler
   mysql-query-profiler -vv queries.sql
   mysql-query-profiler -v --separate --only 2,5,6 queries.sql
   mysql-query-profiler --tab queries.sql > results.csv

It can also just observe what happens in the server:

   mysql-query-profiler --external

Or it can run shell commands from a file and measure the result:

   mysql-query-profiler --external commands.txt
   mysql-query-profiler --external - < commands.txt

Read L<"HOW TO INTERPRET"> to learn what it all means.

=head1 OPTIONS

Some options can be negated by prefixing --no to the option name.

=over

=item --allowcache

Allows the MySQL query cache to cache the queries executed.  By default this
is disabled.  When enabled, cache profiling information is added to the
printout.  See L<http://dev.mysql.com/doc/en/query-cache.html> for more
information about the query cache.

=item --askpass

Prompt for password for connections.

=item --calibrate

Makes MySQL Query Profiler measure and compensate for the "cost of
observation" caused by running SHOW STATUS.  Enabled by default.  Only works
reliably on a quiet server; on a busy server, other processes can cause the
calibration to be wrong.

=item --database

Database to use for connection.

=item --defaults-file

Only read default options from the given file.

=item --external

Makes MySQL Query Profiler measure the cost of observation, then pause,
typically while you run an external program.  When you press [enter] MySQL
Query Profiler will stop sleeping and take another measurement, then print
statistics as usual.

When there is a filename on the command line, MySQL Query Profiler executes
each line in the file as a shell command.  If you give - as the filename,
MySQL Query Profiler reads from STDIN.

Output from shell commands is printed to STDOUT and terminated with __BEGIN__,
after which MySQL Query Profiler prints its own output.

=item --flush

Calls FLUSH TABLES before profiling.  If you are executing queries from a
batch file, specifying --flush twice will cause MySQL Query Profiler to call
FLUSH TABLES between every query, not just once at the beginning.  Default is
not to flush at all. See L<http://dev.mysql.com/doc/en/flush.html> for more
information.

=item --help

Displays a help message.

=item --host

Connect to host.

=item --innodb

Shows InnoDB statistics.  Enabled by default.

=item --only

Only shows statistics for the specified queries or commands in a batch file.
Specify as a comma-separated list of numbers beginning at 1.

=item --password

Password to use for connection.

=item --port

Port number to use for connection.

=item --separate

Print statistics for each query or command in a batch file.  The default is to
show only the summary of the entire batch.  See also L<"--verbose">.

=item --socket

Socket file to use for connection.

=item --tab

Print tab-separated values for easy reading with a spreadsheet, instead of
whitespace-aligned columns for humans to read.

=item --user

User for login if not current user.

=item --verbose

Verbosity; specify multiple times for more detailed output.  When L<"--tab">
is given, prints variables that don't change.  Otherwise increasing the level
of verbosity includes extra sections in the output.

=item --verify

Verify nothing else is accessing the server.  This is a weak verification; it
simply calibrates twice (see L<"--calibrate">) and verifies that the cost of
observation remains constant.

=item --version

Output version information and exit.

=back

=head1 DESCRIPTION

MySQL Query Profiler reads a file containing one or more SQL
statements or shell commands, executes them, and analyzes the output of SHOW STATUS afterwards.
It then prints statistics about how the batch performed.  For example, it can
show how many table scans the batch caused, how many page reads, how many
temporary tables, and so forth.

All command-line arguments are optional, but you must either specify a file
containing the batch to profile as the last argument, or specify that you're
profiling an external program with the L<"--external"> option, or provide
input to STDIN.

If the file contains multiple statements, they must be separated by blank
lines.  If you don't do that, MySQL Query Profiler won't be able to split the
file into individual queries, and MySQL will complain about syntax errors.

If the MySQL server version is before 5.0.2, you should make sure the server
is completely unused before trying to profile a batch.  Prior to this version,
SHOW STATUS showed only global status variables, so other queries will
interfere and produce false results.  MySQL Query Profiler will try to detect
if anything did interfere, but there can be no guarantees.

Prior to MySQL 5.0.2, InnoDB status variables are not available, and prior to
version 5.0.3, InnoDB row lock status variables are not available.  MySQL
Query Profiler will omit any output related to these variables if they're not
available.

For more information about SHOW STATUS, read the relevant section of the MySQL
manual at
L<http://dev.mysql.com/doc/en/server-status-variables.html>

=head1 HOW TO INTERPRET

=head2 TAB-SEPARATED OUTPUT

If you specify L<"--tab">, you will get the raw output of SHOW STATUS in
tab-separated format, convenient for opening with a spreadsheet.  This is not
the default output, but it's so much easier to describe that I'll cover it
first.

=over

=item *

Most of the command-line options for controlling verbosity and such are
ignored in --tab mode.

=item *

The variable names you see in MySQL, such as 'Com_select', are kept --
there are no euphimisms, so you have to know your MySQL variables.

=item *

The columns are Variable_name, Before, After1...AfterN, Calibration.
The Variable_name column is just what it sounds like.  Before is the result
from the first run of SHOW STATUS.  After1, After2, etc are the results of
running SHOW STATUS after each query in the batch.  Finally, the last column
is the result of running SHOW STATUS just after the last AfterN column, so you
can see how much work SHOW STATUS itself causes.

=item *

If you specify L<"--verbose">, output includes every variable MySQL Query
Profiler measures.  If not (default) it only includes variables where there
was some difference from one column to the next.

=back

=head2 NORMAL OUTPUT

If you don't specify --tab, you'll get a report formatted for human
readability.  This is the default output format.

MySQL Query Profiler can output a lot of information, as you've seen if you
ran the examples in the L<"SYNOPSIS">.  What does it all mean?

First, there are two basic groups of information you might see: per-query and
summary.  If your batch contains only one query, these will be the same and
you'll only see the summary.  You can recognize the difference by looking for
centered, all-caps, boxed-in section headers.  Externally profiled commands will
have EXTERNAL, individually profiled queries will have QUERY, and summary will
say SUMMARY.

Next, the information in each section is grouped into subsections, headed by
an underlined title.  Each of these sections has varying information in it.
Which sections you see depends on command-line arguments and your MySQL
version.  I'll explain each section briefly.  If you really want to know where
the numbers come from, read
L<http://dev.mysql.com/doc/en/server-status-variables.html>.

You need to understand which numbers are insulated from other queries and
which are not.  This depends on your MySQL version.  Version 5.0.2 introduced
the concept of session status variables, so you can see information about only
your own connection.  However, many variables aren't session-ized, so when you
have MySQL 5.0.2 or greater, you will actually see a mix of session and global
variables.  That means other queries happening at the same time will pollute
some of your results.  If you have MySQL versions older than 5.0.2, you won't
have ANY connection-specific stats, so your results will be polluted by other
queries no matter what.  Because of the mixture of session and global
variables, by far the best way to profile is on a completely quiet server
where nothing else is interfering with your results.

While explaining the results in the sections that follow, I'll refer to a
value as "protected" if it comes from a session-specific variable and can be
relied upon to be accurate even on a busy server.  Just keep in mind, if
you're not using MySQL 5.0.2 or newer, your results will be inaccurate unless
you're running against a totally quiet server, even if I label it as
"protected."

=head2 Overall stats

This section shows the overall elapsed time for the query, as measured by
Perl, and the optimizer cost as reported by MySQL.

If you're viewing separate query statistics, this is all you'll see.  If
you're looking at a summary, you'll also see a breakdown of the questions the
queries asked the server.

The execution time is not totally reliable, as it includes network round-trip
time, Perl's own execution time, and so on.  However, on a low-latency
network, this should be fairly negligible, giving you a reasonable measure of
the query's time, especially for queries longer than a few tenths of a second.

The optimizer cost comes from the Last_query_cost variable, and is protected
from other connections in MySQL 5.0.7 and greater.  It is not available before
5.0.1.

The total number of questions is not protected, but the breakdown of
individual question types is, because it comes from the Com_ status variables.

=head2 Table and index accesses

This section shows you information about the batch's table and index-level
operations (as opposed to row-level operations, which will be in the next
section).  The "Table locks acquired" and "Temp files" values are unprotected,
but everything else in this section is protected.

The "Potential filesorts" value is calculated as the number of times a query had
both a scan sort (Sort_scan) and created a temporary table (Created_tmp_tables).
There is no Sort_filesort or similar status value, so it's a best guess at
whether a query did a filesort.  It should be fairly accurate.

If you specified L<"--allowcache">, you'll see statistics on the query cache.
These are unprotected.

=head2 Row operations

These values are all about the row-level operations your batch caused.  For
example, how many rows were inserted, updated, or deleted.  You'll also see
row-level index access statistics, such as how many times the query sought and
read the next entry in an index.

Depending on your MySQL version, you'll either see one or two columns of
information in this section.  The one headed "Handler" is all from the
Handler_ variables, and those statistics are protected.  If your MySQL version
supports it, you'll also see a column headed "InnoDB," which is unprotected.

=head2 I/O Operations

This section gives information on I/O operations your batch caused, both in
memory and on disk.  Unless you have MySQL 5.0.2 or greater, you'll only see
information on the key cache.  Otherwise, you'll see a lot of information on
InnoDB's I/O operations as well, such as how many times the query was able to
satisfy a read from the buffer pool and how many times it had to go to the
disk.

None of the information in this section is protected.

=head2 InnoDB Data Operations

This section only appears when you're querying MySQL 5.0.2 or newer.  None of
the information is protected.  You'll see statistics about how many pages were
affected, how many operations took place, and how many bytes were affected.

=head1 BUGS

Please use the Sourceforge bug tracker, forums, and mailing lists to request
support or report bugs: L<http://sourceforge.net/projects/mysqltoolkit/>.

=head1 SYSTEM REQUIREMENTS

You need Perl, DBI, DBD::mysql, and some core modules.

=head1 SEE ALSO

See also L<mysql-profile-compact>.

=head1 LICENSE

This program is copyright (c) 2007 Baron Schwartz.
Feedback and improvements are welcome.

THIS PROGRAM IS PROVIDED "AS IS" AND WITHOUT ANY EXPRESS OR IMPLIED
WARRANTIES, INCLUDING, WITHOUT LIMITATION, THE IMPLIED WARRANTIES OF
MERCHANTIBILITY AND FITNESS FOR A PARTICULAR PURPOSE.

This program is free software; you can redistribute it and/or modify it under
the terms of the GNU General Public License as published by the Free Software
Foundation, version 2; OR the Perl Artistic License.  On UNIX and similar
systems, you can issue `man perlgpl' or `man perlartistic' to read these
licenses.

You should have received a copy of the GNU General Public License along with
this program; if not, write to the Free Software Foundation, Inc., 59 Temple
Place, Suite 330, Boston, MA  02111-1307  USA.

=head1 AUTHOR

Baron Schwartz.

=head1 ACKNOWLEDGEMENTS

I was inspired by the wonderful mysqlreport utility available at
L<http://www.hackmysql.com/>.

Other contributors: Bart van Bragt.

Thanks to all who have helped.

=head1 VERSION

This manual page documents Ver 1.1.5 Distrib 1053 $Revision $.

=cut