Bug #52568 Begin and End option for mysqldumpslow
Submitted: 3 Apr 2010 6:36 Modified: 5 Apr 2010 4:35
Reporter: Sadao Hiratsuka (Basic Quality Contributor) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: mysqldump Command-line Client Severity:S4 (Feature request)
Version:5.1.45 OS:Any
Assigned to: CPU Architecture:Any
Tags: Contribution, mysqldumpslow, qc

[3 Apr 2010 6:36] Sadao Hiratsuka
Description:
mysqldumpslow usually reads all of the slow query log file.
If mysqldumpslow can read a part of the slow query log file,
it is very useful.

Here is a sample patch.
-b and -e options specify Begin and End time.

<<<<<Usage>>>>>
$ mysqldumpslow -s t -b '100403 14:42:37' -e '100403 14:46:00' sandbox03-slow.log

Reading mysql slow query log from sandbox03-slow.log

Begin: 100403 14:42:37
End  : 100403 14:46:00
Count: 20  Time=12.38s (247s)  Lock=0.00s (0s)  Rows=1.0 (20), tpcc[tpcc]@vostro
  SELECT /* S-N */ COUNT(DISTINCT s.s_i_id) FROM district d 
INNER JOIN order_line ol ON ol.ol_w_id = d.d_w_id AND ol.ol_d_id = d.d_id 
AND ol.ol_o_id BETWEEN d.d_next_o_id - N AND d.d_next_o_id - N 
INNER JOIN stock s ON s.s_w_id = ol.ol_w_id AND s.s_i_id = ol.ol_i_id 
WHERE d.d_w_id = N AND d.d_id = N AND s.s_quantity < N

Count: 718  Time=0.29s (209s)  Lock=0.00s (0s)  Rows=0.0 (0), tpcc[tpcc]@vostro
  INSERT /* N-N */ INTO order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, 
ol_delivery_d, ol_quantity, ol_amount, ol_dist_info) VALUES (N, N, N, N, N, N, NULL, N, N.N, 'S')
...

<<<<<Patch>>>>>
*** mysqldumpslow_org	2010-04-03 14:12:41.000000000 +0900
--- mysqldumpslow	2010-04-03 14:11:48.000000000 +0900
***************
*** 14,19 ****
--- 14,21 ----
  my %opt = (
      s => 'at',
      h => '*',
+     b => '000000 00:00:00',
+     e => '999999 23:59:59',
  );
  
  GetOptions(\%opt,
***************
*** 29,38 ****
--- 31,45 ----
      'h=s',	# hostname of db server for *-slow.log filename (can be wildcard)
      'i=s',	# name of server instance (if using mysql.server startup script)
      'l!',	# don't subtract lock time from total time
+     'b=s',	# read slow query log after or equal to 'yymmdd hh:mm:ss'
+     'e=s',	# read slow query log before 'yymmdd hh:mm:ss'
  ) or usage("bad option");
  
  $opt{'help'} and usage();
  
+ die "Invalid datetime format for -b: $opt{b}\n" unless $opt{b} =~ /^\d{6} \d{2}:\d{2}:\d{2}$/;
+ die "Invalid datetime format for -e: $opt{e}\n" unless $opt{e} =~ /^\d{6} \d{2}:\d{2}:\d{2}$/;
+ 
  unless (@ARGV) {
      my $defaults   = `my_print_defaults mysqld`;
      my $basedir = ($defaults =~ m/--basedir=(.*)/)[0]
***************
*** 69,74 ****
--- 76,82 ----
  
  my @pending;
  my %stmt;
+ my $skip;
  $/ = ";\n#";		# read entire statements using paragraph mode
  while ( defined($_ = shift @pending) or defined($_ = <>) ) {
      warn "[[$_]]\n" if $opt{d};	# show raw paragraph being read
***************
*** 80,86 ****
  	next;
      }
  
!     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//;
--- 88,97 ----
  	next;
      }
  
!     my ($time) = s/^#? Time: (\d{6}\s+\d+:\d+:\d+).*\n// ? ($1) : ('');
!     $skip = ($time lt $opt{b}) or ($time ge $opt{e}) if $time;
!     next if $skip;
!     
      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//;
***************
*** 127,132 ****
--- 138,146 ----
      warn "{{$_}}\n\n" if $opt{d};	# show processed statement string
  }
  
+ print "Begin: $opt{b}\n" if $opt{b} ne '000000 00:00:00';
+ print "End  : $opt{e}\n" if $opt{e} ne '999999 23:59:59';
+ 
  foreach (keys %stmt) {
      my $v = $stmt{$_} || die;
      my ($c, $t, $l, $r) = @{ $v }{qw(c t l r)};
***************
*** 180,185 ****
--- 194,201 ----
                 default is '*', i.e. match all
    -i NAME      name of server instance (if using mysql.server startup script)
    -l           don't subtract lock time from total time
+   -b DATETIME  read slow query log after or equal to 'yymmdd hh:mm:ss'
+   -e DATETIME  read slow query log before 'yymmdd hh:mm:ss'
  
  HERE
      if ($str) {

How to repeat:
N/A

Suggested fix:
N/A
[3 Apr 2010 10:20] Valeriy Kravchuk
Thank you for the feature request and patch contributed.
[5 Apr 2010 4:35] Sadao Hiratsuka
Sorry, I found a bug.

<bad>
!     $skip = ($time lt $opt{b}) or ($time ge $opt{e}) if $time;

<ok>
!     $skip = ($time lt $opt{b}) || ($time ge $opt{e}) if $time;