Merge lp:~percona-toolkit-dev/percona-toolkit/fix-928226 into lp:percona-toolkit/2.0

[Daniel Nichter]

[Daniel Nichter (daniel-nichter)]

Overall looks good; just needs one little tweak: simplify the new _d() message like:

_d('Using qtime=0 because average_ios is 0: number_of_ios', $number_of_ios, '+ delta for ios_in_progress', $delta_for->{ios_in_progress});

(Line break it at 80 cols.) The main reason for this change is that debug messages should never interpolate vars in strings because if $foo=undef then _d("foo=$foo") will crash. _d() handles undef args, so _d('foo=', $foo) will not crash.

review: Needs Fixing

[Daniel Nichter (daniel-nichter)]

review: Approve

=== modified file 'bin/pt-diskstats'
--- bin/pt-diskstats	2012-02-03 23:25:29 +0000
+++ bin/pt-diskstats	2012-03-06 21:15:24 +0000
@@ -2192,9 +2192,17 @@
                             + $delta_for->{ms_spent_writing};
 
    if ( $number_of_ios ) {
-      $extra_stats{qtime} =
-         $delta_for->{ms_weighted} / ($number_of_ios + $delta_for->{ios_in_progress})
-            - $delta_for->{ms_spent_doing_io} / $number_of_ios;
+      my $average_ios = $number_of_ios + $delta_for->{ios_in_progress};
+      if ( $average_ios ) {
+         $extra_stats{qtime} =  $delta_for->{ms_weighted} / $average_ios
+                           - $delta_for->{ms_spent_doing_io} / $number_of_ios;
+      }
+      else {
+         PTDEBUG && _d("IOS_IN_PROGRESS is [", $delta_for->{ios_in_progress},
+                       "], and the number of ios is [", $number_of_ios,
+                       "], going to use 0 as qtime.");
+         $extra_stats{qtime} = 0;
+      }
       $extra_stats{stime}
          = $delta_for->{ms_spent_doing_io} / $number_of_ios;
    }

=== modified file 'lib/Diskstats.pm'
--- lib/Diskstats.pm	2012-02-03 17:00:40 +0000
+++ lib/Diskstats.pm	2012-03-06 21:15:24 +0000
@@ -818,9 +818,17 @@
                             + $delta_for->{ms_spent_writing};
 
    if ( $number_of_ios ) {
-      $extra_stats{qtime} =
-         $delta_for->{ms_weighted} / ($number_of_ios + $delta_for->{ios_in_progress})
-            - $delta_for->{ms_spent_doing_io} / $number_of_ios;
+      my $average_ios = $number_of_ios + $delta_for->{ios_in_progress};
+      if ( $average_ios ) {
+         $extra_stats{qtime} =  $delta_for->{ms_weighted} / $average_ios
+                           - $delta_for->{ms_spent_doing_io} / $number_of_ios;
+      }
+      else {
+         PTDEBUG && _d("IOS_IN_PROGRESS is [", $delta_for->{ios_in_progress},
+                       "], and the number of ios is [", $number_of_ios,
+                       "], going to use 0 as qtime.");
+         $extra_stats{qtime} = 0;
+      }
       $extra_stats{stime}
          = $delta_for->{ms_spent_doing_io} / $number_of_ios;
    }

=== modified file 't/lib/Diskstats.t'
--- t/lib/Diskstats.t	2012-02-03 18:30:21 +0000
+++ t/lib/Diskstats.t	2012-03-06 21:15:24 +0000
@@ -9,7 +9,7 @@
 use strict;
 use warnings FATAL => 'all';
 use English qw(-no_match_vars);
-use Test::More tests => 107;
+use Test::More tests => 108;
 
 use PerconaTest;
 
@@ -449,6 +449,30 @@
    "_calc_misc_stats works"
 );
 
+# Bug 928226: IOS IN PROGRESS can be negative due to kernel bugs,
+# which can eventually cause a division by zero if it happens to
+# be the negative of the number of ios.
+# The tool should return zero in that case, rather than dying.
+$deltas->{ios_in_progress} = -$deltas->{ios_requested};
+%misc_stats = $obj->_calc_misc_stats(
+   delta_for     => $deltas,
+   elapsed       => $curr->{TS} - $prev->{TS},
+   devs_in_group => 1,
+   stats         => { %write_stats, %read_stats },
+);
+
+is_deeply(
+   \%misc_stats,
+   {
+      busy => '0.6',
+      line_ts => '  0.0',
+      qtime => 0,
+      s_spent_doing_io => '28.5',
+      stime => '0.0364741641337386',
+   },
+   "_calc_misc_stats works around a negative the IOS IN PROGRESS"
+);
+
 $obj->clear_state();
 
 }