Add Query_time histogram to json output.

This commit is contained in:
Daniel Nichter
2013-08-16 18:21:57 -07:00
parent 4fcb52f678
commit c3ff530037
7 changed files with 460 additions and 0 deletions

View File

@@ -8023,6 +8023,17 @@ override query_report => sub {
} }
} }
my $vals = $stats->{Query_time}->{all};
if ( defined $vals && scalar %$vals ) {
my @buck_tens = $ea->buckets_of(10);
my @distro = map { 0 } (0 .. 7);
my @buckets = map { 0 } (0..999);
map { $buckets[$_] = $vals->{$_} } keys %$vals;
$vals = \@buckets; # repoint vals from given hashref to our array
map { $distro[$buck_tens[$_]] += $vals->[$_] } (1 .. @$vals - 1);
$class->{histograms}->{Query_time} = \@distro;
} # histogram
$class->{metrics} = \%metrics; $class->{metrics} = \%metrics;
if ( @tables ) { if ( @tables ) {
$class->{tables} = \@tables; $class->{tables} = \@tables;

View File

@@ -368,6 +368,20 @@ override query_report => sub {
} }
} }
# Add reponse time histogram for Query_time
my $vals = $stats->{Query_time}->{all};
if ( defined $vals && scalar %$vals ) {
# TODO: this is broken.
my @buck_tens = $ea->buckets_of(10);
my @distro = map { 0 } (0 .. 7);
my @buckets = map { 0 } (0..999);
map { $buckets[$_] = $vals->{$_} } keys %$vals;
$vals = \@buckets; # repoint vals from given hashref to our array
map { $distro[$buck_tens[$_]] += $vals->[$_] } (1 .. @$vals - 1);
# @distro = qw(1us 10us 100us 1ms 10ms 100ms 1s 10s+)
$class->{histograms}->{Query_time} = \@distro;
} # histogram
$class->{metrics} = \%metrics; $class->{metrics} = \%metrics;
if ( @tables ) { if ( @tables ) {
$class->{tables} = \@tables; $class->{tables} = \@tables;

170
t/lib/JSONReportFormatter.t Normal file
View File

@@ -0,0 +1,170 @@
#!/usr/bin/perl
BEGIN {
die "The PERCONA_TOOLKIT_BRANCH environment variable is not set.\n"
unless $ENV{PERCONA_TOOLKIT_BRANCH} && -d $ENV{PERCONA_TOOLKIT_BRANCH};
unshift @INC, "$ENV{PERCONA_TOOLKIT_BRANCH}/lib";
$ENV{PTTEST_PRETTY_JSON} = 1;
};
use strict;
use warnings FATAL => 'all';
use English qw(-no_match_vars);
use Test::More;
use Data::Dumper;
$Data::Dumper::Indent = 1;
$Data::Dumper::Sortkeys = 1;
$Data::Dumper::Quotekeys = 0;
use JSONReportFormatter;
use OptionParser;
use DSNParser;
use EventAggregator;
use QueryRewriter;
use QueryParser;
use Quoter;
use PerconaTest;
my ($result, $events, $expected);
my $o = new OptionParser(description=>'JSONReportFormatter');
my $q = new Quoter();
my $qp = new QueryParser();
my $qr = new QueryRewriter(QueryParser=>$qp);
$o->get_specs("$trunk/bin/pt-query-digest");
my $j = new JSONReportFormatter(
OptionParser => $o,
QueryRewriter => $qr,
QueryParser => $qp,
Quoter => $q,
);
my $ea = new EventAggregator(
groupby => 'fingerprint',
worst => 'Query_time',
attributes => {
Query_time => [qw(Query_time)],
Lock_time => [qw(Lock_time)],
user => [qw(user)],
ts => [qw(ts)],
Rows_sent => [qw(Rows_sent)],
Rows_examined => [qw(Rows_examined)],
db => [qw(db)],
},
);
isa_ok(
$j,
'JSONReportFormatter'
) or die "Cannot create a JSONReportFormatter";
$events = [
{ ts => '071015 21:43:52',
cmd => 'Query',
user => 'root',
host => 'localhost',
ip => '',
arg => "SELECT id FROM users WHERE name='foo'",
Query_time => '8.000652',
Lock_time => '0.000109',
Rows_sent => 1,
Rows_examined => 1,
pos_in_log => 1,
db => 'test3',
},
{ ts => '071015 21:43:52',
cmd => 'Query',
user => 'root',
host => 'localhost',
ip => '',
arg =>
"INSERT IGNORE INTO articles (id, body,)VALUES(3558268,'sample text')",
Query_time => '1.001943',
Lock_time => '0.000145',
Rows_sent => 0,
Rows_examined => 0,
pos_in_log => 2,
db => 'test1',
},
{ ts => '071015 21:43:53',
cmd => 'Query',
user => 'bob',
host => 'localhost',
ip => '',
arg => "SELECT id FROM users WHERE name='bar'",
Query_time => '1.000682',
Lock_time => '0.000201',
Rows_sent => 1,
Rows_examined => 2,
pos_in_log => 5,
db => 'test1',
}
];
# Here's the breakdown of values for those three events:
#
# ATTRIBUTE VALUE BUCKET VALUE RANGE
# Query_time => 8.000652 326 7.700558026 range [7.700558026, 8.085585927)
# Query_time => 1.001943 284 0.992136979 range [0.992136979, 1.041743827)
# Query_time => 1.000682 284 0.992136979 range [0.992136979, 1.041743827)
# -------- -----------
# 10.003277 9.684831984
#
# Lock_time => 0.000109 97 0.000108186 range [0.000108186, 0.000113596)
# Lock_time => 0.000145 103 0.000144980 range [0.000144980, 0.000152229)
# Lock_time => 0.000201 109 0.000194287 range [0.000194287, 0.000204002)
# -------- -----------
# 0.000455 0.000447453
#
# Rows_sent => 1 284 0.992136979 range [0.992136979, 1.041743827)
# Rows_sent => 0 0 0
# Rows_sent => 1 284 0.992136979 range [0.992136979, 1.041743827)
# -------- -----------
# 2 1.984273958
#
# Rows_exam => 1 284 0.992136979 range [0.992136979, 1.041743827)
# Rows_exam => 0 0 0
# Rows_exam => 2 298 1.964363355, range [1.964363355, 2.062581523)
# -------- -----------
# 3 2.956500334
# I hand-checked these values with my TI-83 calculator.
# They are, without a doubt, correct.
foreach my $event (@$events) {
$event->{fingerprint} = $qr->fingerprint( $event->{arg} );
$ea->aggregate($event);
}
$ea->calculate_statistical_metrics(apdex_t=>1);
my %top_spec = (
attrib => 'Query_time',
orderby => 'sum',
total => 100,
count => undef,
);
@top_spec{qw(ol_attrib ol_limit ol_freq)} = split(/:/, "Query_time:1:10");
my ($worst, $other) = $ea->top_events(%top_spec);
$result = $j->query_report(
ea => $ea,
worst => $worst,
orderby => 'Query_time',
groupby => 'fingerprint',
);
ok(
no_diff(
$result,
"t/lib/samples/JSONReportFormatter/report001.json",
cmd_output => 1,
),
'Basic output'
) or diag($test_diff);
# #############################################################################
# Done.
# #############################################################################
done_testing;

View File

@@ -0,0 +1,205 @@
{
"classes" : [
{
"attribute" : "fingerprint",
"checksum" : "82860EDA9A88FCC5",
"distillate" : "SELECT users",
"example" : {
"query" : "SELECT id FROM users WHERE name='foo'",
"ts" : "2007-10-15 21:43:52"
},
"fingerprint" : "select id from users where name=?",
"histograms" : {
"Query_time" : [
0,
0,
0,
0,
0,
0,
2,
0
]
},
"metrics" : {
"Lock_time" : {
"avg" : "0.000155",
"max" : "0.000201",
"median" : "0.000155",
"min" : "0.000109",
"pct" : "0.666667",
"pct_95" : "0.000201",
"stddev" : "0.000065",
"sum" : "0.000310"
},
"Query_time" : {
"avg" : "4.500667",
"max" : "8.000652",
"median" : "4.500667",
"min" : "1.000682",
"pct" : "0.666667",
"pct_95" : "8.000652",
"stddev" : "4.949726",
"sum" : "9.001334"
},
"Rows_examined" : {
"avg" : "1",
"max" : "2",
"median" : "1",
"min" : "1",
"pct" : "0",
"pct_95" : "2",
"stddev" : "0",
"sum" : "3"
},
"Rows_sent" : {
"avg" : "1",
"max" : "1",
"median" : "1",
"min" : "1",
"pct" : "0",
"pct_95" : "1",
"stddev" : "0",
"sum" : "2"
},
"db" : {
"value" : "test3"
},
"user" : {
"value" : "root"
}
},
"query_count" : null,
"tables" : [
{
"create" : "SHOW CREATE TABLE `test3`.`users`\\G",
"status" : "SHOW TABLE STATUS FROM `test3` LIKE 'users'\\G"
}
],
"ts_max" : "2007-10-15 21:43:53",
"ts_min" : "2007-10-15 21:43:52"
},
{
"attribute" : "fingerprint",
"checksum" : "1087A32FED3B7EBB",
"distillate" : "INSERT articles",
"example" : {
"query" : "INSERT IGNORE INTO articles (id, body,)VALUES(3558268,'sample text')",
"ts" : "2007-10-15 21:43:52"
},
"fingerprint" : "insert ignore into articles (id, body,)values(?+)",
"histograms" : {
"Query_time" : [
0,
0,
0,
0,
0,
0,
1,
0
]
},
"metrics" : {
"Lock_time" : {
"avg" : "0.000145",
"max" : "0.000145",
"median" : "0.000145",
"min" : "0.000145",
"pct" : "0.333333",
"pct_95" : "0.000145",
"stddev" : "0.000000",
"sum" : "0.000145"
},
"Query_time" : {
"avg" : "1.001943",
"max" : "1.001943",
"median" : "1.001943",
"min" : "1.001943",
"pct" : "0.333333",
"pct_95" : "1.001943",
"stddev" : "0.000000",
"sum" : "1.001943"
},
"Rows_examined" : {
"avg" : "0",
"max" : "0",
"median" : "0",
"min" : "0",
"pct" : "0",
"pct_95" : "0",
"stddev" : "0",
"sum" : "0"
},
"Rows_sent" : {
"avg" : "0",
"max" : "0",
"median" : "0",
"min" : "0",
"pct" : "0",
"pct_95" : "0",
"stddev" : "0",
"sum" : "0"
},
"db" : {
"value" : "test1"
},
"user" : {
"value" : "root"
}
},
"query_count" : null,
"tables" : [
{
"create" : "SHOW CREATE TABLE `test1`.`articles`\\G",
"status" : "SHOW TABLE STATUS FROM `test1` LIKE 'articles'\\G"
}
],
"ts_max" : "2007-10-15 21:43:52",
"ts_min" : "2007-10-15 21:43:52"
}
],
"global" : {
"files" : null,
"metrics" : {
"Lock_time" : {
"avg" : "0.000152",
"max" : "0.000201",
"median" : "0.000145",
"min" : "0.000109",
"pct_95" : "0.000194",
"stddev" : "0.000035",
"sum" : "0.000455"
},
"Query_time" : {
"avg" : "3.334426",
"max" : "8.000652",
"median" : "0.992137",
"min" : "1.000682",
"pct_95" : "7.700558",
"stddev" : "3.162380",
"sum" : "10.003277"
},
"Rows_examined" : {
"avg" : "1",
"max" : "2",
"median" : "0",
"min" : "0",
"pct_95" : "1",
"stddev" : "0",
"sum" : "3"
},
"Rows_sent" : {
"avg" : "0",
"max" : "1",
"median" : "0",
"min" : "0",
"pct_95" : "0",
"stddev" : "0",
"sum" : "2"
}
},
"query_count" : 3,
"unique_query_count" : 2
}
}

View File

@@ -6,6 +6,18 @@
"checksum" : "66825DDC008FFA89", "checksum" : "66825DDC008FFA89",
"distillate" : "UPDATE db?.tuningdetail_?_? db?.gonzo", "distillate" : "UPDATE db?.tuningdetail_?_? db?.gonzo",
"fingerprint" : "update d?tuningdetail_?_? n inner join d?gonzo a using(gonzo) set n.column? = a.column?, n.word? = a.word?", "fingerprint" : "update d?tuningdetail_?_? n inner join d?gonzo a using(gonzo) set n.column? = a.column?, n.word? = a.word?",
"histograms" : {
"Query_time" : [
0,
0,
0,
0,
0,
1,
0,
0
]
},
"metrics" : { "metrics" : {
"Filesort" : { "Filesort" : {
"yes" : "0" "yes" : "0"

View File

@@ -11,6 +11,18 @@
"ts" : "2007-12-18 11:48:27" "ts" : "2007-12-18 11:48:27"
}, },
"fingerprint" : "update d?tuningdetail_?_? n inner join d?gonzo a using(gonzo) set n.column? = a.column?, n.word? = a.word?", "fingerprint" : "update d?tuningdetail_?_? n inner join d?gonzo a using(gonzo) set n.column? = a.column?, n.word? = a.word?",
"histograms" : {
"Query_time" : [
0,
0,
0,
0,
0,
1,
0,
0
]
},
"metrics" : { "metrics" : {
"Filesort" : { "Filesort" : {
"yes" : "0" "yes" : "0"

View File

@@ -11,6 +11,18 @@
"ts" : "2009-12-08 09:23:49.637394" "ts" : "2009-12-08 09:23:49.637394"
}, },
"fingerprint" : "prepare select i from d.t where i=?", "fingerprint" : "prepare select i from d.t where i=?",
"histograms" : {
"Query_time" : [
0,
0,
1,
0,
0,
0,
0,
0
]
},
"metrics" : { "metrics" : {
"No_good_index_used" : { "No_good_index_used" : {
"yes" : "0" "yes" : "0"
@@ -75,6 +87,18 @@
"ts" : "2009-12-08 09:23:49.637892" "ts" : "2009-12-08 09:23:49.637892"
}, },
"fingerprint" : "execute select i from d.t where i=?", "fingerprint" : "execute select i from d.t where i=?",
"histograms" : {
"Query_time" : [
0,
0,
1,
0,
0,
0,
0,
0
]
},
"metrics" : { "metrics" : {
"No_good_index_used" : { "No_good_index_used" : {
"yes" : "0" "yes" : "0"
@@ -138,6 +162,18 @@
"ts" : "2009-12-08 09:23:49.638381" "ts" : "2009-12-08 09:23:49.638381"
}, },
"fingerprint" : "administrator command: Quit", "fingerprint" : "administrator command: Quit",
"histograms" : {
"Query_time" : [
0,
0,
0,
0,
0,
0,
0,
0
]
},
"metrics" : { "metrics" : {
"No_good_index_used" : { "No_good_index_used" : {
"yes" : "0" "yes" : "0"