mirror of
https://github.com/percona/percona-toolkit.git
synced 2025-09-01 18:25:59 +00:00
9eb95cb4da
SlowLogParser now is able to handle MySQL dates in RFC3339 format. A new test for this case was added and all scripts using SlowLogParser in bin/ have been updated.
1471 lines
47 KiB
Perl
1471 lines
47 KiB
Perl
#!/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";
|
|
};
|
|
|
|
use strict;
|
|
use warnings FATAL => 'all';
|
|
use English qw(-no_match_vars);
|
|
|
|
use Test::More;
|
|
use SlowLogParser;
|
|
use PerconaTest;
|
|
|
|
my $p = new SlowLogParser;
|
|
my $sample = "t/lib/samples/slowlogs";
|
|
|
|
# Check that we can parse MySQL 5.7+ slow log with dates in RFC3339 format.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/mysql5.7.log",
|
|
result => [
|
|
{
|
|
Lock_time => '0.000324',
|
|
Query_time => '0.003464',
|
|
Rows_examined => '2000',
|
|
Rows_sent => '1000',
|
|
Thread_id => '3',
|
|
arg => 'SELECT * FROM db_facturacion.facturas LIMIT 0, 1000',
|
|
bytes => 51,
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '127.0.0.1',
|
|
pos_in_log => 0,
|
|
timestamp => '1469038405',
|
|
ts => '2016-07-20T18:13:25',
|
|
user => 'root'
|
|
},
|
|
{
|
|
Lock_time => '0.000055',
|
|
Query_time => '0.000241',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '4',
|
|
arg => 'SHOW INDEX FROM `db_facturacion`.`facturas`',
|
|
bytes => 43,
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '127.0.0.1',
|
|
pos_in_log => 608,
|
|
timestamp => '1469038405',
|
|
ts => '2016-07-20T18:13:25',
|
|
user => 'root'
|
|
}
|
|
|
|
],
|
|
);
|
|
# Check that I can parse a slow log in the default slow log format.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow001.txt",
|
|
result => [
|
|
{ ts => '071015 21:43:52',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
db => 'test',
|
|
arg => 'select sleep(2) from n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 0,
|
|
bytes => length('select sleep(2) from n'),
|
|
cmd => 'Query',
|
|
},
|
|
{ ts => '071015 21:45:10',
|
|
db => 'sakila',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
arg => 'select sleep(2) from test.n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 359,
|
|
bytes => length('select sleep(2) from test.n'),
|
|
cmd => 'Query',
|
|
},
|
|
],
|
|
);
|
|
|
|
# This one has complex SET insert_id=34484549,timestamp=1197996507;
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow002.txt",
|
|
result => [
|
|
{ arg => 'BEGIN',
|
|
ts => '071218 11:48:27',
|
|
Filesort_on_disk => 'No',
|
|
Merge_passes => '0',
|
|
Full_scan => 'No',
|
|
Full_join => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
Filesort => 'No',
|
|
Query_time => '0.000012',
|
|
Tmp_table_on_disk => 'No',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000000',
|
|
pos_in_log => 0,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 5,
|
|
},
|
|
{ db => 'db1',
|
|
timestamp => 1197996507,
|
|
arg => 'update db2.tuningdetail_21_265507 n
|
|
inner join db1.gonzo a using(gonzo)
|
|
set n.column1 = a.column1, n.word3 = a.word3',
|
|
Filesort_on_disk => 'No',
|
|
Merge_passes => '0',
|
|
Full_scan => 'Yes',
|
|
Full_join => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '62951',
|
|
Filesort => 'No',
|
|
Query_time => '0.726052',
|
|
Tmp_table_on_disk => 'No',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000091',
|
|
pos_in_log => 338,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 129,
|
|
},
|
|
{ timestamp => 1197996507,
|
|
arg => 'INSERT INTO db3.vendor11gonzo (makef, bizzle)
|
|
VALUES (\'\', \'Exact\')',
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '24',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000077',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.000512',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 815,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 66,
|
|
},
|
|
{ arg => 'UPDATE db4.vab3concept1upload
|
|
SET vab3concept1id = \'91848182522\'
|
|
WHERE vab3concept1upload=\'6994465\'',
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '11',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000028',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.033384',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 1334,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 103,
|
|
},
|
|
{ insert_id => 34484549,
|
|
timestamp => 1197996507,
|
|
arg => 'INSERT INTO db1.conch (word3, vid83)
|
|
VALUES (\'211\', \'18\')',
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '18',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000027',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.000530',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 1864,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 57,
|
|
},
|
|
{ arg => 'UPDATE foo.bar
|
|
SET biz = \'91848182522\'',
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '18',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000027',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.000530',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 2393,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 41,
|
|
},
|
|
{ arg => 'UPDATE bizzle.bat
|
|
SET boop=\'bop: 899\'
|
|
WHERE fillze=\'899\'',
|
|
timestamp => 1197996508,
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '18',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000027',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.000530',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 2861,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 60,
|
|
},
|
|
{ arg => 'UPDATE foo.bar
|
|
SET biz = \'91848182522\'',
|
|
InnoDB_IO_r_bytes => '0',
|
|
Merge_passes => '0',
|
|
Full_join => 'No',
|
|
InnoDB_pages_distinct => '18',
|
|
Filesort => 'No',
|
|
InnoDB_queue_wait => '0.000000',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000027',
|
|
InnoDB_rec_lock_wait => '0.000000',
|
|
Full_scan => 'No',
|
|
Filesort_on_disk => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
InnoDB_IO_r_ops => '0',
|
|
Tmp_table_on_disk => 'No',
|
|
Query_time => '0.000530',
|
|
InnoDB_IO_r_wait => '0.000000',
|
|
pos_in_log => 3374,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 41,
|
|
},
|
|
],
|
|
);
|
|
|
|
# Microsecond format.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/microslow001.txt",
|
|
result => [
|
|
{ ts => '071015 21:43:52',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
arg => "SELECT id FROM users WHERE name='baouong'",
|
|
Query_time => '0.000652',
|
|
Lock_time => '0.000109',
|
|
Rows_sent => 1,
|
|
Rows_examined => 1,
|
|
pos_in_log => 0,
|
|
cmd => 'Query',
|
|
bytes => 41,
|
|
},
|
|
{ ts => '071015 21:43:52',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
arg =>
|
|
"INSERT IGNORE INTO articles (id, body,)VALUES(3558268,'sample text')",
|
|
Query_time => '0.001943',
|
|
Lock_time => '0.000145',
|
|
Rows_sent => 0,
|
|
Rows_examined => 0,
|
|
pos_in_log => 183,
|
|
cmd => 'Query',
|
|
bytes => 68,
|
|
},
|
|
],
|
|
);
|
|
|
|
# A log that starts with a blank line.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow003.txt",
|
|
result => [
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'BEGIN',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '0',
|
|
ts => '071218 11:48:27',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 5,
|
|
},
|
|
],
|
|
);
|
|
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow004.txt",
|
|
result => [
|
|
{ Lock_time => '0',
|
|
Query_time => '2',
|
|
Rows_examined => '0',
|
|
Rows_sent => '1',
|
|
arg => 'select 12_13_foo from (select 12foo from 123_bar) as 123baz',
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '',
|
|
pos_in_log => '0',
|
|
ts => '071015 21:43:52',
|
|
user => 'root',
|
|
bytes => 59,
|
|
},
|
|
],
|
|
);
|
|
|
|
# Check a slow log that has tabs in it.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow005.txt",
|
|
result => [
|
|
{ arg => "foo\nbar\n\t\t\t0 AS counter\nbaz",
|
|
ts => '071218 11:48:27',
|
|
Filesort_on_disk => 'No',
|
|
Merge_passes => '0',
|
|
Full_scan => 'No',
|
|
Full_join => 'No',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
Filesort => 'No',
|
|
Query_time => '0.000012',
|
|
Tmp_table_on_disk => 'No',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000000',
|
|
pos_in_log => 0,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 27,
|
|
},
|
|
],
|
|
);
|
|
|
|
# A bunch of case-sensitive and case-insensitive USE stuff.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow006.txt",
|
|
result => [
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '0',
|
|
ts => '071218 11:48:27',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '369',
|
|
ts => '071218 11:48:57',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '20',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
db => 'bar',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '737',
|
|
ts => '071218 11:48:57',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'bar',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1101',
|
|
ts => '071218 11:49:05',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '20',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
db => 'bar',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1469',
|
|
ts => '071218 11:49:07',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '30',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1833',
|
|
ts => '071218 11:49:30',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
}
|
|
],
|
|
);
|
|
|
|
# Schema
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow007.txt",
|
|
result => [
|
|
{ Schema => 'food',
|
|
arg => 'SELECT fruit FROM trees',
|
|
ts => '071218 11:48:27',
|
|
Filesort_on_disk => 'No',
|
|
Merge_passes => '0',
|
|
Full_scan => 'No',
|
|
Full_join => 'No',
|
|
Thread_id => '3',
|
|
Tmp_table => 'No',
|
|
QC_Hit => 'No',
|
|
Rows_examined => '0',
|
|
Filesort => 'No',
|
|
Query_time => '0.000012',
|
|
Tmp_table_on_disk => 'No',
|
|
Rows_sent => '0',
|
|
Lock_time => '0.000000',
|
|
pos_in_log => 0,
|
|
cmd => 'Query',
|
|
user => '[SQL_SLAVE]',
|
|
host => '',
|
|
ip => '',
|
|
bytes => 23,
|
|
},
|
|
],
|
|
);
|
|
|
|
# Check for number of events to see that it doesn't just run forever
|
|
# to the end of the file without returning between events.
|
|
# Also check it parses commented event (admin cmd).
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow008.txt",
|
|
num_events => 3,
|
|
result => [
|
|
{ 'Schema' => 'db1',
|
|
'cmd' => 'Admin',
|
|
'ip' => '1.2.3.8',
|
|
'arg' => 'administrator command: Quit',
|
|
'Thread_id' => '5',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.000002',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 0,
|
|
bytes => 27,
|
|
},
|
|
{ 'Schema' => 'db2',
|
|
'cmd' => 'Query',
|
|
'db' => 'db',
|
|
'ip' => '1.2.3.8',
|
|
arg => 'SET NAMES utf8',
|
|
'Thread_id' => '6',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.000899',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 221,
|
|
bytes => 14,
|
|
},
|
|
{ 'Schema' => 'db2',
|
|
'cmd' => 'Query',
|
|
'arg' => 'SELECT MIN(id),MAX(id) FROM tbl',
|
|
'ip' => '1.2.3.8',
|
|
'Thread_id' => '6',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.018799',
|
|
'Lock_time' => '0.009453',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 435,
|
|
bytes => 31,
|
|
},
|
|
],
|
|
);
|
|
|
|
# Parse embedded meta-attributes
|
|
test_log_parser(
|
|
parser => $p,
|
|
misc => { embed => qr/ -- .*/, capture => qr/(\w+): ([^,]+)/ },
|
|
file => "$sample/slow010.txt",
|
|
result => [
|
|
{ Lock_time => '0',
|
|
Query_time => '2',
|
|
Rows_examined => '0',
|
|
Rows_sent => '1',
|
|
arg => 'SELECT foo -- file: /user.php, line: 417, url: d217d035a34ac9e693b41d4c2&limit=500&offset=0',
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '',
|
|
pos_in_log => '0',
|
|
ts => '071015 21:43:52',
|
|
user => 'root',
|
|
file => '/user.php',
|
|
line => '417',
|
|
url => 'd217d035a34ac9e693b41d4c2&limit=500&offset=0',
|
|
bytes => 91,
|
|
},
|
|
],
|
|
);
|
|
|
|
$p = new SlowLogParser;
|
|
|
|
# Parses commented event lines after uncommented meta-lines
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow011.txt",
|
|
result => [
|
|
{ 'Schema' => 'db1',
|
|
'arg' => 'administrator command: Quit',
|
|
'ip' => '1.2.3.8',
|
|
'Thread_id' => '5',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.000002',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 0,
|
|
cmd => 'Admin',
|
|
bytes => 27,
|
|
},
|
|
{ 'Schema' => 'db2',
|
|
'db' => 'db',
|
|
'ip' => '1.2.3.8',
|
|
arg => 'SET NAMES utf8',
|
|
'Thread_id' => '6',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.000899',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 221,
|
|
cmd => 'Query',
|
|
bytes => 14,
|
|
},
|
|
{ 'Schema' => 'db2',
|
|
'db' => 'db2',
|
|
'arg' => 'administrator command: Quit',
|
|
'ip' => '1.2.3.8',
|
|
'Thread_id' => '7',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.018799',
|
|
'Lock_time' => '0.009453',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 435,
|
|
cmd => 'Admin',
|
|
bytes => 27,
|
|
},
|
|
{ 'Schema' => 'db2',
|
|
'db' => 'db',
|
|
'ip' => '1.2.3.8',
|
|
arg => 'SET NAMES utf8',
|
|
'Thread_id' => '9',
|
|
'host' => '1.2.3.8',
|
|
'Rows_examined' => '0',
|
|
'user' => 'meow',
|
|
'Query_time' => '0.000899',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 663,
|
|
cmd => 'Query',
|
|
bytes => 14,
|
|
}
|
|
],
|
|
);
|
|
|
|
# events that might look like meta data
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow012.txt",
|
|
result => [
|
|
{ 'Schema' => 'sab',
|
|
'arg' => 'SET autocommit=1',
|
|
'ip' => '10.1.250.19',
|
|
'Thread_id' => '39387',
|
|
'host' => '10.1.250.19',
|
|
'Rows_examined' => '0',
|
|
'user' => 'sabapp',
|
|
'Query_time' => '0.000018',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 0,
|
|
cmd => 'Query',
|
|
bytes => 16,
|
|
},
|
|
{ 'Schema' => 'sab',
|
|
'arg' => 'SET autocommit=1',
|
|
'ip' => '10.1.250.19',
|
|
'Thread_id' => '39387',
|
|
'host' => '10.1.250.19',
|
|
'Rows_examined' => '0',
|
|
'user' => 'sabapp',
|
|
'Query_time' => '0.000018',
|
|
'Lock_time' => '0.000000',
|
|
'Rows_sent' => '0',
|
|
pos_in_log => 172,
|
|
cmd => 'Query',
|
|
bytes => 16,
|
|
},
|
|
],
|
|
);
|
|
|
|
# A pathological test case to be sure a crash doesn't happen. Has a bunch of
|
|
# "use" and "set" and administrator commands etc.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow013.txt",
|
|
result => [
|
|
{ 'Schema' => 'abc',
|
|
'cmd' => 'Query',
|
|
'arg' => 'SET autocommit=1',
|
|
'ip' => '10.1.250.19',
|
|
'Thread_id' => '39796',
|
|
'host' => '10.1.250.19',
|
|
'pos_in_log' => '0',
|
|
'Rows_examined' => '0',
|
|
'user' => 'foo_app',
|
|
'Query_time' => '0.000015',
|
|
'Rows_sent' => '0',
|
|
'Lock_time' => '0.000000',
|
|
bytes => 16,
|
|
},
|
|
{ 'Schema' => 'test',
|
|
'db' => 'test',
|
|
'cmd' => 'Query',
|
|
'arg' => 'SHOW STATUS',
|
|
'ip' => '10.1.12.201',
|
|
'ts' => '081127 8:51:20',
|
|
'Thread_id' => '39947',
|
|
'host' => '10.1.12.201',
|
|
'pos_in_log' => '174',
|
|
'Rows_examined' => '226',
|
|
'Query_time' => '0.149435',
|
|
'user' => 'mytopuser',
|
|
'Rows_sent' => '226',
|
|
'Lock_time' => '0.000070',
|
|
bytes => 11,
|
|
},
|
|
{ 'Schema' => 'test',
|
|
'cmd' => 'Admin',
|
|
'arg' => 'administrator command: Quit',
|
|
'ip' => '10.1.12.201',
|
|
'ts' => '081127 8:51:21',
|
|
'Thread_id' => '39947',
|
|
'host' => '10.1.12.201',
|
|
'pos_in_log' => '385',
|
|
'Rows_examined' => '0',
|
|
'Query_time' => '0.000005',
|
|
'user' => 'mytopuser',
|
|
'Rows_sent' => '0',
|
|
'Lock_time' => '0.000000',
|
|
bytes => 27,
|
|
},
|
|
{ 'Schema' => 'abc',
|
|
'db' => 'abc',
|
|
'cmd' => 'Query',
|
|
'arg' => 'SET autocommit=0',
|
|
'ip' => '10.1.250.19',
|
|
'Thread_id' => '39796',
|
|
'host' => '10.1.250.19',
|
|
'pos_in_log' => '600',
|
|
'Rows_examined' => '0',
|
|
'user' => 'foo_app',
|
|
'Query_time' => '0.000067',
|
|
'Rows_sent' => '0',
|
|
'Lock_time' => '0.000000',
|
|
bytes => 16,
|
|
},
|
|
{ 'Schema' => 'abc',
|
|
'cmd' => 'Query',
|
|
'arg' => 'commit',
|
|
'ip' => '10.1.250.19',
|
|
'Thread_id' => '39796',
|
|
'host' => '10.1.250.19',
|
|
'pos_in_log' => '782',
|
|
'Rows_examined' => '0',
|
|
'user' => 'foo_app',
|
|
'Query_time' => '0.000015',
|
|
'Rows_sent' => '0',
|
|
'Lock_time' => '0.000000',
|
|
bytes => 6,
|
|
}
|
|
],
|
|
);
|
|
|
|
# events with a lot of headers
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow014.txt",
|
|
result => [
|
|
{ ts => '071015 21:43:52',
|
|
cmd => 'Query',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
db => 'test',
|
|
arg => 'select sleep(2) from n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 0,
|
|
bytes => 22,
|
|
},
|
|
{ ts => '071015 21:43:52',
|
|
cmd => 'Query',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
db => 'test',
|
|
arg => 'select sleep(2) from n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 1313,
|
|
bytes => 22,
|
|
},
|
|
],
|
|
);
|
|
|
|
# No error parsing truncated event with no newline
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow015.txt",
|
|
);
|
|
|
|
# Some more silly stuff with USE meta-data lines.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow016.txt",
|
|
result => [
|
|
{ user => 'root',
|
|
cmd => 'Query',
|
|
db => 'user_chos',
|
|
host => 'localhost',
|
|
ip => '127.0.0.1',
|
|
Thread_id => 6997,
|
|
Schema => 'user_chos',
|
|
Query_time => '0.000020',
|
|
Lock_time => '0.000000',
|
|
Rows_sent => 0,
|
|
Rows_examined => 0,
|
|
Rows_affected => 0,
|
|
Rows_read => 1,
|
|
arg => 'USE `user_chos`',
|
|
pos_in_log => 0,
|
|
bytes => 15,
|
|
},
|
|
{ user => 'user_user',
|
|
cmd => 'Query',
|
|
db => 'user_sfn',
|
|
host => 'my-server.myplace.net',
|
|
ip => '192.168.100.1',
|
|
Thread_id => 6996,
|
|
Schema => 'user_sfn',
|
|
Query_time => '0.000020',
|
|
Lock_time => '0.000000',
|
|
Rows_sent => 0,
|
|
Rows_examined => 0,
|
|
Rows_affected => 0,
|
|
Rows_read => 0,
|
|
arg => 'SELECT * FROM moderator',
|
|
pos_in_log => 226,
|
|
bytes => 23,
|
|
},
|
|
],
|
|
);
|
|
|
|
# This is fixed in EventAggregator so that we can parse
|
|
# Client: IP:port because an IP looks like a broken Query_time.
|
|
# Check that issue 234 doesn't kill us (broken Query_time).
|
|
#test_log_parser(
|
|
# parser => $p,
|
|
# file => "$sample/slow017.txt",
|
|
# result => [
|
|
# { ts => '081116 15:07:11',
|
|
# cmd => 'Query',
|
|
# user => 'user',
|
|
# host => 'host',
|
|
# ip => '10.1.65.120',
|
|
# db => 'mydb',
|
|
# arg => 'SELECT * FROM mytbl',
|
|
# Query_time => '18446744073708.796870',
|
|
# Lock_time => '0.000036',
|
|
# Rows_sent => 1,
|
|
# Rows_examined => 127,
|
|
# pos_in_log => 0,
|
|
# bytes => 19,
|
|
# },
|
|
# ],
|
|
#});
|
|
|
|
# t/lib/samples/slow018.txt is a test for mk-query-digest.
|
|
|
|
# Has some more combinations of meta-data and explicit query lines and
|
|
# administrator commands.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow019.txt",
|
|
result => [
|
|
{ Lock_time => '0.000000',
|
|
Query_time => '0.000002',
|
|
Rows_examined => '3',
|
|
Rows_sent => '5',
|
|
Schema => 'db1',
|
|
Thread_id => '5',
|
|
arg => 'administrator command: Quit',
|
|
cmd => 'Admin',
|
|
host => '1.2.3.8',
|
|
ip => '1.2.3.8',
|
|
pos_in_log => '0',
|
|
user => 'meow',
|
|
bytes => 27,
|
|
},
|
|
{ Lock_time => '0.000000',
|
|
Query_time => '0.000899',
|
|
Rows_examined => '3',
|
|
Rows_sent => '0',
|
|
Schema => 'db2',
|
|
Thread_id => '6',
|
|
arg => 'SET NAMES utf8',
|
|
cmd => 'Query',
|
|
db => 'db',
|
|
host => '1.2.3.8',
|
|
ip => '1.2.3.8',
|
|
pos_in_log => '221',
|
|
user => 'meow',
|
|
bytes => 14,
|
|
},
|
|
{ Lock_time => '0.009453',
|
|
Query_time => '0.018799',
|
|
Rows_examined => '2',
|
|
Rows_sent => '9',
|
|
Schema => 'db2',
|
|
Thread_id => '7',
|
|
arg => 'administrator command: Quit',
|
|
cmd => 'Admin',
|
|
db => 'db2',
|
|
host => '1.2.3.8',
|
|
ip => '1.2.3.8',
|
|
pos_in_log => '435',
|
|
user => 'meow',
|
|
bytes => 27,
|
|
}
|
|
],
|
|
);
|
|
|
|
# Parse files that begin with Windows paths. It also has TWO lines of
|
|
# meta-data. This is from MySQL 5.1 on Windows.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow031.txt",
|
|
result => [
|
|
{ Lock_time => '0.000000',
|
|
Query_time => '0.453125',
|
|
Rows_examined => '2160',
|
|
Rows_sent => '2160',
|
|
arg => 'SELECT * FROM cottages',
|
|
cmd => 'Query',
|
|
db => 'myplace',
|
|
host => 'secure.myplace.co.uk',
|
|
ip => '88.208.248.160',
|
|
pos_in_log => '0',
|
|
timestamp => '1233019414',
|
|
ts => '090127 1:23:34',
|
|
user => 'swuser',
|
|
bytes => 22,
|
|
},
|
|
],
|
|
);
|
|
|
|
# t/lib/samples/slow021.txt is for mk-query-digest. It has an entry without a Time.
|
|
|
|
# t/lib/samples/slow022.txt has garbled Time entries.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow022.txt",
|
|
result => [
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '0',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '369',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '20',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
db => 'bar',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '737',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'bar',
|
|
Thread_id => '10',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1101',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Thread_id => '20',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM bar_tbl',
|
|
cmd => 'Query',
|
|
db => 'bar',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1469',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
{ Filesort_on_disk => 'No',
|
|
Tmp_table_on_disk => 'No',
|
|
Filesort => 'No',
|
|
Full_join => 'No',
|
|
Full_scan => 'No',
|
|
Lock_time => '0.000000',
|
|
Merge_passes => '0',
|
|
QC_Hit => 'No',
|
|
Query_time => '0.000012',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'foo',
|
|
Thread_id => '30',
|
|
Tmp_table => 'No',
|
|
arg => 'SELECT col FROM foo_tbl',
|
|
cmd => 'Query',
|
|
host => '',
|
|
ip => '',
|
|
pos_in_log => '1833',
|
|
user => '[SQL_SLAVE]',
|
|
bytes => 23,
|
|
},
|
|
],
|
|
);
|
|
|
|
# t/lib/samples/slow025.txt has an empty Schema.
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow025.txt",
|
|
result => [
|
|
{ Lock_time => '0.000066',
|
|
Query_time => '17.737502',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
Schema => '',
|
|
Thread_id => '12342',
|
|
arg => 'SELECT missing_a_schema_above from crash_me',
|
|
bytes => 43,
|
|
cmd => 'Query',
|
|
host => '10.1.12.30',
|
|
ip => '10.1.12.30',
|
|
pos_in_log => '0',
|
|
ts => '081126 13:08:25',
|
|
user => 'root'
|
|
}
|
|
],
|
|
);
|
|
|
|
# #############################################################################
|
|
# Test a callback chain.
|
|
# #############################################################################
|
|
my $oktorun = 1;
|
|
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow001.txt",
|
|
oktorun => sub { $oktorun = $_[0]; },
|
|
result => [
|
|
{ ts => '071015 21:43:52',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
db => 'test',
|
|
arg => 'select sleep(2) from n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 0,
|
|
bytes => length('select sleep(2) from n'),
|
|
cmd => 'Query',
|
|
},
|
|
{ ts => '071015 21:45:10',
|
|
db => 'sakila',
|
|
user => 'root',
|
|
host => 'localhost',
|
|
ip => '',
|
|
arg => 'select sleep(2) from test.n',
|
|
Query_time => 2,
|
|
Lock_time => 0,
|
|
Rows_sent => 1,
|
|
Rows_examined => 0,
|
|
pos_in_log => 359,
|
|
bytes => length('select sleep(2) from test.n'),
|
|
cmd => 'Query',
|
|
},
|
|
],
|
|
);
|
|
|
|
is(
|
|
$oktorun,
|
|
0,
|
|
'Sets oktorun'
|
|
);
|
|
|
|
# #############################################################################
|
|
# Parse "Client: IP:port".
|
|
# #############################################################################
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow036.txt",
|
|
result => [
|
|
{ Lock_time => '0.000000',
|
|
Query_time => '0.000000',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
arg => 'select * from foo',
|
|
bytes => length('select * from foo'),
|
|
cmd => 'Query',
|
|
pos_in_log => '0',
|
|
ts => '071218 11:48:27',
|
|
Client => '127.0.0.1:12345',
|
|
}
|
|
],
|
|
);
|
|
|
|
# #############################################################################
|
|
# Issue 1104: Schema isn't parsed right
|
|
# #############################################################################
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow044.txt",
|
|
result => [
|
|
{ Lock_time => '0.000048',
|
|
Query_time => '0.000173',
|
|
Rows_examined => '18',
|
|
Rows_sent => '18',
|
|
arg => 'select /*this is only parsable by slowlog-to-outfile, not by mqd*/ foo',
|
|
bytes => length('select /*this is only parsable by slowlog-to-outfile, not by mqd*/ foo'),
|
|
cmd => 'Query',
|
|
pos_in_log => '0',
|
|
ts => '100525 10:22:00',
|
|
Thread_id => '342',
|
|
Last_errno => 1,
|
|
Killed => 2,
|
|
},
|
|
{ Lock_time => '0.000048',
|
|
Query_time => '0.000173',
|
|
Rows_examined => '19',
|
|
Rows_sent => '19',
|
|
arg => 'select /*this is only parsable by slowlog-to-outfile, not by mqd*/ foo',
|
|
bytes => length('select /*this is only parsable by slowlog-to-outfile, not by mqd*/ foo'),
|
|
cmd => 'Query',
|
|
pos_in_log => '253',
|
|
Thread_id => '342',
|
|
Last_errno => 3,
|
|
Killed => 4,
|
|
}
|
|
],
|
|
);
|
|
|
|
# #############################################################################
|
|
# pt-query-digest fails to parse timestamp with no query
|
|
# https://bugs.launchpad.net/percona-toolkit/+bug/1082599
|
|
# #############################################################################
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow056.txt",
|
|
result => [
|
|
{ Lock_time => '0.000000',
|
|
Query_time => '0.000102',
|
|
Rows_read => '0',
|
|
Rows_affected => '0',
|
|
Rows_examined => '0',
|
|
Rows_sent => '0',
|
|
arg => '/* No query */',
|
|
bytes => '0',
|
|
cmd => 'Query',
|
|
pos_in_log => '0',
|
|
ts => '121123 19:56:06',
|
|
Thread_id => '558038',
|
|
Last_errno => 0,
|
|
Killed => 0,
|
|
db => 'test_db',
|
|
host => '127.0.0.1',
|
|
Schema => 'test_db',
|
|
ip => '127.0.0.1',
|
|
timestamp => '1111111111',
|
|
user => 'root',
|
|
},
|
|
{
|
|
ts => '121123 19:56:06',
|
|
Killed => '0',
|
|
Last_errno => '0',
|
|
Lock_time => '0.000197',
|
|
Query_time => '0.002515',
|
|
Rows_affected => '1',
|
|
Rows_examined => '1',
|
|
Rows_read => '0',
|
|
Rows_sent => '0',
|
|
Schema => 'test_db',
|
|
Thread_id => '558032',
|
|
arg => 'update t set b = b + 30 where user_id=1',
|
|
bytes => 39,
|
|
cmd => 'Query',
|
|
host => '127.0.0.1',
|
|
ip => '127.0.0.1',
|
|
pos_in_log => 596,
|
|
timestamp => '2222222222',
|
|
user => 'root',
|
|
},
|
|
],
|
|
);
|
|
|
|
|
|
# #############################################################################
|
|
# pt-query-digest fails to parse Thread_id on 5.6
|
|
# https://bugs.launchpad.net/percona-toolkit/+bug/1299387
|
|
# #############################################################################
|
|
|
|
# first test with a Percona 5.5 slow log (includes an explicit Thread_id line)
|
|
# (MySQL 5.5 doesn't include thread id)
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow060.txt",
|
|
result => [
|
|
{
|
|
Thread_id => '1', # here's our item
|
|
Bytes_sent => '64',
|
|
Killed => '0',
|
|
Last_errno => '0',
|
|
Lock_time => '0.000000',
|
|
Query_time => '10.000373',
|
|
Rows_affected => '0',
|
|
Rows_examined => '0',
|
|
Rows_read => '0',
|
|
Rows_sent => '1',
|
|
arg => 'select sleep(10)',
|
|
bytes => 16,
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '127.0.0.1',
|
|
pos_in_log => 0,
|
|
timestamp => '1405358212',
|
|
ts => '140714 14:16:52',
|
|
user => 'root'
|
|
},
|
|
],
|
|
);
|
|
|
|
# now test with a Percona 5.6 slow log. Thread_id is now on the user@host line, and is called 'Id'.
|
|
# (this is in line with MySQL 5.6)
|
|
test_log_parser(
|
|
parser => $p,
|
|
file => "$sample/slow061.txt",
|
|
result => [
|
|
{
|
|
Thread_id => 1, # here's our item
|
|
Bytes_sent => '64',
|
|
Lock_time => '0.000000',
|
|
Query_time => '11.013723',
|
|
Rows_affected => '0',
|
|
Rows_examined => '0',
|
|
Rows_sent => '1',
|
|
arg => 'select sleep(11)',
|
|
bytes => 16,
|
|
cmd => 'Query',
|
|
host => 'localhost',
|
|
ip => '127.0.0.1',
|
|
pos_in_log => 0,
|
|
timestamp => '1405360304',
|
|
ts => '140714 14:51:44',
|
|
user => 'root',
|
|
},
|
|
],
|
|
);
|
|
|
|
|
|
# #############################################################################
|
|
# Done.
|
|
# #############################################################################
|
|
my $output = '';
|
|
{
|
|
local *STDERR;
|
|
open STDERR, '>', \$output;
|
|
$p->_d('Complete test coverage');
|
|
}
|
|
like(
|
|
$output,
|
|
qr/Complete test coverage/,
|
|
'_d() works'
|
|
);
|
|
done_testing;
|