mysqldumpslow and Rows Examined

I have found that watching the ratio of rows sent to rows examined helps me get a much better idea of how hard the server has to work to get a result set. Unfortunately, mysqldumpslow in MySQL 5.1 doesn't provide that capability. Rather than keeping it to myself, I'm sharing my fix with the world in hopes that it gets included in all the current and future versions of MySQL. :-)

This patch is officially entered into the public domain.

--- mysqldumpslow 2010-05-07 10:17:19.000000000 -0500
+++ mysqldumpslow 2011-06-20 11:46:44.000000000 -0500
@@ -8,8 +8,8 @@
 use strict;
 use Getopt::Long;

-# t=time, l=lock time, r=rows
-# at, al, and ar are the corresponding averages
+# t=time, l=lock time, r=rows sent, e=rows examined
+# at, al, ar, and ae are the corresponding averages

 my %opt = (
     s => 'at',
@@ -83,8 +83,8 @@
     s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//;
     my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('','');

-    s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\n//;
-    my ($t, $l, $r) = ($1, $2, $3);
+    s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+)\s+Rows_examined: ([0-9.]+).*\n//;
+    my ($t, $l, $r, $e) = ($1, $2, $3, $4);
     $t -= $l unless $opt{l};

     # remove fluff that mysqld writes to log when it (re)starts:
@@ -121,6 +121,7 @@
     $s->{t} += $t;
     $s->{l} += $l;
     $s->{r} += $r;
+    $s->{e} += $e;
     $s->{users}->{$user}++ if $user;
     $s->{hosts}->{$host}++ if $host;

@@ -129,10 +130,11 @@

 foreach (keys %stmt) {
     my $v = $stmt{$_} || die;
-    my ($c, $t, $l, $r) = @{ $v }{qw(c t l r)};
+    my ($c, $t, $l, $r, $e) = @{ $v }{qw(c t l r e)};
     $v->{at} = $t / $c;
     $v->{al} = $l / $c;
     $v->{ar} = $r / $c;
+    $v->{ae} = $e / $c;
 }

 my @sorted = sort { $stmt{$b}->{$opt{s}} <=> $stmt{$a}->{$opt{s}} } keys %stmt;
@@ -141,13 +143,13 @@

 foreach (@sorted) {
     my $v = $stmt{$_} || die;
-    my ($c, $t,$at, $l,$al, $r,$ar) = @{ $v }{qw(c t at l al r ar)};
+    my ($c, $t,$at, $l,$al, $r,$ar, $e,$ae) = @{ $v }{qw(c t at l al r ar e ae)};
     my @users = keys %{$v->{users}};
     my $user  = (@users==1) ? $users[0] : sprintf "%dusers",scalar @users;
     my @hosts = keys %{$v->{hosts}};
     my $host  = (@hosts==1) ? $hosts[0] : sprintf "%dhosts",scalar @hosts;
-    printf "Count: %d  Time=%.2fs (%ds)  Lock=%.2fs (%ds)  Rows=%.1f (%d), $user\@$host\n%s\n\n",
-           $c, $at,$t, $al,$l, $ar,$r, $_;
+    printf "Count: %d  Time=%.2fs (%ds)  Lock=%.2fs (%ds)  Rows Sent=%.1f (%d) Rows Examined=%.1f (%d), $user\@$host\n%s\n\
n",
+           $c, $at,$t, $al,$l, $ar,$r, $ae,$e, $_;
 }

 sub usage {
@@ -163,11 +165,13 @@

   -v           verbose
   -d           debug
-  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default
+  -s ORDER     what to sort by (ae, al, at, ar, c, e, l, r, t), 'at' is default
+                ae: average rows examined
                 al: average lock time
                 ar: average rows sent
                 at: average query time
                  c: count
+                 e: rows examined
                  l: lock time
                  r: rows sent
                  t: query time