Fix prepared report for statements without corresponding prep or exec.

This commit is contained in:
Daniel Nichter
2011-11-08 12:53:50 -07:00
parent 4f1fa405b7
commit 2f9ab4081a
9 changed files with 200 additions and 19 deletions

View File

@@ -6877,12 +6877,28 @@ sub prepared {
}
if ( !$seen_prepared{$prep_stmt}++ ) {
$exec = $ea->results->{classes}->{$exec_stmt};
$exec_r = $exec->{Query_time}->{sum};
$exec_cnt = $exec->{Query_time}->{cnt};
$prep = $ea->results->{classes}->{$prep_stmt};
$prep_r = $prep->{Query_time}->{sum};
$prep_cnt = scalar keys %{$prep->{Statement_id}->{unq}},
if ( exists $ea->results->{classes}->{$exec_stmt} ) {
$exec = $ea->results->{classes}->{$exec_stmt};
$exec_r = $exec->{Query_time}->{sum};
$exec_cnt = $exec->{Query_time}->{cnt};
}
else {
MKDEBUG && _d('Statement prepared but not executed:', $item);
$exec_r = 0;
$exec_cnt = 0;
}
if ( exists $ea->results->{classes}->{$prep_stmt} ) {
$prep = $ea->results->{classes}->{$prep_stmt};
$prep_r = $prep->{Query_time}->{sum};
$prep_cnt = scalar keys %{$prep->{Statement_id}->{unq}},
}
else {
MKDEBUG && _d('Statement executed but not prepared:', $item);
$prep_r = 0;
$prep_cnt = 0;
}
push @prepared, {
prep_r => $prep_r,
prep_cnt => $prep_cnt,

View File

@@ -163,6 +163,7 @@ sub output {
close *output_fh;
if ( $EVAL_ERROR ) {
die $EVAL_ERROR if $die;
warn $EVAL_ERROR unless $args{stderr};
return $EVAL_ERROR;
}

View File

@@ -1018,12 +1018,28 @@ sub prepared {
# Report each PREPARE/EXECUTE pair once.
if ( !$seen_prepared{$prep_stmt}++ ) {
$exec = $ea->results->{classes}->{$exec_stmt};
$exec_r = $exec->{Query_time}->{sum};
$exec_cnt = $exec->{Query_time}->{cnt};
$prep = $ea->results->{classes}->{$prep_stmt};
$prep_r = $prep->{Query_time}->{sum};
$prep_cnt = scalar keys %{$prep->{Statement_id}->{unq}},
if ( exists $ea->results->{classes}->{$exec_stmt} ) {
$exec = $ea->results->{classes}->{$exec_stmt};
$exec_r = $exec->{Query_time}->{sum};
$exec_cnt = $exec->{Query_time}->{cnt};
}
else {
MKDEBUG && _d('Statement prepared but not executed:', $item);
$exec_r = 0;
$exec_cnt = 0;
}
if ( exists $ea->results->{classes}->{$prep_stmt} ) {
$prep = $ea->results->{classes}->{$prep_stmt};
$prep_r = $prep->{Query_time}->{sum};
$prep_cnt = scalar keys %{$prep->{Statement_id}->{unq}},
}
else {
MKDEBUG && _d('Statement executed but not prepared:', $item);
$prep_r = 0;
$prep_cnt = 0;
}
push @prepared, {
prep_r => $prep_r,
prep_cnt => $prep_cnt,

View File

@@ -9,7 +9,7 @@ BEGIN {
use strict;
use warnings FATAL => 'all';
use English qw(-no_match_vars);
use Test::More tests => 43;
use Test::More tests => 44;
use Data::Dumper;
$Data::Dumper::Indent = 1;
@@ -1010,8 +1010,11 @@ $events = [
},
];
$ea = new EventAggregator(
groupby => 'fingerprint',
worst => 'Query_time',
groupby => 'fingerprint',
worst => 'Query_time',
type_for => {
Statement_id => 'string',
},
);
foreach my $event ( @$events ) {
$ea->aggregate($event);
@@ -1499,6 +1502,60 @@ ok(
'Sparkchart in event header'
);
# ############################################################################
# Bug 887688: Prepared statements crash pt-query-digest
# ############################################################################
# PREP without EXEC
$events = [
{
Query_time => '0.000286',
Warning_count => 0,
arg => 'PREPARE SELECT i FROM d.t WHERE i=?',
fingerprint => 'prepare select i from d.t where i=?',
bytes => 35,
cmd => 'Query',
db => undef,
pos_in_log => 0,
ts => '091208 09:23:49.637394',
Statement_id => 1,
},
];
$ea = new EventAggregator(
groupby => 'fingerprint',
worst => 'Query_time',
type_for => {
Statement_id => 'string',
},
);
foreach my $event ( @$events ) {
$ea->aggregate($event);
}
$ea->calculate_statistical_metrics();
$report = new ReportFormatter(
line_width => 82,
extend_right => 1,
);
$qrf->set_report_formatter(report=>'prepared', formatter=>$report);
ok(
no_diff(
sub {
$qrf->print_reports(
reports => ['prepared'],
ea => $ea,
worst => [
['prepare select i from d.t where i=?', 'top', 1],
],
orderby => 'Query_time',
groupby => 'fingerprint',
variations => [qw(arg)],
);
},
"t/lib/samples/QueryReportFormatter/report030.txt",
),
"PREP without EXEC (bug 887688)"
);
# #############################################################################
# Done.
# #############################################################################

View File

@@ -8,10 +8,10 @@
# Count 50 1
# Exec time 99 30ms 30ms 30ms 30ms 30ms 0 30ms
# Query size 51 37 37 37 37 37 0 37
# Statement id 50 2 2 2 2 2 0 2
# Warning coun 0 0 0 0 0 0 0 0
# String:
# cmd Query
# Statement id 2
# Query_time distribution
# 1us
# 10us
@@ -39,10 +39,10 @@ SELECT i FROM d.t WHERE i="3"\G
# Count 50 1
# Exec time 0 286us 286us 286us 286us 286us 0 286us
# Query size 48 35 35 35 35 35 0 35
# Statement id 50 2 2 2 2 2 0 2
# Warning coun 0 0 0 0 0 0 0 0
# String:
# cmd Query
# Statement id 2
# Query_time distribution
# 1us
# 10us
@@ -64,4 +64,4 @@ SELECT i FROM d.t WHERE i=?\G
# Prepared statements
# Rank Query ID PREP PREP Response EXEC EXEC Response Item
# ==== ================== ==== ============= ==== ============= ==========
# 1 0x3F79759E7FA2F117 0 0.0003 0.9% 1 0.0303 99.1% SELECT d.t
# 1 0x3F79759E7FA2F117 1 0.0003 0.9% 1 0.0303 99.1% SELECT d.t

View File

@@ -0,0 +1,5 @@
# Prepared statements
# Rank Query ID PREP PREP Response EXEC EXEC Response Item
# ==== ================== ==== ============= ==== ============= ==========
# 1 0xAA8E9FA785927259 1 0.0003 100.0% 0 0.0000 0.0% SELECT d.t

View File

@@ -0,0 +1,22 @@
2009-12-08 09:23:49.637108 IP 127.0.0.1.58619 > 127.0.0.1.12345: tcp 32
0x0000: 4508 0054 b468 4000 4006 8831 7f00 0001
0x0010: 7f00 0001 e4fb 3039 47e2 1612 4850 bc0a
0x0020: 8018 0101 fe48 0000 0101 080a 000f a420
0x0030: 000f a13c 1c00 0000 1653 454c 4543 5420
0x0040: 6920 4652 4f4d 2064 2e74 2057 4845 5245
0x0050: 2069 3d3f
2009-12-08 09:23:49.637194 IP 127.0.0.1.12345 > 127.0.0.1.58619: tcp 0
0x0000: 4508 0034 1ab3 4000 4006 2207 7f00 0001
0x0010: 7f00 0001 3039 e4fb 4850 bc0a 47e2 1632
0x0020: 8010 0100 b7b7 0000 0101 080a 000f a420
0x0030: 000f a420
2009-12-08 09:23:49.637394 IP 127.0.0.1.12345 > 127.0.0.1.58619: tcp 92
0x0000: 4508 0090 1ab4 4000 4006 21aa 7f00 0001
0x0010: 7f00 0001 3039 e4fb 4850 bc0a 47e2 1632
0x0020: 8018 0100 fe84 0000 0101 080a 000f a420
0x0030: 000f a420 0c00 0001 0002 0000 0001 0001
0x0040: 0000 0000 1700 0002 0364 6566 0000 0001
0x0050: 3f00 0c3f 0000 0000 00fd 8000 0000 0005
0x0060: 0000 03fe 0000 0200 1b00 0004 0364 6566
0x0070: 0164 0174 0174 0169 0169 0c3f 000b 0000
0x0080: 0003 0000 0000 0005 0000 05fe 0000 0200

View File

@@ -9,7 +9,7 @@ BEGIN {
use strict;
use warnings FATAL => 'all';
use English qw(-no_match_vars);
use Test::More tests => 6;
use Test::More tests => 7;
use PerconaTest;
@@ -69,6 +69,18 @@ ok(
'Analysis for tcpdump033 with prepared statements report'
);
# ############################################################################
# Bug 887688: Prepared statements crash pt-query-digest
# ############################################################################
ok(
no_diff(
sub { pt_query_digest::main(@args, $sample.'tcpdump041.txt',
'--report-format', 'header,query_report,profile,prepared') },
"t/pt-query-digest/samples/tcpdump041.txt",
),
'Analysis for tcpdump041 (bug 887688)'
);
# #############################################################################
# Done.
# #############################################################################

View File

@@ -0,0 +1,52 @@
# Overall: 1 total, 1 unique, 0 QPS, 0x concurrency ______________________
# Time range: all events occurred at 2009-12-08 09:23:49.637394
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 286us 286us 286us 286us 286us 0 286us
# Rows affecte 0 0 0 0 0 0 0
# Query size 35 35 35 35 35 0 35
# Warning coun 0 0 0 0 0 0 0
# Query 1: 0 QPS, 0x concurrency, ID 0xAA8E9FA785927259 at byte 0 ________
# This item is included in the report because it matches --limit.
# Scores: Apdex = 1.00 [1.0]*, V/M = 0.00
# Query_time sparkline: | ^ |
# Time range: all events occurred at 2009-12-08 09:23:49.637394
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 100 1
# Exec time 100 286us 286us 286us 286us 286us 0 286us
# Rows affecte 0 0 0 0 0 0 0 0
# Query size 100 35 35 35 35 35 0 35
# Warning coun 0 0 0 0 0 0 0 0
# String:
# Errors none
# Hosts 127.0.0.1
# Statement id 2
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS FROM `d` LIKE 't'\G
# SHOW CREATE TABLE `d`.`t`\G
PREPARE SELECT i FROM d.t WHERE i=?\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
SELECT i FROM d.t WHERE i=?\G
# Profile
# Rank Query ID Response time Calls R/Call Apdx V/M Item
# ==== ================== ============= ===== ====== ==== ===== ==========
# 1 0xAA8E9FA785927259 0.0003 100.0% 1 0.0003 1.00 0.00 SELECT d.t
# Prepared statements
# Rank Query ID PREP PREP Response EXEC EXEC Response Item
# ==== ================== ==== ============= ==== ============= ==========
# 1 0xAA8E9FA785927259 1 0.0003 100.0% 0 0.0000 0.0% SELECT d.t