1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
|
CREATE TABLE t1(a INT primary key, b int) ENGINE=InnoDB;
INSERT INTO t1 select seq, seq from seq_1_to_1000;
SET SESSION min_examined_row_limit=0;
SET SESSION long_query_time=0;
SET SESSION log_slow_verbosity='innodb,query_plan';
[slow_log_start.inc] log_slow_innodb-verbosity_1
SELECT sum(a+b) FROM t1;
sum(a+b)
1001000
UPDATE t1 set b=b+1 where a=1 or a=999;
[log_slow_stop.inc] log_slow_innodb-verbosity_1
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Thread_id: .+ Schema: .+ QC_hit: (Yes|No)$ expected_matches: 3
[log_grep.inc] found expected match count: 3
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Query_time: \d+\.\d+ Lock_time: \d+\.\d+ Rows_sent: \d+ Rows_examined: \d+$ expected_matches: 3
[log_grep.inc] found expected match count: 3
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Rows_affected: \d+ Bytes_sent: \d+$ expected_matches: 3
[log_grep.inc] found expected match count: 3
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
[log_grep.inc] lines: 1
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Tmp_tables: \d+ Tmp_disk_tables: \d+$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Pages_accessed: \d+ Pages_read: \d+ Pages_prefetched: \d+ Pages_updated: \d+ Old_rows_read: \d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_1 pattern: ^# Pages_read_time: \d+\.\d+ Engine_time: \d+\.\d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
SET SESSION log_slow_verbosity='innodb,query_plan';
[slow_log_start.inc] log_slow_innodb-verbosity_2
SELECT 1;
1
1
[log_slow_stop.inc] log_slow_innodb-verbosity_2
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Thread_id: .+ Schema: .+ QC_hit: (Yes|No)$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Query_time: \d+\.\d+ Lock_time: \d+\.\d+ Rows_sent: \d+ Rows_examined: \d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Rows_affected: \d+ Bytes_sent: \d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Tmp_tables: \d+ Tmp_disk_tables: \d+$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Pages_accessed: \d+ Pages_read: \d+ Pages_prefetched: \d+ Pages_updated: \d+ Old_rows_read: \d+$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_2 pattern: ^# Pages_read_time: \d+\.\d+ Engine_time: \d+\.\d+$
[log_grep.inc] lines: 0
#
# Test 'query_plan'
#
SET SESSION log_slow_verbosity='query_plan';
[slow_log_start.inc] log_slow_innodb-verbosity_3
INSERT INTO t1 VALUE(1001,1001);
[log_slow_stop.inc] log_slow_innodb-verbosity_3
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Thread_id: .+ Schema: .+ QC_hit: (Yes|No)$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Query_time: \d+\.\d+ Lock_time: \d+\.\d+ Rows_sent: \d+ Rows_examined: \d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Rows_affected: \d+ Bytes_sent: \d+$ expected_matches: 2
[log_grep.inc] found expected match count: 2
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\ Priority_queue: (Yes|No)$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Tmp_tables: \d+ Tmp_disk_tables: \d+$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Pages_accessed: \d+ Pages_read: \d+ Pages_prefetched: \d+ Pages_updated: \d+ Old_rows_read: \d+$
[log_grep.inc] lines: 0
[log_grep.inc] file: log_slow_innodb-verbosity_3 pattern: ^# Pages_read_time: \d+\.\d+ Engine_time: \d+\.\d+$
[log_grep.inc] lines: 0
DROP TABLE t1;
#
# Test max_tmp_disk_space_used
#
CREATE TABLE t1(a INT primary key, c varchar(1024)) ENGINE=InnoDB;
insert into t1 select seq, concat(repeat(char(65+mod(seq,61)),32),repeat(char(65+mod(seq,59)),32)) from seq_1_to_1000;
SET SESSION log_slow_verbosity='query_plan';
SET SESSION sort_buffer_size=16384;
SET SESSION long_query_time=0;
[slow_log_start.inc] log_slow_innodb-verbosity_4
SELECT c, count(*) from t1 group by c order by 2 limit 700,10;
c count(*)
CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMMM 2
DDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDDNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNN 2
EEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEEOOOOOOOOOOOOOOOOOOOOOOOOOOOOOOOO 2
FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFPPPPPPPPPPPPPPPPPPPPPPPPPPPPPPPP 2
GGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGGQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQQ 2
HHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHHRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRRR 2
IIIIIIIIIIIIIIIIIIIIIIIIIIIIIIIISSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS 2
JJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJJTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTTT 2
KKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKKUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU 2
LLLLLLLLLLLLLLLLLLLLLLLLLLLLLLLLVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVV 2
[log_slow_stop.inc] log_slow_innodb-verbosity_4
[log_grep.inc] file: log_slow_innodb-verbosity_4 pattern: ^# Max_tmp_disk_space_used.* expected_matches: 1
[log_grep.inc] found expected match count: 1
drop table t1;
#
# Cleanup
#
|
