diff --git a/bin/pt-query-digest b/bin/pt-query-digest index c1b27afb..99c4c9a7 100755 --- a/bin/pt-query-digest +++ b/bin/pt-query-digest @@ -6776,6 +6776,10 @@ sub header { push @result, "# Time range: $time_range"; } + if ( $results->{globals}->{rate_limit} ) { + print "# Rate limits apply\n"; + } + push @result, $self->make_global_header(); my $attribs = $self->sort_attribs( $ea ); @@ -6788,7 +6792,6 @@ sub header { NUM_ATTRIB: foreach my $attrib ( @{$attribs->{$type}} ) { next unless exists $results->{globals}->{$attrib}; - my $store = $results->{globals}->{$attrib}; my $metrics = $ea->stats()->{globals}->{$attrib}; my $func = $attrib =~ m/time|wait$/ ? \µ_t : \&shorten; @@ -7847,6 +7850,25 @@ override query_report => sub { $global_data->{queries_per_second} = $qps if $qps; $global_data->{concurrency} = $conc if $conc; + if ( exists $results->{globals}->{rate_limit} ) { + my $rate_limit = $results->{globals}->{rate_limit}->{min} || ''; + my ($type, $limit) = $rate_limit =~ m/^(\w+):(\d+)$/; + if ( $type && $limit ) { + $global_data->{rate_limit} = { + type => $type, + limit => int($limit), + }; + } + else { + $global_data->{rate_limit}->{error} = "Invalid rate limit: $rate_limit"; + } + + if ( ($results->{globals}->{rate_limit}->{min} || '') + ne ($results->{globals}->{rate_limit}->{max} || '') ) { + $global_data->{rate_limit}->{diff} = 1; + } + } + my %hidden_attrib = ( arg => 1, fingerprint => 1, @@ -13999,6 +14021,24 @@ sub main { ); } # print + # Combine "# Log_slow_rate_type: query Log_slow_rate_limit: 2" + # as rate_limit=>'query:2'. + $pipeline->add( + name => 'rate limit', + process => sub { + my ( $args ) = @_; + my $event = $args->{event}; + PTDEBUG && _d('callback: rate limit'); + if ( my $limit = $event->{Log_slow_rate_limit} ) { + $event->{rate_limit} = ($event->{Log_slow_rate_type} || 'session') . ":$limit"; + delete $event->{Log_slow_rate_limit}; + delete $event->{Log_slow_rate_type}; + } + return $args; + }, + ); + + # Finally, add aggregator obj for each groupby attrib to the callbacks. # These aggregating objs should be the last pipeline processes. foreach my $i ( 0..$#groupby ) { @@ -14024,6 +14064,7 @@ sub main { ip => 'string', port => 'string', Killed => 'bool', + rate_limit => 'string', }; my $ea = new EventAggregator( diff --git a/lib/JSONReportFormatter.pm b/lib/JSONReportFormatter.pm index badbc267..35bd91a3 100644 --- a/lib/JSONReportFormatter.pm +++ b/lib/JSONReportFormatter.pm @@ -147,6 +147,25 @@ override query_report => sub { $global_data->{queries_per_second} = $qps if $qps; $global_data->{concurrency} = $conc if $conc; + if ( exists $results->{globals}->{rate_limit} ) { + my $rate_limit = $results->{globals}->{rate_limit}->{min} || ''; + my ($type, $limit) = $rate_limit =~ m/^(\w+):(\d+)$/; + if ( $type && $limit ) { + $global_data->{rate_limit} = { + type => $type, + limit => int($limit), + }; + } + else { + $global_data->{rate_limit}->{error} = "Invalid rate limit: $rate_limit"; + } + + if ( ($results->{globals}->{rate_limit}->{min} || '') + ne ($results->{globals}->{rate_limit}->{max} || '') ) { + $global_data->{rate_limit}->{diff} = 1; + } + } + my %hidden_attrib = ( arg => 1, fingerprint => 1, diff --git a/lib/PerconaTest.pm b/lib/PerconaTest.pm index 5a693f87..6bedc994 100644 --- a/lib/PerconaTest.pm +++ b/lib/PerconaTest.pm @@ -39,6 +39,7 @@ use Test::More; use Time::HiRes qw(sleep time); use File::Temp qw(tempfile); use POSIX qw(signal_h); +use Data::Dumper; require Exporter; our @ISA = qw(Exporter); diff --git a/lib/QueryReportFormatter.pm b/lib/QueryReportFormatter.pm index 0c3b64b2..7ec51d06 100644 --- a/lib/QueryReportFormatter.pm +++ b/lib/QueryReportFormatter.pm @@ -272,6 +272,11 @@ sub header { push @result, "# Time range: $time_range"; } + # Third line: rate limiting, if any + if ( $results->{globals}->{rate_limit} ) { + print "# Rate limits apply\n"; + } + # Global column headers push @result, $self->make_global_header(); @@ -287,7 +292,6 @@ sub header { NUM_ATTRIB: foreach my $attrib ( @{$attribs->{$type}} ) { next unless exists $results->{globals}->{$attrib}; - my $store = $results->{globals}->{$attrib}; my $metrics = $ea->stats()->{globals}->{$attrib}; my $func = $attrib =~ m/time|wait$/ ? \µ_t : \&shorten; @@ -684,7 +688,7 @@ sub event_report { push @result, sprintf("# Scores: V/M = %.2f", $val->{variance_to_mean} ); - # Last line before column headers: time range + # Time range if ( $val->{time_range} ) { push @result, "# Time range: $val->{time_range}"; } diff --git a/t/lib/samples/slowlogs/slow059.txt b/t/lib/samples/slowlogs/slow059.txt new file mode 100644 index 00000000..7ee16cd5 --- /dev/null +++ b/t/lib/samples/slowlogs/slow059.txt @@ -0,0 +1,40 @@ +# Time: 131128 1:05:31 +# User@Host: user1[user1] @ localhost [127.0.0.1] Id: 69194 +# Schema: maindb Last_errno: 0 Killed: 0 +# Query_time: 0.000228 Lock_time: 0.000114 Rows_sent: 1 Rows_examined: 1 Rows_affected: 0 +# Bytes_sent: 545 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 +# InnoDB_trx_id: 1A88583F +# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No +# Filesort: No Filesort_on_disk: No Merge_passes: 0 +# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 +# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 +# InnoDB_pages_distinct: 2 +# Log_slow_rate_type: query Log_slow_rate_limit: 2 +SET timestamp=1385600731; +SELECT foo FROM bar WHERE id=1; +# User@Host: user1[user1] @ localhost [127.0.0.1] Id: 69195 +# Schema: maindb Last_errno: 0 Killed: 0 +# Query_time: 0.000237 Lock_time: 0.000122 Rows_sent: 1 Rows_examined: 1 Rows_affected: 0 +# Bytes_sent: 545 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 +# InnoDB_trx_id: 1A885840 +# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No +# Filesort: No Filesort_on_disk: No Merge_passes: 0 +# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 +# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 +# InnoDB_pages_distinct: 2 +# Log_slow_rate_type: query Log_slow_rate_limit: 2 +SET timestamp=1385600731; +SELECT foo FROM bar WHERE id=2; +# User@Host: user1[user1] @ localhost [127.0.0.1] Id: 69195 +# Schema: maindb Last_errno: 0 Killed: 0 +# Query_time: 0.000165 Lock_time: 0.000048 Rows_sent: 5 Rows_examined: 10 Rows_affected: 0 +# Bytes_sent: 481 Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0 +# InnoDB_trx_id: 1A885842 +# QC_Hit: No Full_scan: No Full_join: No Tmp_table: No Tmp_table_on_disk: No +# Filesort: Yes Filesort_on_disk: No Merge_passes: 0 +# InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000 +# InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000 +# InnoDB_pages_distinct: 3 +# Log_slow_rate_type: query Log_slow_rate_limit: 2 +SET timestamp=1385600731; +INSERT INTO foo VALUES (NULL, 3); diff --git a/t/pt-query-digest/json.t b/t/pt-query-digest/json.t index b1b84875..245fbd2b 100644 --- a/t/pt-query-digest/json.t +++ b/t/pt-query-digest/json.t @@ -61,6 +61,21 @@ ok( 'json output for for tcpdump021', ) or diag($test_diff); +# ############################################################################# +# pt-query-digest support for Percona Server slow log rate limiting +# https://blueprints.launchpad.net/percona-toolkit/+spec/pt-query-digest-rate-limit +# ############################################################################# +ok( + no_diff( + sub { pt_query_digest::main(@args, + "$trunk/t/lib/samples/slowlogs/slow059.txt", + qw(--output json)) + }, + "t/pt-query-digest/samples/slow059_report02.txt" + ), + 'json output for slow059' +) or diag($test_diff); + # ############################################################################# # Done. # ############################################################################# diff --git a/t/pt-query-digest/samples/slow059_report01.txt b/t/pt-query-digest/samples/slow059_report01.txt new file mode 100644 index 00000000..15777bd1 --- /dev/null +++ b/t/pt-query-digest/samples/slow059_report01.txt @@ -0,0 +1,127 @@ +# Rate limits apply + +# Overall: 3 total, 2 unique, 0 QPS, 0x concurrency ______________________ +# Time range: all events occurred at 2013-11-28 01:05:31 +# Attribute total min max avg 95% stddev median +# ============ ======= ======= ======= ======= ======= ======= ======= +# Exec time 630us 165us 237us 210us 236us 33us 224us +# Lock time 284us 48us 122us 94us 119us 32us 113us +# Rows sent 7 1 5 2.33 4.96 1.87 0.99 +# Rows examine 12 1 10 4 9.83 4.17 0.99 +# Rows affecte 0 0 0 0 0 0 0 +# Bytes sent 1.53k 481 545 523.67 537.02 32 537.02 +# Merge passes 0 0 0 0 0 0 0 +# Tmp tables 0 0 0 0 0 0 0 +# Tmp disk tbl 0 0 0 0 0 0 0 +# Tmp tbl size 0 0 0 0 0 0 0 +# Query size 92 30 32 30.67 31.70 1 28.75 +# InnoDB: +# IO r bytes 0 0 0 0 0 0 0 +# IO r ops 0 0 0 0 0 0 0 +# IO r wait 0 0 0 0 0 0 0 +# pages distin 7 2 3 2.33 2.90 0.44 1.96 +# queue wait 0 0 0 0 0 0 0 +# rec lock wai 0 0 0 0 0 0 0 +# Boolean: +# Filesort 33% yes, 66% no + +# Query 1: 0 QPS, 0x concurrency, ID 0x9EA505F4786E7F15 at byte 733 ______ +# This item is included in the report because it matches --limit. +# Scores: V/M = 0.00 +# Time range: all events occurred at 2013-11-28 01:05:31 +# Attribute pct total min max avg 95% stddev median +# ============ === ======= ======= ======= ======= ======= ======= ======= +# Count 66 2 +# Exec time 73 465us 228us 237us 232us 237us 6us 232us +# Lock time 83 236us 114us 122us 118us 122us 5us 118us +# Rows sent 28 2 1 1 1 1 0 1 +# Rows examine 16 2 1 1 1 1 0 1 +# Rows affecte 0 0 0 0 0 0 0 0 +# Bytes sent 69 1.06k 545 545 545 545 0 545 +# Merge passes 0 0 0 0 0 0 0 0 +# Tmp tables 0 0 0 0 0 0 0 0 +# Tmp disk tbl 0 0 0 0 0 0 0 0 +# Tmp tbl size 0 0 0 0 0 0 0 0 +# Query size 65 60 30 30 30 30 0 30 +# InnoDB: +# IO r bytes 0 0 0 0 0 0 0 0 +# IO r ops 0 0 0 0 0 0 0 0 +# IO r wait 0 0 0 0 0 0 0 0 +# pages distin 57 4 2 2 2 2 0 2 +# queue wait 0 0 0 0 0 0 0 0 +# rec lock wai 0 0 0 0 0 0 0 0 +# String: +# Databases maindb +# Hosts localhost +# InnoDB trxID 1A88583F (1/50%), 1A885840 (1/50%) +# Last errno 0 +# rate limit query:2 +# Users user1 +# Query_time distribution +# 1us +# 10us +# 100us ################################################################ +# 1ms +# 10ms +# 100ms +# 1s +# 10s+ +# Tables +# SHOW TABLE STATUS FROM `maindb` LIKE 'bar'\G +# SHOW CREATE TABLE `maindb`.`bar`\G +# EXPLAIN /*!50100 PARTITIONS*/ +SELECT foo FROM bar WHERE id=2\G + +# Query 2: 0 QPS, 0x concurrency, ID 0xD2BA209E593ABAA7 at byte 1441 _____ +# This item is included in the report because it matches --limit. +# Scores: V/M = 0.00 +# Time range: all events occurred at 2013-11-28 01:05:31 +# Attribute pct total min max avg 95% stddev median +# ============ === ======= ======= ======= ======= ======= ======= ======= +# Count 33 1 +# Exec time 26 165us 165us 165us 165us 165us 0 165us +# Lock time 16 48us 48us 48us 48us 48us 0 48us +# Rows sent 71 5 5 5 5 5 0 5 +# Rows examine 83 10 10 10 10 10 0 10 +# Rows affecte 0 0 0 0 0 0 0 0 +# Bytes sent 30 481 481 481 481 481 0 481 +# Merge passes 0 0 0 0 0 0 0 0 +# Tmp tables 0 0 0 0 0 0 0 0 +# Tmp disk tbl 0 0 0 0 0 0 0 0 +# Tmp tbl size 0 0 0 0 0 0 0 0 +# Query size 34 32 32 32 32 32 0 32 +# InnoDB: +# IO r bytes 0 0 0 0 0 0 0 0 +# IO r ops 0 0 0 0 0 0 0 0 +# IO r wait 0 0 0 0 0 0 0 0 +# pages distin 42 3 3 3 3 3 0 3 +# queue wait 0 0 0 0 0 0 0 0 +# rec lock wai 0 0 0 0 0 0 0 0 +# Boolean: +# Filesort 100% yes, 0% no +# String: +# Databases maindb +# Hosts localhost +# InnoDB trxID 1A885842 +# Last errno 0 +# rate limit query:2 +# Users user1 +# Query_time distribution +# 1us +# 10us +# 100us ################################################################ +# 1ms +# 10ms +# 100ms +# 1s +# 10s+ +# Tables +# SHOW TABLE STATUS FROM `maindb` LIKE 'foo'\G +# SHOW CREATE TABLE `maindb`.`foo`\G +INSERT INTO foo VALUES (NULL, 3)\G + +# Profile +# Rank Query ID Response time Calls R/Call V/M Item +# ==== ================== ============= ===== ====== ===== ========== +# 1 0x9EA505F4786E7F15 0.0005 73.8% 2 0.0002 0.00 SELECT bar +# 2 0xD2BA209E593ABAA7 0.0002 26.2% 1 0.0002 0.00 INSERT foo diff --git a/t/pt-query-digest/samples/slow059_report02.txt b/t/pt-query-digest/samples/slow059_report02.txt new file mode 100644 index 00000000..31fc28fa --- /dev/null +++ b/t/pt-query-digest/samples/slow059_report02.txt @@ -0,0 +1,680 @@ + +{ + "classes" : [ + { + "attribute" : "fingerprint", + "checksum" : "9EA505F4786E7F15", + "distillate" : "SELECT bar", + "example" : { + "Query_time" : "0.000237", + "query" : "SELECT foo FROM bar WHERE id=2", + "ts" : "2013-11-28 01:05:31" + }, + "fingerprint" : "select foo from bar where id=?", + "histograms" : { + "Query_time" : [ + 0, + 0, + 2, + 0, + 0, + 0, + 0, + 0 + ] + }, + "metrics" : { + "Bytes_sent" : { + "avg" : "545", + "max" : "545", + "median" : "545", + "min" : "545", + "pct" : "0", + "pct_95" : "545", + "stddev" : "0", + "sum" : "1090" + }, + "Filesort" : { + "yes" : "0" + }, + "Filesort_on_disk" : { + "yes" : "0" + }, + "Full_join" : { + "yes" : "0" + }, + "Full_scan" : { + "yes" : "0" + }, + "InnoDB_IO_r_bytes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_ops" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.666667", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_pages_distinct" : { + "avg" : "2", + "max" : "2", + "median" : "2", + "min" : "2", + "pct" : "0", + "pct_95" : "2", + "stddev" : "0", + "sum" : "4" + }, + "InnoDB_queue_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.666667", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_rec_lock_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.666667", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_trx_id" : { + "value" : "1A885840" + }, + "Killed" : { + "yes" : "0" + }, + "Last_errno" : { + "value" : "0" + }, + "Lock_time" : { + "avg" : "0.000118", + "max" : "0.000122", + "median" : "0.000118", + "min" : "0.000114", + "pct" : "0.666667", + "pct_95" : "0.000122", + "stddev" : "0.000006", + "sum" : "0.000236" + }, + "Merge_passes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "QC_Hit" : { + "yes" : "0" + }, + "Query_length" : { + "avg" : "30", + "max" : "30", + "median" : "30", + "min" : "30", + "pct" : "0", + "pct_95" : "30", + "stddev" : "0", + "sum" : "60" + }, + "Query_time" : { + "avg" : "0.000233", + "max" : "0.000237", + "median" : "0.000233", + "min" : "0.000228", + "pct" : "0.666667", + "pct_95" : "0.000237", + "stddev" : "0.000006", + "sum" : "0.000465" + }, + "Rows_examined" : { + "avg" : "1", + "max" : "1", + "median" : "1", + "min" : "1", + "pct" : "0", + "pct_95" : "1", + "stddev" : "0", + "sum" : "2" + }, + "Rows_sent" : { + "avg" : "1", + "max" : "1", + "median" : "1", + "min" : "1", + "pct" : "0", + "pct_95" : "1", + "stddev" : "0", + "sum" : "2" + }, + "Tmp_disk_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_table" : { + "yes" : "0" + }, + "Tmp_table_on_disk" : { + "yes" : "0" + }, + "Tmp_table_sizes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "db" : { + "value" : "maindb" + }, + "host" : { + "value" : "localhost" + }, + "rate_limit" : { + "value" : "query:2" + }, + "user" : { + "value" : "user1" + } + }, + "query_count" : 2, + "tables" : [ + { + "create" : "SHOW CREATE TABLE `maindb`.`bar`\\G", + "status" : "SHOW TABLE STATUS FROM `maindb` LIKE 'bar'\\G" + } + ], + "ts_max" : "2013-11-28 01:05:31", + "ts_min" : "2013-11-28 01:05:31" + }, + { + "attribute" : "fingerprint", + "checksum" : "D2BA209E593ABAA7", + "distillate" : "INSERT foo", + "example" : { + "Query_time" : "0.000165", + "query" : "INSERT INTO foo VALUES (NULL, 3)", + "ts" : "2013-11-28 01:05:31" + }, + "fingerprint" : "insert into foo values(?+)", + "histograms" : { + "Query_time" : [ + 0, + 0, + 1, + 0, + 0, + 0, + 0, + 0 + ] + }, + "metrics" : { + "Bytes_sent" : { + "avg" : "481", + "max" : "481", + "median" : "481", + "min" : "481", + "pct" : "0", + "pct_95" : "481", + "stddev" : "0", + "sum" : "481" + }, + "Filesort" : { + "yes" : "1" + }, + "Filesort_on_disk" : { + "yes" : "0" + }, + "Full_join" : { + "yes" : "0" + }, + "Full_scan" : { + "yes" : "0" + }, + "InnoDB_IO_r_bytes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_ops" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.333333", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_pages_distinct" : { + "avg" : "3", + "max" : "3", + "median" : "3", + "min" : "3", + "pct" : "0", + "pct_95" : "3", + "stddev" : "0", + "sum" : "3" + }, + "InnoDB_queue_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.333333", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_rec_lock_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct" : "0.333333", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_trx_id" : { + "value" : "1A885842" + }, + "Killed" : { + "yes" : "0" + }, + "Last_errno" : { + "value" : "0" + }, + "Lock_time" : { + "avg" : "0.000048", + "max" : "0.000048", + "median" : "0.000048", + "min" : "0.000048", + "pct" : "0.333333", + "pct_95" : "0.000048", + "stddev" : "0.000000", + "sum" : "0.000048" + }, + "Merge_passes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "QC_Hit" : { + "yes" : "0" + }, + "Query_length" : { + "avg" : "32", + "max" : "32", + "median" : "32", + "min" : "32", + "pct" : "0", + "pct_95" : "32", + "stddev" : "0", + "sum" : "32" + }, + "Query_time" : { + "avg" : "0.000165", + "max" : "0.000165", + "median" : "0.000165", + "min" : "0.000165", + "pct" : "0.333333", + "pct_95" : "0.000165", + "stddev" : "0.000000", + "sum" : "0.000165" + }, + "Rows_affected" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Rows_examined" : { + "avg" : "10", + "max" : "10", + "median" : "10", + "min" : "10", + "pct" : "0", + "pct_95" : "10", + "stddev" : "0", + "sum" : "10" + }, + "Rows_sent" : { + "avg" : "5", + "max" : "5", + "median" : "5", + "min" : "5", + "pct" : "0", + "pct_95" : "5", + "stddev" : "0", + "sum" : "5" + }, + "Tmp_disk_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_table" : { + "yes" : "0" + }, + "Tmp_table_on_disk" : { + "yes" : "0" + }, + "Tmp_table_sizes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "db" : { + "value" : "maindb" + }, + "host" : { + "value" : "localhost" + }, + "rate_limit" : { + "value" : "query:2" + }, + "user" : { + "value" : "user1" + } + }, + "query_count" : 1, + "tables" : [ + { + "create" : "SHOW CREATE TABLE `maindb`.`foo`\\G", + "status" : "SHOW TABLE STATUS FROM `maindb` LIKE 'foo'\\G" + } + ], + "ts_max" : "2013-11-28 01:05:31", + "ts_min" : "2013-11-28 01:05:31" + } + ], + "global" : { + "files" : [ + { + "name" : "/Users/daniel/p/pqd-ps-rate/t/lib/samples/slowlogs/slow059.txt", + "size" : 2152 + } + ], + "metrics" : { + "Bytes_sent" : { + "avg" : "523", + "max" : "545", + "median" : "537", + "min" : "481", + "pct_95" : "537", + "stddev" : "32", + "sum" : "1571" + }, + "Filesort" : { + "cnt" : "1" + }, + "Filesort_on_disk" : { + "cnt" : "0" + }, + "Full_join" : { + "cnt" : "0" + }, + "Full_scan" : { + "cnt" : "0" + }, + "InnoDB_IO_r_bytes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_ops" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "InnoDB_IO_r_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_pages_distinct" : { + "avg" : "2", + "max" : "3", + "median" : "1", + "min" : "2", + "pct_95" : "2", + "stddev" : "0", + "sum" : "7" + }, + "InnoDB_queue_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "InnoDB_rec_lock_wait" : { + "avg" : "0.000000", + "max" : "0.000000", + "median" : "0.000000", + "min" : "0.000000", + "pct_95" : "0.000000", + "stddev" : "0.000000", + "sum" : "0.000000" + }, + "Killed" : { + "cnt" : "0" + }, + "Lock_time" : { + "avg" : "0.000095", + "max" : "0.000122", + "median" : "0.000114", + "min" : "0.000048", + "pct_95" : "0.000119", + "stddev" : "0.000033", + "sum" : "0.000284" + }, + "Merge_passes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "QC_Hit" : { + "cnt" : "0" + }, + "Query_length" : { + "avg" : "30", + "max" : "32", + "median" : "28", + "min" : "30", + "pct_95" : "31", + "stddev" : "1", + "sum" : "92" + }, + "Query_time" : { + "avg" : "0.000210", + "max" : "0.000237", + "median" : "0.000225", + "min" : "0.000165", + "pct_95" : "0.000236", + "stddev" : "0.000034", + "sum" : "0.000630" + }, + "Rows_affected" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Rows_examined" : { + "avg" : "4", + "max" : "10", + "median" : "0", + "min" : "1", + "pct_95" : "9", + "stddev" : "4", + "sum" : "12" + }, + "Rows_sent" : { + "avg" : "2", + "max" : "5", + "median" : "0", + "min" : "1", + "pct_95" : "4", + "stddev" : "1", + "sum" : "7" + }, + "Tmp_disk_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_table" : { + "cnt" : "0" + }, + "Tmp_table_on_disk" : { + "cnt" : "0" + }, + "Tmp_table_sizes" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + }, + "Tmp_tables" : { + "avg" : "0", + "max" : "0", + "median" : "0", + "min" : "0", + "pct_95" : "0", + "stddev" : "0", + "sum" : "0" + } + }, + "query_count" : 3, + "rate_limit" : { + "limit" : 2, + "type" : "query" + }, + "unique_query_count" : 2 + } +} diff --git a/t/pt-query-digest/slowlog_analyses.t b/t/pt-query-digest/slowlog_analyses.t index 7e6c7c20..5cf5aac8 100644 --- a/t/pt-query-digest/slowlog_analyses.t +++ b/t/pt-query-digest/slowlog_analyses.t @@ -423,6 +423,20 @@ ok( 'Analysis for slow058 (bug 821692, bug 984053)' ) or diag($test_diff); +# ############################################################################# +# pt-query-digest support for Percona Server slow log rate limiting +# https://blueprints.launchpad.net/percona-toolkit/+spec/pt-query-digest-rate-limit +# ############################################################################# +ok( + no_diff( + sub { pt_query_digest::main(@args, $sample.'slow059.txt', + '--report-format', 'header,query_report,profile') + }, + "t/pt-query-digest/samples/slow059_report01.txt" + ), + 'Analysis for slow059 with rate limiting' +) or diag($test_diff); + # ############################################################################# # Done. # #############################################################################