Merge lp:~laurynas-biveinis/percona-server/slow-log-fixes-5.5 into lp:percona-server/5.5

Proposed by Laurynas Biveinis on 2013-01-21
Status: Merged
Approved by: Stewart Smith on 2013-02-08
Approved revision: 397
Merged at revision: 438
Proposed branch: lp:~laurynas-biveinis/percona-server/slow-log-fixes-5.5
Merge into: lp:percona-server/5.5
Diff against target: 3690 lines (+1002/-1194)
55 files modified
Percona-Server/mysql-test/include/log_cleanup.inc (+1/-0)
Percona-Server/mysql-test/include/log_start.inc (+0/-16)
Percona-Server/mysql-test/include/log_stop.inc (+0/-7)
Percona-Server/mysql-test/include/percona_slow_extended_error_on_quit.inc (+0/-50)
Percona-Server/mysql-test/include/percona_slow_log_verbosity_grep.inc (+26/-0)
Percona-Server/mysql-test/include/percona_slow_query_log_rate.inc (+5/-10)
Percona-Server/mysql-test/r/mysqld--help-notwin.result (+2/-2)
Percona-Server/mysql-test/r/percona_bug643149.result (+0/-21)
Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result (+0/-35)
Percona-Server/mysql-test/r/percona_log_slow_filter.result (+0/-16)
Percona-Server/mysql-test/r/percona_log_slow_innodb.result (+42/-0)
Percona-Server/mysql-test/r/percona_log_slow_query_plan.result (+268/-0)
Percona-Server/mysql-test/r/percona_log_slow_query_plan_qc.result (+46/-0)
Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result (+0/-19)
Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result (+0/-45)
Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result (+0/-25)
Percona-Server/mysql-test/r/percona_log_slow_verbosity.result (+0/-16)
Percona-Server/mysql-test/r/percona_long_query_time.result (+0/-33)
Percona-Server/mysql-test/r/percona_min_examined_row_limit.result (+1/-1)
Percona-Server/mysql-test/r/percona_slow_extended_error_on_quit.result (+23/-168)
Percona-Server/mysql-test/r/percona_slow_extended_log_error.result (+0/-10)
Percona-Server/mysql-test/r/percona_slow_query_log_rate.result (+45/-69)
Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result (+0/-41)
Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result (+0/-18)
Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result (+0/-18)
Percona-Server/mysql-test/t/disabled.def (+1/-0)
Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test (+0/-20)
Percona-Server/mysql-test/t/percona_log_slow_filter.test (+0/-26)
Percona-Server/mysql-test/t/percona_log_slow_innodb.test (+82/-0)
Percona-Server/mysql-test/t/percona_log_slow_query_plan.test (+302/-0)
Percona-Server/mysql-test/t/percona_log_slow_query_plan_qc.test (+71/-0)
Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb-slave.opt (+0/-1)
Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test (+0/-42)
Percona-Server/mysql-test/t/percona_log_slow_slave_statements-slave.opt (+0/-1)
Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test (+0/-117)
Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test (+0/-29)
Percona-Server/mysql-test/t/percona_log_slow_verbosity.test (+0/-19)
Percona-Server/mysql-test/t/percona_long_query_time.test (+0/-25)
Percona-Server/mysql-test/t/percona_min_examined_row_limit.test (+0/-35)
Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test (+0/-87)
Percona-Server/mysql-test/t/percona_slow_extended_log_error.test (+0/-15)
Percona-Server/mysql-test/t/percona_slow_query_log_rate.test (+10/-3)
Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test (+0/-34)
Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test (+0/-25)
Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test (+0/-28)
Percona-Server/sql/event_scheduler.cc (+0/-1)
Percona-Server/sql/log.cc (+49/-23)
Percona-Server/sql/log_event.cc (+1/-1)
Percona-Server/sql/slave.cc (+1/-2)
Percona-Server/sql/sql_class.cc (+0/-5)
Percona-Server/sql/sql_class.h (+8/-20)
Percona-Server/sql/sql_connect.cc (+0/-8)
Percona-Server/sql/sql_parse.cc (+15/-5)
Percona-Server/sql/sys_vars.cc (+2/-1)
Percona-Server/storage/innobase/handler/ha_innodb.cc (+1/-1)
To merge this branch: bzr merge lp:~laurynas-biveinis/percona-server/slow-log-fixes-5.5
Reviewer Review Type Date Requested Status
Stewart Smith (community) 2013-01-21 Approve on 2013-02-08
Review via email: mp+144058@code.launchpad.net

Description of the change

Merge multiple slow query log fixes from 5.1.
http://jenkins.percona.com/job/percona-server-5.5-param/637/

To post a comment you must log in.
Stewart Smith (stewart) :
review: Approve

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== added file 'Percona-Server/mysql-test/include/log_cleanup.inc'
2--- Percona-Server/mysql-test/include/log_cleanup.inc 1970-01-01 00:00:00 +0000
3+++ Percona-Server/mysql-test/include/log_cleanup.inc 2013-01-21 06:27:51 +0000
4@@ -0,0 +1,1 @@
5+--remove_files_wildcard $MYSQLTEST_VARDIR *.slog
6
7=== added file 'Percona-Server/mysql-test/include/log_start.inc'
8--- Percona-Server/mysql-test/include/log_start.inc 1970-01-01 00:00:00 +0000
9+++ Percona-Server/mysql-test/include/log_start.inc 2013-01-21 06:27:51 +0000
10@@ -0,0 +1,11 @@
11+--let slow_query_log_file_old=`SELECT Variable_value FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE Variable_name = 'slow_query_log_file';`
12+--let slow_query_log_old=`SELECT Variable_value FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE Variable_name = 'slow_query_log';`
13+--let log_output_old=`SELECT Variable_value FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE Variable_name = 'log_output';`
14+--disable_query_log
15+--let log_file_full_path = $MYSQLTEST_VARDIR/$log_file.slog
16+SET GLOBAL slow_query_log=0;
17+SET GLOBAL log_output=FILE;
18+--echo [log_start.inc] $log_file
19+EVAL SET GLOBAL slow_query_log_file="$log_file_full_path";
20+SET GLOBAL slow_query_log=1;
21+--enable_query_log
22
23=== removed file 'Percona-Server/mysql-test/include/log_start.inc'
24--- Percona-Server/mysql-test/include/log_start.inc 2012-04-18 23:25:38 +0000
25+++ Percona-Server/mysql-test/include/log_start.inc 1970-01-01 00:00:00 +0000
26@@ -1,16 +0,0 @@
27---disable_query_log
28---let log_file_full_path = $MYSQLTEST_VARDIR/$log_file
29-SET @slow_query_log_old=@@slow_query_log;
30-SET @slow_query_log_file_old= @@slow_query_log_file;
31-SET GLOBAL slow_query_log=OFF;
32-perl;
33- $log_file_full_path= $ENV{'log_file_full_path'};
34- unlink $log_file_full_path;
35- open(FILE, '>', $log_file_full_path)
36- or die "Cannot create log file $log_file_full_path, reason: $!";
37- close(FILE);
38-EOF
39---echo [log_start.inc] $log_file
40-EVAL SET GLOBAL slow_query_log_file="$log_file_full_path";
41-SET GLOBAL slow_query_log=ON;
42---enable_query_log
43
44=== added file 'Percona-Server/mysql-test/include/log_stop.inc'
45--- Percona-Server/mysql-test/include/log_stop.inc 1970-01-01 00:00:00 +0000
46+++ Percona-Server/mysql-test/include/log_stop.inc 2013-01-21 06:27:51 +0000
47@@ -0,0 +1,7 @@
48+--disable_query_log
49+SET GLOBAL slow_query_log=0;
50+--echo [log_stop.inc] $log_file
51+EVAL SET GLOBAL log_output= $log_output_old;
52+EVAL SET GLOBAL slow_query_log_file= "$slow_query_log_file_old";
53+EVAL SET GLOBAL slow_query_log= $slow_query_log_old;
54+--enable_query_log
55
56=== removed file 'Percona-Server/mysql-test/include/log_stop.inc'
57--- Percona-Server/mysql-test/include/log_stop.inc 2012-04-18 23:25:38 +0000
58+++ Percona-Server/mysql-test/include/log_stop.inc 1970-01-01 00:00:00 +0000
59@@ -1,7 +0,0 @@
60---disable_query_log
61-FLUSH LOGS;
62-SET GLOBAL slow_query_log=OFF;
63---echo [log_stop.inc] $log_file
64-SET GLOBAL slow_query_log_file= @slow_query_log_file_old;
65-SET GLOBAL slow_query_log= @slow_query_log_old;
66---enable_query_log
67
68=== removed file 'Percona-Server/mysql-test/include/percona_slow_extended_error_on_quit.inc'
69--- Percona-Server/mysql-test/include/percona_slow_extended_error_on_quit.inc 2012-10-27 05:16:07 +0000
70+++ Percona-Server/mysql-test/include/percona_slow_extended_error_on_quit.inc 1970-01-01 00:00:00 +0000
71@@ -1,50 +0,0 @@
72---echo ################################################################################
73---let grep_pattern=CREATE
74---source include/log_grep.inc
75---let grep_pattern=INSERT
76---source include/log_grep.inc
77---let grep_pattern=SELECT
78---source include/log_grep.inc
79---let grep_pattern=Quit
80---source include/log_grep.inc
81---let grep_pattern=Last_errno: [^0]+
82---source include/log_grep.inc
83---let grep_pattern=Last_errno: 0
84---source include/log_grep.inc
85---let grep_pattern=Rows_sent: [^0]+
86---source include/log_grep.inc
87---let grep_pattern=Rows_sent: 0
88---source include/log_grep.inc
89---let grep_pattern=Rows_examined: [^0]+
90---source include/log_grep.inc
91---let grep_pattern=Rows_examined: 0
92---source include/log_grep.inc
93---let grep_pattern=Rows_affected: [^0]+
94---source include/log_grep.inc
95---let grep_pattern=Rows_affected: 0
96---source include/log_grep.inc
97---let grep_pattern=Rows_read: [^0]+
98---source include/log_grep.inc
99---let grep_pattern=Rows_read: 0
100---source include/log_grep.inc
101---let grep_pattern=Bytes_sent: [^0]+
102---source include/log_grep.inc
103---let grep_pattern=Bytes_sent: 0
104---source include/log_grep.inc
105---let grep_pattern=Tmp_tables: [^0]+
106---source include/log_grep.inc
107---let grep_pattern=Tmp_tables: 0
108---source include/log_grep.inc
109---let grep_pattern=Tmp_disk_tables: [^0]+
110---source include/log_grep.inc
111---let grep_pattern=Tmp_disk_tables: 0
112---source include/log_grep.inc
113---let grep_pattern=Tmp_table_sizes: [^0]+
114---source include/log_grep.inc
115---let grep_pattern=Tmp_table_sizes: 0
116---source include/log_grep.inc
117---let grep_pattern=# No InnoDB statistics available for this query
118---source include/log_grep.inc
119---let grep_pattern=# InnoDB_trx_id:
120---source include/log_grep.inc
121---echo ################################################################################
122
123=== added file 'Percona-Server/mysql-test/include/percona_slow_log_verbosity_grep.inc'
124--- Percona-Server/mysql-test/include/percona_slow_log_verbosity_grep.inc 1970-01-01 00:00:00 +0000
125+++ Percona-Server/mysql-test/include/percona_slow_log_verbosity_grep.inc 2013-01-21 06:27:51 +0000
126@@ -0,0 +1,26 @@
127+# Common extensions to the slow query log
128+--let grep_pattern = ^# Thread_id: \d+ Schema: .+ Last_errno: \d+ Killed: \d+\$
129+--source include/log_grep.inc
130+--let grep_pattern = ^#.*Rows_affected: \d+ Rows_read: \d+\$
131+--source include/log_grep.inc
132+--let grep_pattern = ^# Bytes_sent: \d+.*\$
133+--source include/log_grep.inc
134+# InnoDB
135+--let grep_pattern = ^# InnoDB_trx_id: \w+\$
136+--source include/log_grep.inc
137+# Query plan
138+--let grep_pattern = ^# Bytes_sent: \d+ Tmp_tables: \d+ Tmp_disk_tables: \d+ Tmp_table_sizes: \d+\$
139+--source include/log_grep.inc
140+--let grep_pattern = ^# QC_Hit: (Yes|No) Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)\$
141+--source include/log_grep.inc
142+--let grep_pattern = ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+\$
143+--source include/log_grep.inc
144+# InnoDB
145+--let grep_pattern = ^# InnoDB_IO_r_ops: \d+ InnoDB_IO_r_bytes: \d+ InnoDB_IO_r_wait: \d*\.\d*\$
146+--source include/log_grep.inc
147+--let grep_pattern = ^# InnoDB_rec_lock_wait: \d*\.\d* InnoDB_queue_wait: \d*\.\d*\$
148+--source include/log_grep.inc
149+--let grep_pattern = ^# InnoDB_pages_distinct: \d+\$
150+--source include/log_grep.inc
151+--let grep_pattern = ^# No InnoDB statistics available for this query\$
152+--source include/log_grep.inc
153
154=== modified file 'Percona-Server/mysql-test/include/percona_slow_query_log_rate.inc'
155--- Percona-Server/mysql-test/include/percona_slow_query_log_rate.inc 2012-04-18 23:25:38 +0000
156+++ Percona-Server/mysql-test/include/percona_slow_query_log_rate.inc 2013-01-21 06:27:51 +0000
157@@ -1,31 +1,26 @@
158---let wait_condition=SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST;
159 --connection default
160---source include/log_start.inc
161
162+--source include/count_sessions.inc
163 --connect (connection_one,localhost,root,,)
164 --connect (connection_two,localhost,root,,)
165 --connect (connection_three,localhost,root,,)
166
167+--source include/log_start.inc
168+
169 --let i=2
170 --let k=1
171
172 while($i)
173 {
174 --connection connection_one
175-SET SESSION query_exec_time=1.1;
176-eval SET SESSION query_exec_id=$k;
177 inc $k;
178 SELECT 'connection_one';
179
180 --connection connection_two
181-SET SESSION query_exec_time=1.1;
182-eval SET SESSION query_exec_id=$k;
183 inc $k;
184 SELECT 'connection_two';
185
186 --connection connection_three
187-SET SESSION query_exec_time=1.1;
188-eval SET SESSION query_exec_id=$k;
189 inc $k;
190 SELECT 'connection_three';
191
192@@ -33,10 +28,10 @@
193 }
194
195 --connection default
196+--source include/log_stop.inc
197 --disconnect connection_one
198 --disconnect connection_two
199 --disconnect connection_three
200---source include/wait_condition.inc
201---source include/log_stop.inc
202+--source include/wait_until_count_sessions.inc
203 --let log_slow_rate_test=1
204 --source include/log_grep.inc
205
206=== modified file 'Percona-Server/mysql-test/r/mysqld--help-notwin.result'
207--- Percona-Server/mysql-test/r/mysqld--help-notwin.result 2012-09-28 01:36:45 +0000
208+++ Percona-Server/mysql-test/r/mysqld--help-notwin.result 2013-01-21 06:27:51 +0000
209@@ -719,8 +719,8 @@
210 Timestamp is printed for all records of the slow log even
211 if they are same time.
212 --slow-query-log-timestamp-precision=name
213- Log slow statements executed by stored procedure to the
214- slow log if it is open. [second, microsecond]
215+ Select the timestamp precision for use in the slow query
216+ log. [second, microsecond]
217 --slow-query-log-use-global-control=name
218 Choose flags, wich always use the global variables.
219 Multiple flags allowed in a comma-separated string.
220
221=== added file 'Percona-Server/mysql-test/r/percona_bug643149.result'
222--- Percona-Server/mysql-test/r/percona_bug643149.result 1970-01-01 00:00:00 +0000
223+++ Percona-Server/mysql-test/r/percona_bug643149.result 2013-01-21 06:27:51 +0000
224@@ -0,0 +1,21 @@
225+SET @old_slow_query_log_file=@@global.slow_query_log_file;
226+SET GLOBAL slow_query_log=on;
227+SET LOCAL log_slow_verbosity='profiling';
228+SET LOCAL long_query_time=0;
229+SET GLOBAL slow_query_log_file='MYSQLTEST_VARDIR/percona_bug643149_slow.log';;
230+SELECT 1;
231+1
232+1
233+# User@Host: root[root] @ localhost []
234+# Thread_id: X Schema: test Last_errno: X Killed: X
235+# Query_time: X.X Lock_time: X.X Rows_sent: X Rows_examined: X Rows_affected: X Rows_read: X
236+# Bytes_sent: X
237+# Profile_starting: X.X Profile_starting_cpu: X.X Profile_Opening_tables: X.X Profile_Opening_tables_cpu: X.X Profile_query_end: X.X Profile_query_end_cpu: X.X Profile_closing_tables: X.X Profile_closing_tables_cpu: X.X Profile_freeing_items: X.X Profile_freeing_items_cpu: X.X Profile_logging_slow_query: X.X Profile_logging_slow_query_cpu: X.X
238+# Profile_total: X.X Profile_total_cpu: X.X
239+# User@Host: root[root] @ localhost []
240+# Thread_id: X Schema: test Last_errno: X Killed: X
241+# Query_time: X.X Lock_time: X.X Rows_sent: X Rows_examined: X Rows_affected: X Rows_read: X
242+# Bytes_sent: X
243+# Profile_starting: X.X Profile_starting_cpu: X.X Profile_checking_permissions: X.X Profile_checking_permissions_cpu: X.X Profile_Opening_tables: X.X Profile_Opening_tables_cpu: X.X Profile_init: X.X Profile_init_cpu: X.X Profile_optimizing: X.X Profile_optimizing_cpu: X.X Profile_executing: X.X Profile_executing_cpu: X.X Profile_end: X.X Profile_end_cpu: X.X Profile_query_end: X.X Profile_query_end_cpu: X.X Profile_closing_tables: X.X Profile_closing_tables_cpu: X.X Profile_freeing_items: X.X Profile_freeing_items_cpu: X.X Profile_logging_slow_query: X.X Profile_logging_slow_query_cpu: X.X
244+# Profile_total: X.X Profile_total_cpu: X.X
245+SET GLOBAL slow_query_log_file=@old_slow_query_log_file;
246
247=== removed file 'Percona-Server/mysql-test/r/percona_bug643149.result'
248--- Percona-Server/mysql-test/r/percona_bug643149.result 2012-04-18 23:25:38 +0000
249+++ Percona-Server/mysql-test/r/percona_bug643149.result 1970-01-01 00:00:00 +0000
250@@ -1,21 +0,0 @@
251-SET @old_slow_query_log_file=@@global.slow_query_log_file;
252-SET GLOBAL slow_query_log=on;
253-SET LOCAL log_slow_verbosity='profiling';
254-SET LOCAL long_query_time=0;
255-SET GLOBAL slow_query_log_file='MYSQLTEST_VARDIR/percona_bug643149_slow.log';;
256-SELECT 1;
257-1
258-1
259-# User@Host: root[root] @ localhost []
260-# Thread_id: X Schema: test Last_errno: X Killed: X
261-# Query_time: X.X Lock_time: X.X Rows_sent: X Rows_examined: X Rows_affected: X Rows_read: X
262-# Bytes_sent: X Tmp_tables: X Tmp_disk_tables: X Tmp_table_sizes: X
263-# Profile_starting: X.X Profile_starting_cpu: X.X Profile_Opening_tables: X.X Profile_Opening_tables_cpu: X.X Profile_query_end: X.X Profile_query_end_cpu: X.X Profile_closing_tables: X.X Profile_closing_tables_cpu: X.X Profile_freeing_items: X.X Profile_freeing_items_cpu: X.X Profile_logging_slow_query: X.X Profile_logging_slow_query_cpu: X.X
264-# Profile_total: X.X Profile_total_cpu: X.X
265-# User@Host: root[root] @ localhost []
266-# Thread_id: X Schema: test Last_errno: X Killed: X
267-# Query_time: X.X Lock_time: X.X Rows_sent: X Rows_examined: X Rows_affected: X Rows_read: X
268-# Bytes_sent: X Tmp_tables: X Tmp_disk_tables: X Tmp_table_sizes: X
269-# Profile_starting: X.X Profile_starting_cpu: X.X Profile_checking_permissions: X.X Profile_checking_permissions_cpu: X.X Profile_Opening_tables: X.X Profile_Opening_tables_cpu: X.X Profile_init: X.X Profile_init_cpu: X.X Profile_optimizing: X.X Profile_optimizing_cpu: X.X Profile_executing: X.X Profile_executing_cpu: X.X Profile_end: X.X Profile_end_cpu: X.X Profile_query_end: X.X Profile_query_end_cpu: X.X Profile_closing_tables: X.X Profile_closing_tables_cpu: X.X Profile_freeing_items: X.X Profile_freeing_items_cpu: X.X Profile_logging_slow_query: X.X Profile_logging_slow_query_cpu: X.X
270-# Profile_total: X.X Profile_total_cpu: X.X
271-SET GLOBAL slow_query_log_file=@old_slow_query_log_file;
272
273=== added file 'Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result'
274--- Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result 1970-01-01 00:00:00 +0000
275+++ Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result 2013-01-21 06:27:51 +0000
276@@ -0,0 +1,20 @@
277+DROP TABLE IF EXISTS t1;
278+CREATE TABLE t1 (a INT);
279+SET SESSION min_examined_row_limit=0;
280+SET SESSION long_query_time=0;
281+SET GLOBAL log_slow_admin_statements=ON;
282+[log_start.inc] percona_log_slow_admin_stmt_1
283+ALTER TABLE t1 ADD INDEX a(a);
284+[log_stop.inc] percona_log_slow_admin_stmt_1
285+[log_grep.inc] file: percona_log_slow_admin_stmt_1 pattern: ALTER TABLE t1 ADD INDEX a\(a\);
286+[log_grep.inc] lines: 1
287+SET GLOBAL log_slow_admin_statements=OFF;
288+[log_start.inc] percona_log_slow_admin_stmt_2
289+ALTER TABLE t1 DROP INDEX a;
290+[log_stop.inc] percona_log_slow_admin_stmt_2
291+[log_grep.inc] file: percona_log_slow_admin_stmt_2 pattern: ALTER TABLE t1 DROP INDEX a;
292+[log_grep.inc] lines: 0
293+SET GLOBAL log_slow_admin_statements=default;
294+SET SESSION long_query_time=default;
295+SET SESSION min_examined_row_limit=default;
296+DROP TABLE t1;
297
298=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result'
299--- Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result 2012-04-18 23:25:38 +0000
300+++ Percona-Server/mysql-test/r/percona_log_slow_admin_statements.result 1970-01-01 00:00:00 +0000
301@@ -1,35 +0,0 @@
302-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
303-Variable_name Value
304-log_slow_admin_statements OFF
305-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
306-VARIABLE_NAME VARIABLE_VALUE
307-LOG_SLOW_ADMIN_STATEMENTS OFF
308-SET GLOBAL log_slow_admin_statements=true;
309-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
310-Variable_name Value
311-log_slow_admin_statements ON
312-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
313-VARIABLE_NAME VARIABLE_VALUE
314-LOG_SLOW_ADMIN_STATEMENTS ON
315-SET GLOBAL log_slow_admin_statements=false;
316-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
317-Variable_name Value
318-log_slow_admin_statements OFF
319-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
320-VARIABLE_NAME VARIABLE_VALUE
321-LOG_SLOW_ADMIN_STATEMENTS OFF
322-SET GLOBAL log_slow_admin_statements=foo;
323-ERROR 42000: Variable 'log_slow_admin_statements' can't be set to the value of 'foo'
324-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
325-Variable_name Value
326-log_slow_admin_statements OFF
327-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
328-VARIABLE_NAME VARIABLE_VALUE
329-LOG_SLOW_ADMIN_STATEMENTS OFF
330-SET GLOBAL log_slow_admin_statements=default;
331-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
332-Variable_name Value
333-log_slow_admin_statements OFF
334-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
335-VARIABLE_NAME VARIABLE_VALUE
336-LOG_SLOW_ADMIN_STATEMENTS OFF
337
338=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_filter.result'
339--- Percona-Server/mysql-test/r/percona_log_slow_filter.result 2012-04-18 23:25:38 +0000
340+++ Percona-Server/mysql-test/r/percona_log_slow_filter.result 1970-01-01 00:00:00 +0000
341@@ -1,16 +0,0 @@
342-CREATE TABLE t(id INT PRIMARY KEY);
343-INSERT INTO t VALUES(1);
344-INSERT INTO t VALUES(2);
345-INSERT INTO t VALUES(3);
346-SET long_query_time=1;
347-SET log_slow_filter=full_join;
348-[log_start.inc] percona.slow_extended.log_slow_filter
349-SET query_exec_time = 1.1;
350-SELECT * FROM t AS t1, t AS t2;
351-SET query_exec_time = default;
352-[log_stop.inc] percona.slow_extended.log_slow_filter
353-SET log_slow_filter=default;
354-SET long_query_time=default;
355-[log_grep.inc] file: percona.slow_extended.log_slow_filter pattern: Query_time
356-[log_grep.inc] lines: 1
357-DROP TABLE t;
358
359=== added file 'Percona-Server/mysql-test/r/percona_log_slow_innodb.result'
360--- Percona-Server/mysql-test/r/percona_log_slow_innodb.result 1970-01-01 00:00:00 +0000
361+++ Percona-Server/mysql-test/r/percona_log_slow_innodb.result 2013-01-21 06:27:51 +0000
362@@ -0,0 +1,42 @@
363+DROP TABLE IF EXISTS t1, t2;
364+CREATE TABLE t1(a INT) ENGINE=InnoDB;
365+INSERT INTO t1 VALUE(1);
366+CREATE TABLE t2(a INT) ENGINE=InnoDB;
367+INSERT INTO t2 VALUE(1);
368+SET SESSION min_examined_row_limit=0;
369+SET SESSION long_query_time=0;
370+SET @old_log_slow_verbosity := @@log_slow_verbosity;
371+SET SESSION log_slow_verbosity='microtime,innodb';
372+[log_start.inc] percona.slow_extended.innodb_0
373+INSERT INTO t1 VALUES(2);
374+INSERT INTO t2 VALUES(2);
375+INSERT INTO t1 VALUES(3);
376+SELECT 5;
377+5
378+5
379+[log_stop.inc] percona.slow_extended.innodb_0
380+LOCK TABLE t1 WRITE;
381+[log_start.inc] percona.slow_extended.innodb_3
382+LOCK TABLE t1 WRITE;
383+SELECT SLEEP(5);
384+SLEEP(5)
385+0
386+UNLOCK TABLES;
387+[log_stop.inc] percona.slow_extended.innodb_3
388+UNLOCK TABLES;
389+BEGIN;
390+SELECT * FROM t2 FOR UPDATE;
391+a
392+1
393+2
394+[log_start.inc] percona.slow_extended.innodb_4
395+DELETE FROM t2 WHERE a=2;
396+SELECT SLEEP(5);
397+SLEEP(5)
398+0
399+COMMIT;
400+[log_stop.inc] percona.slow_extended.innodb_4
401+SET SESSION min_examined_row_limit=default;
402+SET SESSION long_query_time=default;
403+SET SESSION log_slow_verbosity=@old_log_slow_verbosity;
404+DROP TABLE t1, t2;
405
406=== added file 'Percona-Server/mysql-test/r/percona_log_slow_query_plan.result'
407--- Percona-Server/mysql-test/r/percona_log_slow_query_plan.result 1970-01-01 00:00:00 +0000
408+++ Percona-Server/mysql-test/r/percona_log_slow_query_plan.result 2013-01-21 06:27:51 +0000
409@@ -0,0 +1,268 @@
410+FLUSH STATUS;
411+DROP TABLE IF EXISTS t1;
412+CREATE TABLE t1(
413+a INT NOT NULL AUTO_INCREMENT PRIMARY KEY,
414+b INT) ENGINE=InnoDB;
415+INSERT INTO t1 VALUES(NULL, 10), (NULL, 5);
416+SET SESSION long_query_time=0;
417+SET SESSION min_examined_row_limit=0;
418+SET SESSION log_slow_verbosity='microtime,query_plan';
419+EXPLAIN SELECT * FROM t1;
420+id select_type table type possible_keys key key_len ref rows Extra
421+1 SIMPLE t1 ALL NULL NULL NULL NULL 2
422+[log_start.inc] percona_slow_query_log.query_plan_0
423+SELECT * FROM t1;
424+a b
425+1 10
426+2 5
427+[log_stop.inc] percona_slow_query_log.query_plan_0
428+[log_grep.inc] file: percona_slow_query_log.query_plan_0 pattern: ^# Filesort: No Filesort_on_disk: No Merge_passes: 0$
429+[log_grep.inc] lines: 2
430+EXPLAIN SELECT * FROM t1 ORDER BY b;
431+id select_type table type possible_keys key key_len ref rows Extra
432+1 SIMPLE t1 ALL NULL NULL NULL NULL 2 Using filesort
433+[log_start.inc] percona_slow_query_log.query_plan_1
434+SELECT * FROM t1 ORDER BY b;
435+a b
436+2 5
437+1 10
438+[log_stop.inc] percona_slow_query_log.query_plan_1
439+[log_grep.inc] file: percona_slow_query_log.query_plan_1 pattern: ^# Filesort: Yes Filesort_on_disk: No Merge_passes: 0$
440+[log_grep.inc] lines: 1
441+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort_on_disk';
442+[log_start.inc] percona_slow_query_log.query_plan_1a
443+SELECT * FROM t1 ORDER BY b;
444+a b
445+2 5
446+1 10
447+[log_stop.inc] percona_slow_query_log.query_plan_1a
448+[log_grep.inc] file: percona_slow_query_log.query_plan_1a pattern: ^# Filesort: Yes Filesort_on_disk: No Merge_passes: 0$
449+[log_grep.inc] lines: 0
450+SET SESSION log_slow_filter=default;
451+SET SESSION sort_buffer_size=32804;
452+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
453+INSERT INTO t2 VALUES (5), (16), (2), (17), (1);
454+INSERT INTO t2 SELECT * FROM t2;
455+INSERT INTO t2 SELECT * FROM t2;
456+INSERT INTO t2 SELECT * FROM t2;
457+INSERT INTO t2 SELECT * FROM t2;
458+INSERT INTO t2 SELECT * FROM t2;
459+INSERT INTO t2 SELECT * FROM t2;
460+INSERT INTO t2 SELECT * FROM t2;
461+INSERT INTO t2 SELECT * FROM t2;
462+INSERT INTO t2 SELECT * FROM t2;
463+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
464+Variable_name Value
465+Sort_merge_passes 0
466+EXPLAIN SELECT * FROM t2 ORDER BY a;
467+id select_type table type possible_keys key key_len ref rows Extra
468+1 SIMPLE t2 ALL NULL NULL NULL NULL ROWS Using filesort
469+[log_start.inc] percona_slow_query_log.query_plan_2
470+SELECT * FROM t2 ORDER BY a;
471+[log_stop.inc] percona_slow_query_log.query_plan_2
472+[log_grep.inc] file: percona_slow_query_log.query_plan_2 pattern: ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 1$
473+[log_grep.inc] lines: 1
474+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
475+Variable_name Value
476+Sort_merge_passes 1
477+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk';
478+[log_start.inc] percona_slow_query_log.query_plan_2a
479+SELECT * FROM t2 ORDER BY a;
480+[log_stop.inc] percona_slow_query_log.query_plan_2a
481+[log_grep.inc] file: percona_slow_query_log.query_plan_2a pattern: ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 1$
482+[log_grep.inc] lines: 0
483+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
484+Variable_name Value
485+Sort_merge_passes 2
486+SET SESSION log_slow_filter=default;
487+INSERT INTO t2 SELECT * FROM t2;
488+INSERT INTO t2 SELECT * FROM t2;
489+INSERT INTO t2 SELECT * FROM t2;
490+INSERT INTO t2 SELECT * FROM t2;
491+[log_start.inc] percona_slow_query_log.query_plan_3
492+SELECT * FROM t2 ORDER BY a;
493+[log_stop.inc] percona_slow_query_log.query_plan_3
494+[log_grep.inc] file: percona_slow_query_log.query_plan_3 pattern: ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 4$
495+[log_grep.inc] lines: 1
496+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
497+Variable_name Value
498+Sort_merge_passes 6
499+SET SESSION sort_buffer_size=default;
500+SHOW SESSION STATUS LIKE 'Select_scan';
501+Variable_name Value
502+Select_scan 37
503+[log_start.inc] percona_slow_query_log.query_plan_4
504+SELECT * FROM t1 WHERE a=1;
505+a b
506+1 10
507+[log_stop.inc] percona_slow_query_log.query_plan_4
508+[log_grep.inc] file: percona_slow_query_log.query_plan_4 pattern: ^#.*Full_scan: No.*$
509+[log_grep.inc] lines: 2
510+SHOW SESSION STATUS LIKE 'Select_scan';
511+Variable_name Value
512+Select_scan 40
513+[log_start.inc] percona_slow_query_log.query_plan_5
514+SELECT COUNT(*) FROM t1;
515+COUNT(*)
516+2
517+[log_stop.inc] percona_slow_query_log.query_plan_5
518+[log_grep.inc] file: percona_slow_query_log.query_plan_5 pattern: ^#.*Full_scan: Yes.*$
519+[log_grep.inc] lines: 1
520+SHOW SESSION STATUS LIKE 'Select_scan';
521+Variable_name Value
522+Select_scan 44
523+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
524+[log_start.inc] percona_slow_query_log.query_plan_5a
525+SELECT COUNT(*) FROM t1;
526+COUNT(*)
527+2
528+[log_stop.inc] percona_slow_query_log.query_plan_5a
529+[log_grep.inc] file: percona_slow_query_log.query_plan_5a pattern: ^#.*Full_scan: Yes.*$
530+[log_grep.inc] lines: 0
531+SHOW SESSION STATUS LIKE 'Select_scan';
532+Variable_name Value
533+Select_scan 48
534+SET SESSION log_slow_filter=default;
535+CREATE TABLE t3(a INT NOT NULL AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB;
536+INSERT INTO t3 VALUES (1), (2), (3);
537+SHOW SESSION STATUS LIKE 'Select_full_join';
538+Variable_name Value
539+Select_full_join 0
540+[log_start.inc] percona_slow_query_log.query_plan_6
541+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a;
542+COUNT(*)
543+2
544+[log_stop.inc] percona_slow_query_log.query_plan_6
545+[log_grep.inc] file: percona_slow_query_log.query_plan_6 pattern: ^#.*Full_join: No.*$
546+[log_grep.inc] lines: 2
547+SHOW SESSION STATUS LIKE 'Select_full_join';
548+Variable_name Value
549+Select_full_join 0
550+[log_start.inc] percona_slow_query_log.query_plan_7
551+SELECT COUNT(*) FROM t1, t2 WHERE t1.b = t2.a;
552+COUNT(*)
553+8192
554+[log_stop.inc] percona_slow_query_log.query_plan_7
555+[log_grep.inc] file: percona_slow_query_log.query_plan_7 pattern: ^#.*Full_join: Yes.*$
556+[log_grep.inc] lines: 1
557+SHOW SESSION STATUS LIKE 'Select_full_join';
558+Variable_name Value
559+Select_full_join 1
560+SET SESSION log_slow_filter='tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
561+[log_start.inc] percona_slow_query_log.query_plan_7a
562+SELECT COUNT(*) FROM t1, t2 WHERE t1.b = t2.a;
563+COUNT(*)
564+8192
565+[log_stop.inc] percona_slow_query_log.query_plan_7a
566+[log_grep.inc] file: percona_slow_query_log.query_plan_7a pattern: ^#.*Full_join: Yes.*$
567+[log_grep.inc] lines: 0
568+SHOW SESSION STATUS LIKE 'Select_full_join';
569+Variable_name Value
570+Select_full_join 2
571+SET SESSION log_slow_filter=default;
572+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
573+Variable_name Value
574+Created_tmp_tables 49
575+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
576+Variable_name Value
577+Created_tmp_disk_tables 0
578+EXPLAIN SELECT COUNT(*) FROM t1;
579+id select_type table type possible_keys key key_len ref rows Extra
580+1 SIMPLE t1 index NULL PRIMARY 4 NULL 2 Using index
581+[log_start.inc] percona_slow_query_log.query_plan_8
582+SELECT COUNT(*) FROM t1;
583+COUNT(*)
584+2
585+[log_stop.inc] percona_slow_query_log.query_plan_8
586+[log_grep.inc] file: percona_slow_query_log.query_plan_8 pattern: ^#.*Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0$
587+[log_grep.inc] lines: 2
588+[log_grep.inc] file: percona_slow_query_log.query_plan_8 pattern: ^#.*Tmp_table: No Tmp_table_on_disk: No$
589+[log_grep.inc] lines: 2
590+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
591+Variable_name Value
592+Created_tmp_tables 52
593+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
594+Variable_name Value
595+Created_tmp_disk_tables 0
596+EXPLAIN SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
597+id select_type table type possible_keys key key_len ref rows Extra
598+1 SIMPLE t1 index PRIMARY PRIMARY 4 NULL 2 Using index; Using temporary; Using filesort
599+1 SIMPLE t3 eq_ref PRIMARY PRIMARY 4 test.t1.a 1 Using index
600+[log_start.inc] percona_slow_query_log.query_plan_9
601+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
602+COUNT(*)
603+1
604+1
605+[log_stop.inc] percona_slow_query_log.query_plan_9
606+[log_grep.inc] file: percona_slow_query_log.query_plan_9 pattern: ^#.*Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: [1-9][0-9]*$
607+[log_grep.inc] lines: 1
608+[log_grep.inc] file: percona_slow_query_log.query_plan_9 pattern: ^#.*Tmp_table: Yes Tmp_table_on_disk: No$
609+[log_grep.inc] lines: 1
610+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
611+Variable_name Value
612+Created_tmp_tables 56
613+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
614+Variable_name Value
615+Created_tmp_disk_tables 0
616+SET SESSION log_slow_filter='full_join,tmp_table_on_disk,filesort_on_disk';
617+[log_start.inc] percona_slow_query_log.query_plan_9a
618+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
619+COUNT(*)
620+1
621+1
622+[log_stop.inc] percona_slow_query_log.query_plan_9a
623+[log_grep.inc] file: percona_slow_query_log.query_plan_9a pattern: ^#.*Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: [1-9][0-9]*$
624+[log_grep.inc] lines: 0
625+[log_grep.inc] file: percona_slow_query_log.query_plan_9a pattern: ^#.*Tmp_table: Yes Tmp_table_on_disk: No$
626+[log_grep.inc] lines: 0
627+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
628+Variable_name Value
629+Created_tmp_tables 60
630+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
631+Variable_name Value
632+Created_tmp_disk_tables 0
633+SET SESSION log_slow_filter=default;
634+CREATE TABLE t4(a INT NOT NULL AUTO_INCREMENT PRIMARY KEY, b TEXT) ENGINE=InnoDB;
635+INSERT INTO t4 VALUES (1, "aaa"), (2, "bbb"), (3, "ccc");
636+EXPLAIN SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.a;
637+id select_type table type possible_keys key key_len ref rows Extra
638+1 SIMPLE t1 index PRIMARY PRIMARY 4 NULL 2 Using index; Using temporary; Using filesort
639+1 SIMPLE t4 eq_ref PRIMARY PRIMARY 4 test.t1.a 1 Using index
640+[log_start.inc] percona_slow_query_log.query_plan_10
641+SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.b;
642+COUNT(*)
643+1
644+1
645+[log_stop.inc] percona_slow_query_log.query_plan_10
646+[log_grep.inc] file: percona_slow_query_log.query_plan_10 pattern: ^#.*Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: [1-9][0-9]*$
647+[log_grep.inc] lines: 1
648+[log_grep.inc] file: percona_slow_query_log.query_plan_10 pattern: ^#.*Tmp_table: Yes Tmp_table_on_disk: Yes$
649+[log_grep.inc] lines: 1
650+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
651+Variable_name Value
652+Created_tmp_tables 64
653+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
654+Variable_name Value
655+Created_tmp_disk_tables 1
656+SET SESSION log_slow_filter='full_join,filesort_on_disk';
657+[log_start.inc] percona_slow_query_log.query_plan_10a
658+SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.b;
659+COUNT(*)
660+1
661+1
662+[log_stop.inc] percona_slow_query_log.query_plan_10a
663+[log_grep.inc] file: percona_slow_query_log.query_plan_10a pattern: ^#.*Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: [1-9][0-9]*$
664+[log_grep.inc] lines: 0
665+[log_grep.inc] file: percona_slow_query_log.query_plan_10a pattern: ^#.*Tmp_table: Yes Tmp_table_on_disk: Yes$
666+[log_grep.inc] lines: 0
667+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
668+Variable_name Value
669+Created_tmp_tables 68
670+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
671+Variable_name Value
672+Created_tmp_disk_tables 2
673+SET SESSION log_slow_filter=default;
674+SET SESSION long_query_time=default;
675+SET SESSION min_examined_row_limit=default;
676+SET SESSION log_slow_verbosity=default;
677+DROP TABLE t1, t2, t3, t4;
678
679=== added file 'Percona-Server/mysql-test/r/percona_log_slow_query_plan_qc.result'
680--- Percona-Server/mysql-test/r/percona_log_slow_query_plan_qc.result 1970-01-01 00:00:00 +0000
681+++ Percona-Server/mysql-test/r/percona_log_slow_query_plan_qc.result 2013-01-21 06:27:51 +0000
682@@ -0,0 +1,46 @@
683+FLUSH STATUS;
684+SET SESSION min_examined_row_limit=0;
685+DROP TABLE IF EXISTS t1;
686+CREATE TABLE t1 (a INT) ENGINE=InnoDB;
687+INSERT INTO t1 VALUE(5);
688+SET SESSION query_cache_type=1;
689+SET GLOBAL query_cache_size=1355776;
690+SET SESSION long_query_time=0;
691+SET SESSION log_slow_verbosity='microtime,query_plan';
692+[log_start.inc] percona_slow_query_log.query_plan_qc_1
693+SELECT * FROM t1;
694+a
695+5
696+[log_stop.inc] percona_slow_query_log.query_plan_qc_1
697+[log_grep.inc] file: percona_slow_query_log.query_plan_qc_1 pattern: ^# QC_Hit: No.*$
698+[log_grep.inc] lines: 2
699+SHOW STATUS LIKE 'Qcache_hits';
700+Variable_name Value
701+Qcache_hits 0
702+[log_start.inc] percona_slow_query_log.query_plan_qc_2
703+SELECT * FROM t1;
704+a
705+5
706+[log_stop.inc] percona_slow_query_log.query_plan_qc_2
707+[log_grep.inc] file: percona_slow_query_log.query_plan_qc_2 pattern: ^# QC_Hit: Yes.*$
708+[log_grep.inc] lines: 1
709+SHOW STATUS LIKE 'Qcache_hits';
710+Variable_name Value
711+Qcache_hits 1
712+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
713+[log_start.inc] percona_slow_query_log.query_plan_qc_3
714+SELECT * FROM t1 WHERE a > 5;
715+a
716+[log_stop.inc] percona_slow_query_log.query_plan_qc_3
717+[log_grep.inc] file: percona_slow_query_log.query_plan_qc_3 pattern: ^# QC_Hit: No.*$
718+[log_grep.inc] lines: 0
719+SHOW STATUS LIKE 'Qcache_hits';
720+Variable_name Value
721+Qcache_hits 1
722+SET SESSION log_slow_filter=default;
723+SET SESSION long_query_time=default;
724+SET SESSION log_slow_verbosity=default;
725+SET SESSION query_cache_type=default;
726+SET GLOBAL query_cache_size=default;
727+SET SESSION min_examined_row_limit=default;
728+DROP TABLE t1;
729
730=== added file 'Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result'
731--- Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result 1970-01-01 00:00:00 +0000
732+++ Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result 2013-01-21 06:27:51 +0000
733@@ -0,0 +1,28 @@
734+include/master-slave.inc
735+[connection master]
736+SET SESSION min_examined_row_limit=0;
737+DROP TABLE IF EXISTS t;
738+CREATE TABLE t(id INT,data CHAR(30)) ENGINE=InnoDB;
739+INSERT INTO t VALUES
740+(1,"aaaaabbbbbcccccdddddeeeeefffff"),
741+(2,"aaaaabbbbbcccccdddddeeeeefffff"),
742+(3,"aaaaabbbbbcccccdddddeeeeefffff"),
743+(4,"aaaaabbbbbcccccdddddeeeeefffff"),
744+(5,"aaaaabbbbbcccccdddddeeeeefffff");
745+INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
746+INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
747+SET GLOBAL long_query_time=0;
748+SET GLOBAL log_slow_slave_statements=TRUE;
749+SET GLOBAL log_slow_verbosity='innodb';
750+include/restart_slave.inc
751+[log_start.inc] percona.slow_extended.log_slow_slave_statements-innodb
752+INSERT INTO t SELECT t.id,t.data from t;
753+[log_stop.inc] percona.slow_extended.log_slow_slave_statements-innodb
754+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements-innodb pattern: InnoDB_IO_r_ops
755+[log_grep.inc] lines: 1
756+DROP TABLE t;
757+SET GLOBAL long_query_time=default;
758+SET GLOBAL log_slow_slave_statements=default;
759+SET GLOBAL log_slow_verbosity=default;
760+SET SESSION min_examined_row_limit=default;
761+include/rpl_end.inc
762
763=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result'
764--- Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result 2012-04-18 23:25:38 +0000
765+++ Percona-Server/mysql-test/r/percona_log_slow_slave_statements-innodb.result 1970-01-01 00:00:00 +0000
766@@ -1,19 +0,0 @@
767-include/master-slave.inc
768-[connection master]
769-DROP TABLE IF EXISTS t;
770-CREATE TABLE t(id INT,data CHAR(30)) ENGINE=InnoDB;
771-INSERT INTO t VALUES
772-(1,"aaaaabbbbbcccccdddddeeeeefffff"),
773-(2,"aaaaabbbbbcccccdddddeeeeefffff"),
774-(3,"aaaaabbbbbcccccdddddeeeeefffff"),
775-(4,"aaaaabbbbbcccccdddddeeeeefffff"),
776-(5,"aaaaabbbbbcccccdddddeeeeefffff");
777-INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
778-INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
779-[log_start.inc] percona.slow_extended.log_slow_slave_statements-innodb
780-INSERT INTO t SELECT t.id,t.data from t;
781-[log_stop.inc] percona.slow_extended.log_slow_slave_statements-innodb
782-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements-innodb pattern: InnoDB_IO_r_ops
783-[log_grep.inc] lines: 1
784-DROP TABLE t;
785-include/rpl_end.inc
786
787=== added file 'Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result'
788--- Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result 1970-01-01 00:00:00 +0000
789+++ Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result 2013-01-21 06:27:51 +0000
790@@ -0,0 +1,30 @@
791+include/master-slave.inc
792+[connection master]
793+DROP TABLE IF EXISTS t;
794+CREATE TABLE t(id INT) ENGINE=InnoDB;
795+SET GLOBAL min_examined_row_limit=0;
796+SET GLOBAL long_query_time=0;
797+SET GLOBAL log_slow_slave_statements=OFF;
798+include/restart_slave.inc
799+[log_start.inc] percona.slow_extended.log_slow_slave_statements
800+INSERT INTO t VALUES (1);
801+SET GLOBAL log_slow_slave_statements=ON;
802+BEGIN;
803+INSERT INTO t VALUES (2);
804+COMMIT;
805+SET GLOBAL log_slow_slave_statements=OFF;
806+INSERT INTO t VALUES (3);
807+[log_stop.inc] percona.slow_extended.log_slow_slave_statements
808+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(1\)
809+[log_grep.inc] lines: 0
810+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(2\)
811+[log_grep.inc] lines: 1
812+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(3\)
813+[log_grep.inc] lines: 0
814+[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: ^# User@Host: \[SQL_SLAVE\] @ \[\]
815+[log_grep.inc] lines: 2
816+DROP TABLE t;
817+SET GLOBAL log_slow_slave_statements=default;
818+SET GLOBAL long_query_time=default;
819+SET GLOBAL min_examined_row_limit=default;
820+include/rpl_end.inc
821
822=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result'
823--- Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result 2012-04-18 23:25:38 +0000
824+++ Percona-Server/mysql-test/r/percona_log_slow_slave_statements.result 1970-01-01 00:00:00 +0000
825@@ -1,45 +0,0 @@
826-include/master-slave.inc
827-[connection master]
828-DROP TABLE IF EXISTS t;
829-CREATE TABLE t(id INT);
830-[log_start.inc] percona.slow_extended.log_slow_slave_statements
831-LINE 1
832-LOG_SLOW_SLAVE_STATAMENTS is OFF
833-LOG_SLOW_SLAVE_STATEMENTS=ON
834-LOG_SLOW_SLAVE_STATAMENTS is ON
835-LINE 2
836-include/restart_slave.inc
837-LOG_SLOW_SLAVE_STATAMENTS is ON
838-LINE 3
839-LOG_SLOW_SLAVE_STATAMENTS is ON
840-LOG_SLOW_SLAVE_STATEMENTS=OFF
841-LOG_SLOW_SLAVE_STATAMENTS is OFF
842-LINE 4
843-include/restart_slave.inc
844-LOG_SLOW_SLAVE_STATAMENTS is OFF
845-LINE 5
846-LOG_SLOW_SLAVE_STATAMENTS is OFF
847-LOG_SLOW_SLAVE_STATEMENTS=ON
848-LOG_SLOW_SLAVE_STATAMENTS is ON
849-LINE 6
850-include/restart_slave.inc
851-LOG_SLOW_SLAVE_STATAMENTS is ON
852-LINE 7
853-[log_stop.inc] percona.slow_extended.log_slow_slave_statements
854-SET GLOBAL log_slow_slave_statements=default;
855-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(1\)
856-[log_grep.inc] lines: 0
857-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(2\)
858-[log_grep.inc] lines: 0
859-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(3\)
860-[log_grep.inc] lines: 1
861-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(4\)
862-[log_grep.inc] lines: 0
863-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(5\)
864-[log_grep.inc] lines: 0
865-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(6\)
866-[log_grep.inc] lines: 0
867-[log_grep.inc] file: percona.slow_extended.log_slow_slave_statements pattern: INSERT INTO t VALUES \(7\)
868-[log_grep.inc] lines: 1
869-DROP TABLE t;
870-include/rpl_end.inc
871
872=== added file 'Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result'
873--- Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result 1970-01-01 00:00:00 +0000
874+++ Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result 2013-01-21 06:27:51 +0000
875@@ -0,0 +1,29 @@
876+DROP PROCEDURE IF EXISTS test_f;
877+SET SESSION min_examined_row_limit=0;
878+SET SESSION long_query_time=0;
879+SET SESSION query_cache_type=0;
880+CREATE PROCEDURE test_f()
881+BEGIN
882+SELECT 1;
883+END^
884+SET GLOBAL log_slow_sp_statements=ON;
885+[log_start.inc] percona.slow_extended.sp1
886+CALL test_f();
887+1
888+1
889+[log_stop.inc] percona.slow_extended.sp1
890+[log_grep.inc] file: percona.slow_extended.sp1 pattern: SELECT 1;
891+[log_grep.inc] lines: 1
892+SET GLOBAL log_slow_sp_statements=OFF;
893+[log_start.inc] percona.slow_extended.sp2
894+CALL test_f();
895+1
896+1
897+[log_stop.inc] percona.slow_extended.sp2
898+[log_grep.inc] file: percona.slow_extended.sp2 pattern: SELECT 1;
899+[log_grep.inc] lines: 0
900+DROP PROCEDURE test_f;
901+SET GLOBAL log_slow_sp_statements=default;
902+SET SESSION long_query_time=default;
903+SET SESSION min_examined_row_limit=default;
904+SET SESSION query_cache_type=default;
905
906=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result'
907--- Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result 2012-04-18 23:25:38 +0000
908+++ Percona-Server/mysql-test/r/percona_log_slow_sp_statements.result 1970-01-01 00:00:00 +0000
909@@ -1,25 +0,0 @@
910-SET long_query_time=1;
911-SET GLOBAL log_slow_sp_statements=ON;
912-SET SESSION query_exec_time=0.1;
913-[log_start.inc] percona.slow_extended.log_slow_sp_statements
914-CREATE PROCEDURE test_f()
915-BEGIN
916-SET SESSION query_exec_time=1.1; SELECT 1;
917-SET SESSION query_exec_time=2.1; SELECT 1;
918-SET SESSION query_exec_time=3.1; SELECT 1;
919-SET SESSION query_exec_time=0.1;
920-END^
921-CALL test_f();
922-1
923-1
924-1
925-1
926-1
927-1
928-[log_stop.inc] percona.slow_extended.log_slow_sp_statements
929-SET SESSION query_exec_time=default;
930-SET GLOBAL log_slow_sp_statements=default;
931-SET long_query_time=default;
932-[log_grep.inc] file: percona.slow_extended.log_slow_sp_statements pattern: Query_time
933-[log_grep.inc] lines: 3
934-DROP PROCEDURE test_f;
935
936=== added file 'Percona-Server/mysql-test/r/percona_log_slow_verbosity.result'
937--- Percona-Server/mysql-test/r/percona_log_slow_verbosity.result 1970-01-01 00:00:00 +0000
938+++ Percona-Server/mysql-test/r/percona_log_slow_verbosity.result 2013-01-21 06:27:51 +0000
939@@ -0,0 +1,118 @@
940+DROP TABLE IF EXISTS t1;
941+CREATE TABLE t1(a INT) ENGINE=InnoDB;
942+SET SESSION min_examined_row_limit=0;
943+SET SESSION long_query_time=0;
944+SET SESSION log_slow_verbosity='microtime,innodb,query_plan';
945+[log_start.inc] percona.slow_extended.log_slow_verbosity_0
946+INSERT INTO t1 VALUE(0);
947+[log_stop.inc] percona.slow_extended.log_slow_verbosity_0
948+log_slow_verbosity='microtime,innodb,query_plan':
949+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# Thread_id: \d+ Schema: .+ Last_errno: \d+ Killed: \d+$
950+[log_grep.inc] lines: 2
951+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^#.*Rows_affected: \d+ Rows_read: \d+$
952+[log_grep.inc] lines: 2
953+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# Bytes_sent: \d+.*$
954+[log_grep.inc] lines: 2
955+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# InnoDB_trx_id: \w+$
956+[log_grep.inc] lines: 1
957+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# Bytes_sent: \d+ Tmp_tables: \d+ Tmp_disk_tables: \d+ Tmp_table_sizes: \d+$
958+[log_grep.inc] lines: 2
959+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# QC_Hit: (Yes|No) Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
960+[log_grep.inc] lines: 2
961+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+$
962+[log_grep.inc] lines: 2
963+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# InnoDB_IO_r_ops: \d+ InnoDB_IO_r_bytes: \d+ InnoDB_IO_r_wait: \d*\.\d*$
964+[log_grep.inc] lines: 1
965+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# InnoDB_rec_lock_wait: \d*\.\d* InnoDB_queue_wait: \d*\.\d*$
966+[log_grep.inc] lines: 1
967+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# InnoDB_pages_distinct: \d+$
968+[log_grep.inc] lines: 1
969+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_0 pattern: ^# No InnoDB statistics available for this query$
970+[log_grep.inc] lines: 1
971+SET SESSION log_slow_verbosity='microtime,innodb,query_plan';
972+[log_start.inc] percona.slow_extended.log_slow_verbosity_1
973+SELECT 1;
974+1
975+1
976+[log_stop.inc] percona.slow_extended.log_slow_verbosity_1
977+log_slow_verbosity='microtime,innodb,query_plan':
978+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# Thread_id: \d+ Schema: .+ Last_errno: \d+ Killed: \d+$
979+[log_grep.inc] lines: 2
980+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^#.*Rows_affected: \d+ Rows_read: \d+$
981+[log_grep.inc] lines: 2
982+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# Bytes_sent: \d+.*$
983+[log_grep.inc] lines: 2
984+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# InnoDB_trx_id: \w+$
985+[log_grep.inc] lines: 0
986+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# Bytes_sent: \d+ Tmp_tables: \d+ Tmp_disk_tables: \d+ Tmp_table_sizes: \d+$
987+[log_grep.inc] lines: 2
988+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# QC_Hit: (Yes|No) Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
989+[log_grep.inc] lines: 2
990+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+$
991+[log_grep.inc] lines: 2
992+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# InnoDB_IO_r_ops: \d+ InnoDB_IO_r_bytes: \d+ InnoDB_IO_r_wait: \d*\.\d*$
993+[log_grep.inc] lines: 0
994+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# InnoDB_rec_lock_wait: \d*\.\d* InnoDB_queue_wait: \d*\.\d*$
995+[log_grep.inc] lines: 0
996+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# InnoDB_pages_distinct: \d+$
997+[log_grep.inc] lines: 0
998+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_1 pattern: ^# No InnoDB statistics available for this query$
999+[log_grep.inc] lines: 2
1000+SET log_slow_verbosity='microtime';
1001+[log_start.inc] percona.slow_extended.log_slow_verbosity_2
1002+INSERT INTO t1 VALUE(1);
1003+[log_stop.inc] percona.slow_extended.log_slow_verbosity_2
1004+log_slow_verbosity='microtime':
1005+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# Thread_id: \d+ Schema: .+ Last_errno: \d+ Killed: \d+$
1006+[log_grep.inc] lines: 2
1007+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^#.*Rows_affected: \d+ Rows_read: \d+$
1008+[log_grep.inc] lines: 2
1009+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# Bytes_sent: \d+.*$
1010+[log_grep.inc] lines: 2
1011+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# InnoDB_trx_id: \w+$
1012+[log_grep.inc] lines: 0
1013+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# Bytes_sent: \d+ Tmp_tables: \d+ Tmp_disk_tables: \d+ Tmp_table_sizes: \d+$
1014+[log_grep.inc] lines: 0
1015+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# QC_Hit: (Yes|No) Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
1016+[log_grep.inc] lines: 0
1017+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+$
1018+[log_grep.inc] lines: 0
1019+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# InnoDB_IO_r_ops: \d+ InnoDB_IO_r_bytes: \d+ InnoDB_IO_r_wait: \d*\.\d*$
1020+[log_grep.inc] lines: 0
1021+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# InnoDB_rec_lock_wait: \d*\.\d* InnoDB_queue_wait: \d*\.\d*$
1022+[log_grep.inc] lines: 0
1023+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# InnoDB_pages_distinct: \d+$
1024+[log_grep.inc] lines: 0
1025+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_2 pattern: ^# No InnoDB statistics available for this query$
1026+[log_grep.inc] lines: 0
1027+SET log_slow_verbosity='microtime,query_plan';
1028+[log_start.inc] percona.slow_extended.log_slow_verbosity_3
1029+INSERT INTO t1 VALUE(2);
1030+[log_stop.inc] percona.slow_extended.log_slow_verbosity_3
1031+log_slow_verbosity='query_plan':
1032+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# Thread_id: \d+ Schema: .+ Last_errno: \d+ Killed: \d+$
1033+[log_grep.inc] lines: 2
1034+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^#.*Rows_affected: \d+ Rows_read: \d+$
1035+[log_grep.inc] lines: 2
1036+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# Bytes_sent: \d+.*$
1037+[log_grep.inc] lines: 2
1038+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# InnoDB_trx_id: \w+$
1039+[log_grep.inc] lines: 0
1040+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# Bytes_sent: \d+ Tmp_tables: \d+ Tmp_disk_tables: \d+ Tmp_table_sizes: \d+$
1041+[log_grep.inc] lines: 2
1042+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# QC_Hit: (Yes|No) Full_scan: (Yes|No) Full_join: (Yes|No) Tmp_table: (Yes|No) Tmp_table_on_disk: (Yes|No)$
1043+[log_grep.inc] lines: 2
1044+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# Filesort: (Yes|No) Filesort_on_disk: (Yes|No) Merge_passes: \d+$
1045+[log_grep.inc] lines: 2
1046+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# InnoDB_IO_r_ops: \d+ InnoDB_IO_r_bytes: \d+ InnoDB_IO_r_wait: \d*\.\d*$
1047+[log_grep.inc] lines: 0
1048+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# InnoDB_rec_lock_wait: \d*\.\d* InnoDB_queue_wait: \d*\.\d*$
1049+[log_grep.inc] lines: 0
1050+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# InnoDB_pages_distinct: \d+$
1051+[log_grep.inc] lines: 0
1052+[log_grep.inc] file: percona.slow_extended.log_slow_verbosity_3 pattern: ^# No InnoDB statistics available for this query$
1053+[log_grep.inc] lines: 0
1054+SET SESSION log_slow_verbosity=default;
1055+SET SESSION long_query_time=default;
1056+SET SESSION min_examined_row_limit=default;
1057+DROP TABLE t1;
1058
1059=== removed file 'Percona-Server/mysql-test/r/percona_log_slow_verbosity.result'
1060--- Percona-Server/mysql-test/r/percona_log_slow_verbosity.result 2012-04-18 23:25:38 +0000
1061+++ Percona-Server/mysql-test/r/percona_log_slow_verbosity.result 1970-01-01 00:00:00 +0000
1062@@ -1,16 +0,0 @@
1063-SET SESSION long_query_time=1;
1064-[log_start.inc] percona.slow_extended.log_slow_verbosity
1065-SET SESSION query_exec_time=2.1;
1066-SELECT 1;
1067-1
1068-1
1069-SET SESSION log_slow_verbosity=innodb;
1070-SELECT 1;
1071-1
1072-1
1073-SET SESSION query_exec_time=default;
1074-[log_stop.inc] percona.slow_extended.log_slow_verbosity
1075-SET log_slow_verbosity=default;
1076-SET long_query_time=default;
1077-[log_grep.inc] file: percona.slow_extended.log_slow_verbosity pattern: No InnoDB statistics available for this query
1078-[log_grep.inc] lines: 1
1079
1080=== added file 'Percona-Server/mysql-test/r/percona_long_query_time.result'
1081--- Percona-Server/mysql-test/r/percona_long_query_time.result 1970-01-01 00:00:00 +0000
1082+++ Percona-Server/mysql-test/r/percona_long_query_time.result 2013-01-21 06:27:51 +0000
1083@@ -0,0 +1,35 @@
1084+SET SESSION min_examined_row_limit=0;
1085+SET long_query_time=2;
1086+[log_start.inc] percona.slow_extended.long_query_time
1087+SET SESSION query_exec_time=1.1;
1088+SELECT 1;
1089+1
1090+1
1091+SET SESSION query_exec_time=3.1;
1092+SELECT 1;
1093+1
1094+1
1095+SET SESSION query_exec_time=5.1;
1096+SELECT 1;
1097+1
1098+1
1099+SET long_query_time=4;
1100+SET SESSION query_exec_time=1.1;
1101+SELECT 1;
1102+1
1103+1
1104+SET SESSION query_exec_time=3.1;
1105+SELECT 1;
1106+1
1107+1
1108+SET SESSION query_exec_time=5.1;
1109+SELECT 1;
1110+1
1111+1
1112+SET SESSION query_exec_time=default;
1113+SET long_query_time=2;
1114+[log_stop.inc] percona.slow_extended.long_query_time
1115+SET long_query_time=default;
1116+SET SESSION min_examined_row_limit=default;
1117+[log_grep.inc] file: percona.slow_extended.long_query_time pattern: Query_time
1118+[log_grep.inc] lines: 3
1119
1120=== removed file 'Percona-Server/mysql-test/r/percona_long_query_time.result'
1121--- Percona-Server/mysql-test/r/percona_long_query_time.result 2012-04-18 23:25:38 +0000
1122+++ Percona-Server/mysql-test/r/percona_long_query_time.result 1970-01-01 00:00:00 +0000
1123@@ -1,33 +0,0 @@
1124-SET long_query_time=2;
1125-[log_start.inc] percona.slow_extended.long_query_time
1126-SET SESSION query_exec_time=1.1;
1127-SELECT 1;
1128-1
1129-1
1130-SET SESSION query_exec_time=3.1;
1131-SELECT 1;
1132-1
1133-1
1134-SET SESSION query_exec_time=5.1;
1135-SELECT 1;
1136-1
1137-1
1138-SET long_query_time=4;
1139-SET SESSION query_exec_time=1.1;
1140-SELECT 1;
1141-1
1142-1
1143-SET SESSION query_exec_time=3.1;
1144-SELECT 1;
1145-1
1146-1
1147-SET SESSION query_exec_time=5.1;
1148-SELECT 1;
1149-1
1150-1
1151-SET SESSION query_exec_time=default;
1152-SET long_query_time=2;
1153-[log_stop.inc] percona.slow_extended.long_query_time
1154-SET long_query_time=default;
1155-[log_grep.inc] file: percona.slow_extended.long_query_time pattern: Query_time
1156-[log_grep.inc] lines: 3
1157
1158=== modified file 'Percona-Server/mysql-test/r/percona_min_examined_row_limit.result'
1159--- Percona-Server/mysql-test/r/percona_min_examined_row_limit.result 2012-04-18 23:25:38 +0000
1160+++ Percona-Server/mysql-test/r/percona_min_examined_row_limit.result 2013-01-21 06:27:51 +0000
1161@@ -11,7 +11,7 @@
1162 1
1163 1
1164 SET GLOBAL min_examined_row_limit=5;
1165-select * from t as t1, t as t2;
1166+SELECT * FROM t AS t1, t AS t2;
1167 id id
1168 1 1
1169 2 1
1170
1171=== modified file 'Percona-Server/mysql-test/r/percona_slow_extended_error_on_quit.result'
1172--- Percona-Server/mysql-test/r/percona_slow_extended_error_on_quit.result 2012-10-27 05:16:07 +0000
1173+++ Percona-Server/mysql-test/r/percona_slow_extended_error_on_quit.result 2013-01-21 06:27:51 +0000
1174@@ -1,172 +1,27 @@
1175 DROP TABLE IF EXISTS t;
1176-CREATE TABLE t(a INT) engine=InnoDB;
1177-INSERT INTO t VALUES(0),(1),(2),(3),(4);
1178-[log_start.inc] percona.slow_extended.error_on_quit
1179-SET log_slow_verbosity=innodb;
1180-SET long_query_time= 0;
1181-CREATE TABLE t(a INT) engine=InnoDB;
1182-# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
1183-[log_stop.inc] percona.slow_extended.error_on_quit
1184-################################################################################
1185-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
1186-[log_grep.inc] lines: 1
1187-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
1188-[log_grep.inc] lines: 0
1189-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
1190-[log_grep.inc] lines: 0
1191-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
1192-[log_grep.inc] lines: 1
1193-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
1194-[log_grep.inc] lines: 1
1195-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
1196-[log_grep.inc] lines: 2
1197-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
1198-[log_grep.inc] lines: 0
1199-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
1200-[log_grep.inc] lines: 3
1201-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
1202-[log_grep.inc] lines: 0
1203-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
1204-[log_grep.inc] lines: 3
1205-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
1206-[log_grep.inc] lines: 0
1207-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
1208-[log_grep.inc] lines: 3
1209-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
1210-[log_grep.inc] lines: 0
1211-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
1212-[log_grep.inc] lines: 3
1213-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
1214-[log_grep.inc] lines: 2
1215-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
1216-[log_grep.inc] lines: 1
1217-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
1218-[log_grep.inc] lines: 0
1219-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
1220-[log_grep.inc] lines: 3
1221-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
1222-[log_grep.inc] lines: 0
1223-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
1224-[log_grep.inc] lines: 3
1225-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
1226-[log_grep.inc] lines: 0
1227-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
1228-[log_grep.inc] lines: 3
1229-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
1230-[log_grep.inc] lines: 2
1231-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id:
1232-[log_grep.inc] lines: 1
1233-################################################################################
1234-[log_start.inc] percona.slow_extended.error_on_quit
1235-SET log_slow_verbosity=innodb;
1236-SET long_query_time= 0;
1237-INSERT INTO t SELECT * FROM t ORDER BY RAND();
1238-# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
1239-[log_stop.inc] percona.slow_extended.error_on_quit
1240-################################################################################
1241-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
1242-[log_grep.inc] lines: 0
1243-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
1244-[log_grep.inc] lines: 1
1245-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
1246-[log_grep.inc] lines: 1
1247-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
1248-[log_grep.inc] lines: 1
1249-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
1250-[log_grep.inc] lines: 0
1251-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
1252-[log_grep.inc] lines: 3
1253-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
1254-[log_grep.inc] lines: 0
1255-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
1256-[log_grep.inc] lines: 3
1257-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
1258-[log_grep.inc] lines: 1
1259-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
1260-[log_grep.inc] lines: 2
1261-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
1262-[log_grep.inc] lines: 2
1263-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
1264-[log_grep.inc] lines: 1
1265-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
1266-[log_grep.inc] lines: 1
1267-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
1268-[log_grep.inc] lines: 2
1269-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
1270-[log_grep.inc] lines: 2
1271-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
1272-[log_grep.inc] lines: 1
1273-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
1274-[log_grep.inc] lines: 1
1275-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
1276-[log_grep.inc] lines: 2
1277-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
1278-[log_grep.inc] lines: 0
1279-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
1280-[log_grep.inc] lines: 3
1281-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
1282-[log_grep.inc] lines: 1
1283-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
1284-[log_grep.inc] lines: 2
1285-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
1286-[log_grep.inc] lines: 2
1287-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id:
1288-[log_grep.inc] lines: 1
1289-################################################################################
1290-[log_start.inc] percona.slow_extended.error_on_quit
1291-SET log_slow_verbosity=innodb;
1292-SET long_query_time= 0;
1293+SET GLOBAL log_slow_admin_statements=ON;
1294+SET GLOBAL long_query_time=0;
1295+SET GLOBAL min_examined_row_limit=0;
1296+CREATE TABLE t(a INT) engine=InnoDB;
1297+[log_start.inc] percona.slow_extended.error_on_quit_1
1298+CREATE TABLE t(a INT) engine=InnoDB;
1299+ERROR 42S01: Table 't' already exists
1300+[log_stop.inc] percona.slow_extended.error_on_quit_1
1301+[log_grep.inc] file: percona.slow_extended.error_on_quit_1 pattern: Last_errno: [1-9]\d*\s
1302+[log_grep.inc] lines: 1
1303+[log_start.inc] percona.slow_extended.error_on_quit_2
1304+# Disconnecting (passing to Slow Query Log "# administrative command: Quit")
1305+[log_stop.inc] percona.slow_extended.error_on_quit_2
1306+[log_grep.inc] file: percona.slow_extended.error_on_quit_2 pattern: Last_errno: 0\s
1307+[log_grep.inc] lines: 2
1308+[log_start.inc] percona.slow_extended.error_on_quit_3
1309 SELECT * FROM t;
1310+a
1311 # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
1312-[log_stop.inc] percona.slow_extended.error_on_quit
1313-################################################################################
1314-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE
1315-[log_grep.inc] lines: 0
1316-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT
1317-[log_grep.inc] lines: 0
1318-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT
1319-[log_grep.inc] lines: 1
1320-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit
1321-[log_grep.inc] lines: 1
1322-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+
1323-[log_grep.inc] lines: 0
1324-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0
1325-[log_grep.inc] lines: 3
1326-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+
1327-[log_grep.inc] lines: 1
1328-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0
1329-[log_grep.inc] lines: 2
1330-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+
1331-[log_grep.inc] lines: 1
1332-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0
1333-[log_grep.inc] lines: 2
1334-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+
1335-[log_grep.inc] lines: 0
1336-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0
1337-[log_grep.inc] lines: 3
1338-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+
1339-[log_grep.inc] lines: 1
1340-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0
1341-[log_grep.inc] lines: 2
1342-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+
1343-[log_grep.inc] lines: 2
1344-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0
1345-[log_grep.inc] lines: 1
1346-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+
1347-[log_grep.inc] lines: 0
1348-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0
1349-[log_grep.inc] lines: 3
1350-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+
1351-[log_grep.inc] lines: 0
1352-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0
1353-[log_grep.inc] lines: 3
1354-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+
1355-[log_grep.inc] lines: 0
1356-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0
1357-[log_grep.inc] lines: 3
1358-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query
1359-[log_grep.inc] lines: 2
1360-[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id:
1361-[log_grep.inc] lines: 1
1362-################################################################################
1363+[log_stop.inc] percona.slow_extended.error_on_quit_3
1364+[log_grep.inc] file: percona.slow_extended.error_on_quit_3 pattern: Last_errno: 0\s
1365+[log_grep.inc] lines: 3
1366 DROP TABLE t;
1367+SET GLOBAL log_slow_admin_statements=default;
1368+SET GLOBAL long_query_time=default;
1369+SET GLOBAL min_examined_row_limit=default;
1370
1371=== added file 'Percona-Server/mysql-test/r/percona_slow_extended_log_error.result'
1372--- Percona-Server/mysql-test/r/percona_slow_extended_log_error.result 1970-01-01 00:00:00 +0000
1373+++ Percona-Server/mysql-test/r/percona_slow_extended_log_error.result 2013-01-21 06:27:51 +0000
1374@@ -0,0 +1,17 @@
1375+DROP TABLE IF EXISTS t1;
1376+SET SESSION min_examined_row_limit=0;
1377+SET long_query_time=0;
1378+[log_start.inc] percona.slow_extended.log_error_1
1379+CREATE TABLE t1(a INT);
1380+[log_stop.inc] percona.slow_extended.log_error_1
1381+[log_grep.inc] file: percona.slow_extended.log_error_1 pattern: ^.*Last_errno: 0 .*$
1382+[log_grep.inc] lines: 2
1383+[log_start.inc] percona.slow_extended.log_error_2
1384+CREATE TABLE t1(a INT);
1385+ERROR 42S01: Table 't1' already exists
1386+[log_stop.inc] percona.slow_extended.log_error_2
1387+[log_grep.inc] file: percona.slow_extended.log_error_2 pattern: ^.*Last_errno: 1050 .*$
1388+[log_grep.inc] lines: 1
1389+DROP TABLE t1;
1390+SET long_query_time=default;
1391+SET SESSION min_examined_row_limit=default;
1392
1393=== removed file 'Percona-Server/mysql-test/r/percona_slow_extended_log_error.result'
1394--- Percona-Server/mysql-test/r/percona_slow_extended_log_error.result 2012-04-18 23:25:38 +0000
1395+++ Percona-Server/mysql-test/r/percona_slow_extended_log_error.result 1970-01-01 00:00:00 +0000
1396@@ -1,10 +0,0 @@
1397-SET long_query_time=0;
1398-DROP TABLE IF EXISTS t1;
1399-CREATE TABLE t(a INT);
1400-[log_start.inc] percona.slow_extended.log_error
1401-CREATE TABLE t(a INT);
1402-ERROR 42S01: Table 't' already exists
1403-[log_stop.inc] percona.slow_extended.log_error
1404-[log_grep.inc] file: percona.slow_extended.log_error pattern: Last_errno: 1050
1405-[log_grep.inc] lines: 1
1406-DROP TABLE t;
1407
1408=== modified file 'Percona-Server/mysql-test/r/percona_slow_query_log_rate.result'
1409--- Percona-Server/mysql-test/r/percona_slow_query_log_rate.result 2012-04-18 23:25:38 +0000
1410+++ Percona-Server/mysql-test/r/percona_slow_query_log_rate.result 2013-01-21 06:27:51 +0000
1411@@ -1,78 +1,54 @@
1412-SET GLOBAL long_query_time=1;
1413+SET GLOBAL long_query_time=0;
1414 SET GLOBAL log_slow_rate_type='session';
1415 SET GLOBAL log_slow_rate_limit=3;
1416-[log_start.inc] percona.slow_extended.log_slow_rate_limit
1417-SET SESSION query_exec_time=1.1;
1418-SET SESSION query_exec_id=1;
1419-SELECT 'connection_one';
1420-connection_one
1421-connection_one
1422-SET SESSION query_exec_time=1.1;
1423-SET SESSION query_exec_id=2;
1424-SELECT 'connection_two';
1425-connection_two
1426-connection_two
1427-SET SESSION query_exec_time=1.1;
1428-SET SESSION query_exec_id=3;
1429-SELECT 'connection_three';
1430-connection_three
1431-connection_three
1432-SET SESSION query_exec_time=1.1;
1433-SET SESSION query_exec_id=4;
1434-SELECT 'connection_one';
1435-connection_one
1436-connection_one
1437-SET SESSION query_exec_time=1.1;
1438-SET SESSION query_exec_id=5;
1439-SELECT 'connection_two';
1440-connection_two
1441-connection_two
1442-SET SESSION query_exec_time=1.1;
1443-SET SESSION query_exec_id=6;
1444-SELECT 'connection_three';
1445-connection_three
1446-connection_three
1447-[log_stop.inc] percona.slow_extended.log_slow_rate_limit
1448-[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit pattern:
1449+[log_start.inc] percona.slow_extended.log_slow_rate_limit_1
1450+SELECT 'connection_one';
1451+connection_one
1452+connection_one
1453+SELECT 'connection_two';
1454+connection_two
1455+connection_two
1456+SELECT 'connection_three';
1457+connection_three
1458+connection_three
1459+SELECT 'connection_one';
1460+connection_one
1461+connection_one
1462+SELECT 'connection_two';
1463+connection_two
1464+connection_two
1465+SELECT 'connection_three';
1466+connection_three
1467+connection_three
1468+[log_stop.inc] percona.slow_extended.log_slow_rate_limit_1
1469+[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit_1 pattern:
1470 [log_grep.inc] sum: 2
1471 [log_grep.inc] zero: 2
1472 SET GLOBAL log_slow_rate_type='query';
1473 SET GLOBAL log_slow_rate_limit=2;
1474-[log_start.inc] percona.slow_extended.log_slow_rate_limit
1475-SET SESSION query_exec_time=1.1;
1476-SET SESSION query_exec_id=1;
1477-SELECT 'connection_one';
1478-connection_one
1479-connection_one
1480-SET SESSION query_exec_time=1.1;
1481-SET SESSION query_exec_id=2;
1482-SELECT 'connection_two';
1483-connection_two
1484-connection_two
1485-SET SESSION query_exec_time=1.1;
1486-SET SESSION query_exec_id=3;
1487-SELECT 'connection_three';
1488-connection_three
1489-connection_three
1490-SET SESSION query_exec_time=1.1;
1491-SET SESSION query_exec_id=4;
1492-SELECT 'connection_one';
1493-connection_one
1494-connection_one
1495-SET SESSION query_exec_time=1.1;
1496-SET SESSION query_exec_id=5;
1497-SELECT 'connection_two';
1498-connection_two
1499-connection_two
1500-SET SESSION query_exec_time=1.1;
1501-SET SESSION query_exec_id=6;
1502-SELECT 'connection_three';
1503-connection_three
1504-connection_three
1505-[log_stop.inc] percona.slow_extended.log_slow_rate_limit
1506-[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit pattern:
1507-[log_grep.inc] sum: 3
1508-[log_grep.inc] zero: 0
1509+[log_start.inc] percona.slow_extended.log_slow_rate_limit_2
1510+SELECT 'connection_one';
1511+connection_one
1512+connection_one
1513+SELECT 'connection_two';
1514+connection_two
1515+connection_two
1516+SELECT 'connection_three';
1517+connection_three
1518+connection_three
1519+SELECT 'connection_one';
1520+connection_one
1521+connection_one
1522+SELECT 'connection_two';
1523+connection_two
1524+connection_two
1525+SELECT 'connection_three';
1526+connection_three
1527+connection_three
1528+[log_stop.inc] percona.slow_extended.log_slow_rate_limit_2
1529+[log_grep.inc] file: percona.slow_extended.log_slow_rate_limit_2 pattern:
1530+[log_grep.inc] sum: 0
1531+[log_grep.inc] zero: 3
1532 SET GLOBAL long_query_time=default;
1533 SET GLOBAL log_slow_rate_type=default;
1534 SET GLOBAL log_slow_rate_limit=default;
1535
1536=== added file 'Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result'
1537--- Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result 1970-01-01 00:00:00 +0000
1538+++ Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result 2013-01-21 06:27:51 +0000
1539@@ -0,0 +1,16 @@
1540+SET SESSION min_examined_row_limit=0;
1541+SET SESSION long_query_time=0;
1542+SET GLOBAL slow_query_log_timestamp_always=TRUE;
1543+[log_start.inc] percona_slow_extended_query_log_1
1544+SELECT 1;
1545+1
1546+1
1547+SELECT 2;
1548+2
1549+2
1550+[log_stop.inc] percona_slow_extended_query_log_1
1551+[log_grep.inc] file: percona_slow_extended_query_log_1 pattern: ^# Time: \d{6} (\d| )\d:\d\d:\d\d$
1552+[log_grep.inc] lines: 3
1553+SET GLOBAL slow_query_log_timestamp_always=default;
1554+SET SESSION long_query_time=default;
1555+SET SESSION min_examined_row_limit=default;
1556
1557=== removed file 'Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result'
1558--- Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result 2012-04-18 23:25:38 +0000
1559+++ Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_always.result 1970-01-01 00:00:00 +0000
1560@@ -1,41 +0,0 @@
1561-SET long_query_time=2;
1562-SET GLOBAL slow_query_log_timestamp_always=ON;
1563-[log_start.inc] percona.slow_extended.slow_query_log_timestamp_always
1564-SET SESSION query_exec_time=2.1;
1565-SELECT 1;
1566-1
1567-1
1568-SELECT 1;
1569-1
1570-1
1571-SELECT 1;
1572-1
1573-1
1574-SET GLOBAL slow_query_log_timestamp_always=OFF;
1575-SET SESSION query_exec_time=2.1;
1576-SELECT 1;
1577-1
1578-1
1579-SELECT 1;
1580-1
1581-1
1582-SELECT 1;
1583-1
1584-1
1585-SET GLOBAL slow_query_log_timestamp_always=ON;
1586-SET SESSION query_exec_time=2.1;
1587-SELECT 1;
1588-1
1589-1
1590-SELECT 1;
1591-1
1592-1
1593-SELECT 1;
1594-1
1595-1
1596-SET SESSION query_exec_time=default;
1597-[log_stop.inc] percona.slow_extended.slow_query_log_timestamp_always
1598-SET GLOBAL slow_query_log_timestamp_always=default;
1599-SET long_query_time=default;
1600-[log_grep.inc] file: percona.slow_extended.slow_query_log_timestamp_always pattern: # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+
1601-[log_grep.inc] lines: 6
1602
1603=== added file 'Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result'
1604--- Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result 1970-01-01 00:00:00 +0000
1605+++ Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result 2013-01-21 06:27:51 +0000
1606@@ -0,0 +1,24 @@
1607+SET @old_slow_query_log_timestamp_always=@@slow_query_log_timestamp_always;
1608+SET SESSION min_examined_row_limit=0;
1609+SET long_query_time=0;
1610+SET GLOBAL slow_query_log_timestamp_always=TRUE;
1611+SET GLOBAL slow_query_log_timestamp_precision='microsecond';
1612+[log_start.inc] percona_slow_extended_1
1613+SELECT 1;
1614+1
1615+1
1616+[log_stop.inc] percona_slow_extended_1
1617+[log_grep.inc] file: percona_slow_extended_1 pattern: ^# Time: \d{6} (\d| )\d:\d\d:\d\d\.\d{6}$
1618+[log_grep.inc] lines: 2
1619+SET GLOBAL slow_query_log_timestamp_precision='second';
1620+[log_start.inc] percona_slow_extended_2
1621+SELECT 1;
1622+1
1623+1
1624+[log_stop.inc] percona_slow_extended_2
1625+[log_grep.inc] file: percona_slow_extended_2 pattern: ^# Time: \d{6} (\d| )\d:\d\d:\d\d$
1626+[log_grep.inc] lines: 2
1627+SET long_query_time=default;
1628+SET SESSION min_examined_row_limit=default;
1629+SET GLOBAL slow_query_log_timestamp_always=@old_slow_query_log_timestamp_always;
1630+SET GLOBAL slow_query_log_timestamp_precision=default;
1631
1632=== removed file 'Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result'
1633--- Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result 2012-04-18 23:25:38 +0000
1634+++ Percona-Server/mysql-test/r/percona_slow_query_log_timestamp_precision.result 1970-01-01 00:00:00 +0000
1635@@ -1,18 +0,0 @@
1636-SET long_query_time=2;
1637-[log_start.inc] percona.slow_extended.slow_query_log_timestamp_precision
1638-SET SESSION query_exec_time=2.1;
1639-SELECT 1;
1640-1
1641-1
1642-SET GLOBAL slow_query_log_timestamp_precision='microsecond';
1643-SELECT 1;
1644-1
1645-1
1646-SET SESSION query_exec_time=default;
1647-[log_stop.inc] percona.slow_extended.slow_query_log_timestamp_precision
1648-SET GLOBAL slow_query_log_timestamp_precision=default;
1649-SET long_query_time=default;
1650-[log_grep.inc] file: percona.slow_extended.slow_query_log_timestamp_precision pattern: # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+.[0-9]+
1651-[log_grep.inc] lines: 1
1652-[log_grep.inc] file: percona.slow_extended.slow_query_log_timestamp_precision pattern: # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+
1653-[log_grep.inc] lines: 2
1654
1655=== added file 'Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result'
1656--- Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result 1970-01-01 00:00:00 +0000
1657+++ Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result 2013-01-21 06:27:51 +0000
1658@@ -0,0 +1,20 @@
1659+SET SESSION min_examined_row_limit=0;
1660+SET GLOBAL long_query_time=1;
1661+[log_start.inc] percona.slow_extended.slow_query_log_use_global_control
1662+SET SESSION query_exec_time=1.1;
1663+SELECT 1;
1664+1
1665+1
1666+SET GLOBAL log_slow_verbosity=innodb;
1667+SET GLOBAL slow_query_log_use_global_control="log_slow_verbosity,long_query_time";
1668+SELECT 1;
1669+1
1670+1
1671+SET SESSION query_exec_time=default;
1672+[log_stop.inc] percona.slow_extended.slow_query_log_use_global_control
1673+SET GLOBAL slow_query_log_use_global_control='';
1674+SET GLOBAL log_slow_verbosity='';
1675+SET GLOBAL long_query_time=default;
1676+SET SESSION min_examined_row_limit=default;
1677+[log_grep.inc] file: percona.slow_extended.slow_query_log_use_global_control pattern: No InnoDB statistics available for this query
1678+[log_grep.inc] lines: 1
1679
1680=== removed file 'Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result'
1681--- Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result 2012-04-18 23:25:38 +0000
1682+++ Percona-Server/mysql-test/r/percona_slow_query_log_use_global_control.result 1970-01-01 00:00:00 +0000
1683@@ -1,18 +0,0 @@
1684-SET GLOBAL long_query_time=1;
1685-[log_start.inc] percona.slow_extended.slow_query_log_use_global_control
1686-SET SESSION query_exec_time=1.1;
1687-SELECT 1;
1688-1
1689-1
1690-SET GLOBAL log_slow_verbosity=innodb;
1691-SET GLOBAL slow_query_log_use_global_control="log_slow_verbosity,long_query_time";
1692-SELECT 1;
1693-1
1694-1
1695-SET SESSION query_exec_time=default;
1696-[log_stop.inc] percona.slow_extended.slow_query_log_use_global_control
1697-SET GLOBAL slow_query_log_use_global_control=default;
1698-SET GLOBAL log_slow_verbosity=default;
1699-SET GLOBAL long_query_time=default;
1700-[log_grep.inc] file: percona.slow_extended.slow_query_log_use_global_control pattern: No InnoDB statistics available for this query
1701-[log_grep.inc] lines: 1
1702
1703=== modified file 'Percona-Server/mysql-test/t/disabled.def'
1704--- Percona-Server/mysql-test/t/disabled.def 2012-05-10 07:49:14 +0000
1705+++ Percona-Server/mysql-test/t/disabled.def 2013-01-21 06:27:51 +0000
1706@@ -15,3 +15,4 @@
1707 archive-big : Bug#11817185 2011-03-10 Anitha Disabled since this leads to timeout on Solaris Sparc
1708 log_tables-big : Bug#11756699 2010-11-15 mattiasj report already exists
1709 mysql_embedded : Bug#12561297 2011-05-14 Anitha Dependent on PB2 changes - eventum#41836
1710+percona_slow_extended_error_on_quit : https://bugs.launchpad.net/percona-server/+bug/1098857 2013-01-12 laurynas
1711
1712=== added file 'Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test'
1713--- Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test 1970-01-01 00:00:00 +0000
1714+++ Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test 2013-01-21 06:27:51 +0000
1715@@ -0,0 +1,41 @@
1716+#
1717+# Test log_slow_slave_admin_statements
1718+#
1719+
1720+--disable_warnings
1721+DROP TABLE IF EXISTS t1;
1722+--enable_warnings
1723+
1724+CREATE TABLE t1 (a INT);
1725+
1726+SET SESSION min_examined_row_limit=0;
1727+SET SESSION long_query_time=0;
1728+
1729+#
1730+# Test enabled admin statement slow-logging
1731+#
1732+SET GLOBAL log_slow_admin_statements=ON;
1733+--let log_file=percona_log_slow_admin_stmt_1
1734+--source include/log_start.inc
1735+ALTER TABLE t1 ADD INDEX a(a);
1736+--source include/log_stop.inc
1737+--let grep_pattern=ALTER TABLE t1 ADD INDEX a\(a\);
1738+--source include/log_grep.inc
1739+
1740+#
1741+# Test disabled admin statement slow-logging
1742+#
1743+SET GLOBAL log_slow_admin_statements=OFF;
1744+--let log_file=percona_log_slow_admin_stmt_2
1745+--source include/log_start.inc
1746+ALTER TABLE t1 DROP INDEX a;
1747+--source include/log_stop.inc
1748+--let grep_pattern=ALTER TABLE t1 DROP INDEX a;
1749+--source include/log_grep.inc
1750+
1751+SET GLOBAL log_slow_admin_statements=default;
1752+SET SESSION long_query_time=default;
1753+SET SESSION min_examined_row_limit=default;
1754+
1755+DROP TABLE t1;
1756+--source include/log_cleanup.inc
1757
1758=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test'
1759--- Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test 2012-04-18 23:25:38 +0000
1760+++ Percona-Server/mysql-test/t/percona_log_slow_admin_statements.test 1970-01-01 00:00:00 +0000
1761@@ -1,20 +0,0 @@
1762-# default value
1763-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
1764-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
1765-# set value to 'true'
1766-SET GLOBAL log_slow_admin_statements=true;
1767-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
1768-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
1769-# set value to 'false'
1770-SET GLOBAL log_slow_admin_statements=false;
1771-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
1772-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
1773-# set value to 'foo'
1774---error ER_WRONG_VALUE_FOR_VAR
1775-SET GLOBAL log_slow_admin_statements=foo;
1776-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
1777-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
1778-# set value to default
1779-SET GLOBAL log_slow_admin_statements=default;
1780-SHOW GLOBAL VARIABLES like 'log_slow_admin_statements';
1781-SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements';
1782
1783=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_filter.test'
1784--- Percona-Server/mysql-test/t/percona_log_slow_filter.test 2012-04-18 23:25:38 +0000
1785+++ Percona-Server/mysql-test/t/percona_log_slow_filter.test 1970-01-01 00:00:00 +0000
1786@@ -1,26 +0,0 @@
1787---source include/have_debug.inc
1788-
1789-CREATE TABLE t(id INT PRIMARY KEY);
1790-INSERT INTO t VALUES(1);
1791-INSERT INTO t VALUES(2);
1792-INSERT INTO t VALUES(3);
1793-
1794-SET long_query_time=1;
1795-SET log_slow_filter=full_join;
1796---let log_file=percona.slow_extended.log_slow_filter
1797---source include/log_start.inc
1798-
1799-SET query_exec_time = 1.1;
1800---disable_result_log
1801-SELECT * FROM t AS t1, t AS t2;
1802---enable_result_log
1803-SET query_exec_time = default;
1804-
1805---source include/log_stop.inc
1806-SET log_slow_filter=default;
1807-SET long_query_time=default;
1808-
1809---let grep_pattern = Query_time
1810---source include/log_grep.inc
1811-
1812-DROP TABLE t;
1813
1814=== added file 'Percona-Server/mysql-test/t/percona_log_slow_innodb.test'
1815--- Percona-Server/mysql-test/t/percona_log_slow_innodb.test 1970-01-01 00:00:00 +0000
1816+++ Percona-Server/mysql-test/t/percona_log_slow_innodb.test 2013-01-21 06:27:51 +0000
1817@@ -0,0 +1,82 @@
1818+#
1819+# Test that InnoDB stats for the extended slow query log are collected.
1820+# We do not parse the log to see that the values are reasonable. That should be done after log to table is implemented.
1821+# We also do not test the stats that would require DEBUG_SYNC: InnoDB_queue_wait and InnoDB_rec_lock_wait. The latter is
1822+# "tested" with SLEEP here, but this is not guaranteed to work. The testcase is not unstable because of this as we don't
1823+# actually check the value.
1824+#
1825+--source include/have_innodb.inc
1826+
1827+--disable_warnings
1828+DROP TABLE IF EXISTS t1, t2;
1829+--enable_warnings
1830+
1831+let $MYSQLD_TMPDIR = `SELECT @@tmpdir`;
1832+let $MYSQLD_DATADIR = `SELECT @@datadir`;
1833+
1834+CREATE TABLE t1(a INT) ENGINE=InnoDB;
1835+INSERT INTO t1 VALUE(1);
1836+
1837+CREATE TABLE t2(a INT) ENGINE=InnoDB;
1838+INSERT INTO t2 VALUE(1);
1839+
1840+# Force cold buffer pool
1841+--source include/restart_mysqld.inc
1842+
1843+SET SESSION min_examined_row_limit=0;
1844+SET SESSION long_query_time=0;
1845+SET @old_log_slow_verbosity := @@log_slow_verbosity;
1846+SET SESSION log_slow_verbosity='microtime,innodb';
1847+
1848+--let log_file=percona.slow_extended.innodb_0
1849+--source include/log_start.inc
1850+INSERT INTO t1 VALUES(2);
1851+INSERT INTO t2 VALUES(2);
1852+INSERT INTO t1 VALUES(3); # Pages in the buffer pool already
1853+SELECT 5; # No InnoDB pages accessed
1854+--source include/log_stop.inc
1855+
1856+#
1857+# Table lock waits
1858+#
1859+
1860+LOCK TABLE t1 WRITE;
1861+--connect (con2,localhost,root,,test,,)
1862+--connection con2
1863+--let log_file=percona.slow_extended.innodb_3
1864+--source include/log_start.inc
1865+send LOCK TABLE t1 WRITE;
1866+--connection default
1867+# TODO: best-effort test for now. A bug if we check the actual lock time!
1868+SELECT SLEEP(5);
1869+UNLOCK TABLES;
1870+--connection con2
1871+reap;
1872+--source include/log_stop.inc
1873+UNLOCK TABLES;
1874+--connection default
1875+
1876+#
1877+# Row lock waits
1878+#
1879+BEGIN;
1880+SELECT * FROM t2 FOR UPDATE;
1881+--connection con2
1882+--let log_file=percona.slow_extended.innodb_4
1883+--source include/log_start.inc
1884+send DELETE FROM t2 WHERE a=2;
1885+--connection default
1886+SELECT SLEEP(5);
1887+COMMIT;
1888+--connection con2
1889+reap;
1890+--source include/log_stop.inc
1891+--disconnect con2
1892+--connection default
1893+
1894+SET SESSION min_examined_row_limit=default;
1895+SET SESSION long_query_time=default;
1896+SET SESSION log_slow_verbosity=@old_log_slow_verbosity;
1897+
1898+DROP TABLE t1, t2;
1899+--source include/log_cleanup.inc
1900
1901=== added file 'Percona-Server/mysql-test/t/percona_log_slow_query_plan.test'
1902--- Percona-Server/mysql-test/t/percona_log_slow_query_plan.test 1970-01-01 00:00:00 +0000
1903+++ Percona-Server/mysql-test/t/percona_log_slow_query_plan.test 2013-01-21 06:27:51 +0000
1904@@ -0,0 +1,302 @@
1905+#
1906+# Test that various query plans are logged correctly in the slow query log.
1907+#
1908+--source include/have_innodb.inc
1909+
1910+FLUSH STATUS;
1911+
1912+--disable_warnings
1913+DROP TABLE IF EXISTS t1;
1914+--enable_warnings
1915+
1916+CREATE TABLE t1(
1917+ a INT NOT NULL AUTO_INCREMENT PRIMARY KEY,
1918+ b INT) ENGINE=InnoDB;
1919+
1920+INSERT INTO t1 VALUES(NULL, 10), (NULL, 5);
1921+
1922+SET SESSION long_query_time=0;
1923+SET SESSION min_examined_row_limit=0;
1924+SET SESSION log_slow_verbosity='microtime,query_plan';
1925+
1926+#
1927+# filesort, disk filesort, and filesort merge passes negative test
1928+#
1929+EXPLAIN SELECT * FROM t1;
1930+--let log_file=percona_slow_query_log.query_plan_0
1931+--source include/log_start.inc
1932+SELECT * FROM t1;
1933+--source include/log_stop.inc
1934+--let grep_pattern = ^# Filesort: No Filesort_on_disk: No Merge_passes: 0\$
1935+--source include/log_grep.inc
1936+
1937+#
1938+# filesort positive test, memory, zero merge passes
1939+#
1940+EXPLAIN SELECT * FROM t1 ORDER BY b;
1941+--let log_file=percona_slow_query_log.query_plan_1
1942+--source include/log_start.inc
1943+SELECT * FROM t1 ORDER BY b;
1944+--source include/log_stop.inc
1945+--let grep_pattern = ^# Filesort: Yes Filesort_on_disk: No Merge_passes: 0\$
1946+--source include/log_grep.inc
1947+
1948+#
1949+# Same as above but filtered away
1950+#
1951+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort_on_disk';
1952+--let log_file=percona_slow_query_log.query_plan_1a
1953+--source include/log_start.inc
1954+SELECT * FROM t1 ORDER BY b;
1955+--source include/log_stop.inc
1956+--let grep_pattern = ^# Filesort: Yes Filesort_on_disk: No Merge_passes: 0\$
1957+--source include/log_grep.inc
1958+SET SESSION log_slow_filter=default;
1959+
1960+#
1961+# filesort positive test, disk, one merge pass
1962+#
1963+SET SESSION sort_buffer_size=32804;
1964+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
1965+INSERT INTO t2 VALUES (5), (16), (2), (17), (1);
1966+INSERT INTO t2 SELECT * FROM t2;
1967+INSERT INTO t2 SELECT * FROM t2;
1968+INSERT INTO t2 SELECT * FROM t2;
1969+INSERT INTO t2 SELECT * FROM t2;
1970+INSERT INTO t2 SELECT * FROM t2;
1971+INSERT INTO t2 SELECT * FROM t2;
1972+INSERT INTO t2 SELECT * FROM t2;
1973+INSERT INTO t2 SELECT * FROM t2;
1974+INSERT INTO t2 SELECT * FROM t2;
1975+
1976+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
1977+--replace_column 9 ROWS
1978+EXPLAIN SELECT * FROM t2 ORDER BY a;
1979+
1980+--let log_file=percona_slow_query_log.query_plan_2
1981+--source include/log_start.inc
1982+--disable_result_log
1983+SELECT * FROM t2 ORDER BY a;
1984+--enable_result_log
1985+--source include/log_stop.inc
1986+--let grep_pattern = ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 1\$
1987+--source include/log_grep.inc
1988+
1989+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
1990+
1991+#
1992+# Same as above but filtered away
1993+#
1994+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk';
1995+--let log_file=percona_slow_query_log.query_plan_2a
1996+--source include/log_start.inc
1997+--disable_result_log
1998+SELECT * FROM t2 ORDER BY a;
1999+--enable_result_log
2000+--source include/log_stop.inc
2001+--let grep_pattern = ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 1\$
2002+--source include/log_grep.inc
2003+
2004+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
2005+
2006+SET SESSION log_slow_filter=default;
2007+
2008+#
2009+# Same as the above, with more than one merge pass
2010+#
2011+INSERT INTO t2 SELECT * FROM t2;
2012+INSERT INTO t2 SELECT * FROM t2;
2013+INSERT INTO t2 SELECT * FROM t2;
2014+INSERT INTO t2 SELECT * FROM t2;
2015+--let log_file=percona_slow_query_log.query_plan_3
2016+--source include/log_start.inc
2017+--disable_result_log
2018+SELECT * FROM t2 ORDER BY a;
2019+--enable_result_log
2020+--source include/log_stop.inc
2021+--let grep_pattern = ^# Filesort: Yes Filesort_on_disk: Yes Merge_passes: 4\$
2022+--source include/log_grep.inc
2023+
2024+SHOW SESSION STATUS LIKE 'Sort_merge_passes';
2025+
2026+SET SESSION sort_buffer_size=default;
2027+
2028+#
2029+# Full_scan, negative test
2030+#
2031+SHOW SESSION STATUS LIKE 'Select_scan';
2032+--let log_file=percona_slow_query_log.query_plan_4
2033+--source include/log_start.inc
2034+SELECT * FROM t1 WHERE a=1;
2035+--source include/log_stop.inc
2036+--let grep_pattern = ^#.*Full_scan: No.*\$
2037+--source include/log_grep.inc
2038+
2039+SHOW SESSION STATUS LIKE 'Select_scan';
2040+
2041+#
2042+# Full_scan, positive test
2043+#
2044+--let log_file=percona_slow_query_log.query_plan_5
2045+--source include/log_start.inc
2046+SELECT COUNT(*) FROM t1;
2047+--source include/log_stop.inc
2048+--let grep_pattern = ^#.*Full_scan: Yes.*\$
2049+--source include/log_grep.inc
2050+
2051+SHOW SESSION STATUS LIKE 'Select_scan';
2052+
2053+#
2054+# Same as above, but filtered away
2055+#
2056+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
2057+--let log_file=percona_slow_query_log.query_plan_5a
2058+--source include/log_start.inc
2059+SELECT COUNT(*) FROM t1;
2060+--source include/log_stop.inc
2061+--let grep_pattern = ^#.*Full_scan: Yes.*\$
2062+--source include/log_grep.inc
2063+
2064+SHOW SESSION STATUS LIKE 'Select_scan';
2065+
2066+SET SESSION log_slow_filter=default;
2067+
2068+#
2069+# Full_join, negative test
2070+#
2071+CREATE TABLE t3(a INT NOT NULL AUTO_INCREMENT PRIMARY KEY) ENGINE=InnoDB;
2072+INSERT INTO t3 VALUES (1), (2), (3);
2073+
2074+SHOW SESSION STATUS LIKE 'Select_full_join';
2075+--let log_file=percona_slow_query_log.query_plan_6
2076+--source include/log_start.inc
2077+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a;
2078+--source include/log_stop.inc
2079+--let grep_pattern = ^#.*Full_join: No.*\$
2080+--source include/log_grep.inc
2081+SHOW SESSION STATUS LIKE 'Select_full_join';
2082+
2083+#
2084+# Full_join, positive test
2085+#
2086+--let log_file=percona_slow_query_log.query_plan_7
2087+--source include/log_start.inc
2088+SELECT COUNT(*) FROM t1, t2 WHERE t1.b = t2.a;
2089+--source include/log_stop.inc
2090+--let grep_pattern = ^#.*Full_join: Yes.*\$
2091+--source include/log_grep.inc
2092+
2093+SHOW SESSION STATUS LIKE 'Select_full_join';
2094+
2095+#
2096+# Same as above, but filtered away
2097+#
2098+SET SESSION log_slow_filter='tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
2099+--let log_file=percona_slow_query_log.query_plan_7a
2100+--source include/log_start.inc
2101+SELECT COUNT(*) FROM t1, t2 WHERE t1.b = t2.a;
2102+--source include/log_stop.inc
2103+--let grep_pattern = ^#.*Full_join: Yes.*\$
2104+--source include/log_grep.inc
2105+
2106+SHOW SESSION STATUS LIKE 'Select_full_join';
2107+
2108+SET SESSION log_slow_filter=default;
2109+
2110+#
2111+# Tmp_table and Tmp_table_on_disk negative test
2112+#
2113+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2114+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2115+EXPLAIN SELECT COUNT(*) FROM t1;
2116+--let log_file=percona_slow_query_log.query_plan_8
2117+--source include/log_start.inc
2118+SELECT COUNT(*) FROM t1;
2119+--source include/log_stop.inc
2120+--let grep_pattern = ^#.*Tmp_tables: 0 Tmp_disk_tables: 0 Tmp_table_sizes: 0\$
2121+--source include/log_grep.inc
2122+--let grep_pattern = ^#.*Tmp_table: No Tmp_table_on_disk: No\$
2123+--source include/log_grep.inc
2124+
2125+#
2126+# Tmp_table positive, Tmp_table_on_disk negative test
2127+#
2128+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2129+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2130+
2131+EXPLAIN SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
2132+--let log_file=percona_slow_query_log.query_plan_9
2133+--source include/log_start.inc
2134+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
2135+--source include/log_stop.inc
2136+--let grep_pattern = ^#.*Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: [1-9][0-9]*\$
2137+--source include/log_grep.inc
2138+--let grep_pattern = ^#.*Tmp_table: Yes Tmp_table_on_disk: No\$
2139+--source include/log_grep.inc
2140+
2141+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2142+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2143+
2144+#
2145+# Same as above but filtered away
2146+#
2147+SET SESSION log_slow_filter='full_join,tmp_table_on_disk,filesort_on_disk';
2148+
2149+--let log_file=percona_slow_query_log.query_plan_9a
2150+--source include/log_start.inc
2151+SELECT COUNT(*) FROM t1, t3 WHERE t1.a = t3.a GROUP BY t3.a;
2152+--source include/log_stop.inc
2153+--let grep_pattern = ^#.*Tmp_tables: 1 Tmp_disk_tables: 0 Tmp_table_sizes: [1-9][0-9]*\$
2154+--source include/log_grep.inc
2155+--let grep_pattern = ^#.*Tmp_table: Yes Tmp_table_on_disk: No\$
2156+--source include/log_grep.inc
2157+
2158+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2159+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2160+
2161+SET SESSION log_slow_filter=default;
2162+
2163+#
2164+# Tmp_table and Tmp_table_on_disk positive test
2165+#
2166+CREATE TABLE t4(a INT NOT NULL AUTO_INCREMENT PRIMARY KEY, b TEXT) ENGINE=InnoDB;
2167+INSERT INTO t4 VALUES (1, "aaa"), (2, "bbb"), (3, "ccc");
2168+
2169+EXPLAIN SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.a;
2170+--let log_file=percona_slow_query_log.query_plan_10
2171+--source include/log_start.inc
2172+SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.b;
2173+--source include/log_stop.inc
2174+--let grep_pattern = ^#.*Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: [1-9][0-9]*\$
2175+--source include/log_grep.inc
2176+--let grep_pattern = ^#.*Tmp_table: Yes Tmp_table_on_disk: Yes\$
2177+--source include/log_grep.inc
2178+
2179+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2180+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2181+
2182+#
2183+# Same as above but filtered away
2184+#
2185+SET SESSION log_slow_filter='full_join,filesort_on_disk';
2186+
2187+--let log_file=percona_slow_query_log.query_plan_10a
2188+--source include/log_start.inc
2189+SELECT COUNT(*) FROM t1, t4 WHERE t1.a = t4.a GROUP BY t4.b;
2190+--source include/log_stop.inc
2191+--let grep_pattern = ^#.*Tmp_tables: 1 Tmp_disk_tables: 1 Tmp_table_sizes: [1-9][0-9]*\$
2192+--source include/log_grep.inc
2193+--let grep_pattern = ^#.*Tmp_table: Yes Tmp_table_on_disk: Yes\$
2194+--source include/log_grep.inc
2195+
2196+SHOW SESSION STATUS LIKE 'Created_tmp_tables';
2197+SHOW SESSION STATUS LIKE 'Created_tmp_disk_tables';
2198+
2199+SET SESSION log_slow_filter=default;
2200+
2201+SET SESSION long_query_time=default;
2202+SET SESSION min_examined_row_limit=default;
2203+SET SESSION log_slow_verbosity=default;
2204+
2205+DROP TABLE t1, t2, t3, t4;
2206+--source include/log_cleanup.inc
2207
2208=== added file 'Percona-Server/mysql-test/t/percona_log_slow_query_plan_qc.test'
2209--- Percona-Server/mysql-test/t/percona_log_slow_query_plan_qc.test 1970-01-01 00:00:00 +0000
2210+++ Percona-Server/mysql-test/t/percona_log_slow_query_plan_qc.test 2013-01-21 06:27:51 +0000
2211@@ -0,0 +1,71 @@
2212+#
2213+# Tests the query cache logging for the extended slow query log
2214+#
2215+--source include/have_innodb.inc
2216+--source include/have_query_cache.inc
2217+
2218+FLUSH STATUS;
2219+SET SESSION min_examined_row_limit=0;
2220+
2221+--disable_warnings
2222+DROP TABLE IF EXISTS t1;
2223+--enable_warnings
2224+
2225+CREATE TABLE t1 (a INT) ENGINE=InnoDB;
2226+
2227+INSERT INTO t1 VALUE(5);
2228+
2229+SET SESSION query_cache_type=1;
2230+SET GLOBAL query_cache_size=1355776;
2231+
2232+SET SESSION long_query_time=0;
2233+SET SESSION log_slow_verbosity='microtime,query_plan';
2234+
2235+#
2236+# Test uncached query
2237+#
2238+--let log_file = percona_slow_query_log.query_plan_qc_1
2239+--source include/log_start.inc
2240+SELECT * FROM t1;
2241+--source include/log_stop.inc
2242+--let grep_pattern = ^# QC_Hit: No.*\$
2243+--source include/log_grep.inc
2244+
2245+SHOW STATUS LIKE 'Qcache_hits';
2246+
2247+#
2248+# Test cached query
2249+#
2250+
2251+--let log_file = percona_slow_query_log.query_plan_qc_2
2252+--source include/log_start.inc
2253+SELECT * FROM t1;
2254+--source include/log_stop.inc
2255+--let grep_pattern = ^# QC_Hit: Yes.*\$
2256+--source include/log_grep.inc
2257+
2258+SHOW STATUS LIKE 'Qcache_hits';
2259+
2260+#
2261+# Test uncached query that is filtered away
2262+#
2263+SET SESSION log_slow_filter='full_join,tmp_table,tmp_table_on_disk,filesort,filesort_on_disk';
2264+--let log_file = percona_slow_query_log.query_plan_qc_3
2265+--source include/log_start.inc
2266+SELECT * FROM t1 WHERE a > 5;
2267+--source include/log_stop.inc
2268+--let grep_pattern = ^# QC_Hit: No.*\$
2269+--source include/log_grep.inc
2270+
2271+SHOW STATUS LIKE 'Qcache_hits';
2272+
2273+SET SESSION log_slow_filter=default;
2274+
2275+SET SESSION long_query_time=default;
2276+SET SESSION log_slow_verbosity=default;
2277+SET SESSION query_cache_type=default;
2278+SET GLOBAL query_cache_size=default;
2279+SET SESSION min_examined_row_limit=default;
2280+
2281+DROP TABLE t1;
2282+--source include/log_cleanup.inc
2283
2284=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb-slave.opt'
2285--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb-slave.opt 2012-04-18 23:25:38 +0000
2286+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb-slave.opt 1970-01-01 00:00:00 +0000
2287@@ -1,1 +0,0 @@
2288---long_query_time=0 --log_slow_slave_statements --log_slow_verbosity=innodb
2289\ No newline at end of file
2290
2291=== added file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test'
2292--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test 1970-01-01 00:00:00 +0000
2293+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test 2013-01-21 06:27:51 +0000
2294@@ -0,0 +1,48 @@
2295+--source include/have_binlog_format_statement.inc
2296+--source include/master-slave.inc
2297+--source include/have_innodb.inc
2298+
2299+SET SESSION min_examined_row_limit=0;
2300+-- disable_warnings
2301+DROP TABLE IF EXISTS t;
2302+-- enable_warnings
2303+
2304+CREATE TABLE t(id INT,data CHAR(30)) ENGINE=InnoDB;
2305+INSERT INTO t VALUES
2306+(1,"aaaaabbbbbcccccdddddeeeeefffff"),
2307+(2,"aaaaabbbbbcccccdddddeeeeefffff"),
2308+(3,"aaaaabbbbbcccccdddddeeeeefffff"),
2309+(4,"aaaaabbbbbcccccdddddeeeeefffff"),
2310+(5,"aaaaabbbbbcccccdddddeeeeefffff");
2311+INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
2312+INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
2313+sync_slave_with_master;
2314+
2315+SET GLOBAL long_query_time=0;
2316+SET GLOBAL log_slow_slave_statements=TRUE;
2317+SET GLOBAL log_slow_verbosity='innodb';
2318+--source include/restart_slave_sql.inc
2319+
2320+--let log_file=percona.slow_extended.log_slow_slave_statements-innodb
2321+
2322+--source include/log_start.inc
2323+connection master;
2324+INSERT INTO t SELECT t.id,t.data from t;
2325+sync_slave_with_master;
2326+--source include/log_stop.inc
2327+
2328+--let grep_pattern = InnoDB_IO_r_ops
2329+--source include/log_grep.inc
2330+
2331+connection master;
2332+DROP TABLE t;
2333+sync_slave_with_master;
2334+
2335+SET GLOBAL long_query_time=default;
2336+SET GLOBAL log_slow_slave_statements=default;
2337+SET GLOBAL log_slow_verbosity=default;
2338+SET SESSION min_examined_row_limit=default;
2339+
2340+--source include/rpl_end.inc
2341+
2342+--source include/log_cleanup.inc
2343
2344=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test'
2345--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test 2012-04-18 23:25:38 +0000
2346+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements-innodb.test 1970-01-01 00:00:00 +0000
2347@@ -1,42 +0,0 @@
2348---source include/have_binlog_format_statement.inc
2349---source include/master-slave.inc
2350---source include/have_innodb.inc
2351---let log_file=percona.slow_extended.log_slow_slave_statements-innodb
2352-
2353-connection master;
2354--- disable_warnings
2355-DROP TABLE IF EXISTS t;
2356--- enable_warnings
2357-
2358-CREATE TABLE t(id INT,data CHAR(30)) ENGINE=InnoDB;
2359-INSERT INTO t VALUES
2360-(1,"aaaaabbbbbcccccdddddeeeeefffff"),
2361-(2,"aaaaabbbbbcccccdddddeeeeefffff"),
2362-(3,"aaaaabbbbbcccccdddddeeeeefffff"),
2363-(4,"aaaaabbbbbcccccdddddeeeeefffff"),
2364-(5,"aaaaabbbbbcccccdddddeeeeefffff");
2365-INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
2366-INSERT INTO t SELECT t2.id,t2.data from t as t1, t as t2;
2367-sync_slave_with_master;
2368-
2369-connection slave;
2370---source include/log_start.inc
2371-
2372-connection master;
2373-INSERT INTO t SELECT t.id,t.data from t;
2374-sync_slave_with_master;
2375-
2376-connection slave;
2377---source include/log_stop.inc
2378-
2379---enable_query_log
2380---enable_result_log
2381-
2382---let grep_pattern = InnoDB_IO_r_ops
2383---source include/log_grep.inc
2384-
2385-connection master;
2386-DROP TABLE t;
2387-sync_slave_with_master;
2388-
2389---source include/rpl_end.inc
2390
2391=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements-slave.opt'
2392--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements-slave.opt 2012-04-18 23:25:38 +0000
2393+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements-slave.opt 1970-01-01 00:00:00 +0000
2394@@ -1,1 +0,0 @@
2395---long_query_time=0
2396\ No newline at end of file
2397
2398=== added file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test'
2399--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test 1970-01-01 00:00:00 +0000
2400+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test 2013-01-21 06:27:51 +0000
2401@@ -0,0 +1,68 @@
2402+#
2403+# Test log_slow_slave_statements
2404+#
2405+--source include/have_innodb.inc
2406+--source include/have_binlog_format_statement.inc
2407+--source include/master-slave.inc
2408+
2409+--disable_warnings
2410+DROP TABLE IF EXISTS t;
2411+--enable_warnings
2412+
2413+CREATE TABLE t(id INT) ENGINE=InnoDB;
2414+sync_slave_with_master;
2415+
2416+SET GLOBAL min_examined_row_limit=0;
2417+SET GLOBAL long_query_time=0;
2418+SET GLOBAL log_slow_slave_statements=OFF;
2419+--source include/restart_slave_sql.inc
2420+
2421+--let log_file=percona.slow_extended.log_slow_slave_statements
2422+--source include/log_start.inc
2423+
2424+#
2425+# A statement that should not be slow-logged
2426+#
2427+connection master;
2428+INSERT INTO t VALUES (1);
2429+sync_slave_with_master;
2430+
2431+#
2432+# A statement that should be slow-logged
2433+#
2434+SET GLOBAL log_slow_slave_statements=ON;
2435+connection master;
2436+# Explicit transaction to avoid slow-logging implicit BEGIN/COMMIT
2437+BEGIN;
2438+INSERT INTO t VALUES (2);
2439+COMMIT;
2440+sync_slave_with_master;
2441+
2442+#
2443+# A statement that should not be slow-logged
2444+#
2445+SET GLOBAL log_slow_slave_statements=OFF;
2446+connection master;
2447+INSERT INTO t VALUES (3);
2448+sync_slave_with_master;
2449+
2450+--source include/log_stop.inc
2451+
2452+--let grep_pattern= INSERT INTO t VALUES \(1\)
2453+--source include/log_grep.inc
2454+--let grep_pattern= INSERT INTO t VALUES \(2\)
2455+--source include/log_grep.inc
2456+--let grep_pattern= INSERT INTO t VALUES \(3\)
2457+--source include/log_grep.inc
2458+--let grep_pattern= ^# User@Host: \[SQL_SLAVE\] @ \[\]
2459+--source include/log_grep.inc
2460+
2461+connection master;
2462+DROP TABLE t;
2463+sync_slave_with_master;
2464+
2465+SET GLOBAL log_slow_slave_statements=default;
2466+SET GLOBAL long_query_time=default;
2467+SET GLOBAL min_examined_row_limit=default;
2468+--source include/rpl_end.inc
2469+--source include/log_cleanup.inc
2470
2471=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test'
2472--- Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test 2012-04-18 23:25:38 +0000
2473+++ Percona-Server/mysql-test/t/percona_log_slow_slave_statements.test 1970-01-01 00:00:00 +0000
2474@@ -1,117 +0,0 @@
2475--- source include/have_binlog_format_statement.inc
2476--- source include/master-slave.inc
2477---let log_file=percona.slow_extended.log_slow_slave_statements
2478---let show=SELECT Variable_value FROM INFORMATION_SCHEMA.SESSION_VARIABLES WHERE Variable_name LIKE 'log_slow_slave_statements';
2479-
2480-connection master;
2481--- disable_warnings
2482-DROP TABLE IF EXISTS t;
2483--- enable_warnings
2484-
2485-CREATE TABLE t(id INT);
2486-sync_slave_with_master;
2487-
2488-connection slave;
2489---source include/log_start.inc
2490-
2491---disable_query_log
2492---disable_result_log
2493-
2494---echo LINE 1
2495-connection master;
2496-INSERT INTO t VALUES (1);
2497-sync_slave_with_master;
2498-
2499-connection slave;
2500---let value=`$show`
2501---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2502---echo LOG_SLOW_SLAVE_STATEMENTS=ON
2503-SET GLOBAL log_slow_slave_statements=ON;
2504---let value=`$show`
2505---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2506-
2507---echo LINE 2
2508-connection master;
2509-INSERT INTO t VALUES (2);
2510-sync_slave_with_master;
2511-
2512---source include/restart_slave_sql.inc
2513-
2514-connection slave;
2515---let value=`$show`
2516---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2517-
2518---echo LINE 3
2519-connection master;
2520-INSERT INTO t VALUES (3);
2521-sync_slave_with_master;
2522-
2523-connection slave;
2524---let value=`$show`
2525---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2526---echo LOG_SLOW_SLAVE_STATEMENTS=OFF
2527-SET GLOBAL log_slow_slave_statements=OFF;
2528---let value=`$show`
2529---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2530-
2531---echo LINE 4
2532-connection master;
2533-INSERT INTO t VALUES (4);
2534-sync_slave_with_master;
2535-
2536---source include/restart_slave_sql.inc
2537-
2538-connection slave;
2539---let value=`$show`
2540---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2541-
2542---echo LINE 5
2543-connection master;
2544-INSERT INTO t VALUES (5);
2545-sync_slave_with_master;
2546-
2547-connection slave;
2548---let value=`$show`
2549---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2550---echo LOG_SLOW_SLAVE_STATEMENTS=ON
2551-SET GLOBAL log_slow_slave_statements=ON;
2552---let value=`$show`
2553---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2554-
2555---echo LINE 6
2556-connection master;
2557-INSERT INTO t VALUES (6);
2558-sync_slave_with_master;
2559-
2560---source include/restart_slave_sql.inc
2561-
2562-connection slave;
2563---let value=`$show`
2564---echo LOG_SLOW_SLAVE_STATAMENTS is $value
2565-
2566---echo LINE 7
2567-connection master;
2568-INSERT INTO t VALUES (7);
2569-sync_slave_with_master;
2570-
2571---enable_query_log
2572---enable_result_log
2573-
2574-connection slave;
2575---source include/log_stop.inc
2576-SET GLOBAL log_slow_slave_statements=default;
2577-
2578-connection slave;
2579---let i=1
2580-while($i < 8)
2581-{
2582---let grep_pattern= INSERT INTO t VALUES \($i\)
2583---source include/log_grep.inc
2584- inc $i;
2585-}
2586-
2587-connection master;
2588-DROP TABLE t;
2589-sync_slave_with_master;
2590-
2591---source include/rpl_end.inc
2592
2593=== added file 'Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test'
2594--- Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test 1970-01-01 00:00:00 +0000
2595+++ Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test 2013-01-21 06:27:51 +0000
2596@@ -0,0 +1,41 @@
2597+#
2598+# Test slow-logging of statements in stored procedures
2599+#
2600+--disable_warnings
2601+DROP PROCEDURE IF EXISTS test_f;
2602+--enable_warnings
2603+
2604+SET SESSION min_examined_row_limit=0;
2605+SET SESSION long_query_time=0;
2606+SET SESSION query_cache_type=0;
2607+
2608+delimiter ^;
2609+CREATE PROCEDURE test_f()
2610+BEGIN
2611+ SELECT 1;
2612+END^
2613+delimiter ;^
2614+
2615+SET GLOBAL log_slow_sp_statements=ON;
2616+--let log_file=percona.slow_extended.sp1
2617+--source include/log_start.inc
2618+CALL test_f();
2619+--source include/log_stop.inc
2620+--let grep_pattern=SELECT 1;
2621+--source include/log_grep.inc
2622+
2623+SET GLOBAL log_slow_sp_statements=OFF;
2624+--let log_file=percona.slow_extended.sp2
2625+--source include/log_start.inc
2626+CALL test_f();
2627+--source include/log_stop.inc
2628+--let grep_pattern=SELECT 1;
2629+--source include/log_grep.inc
2630+
2631+DROP PROCEDURE test_f;
2632+
2633+SET GLOBAL log_slow_sp_statements=default;
2634+SET SESSION long_query_time=default;
2635+SET SESSION min_examined_row_limit=default;
2636+SET SESSION query_cache_type=default;
2637+--source include/log_cleanup.inc
2638
2639=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test'
2640--- Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test 2012-04-18 23:25:38 +0000
2641+++ Percona-Server/mysql-test/t/percona_log_slow_sp_statements.test 1970-01-01 00:00:00 +0000
2642@@ -1,29 +0,0 @@
2643---source include/have_debug.inc
2644-
2645-SET long_query_time=1;
2646-SET GLOBAL log_slow_sp_statements=ON;
2647-SET SESSION query_exec_time=0.1;
2648---let log_file=percona.slow_extended.log_slow_sp_statements
2649---source include/log_start.inc
2650-
2651-delimiter ^;
2652-CREATE PROCEDURE test_f()
2653-BEGIN
2654- SET SESSION query_exec_time=1.1; SELECT 1;
2655- SET SESSION query_exec_time=2.1; SELECT 1;
2656- SET SESSION query_exec_time=3.1; SELECT 1;
2657- SET SESSION query_exec_time=0.1;
2658-END^
2659-delimiter ;^
2660-
2661-CALL test_f();
2662-
2663---source include/log_stop.inc
2664-SET SESSION query_exec_time=default;
2665-SET GLOBAL log_slow_sp_statements=default;
2666-SET long_query_time=default;
2667-
2668---let grep_pattern = Query_time
2669---source include/log_grep.inc
2670-
2671-DROP PROCEDURE test_f;
2672
2673=== added file 'Percona-Server/mysql-test/t/percona_log_slow_verbosity.test'
2674--- Percona-Server/mysql-test/t/percona_log_slow_verbosity.test 1970-01-01 00:00:00 +0000
2675+++ Percona-Server/mysql-test/t/percona_log_slow_verbosity.test 2013-01-21 06:27:51 +0000
2676@@ -0,0 +1,75 @@
2677+#
2678+# Test the extended slow query log output format for various log_slow_verbosity values.
2679+#
2680+--source include/have_innodb.inc
2681+
2682+--disable_warnings
2683+DROP TABLE IF EXISTS t1;
2684+--enable_warnings
2685+
2686+CREATE TABLE t1(a INT) ENGINE=InnoDB;
2687+
2688+SET SESSION min_examined_row_limit=0;
2689+SET SESSION long_query_time=0;
2690+
2691+#
2692+# Test all enabled options with InnoDB-involving query
2693+#
2694+SET SESSION log_slow_verbosity='microtime,innodb,query_plan';
2695+--let log_file=percona.slow_extended.log_slow_verbosity_0
2696+
2697+--source include/log_start.inc
2698+INSERT INTO t1 VALUE(0);
2699+--source include/log_stop.inc
2700+
2701+--echo log_slow_verbosity='microtime,innodb,query_plan':
2702+--source include/percona_slow_log_verbosity_grep.inc
2703+
2704+#
2705+# Test for "No InnoDB statistics available" in output when InnoDB stats are requested
2706+# but the query does not involve InnoDB tables
2707+#
2708+
2709+SET SESSION log_slow_verbosity='microtime,innodb,query_plan';
2710+--let log_file=percona.slow_extended.log_slow_verbosity_1
2711+
2712+--source include/log_start.inc
2713+SELECT 1;
2714+--source include/log_stop.inc
2715+
2716+--echo log_slow_verbosity='microtime,innodb,query_plan':
2717+--source include/percona_slow_log_verbosity_grep.inc
2718+
2719+#
2720+# Test only 'microtime' in the output (bug 730173: InnoDB and query plan information
2721+# are logged when not enabled)
2722+#
2723+SET log_slow_verbosity='microtime';
2724+--let log_file=percona.slow_extended.log_slow_verbosity_2
2725+
2726+--source include/log_start.inc
2727+INSERT INTO t1 VALUE(1);
2728+--source include/log_stop.inc
2729+
2730+--echo log_slow_verbosity='microtime':
2731+--source include/percona_slow_log_verbosity_grep.inc
2732+
2733+#
2734+# Test 'query_plan'
2735+#
2736+SET log_slow_verbosity='microtime,query_plan';
2737+--let log_file=percona.slow_extended.log_slow_verbosity_3
2738+
2739+--source include/log_start.inc
2740+INSERT INTO t1 VALUE(2);
2741+--source include/log_stop.inc
2742+
2743+--echo log_slow_verbosity='query_plan':
2744+--source include/percona_slow_log_verbosity_grep.inc
2745+
2746+SET SESSION log_slow_verbosity=default;
2747+SET SESSION long_query_time=default;
2748+SET SESSION min_examined_row_limit=default;
2749+
2750+DROP TABLE t1;
2751+--source include/log_cleanup.inc
2752
2753=== removed file 'Percona-Server/mysql-test/t/percona_log_slow_verbosity.test'
2754--- Percona-Server/mysql-test/t/percona_log_slow_verbosity.test 2012-04-18 23:25:38 +0000
2755+++ Percona-Server/mysql-test/t/percona_log_slow_verbosity.test 1970-01-01 00:00:00 +0000
2756@@ -1,19 +0,0 @@
2757---source include/have_innodb.inc
2758---source include/have_debug.inc
2759-
2760-SET SESSION long_query_time=1;
2761---let log_file=percona.slow_extended.log_slow_verbosity
2762---source include/log_start.inc
2763-
2764-SET SESSION query_exec_time=2.1;
2765-SELECT 1;
2766-SET SESSION log_slow_verbosity=innodb;
2767-SELECT 1;
2768-SET SESSION query_exec_time=default;
2769-
2770---source include/log_stop.inc
2771-SET log_slow_verbosity=default;
2772-SET long_query_time=default;
2773-
2774---let grep_pattern = No InnoDB statistics available for this query
2775---source include/log_grep.inc
2776
2777=== added file 'Percona-Server/mysql-test/t/percona_long_query_time.test'
2778--- Percona-Server/mysql-test/t/percona_long_query_time.test 1970-01-01 00:00:00 +0000
2779+++ Percona-Server/mysql-test/t/percona_long_query_time.test 2013-01-21 06:27:51 +0000
2780@@ -0,0 +1,29 @@
2781+--source include/have_debug.inc
2782+
2783+SET SESSION min_examined_row_limit=0;
2784+SET long_query_time=2;
2785+--let log_file=percona.slow_extended.long_query_time
2786+--source include/log_start.inc
2787+
2788+SET SESSION query_exec_time=1.1; SELECT 1;
2789+SET SESSION query_exec_time=3.1; SELECT 1;
2790+SET SESSION query_exec_time=5.1; SELECT 1;
2791+
2792+SET long_query_time=4;
2793+
2794+SET SESSION query_exec_time=1.1; SELECT 1;
2795+SET SESSION query_exec_time=3.1; SELECT 1;
2796+SET SESSION query_exec_time=5.1; SELECT 1;
2797+
2798+SET SESSION query_exec_time=default;
2799+
2800+SET long_query_time=2;
2801+
2802+--source include/log_stop.inc
2803+SET long_query_time=default;
2804+SET SESSION min_examined_row_limit=default;
2805+
2806+--let grep_pattern = Query_time
2807+--source include/log_grep.inc
2808+
2809+--source include/log_cleanup.inc
2810
2811=== removed file 'Percona-Server/mysql-test/t/percona_long_query_time.test'
2812--- Percona-Server/mysql-test/t/percona_long_query_time.test 2012-04-18 23:25:38 +0000
2813+++ Percona-Server/mysql-test/t/percona_long_query_time.test 1970-01-01 00:00:00 +0000
2814@@ -1,25 +0,0 @@
2815---source include/have_debug.inc
2816-
2817-SET long_query_time=2;
2818---let log_file=percona.slow_extended.long_query_time
2819---source include/log_start.inc
2820-
2821-SET SESSION query_exec_time=1.1; SELECT 1;
2822-SET SESSION query_exec_time=3.1; SELECT 1;
2823-SET SESSION query_exec_time=5.1; SELECT 1;
2824-
2825-SET long_query_time=4;
2826-
2827-SET SESSION query_exec_time=1.1; SELECT 1;
2828-SET SESSION query_exec_time=3.1; SELECT 1;
2829-SET SESSION query_exec_time=5.1; SELECT 1;
2830-
2831-SET SESSION query_exec_time=default;
2832-
2833-SET long_query_time=2;
2834-
2835---source include/log_stop.inc
2836-SET long_query_time=default;
2837-
2838---let grep_pattern = Query_time
2839---source include/log_grep.inc
2840
2841=== added file 'Percona-Server/mysql-test/t/percona_min_examined_row_limit.test'
2842--- Percona-Server/mysql-test/t/percona_min_examined_row_limit.test 1970-01-01 00:00:00 +0000
2843+++ Percona-Server/mysql-test/t/percona_min_examined_row_limit.test 2013-01-21 06:27:51 +0000
2844@@ -0,0 +1,36 @@
2845+--source include/have_debug.inc
2846+
2847+--disable_warnings
2848+drop table if exists t;
2849+--enable_warnings
2850+
2851+create table t(id INT PRIMARY KEY);
2852+insert into t values(1);
2853+insert into t values(2);
2854+insert into t values(3);
2855+
2856+SET GLOBAL long_query_time=2;
2857+SET GLOBAL slow_query_log_use_global_control='long_query_time,min_examined_row_limit';
2858+--let log_file=percona.slow_extended.min_examined_row_limit
2859+--source include/log_start.inc
2860+
2861+SET SESSION query_exec_time=2.1;
2862+SELECT 1;
2863+
2864+SET GLOBAL min_examined_row_limit=5;
2865+
2866+SELECT * FROM t AS t1, t AS t2;
2867+SELECT 1;
2868+
2869+SET SESSION query_exec_time=default;
2870+
2871+--source include/log_stop.inc
2872+SET GLOBAL min_examined_row_limit=default;
2873+SET GLOBAL slow_query_log_use_global_control=default;
2874+SET GLOBAL long_query_time=default;
2875+
2876+--let grep_pattern = Query_time
2877+--source include/log_grep.inc
2878+
2879+DROP TABLE t;
2880+--source include/log_cleanup.inc
2881
2882=== removed file 'Percona-Server/mysql-test/t/percona_min_examined_row_limit.test'
2883--- Percona-Server/mysql-test/t/percona_min_examined_row_limit.test 2012-04-18 23:25:38 +0000
2884+++ Percona-Server/mysql-test/t/percona_min_examined_row_limit.test 1970-01-01 00:00:00 +0000
2885@@ -1,35 +0,0 @@
2886---source include/have_debug.inc
2887-
2888---disable_warnings
2889-drop table if exists t;
2890---enable_warnings
2891-
2892-create table t(id INT PRIMARY KEY);
2893-insert into t values(1);
2894-insert into t values(2);
2895-insert into t values(3);
2896-
2897-SET GLOBAL long_query_time=2;
2898-SET GLOBAL slow_query_log_use_global_control='long_query_time,min_examined_row_limit';
2899---let log_file=percona.slow_extended.min_examined_row_limit
2900---source include/log_start.inc
2901-
2902-SET SESSION query_exec_time=2.1;
2903-SELECT 1;
2904-
2905-SET GLOBAL min_examined_row_limit=5;
2906-
2907-select * from t as t1, t as t2;
2908-SELECT 1;
2909-
2910-SET SESSION query_exec_time=default;
2911-
2912---source include/log_stop.inc
2913-SET GLOBAL min_examined_row_limit=default;
2914-SET GLOBAL slow_query_log_use_global_control=default;
2915-SET GLOBAL long_query_time=default;
2916-
2917---let grep_pattern = Query_time
2918---source include/log_grep.inc
2919-
2920-DROP TABLE t;
2921
2922=== added file 'Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test'
2923--- Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test 1970-01-01 00:00:00 +0000
2924+++ Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test 2013-01-21 06:27:51 +0000
2925@@ -0,0 +1,71 @@
2926+# Current test checks Last_errno for administrative command "Quit"
2927+# See Launchpad Bug #716210
2928+
2929+--source include/have_innodb.inc
2930+--source include/count_sessions.inc
2931+
2932+--disable_warnings
2933+DROP TABLE IF EXISTS t;
2934+--enable_warnings
2935+
2936+SET GLOBAL log_slow_admin_statements=ON;
2937+SET GLOBAL long_query_time=0;
2938+SET GLOBAL min_examined_row_limit=0;
2939+
2940+CREATE TABLE t(a INT) engine=InnoDB;
2941+
2942+--connect(additional,localhost,root,,)
2943+--connection additional
2944+
2945+#
2946+# 1st command in the log that sets Last_errno
2947+#
2948+--let log_file=percona.slow_extended.error_on_quit_1
2949+--source include/log_start.inc
2950+
2951+--error ER_TABLE_EXISTS_ERROR
2952+CREATE TABLE t(a INT) engine=InnoDB;
2953+--source include/log_stop.inc
2954+
2955+--let grep_pattern=Last_errno: [1-9]\d*\s
2956+--source include/log_grep.inc
2957+
2958+#
2959+# Subsequent Quit should not have Last_errno set
2960+#
2961+--let log_file=percona.slow_extended.error_on_quit_2
2962+--source include/log_start.inc
2963+--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
2964+--disconnect additional
2965+--connection default
2966+--source include/wait_until_count_sessions.inc
2967+--source include/log_stop.inc
2968+
2969+--let grep_pattern=Last_errno: 0\s
2970+--source include/log_grep.inc
2971+
2972+--connect(additional,localhost,root,,)
2973+--connection additional
2974+
2975+#
2976+# Negative case: both regular command and Quit with errno = 0
2977+#
2978+--let log_file=percona.slow_extended.error_on_quit_3
2979+--source include/log_start.inc
2980+
2981+SELECT * FROM t;
2982+
2983+--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
2984+--disconnect additional
2985+--connection default
2986+--source include/wait_until_count_sessions.inc
2987+--source include/log_stop.inc
2988+
2989+--let grep_pattern= Last_errno: 0\s
2990+--source include/log_grep.inc
2991+
2992+DROP TABLE t;
2993+SET GLOBAL log_slow_admin_statements=default;
2994+SET GLOBAL long_query_time=default;
2995+SET GLOBAL min_examined_row_limit=default;
2996+--source include/log_cleanup.inc
2997
2998=== removed file 'Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test'
2999--- Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test 2012-10-27 05:16:07 +0000
3000+++ Percona-Server/mysql-test/t/percona_slow_extended_error_on_quit.test 1970-01-01 00:00:00 +0000
3001@@ -1,87 +0,0 @@
3002-################################################################################
3003-# Current test check following attributes: #
3004-# 1) "Last_errno" #
3005-# 2) "Rows_{sent,examined|affected|read} #
3006-# 3) Bytes_sent #
3007-# 4) Tmp_{tables|dist_tables|table_size} #
3008-# 5) InnoDB statistic counters #
3009-# in Slow Query Log #
3010-# for administrative command "Quit" #
3011-# #
3012-# See Launchpad Bug #716210 #
3013-################################################################################
3014-
3015---source include/have_innodb.inc
3016-
3017-################################################################################
3018---let log_file=percona.slow_extended.error_on_quit
3019---let wait_condition=SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST;
3020-################################################################################
3021-
3022---disable_warnings
3023-DROP TABLE IF EXISTS t;
3024---enable_warnings
3025-CREATE TABLE t(a INT) engine=InnoDB;
3026-INSERT INTO t VALUES(0),(1),(2),(3),(4);
3027-
3028-################################################################################
3029---source include/log_start.inc
3030-
3031---connect(additional,localhost,root,,)
3032---connection additional
3033-
3034- SET log_slow_verbosity=innodb;
3035- SET long_query_time= 0;
3036-
3037---disable_result_log
3038---error ER_TABLE_EXISTS_ERROR
3039- CREATE TABLE t(a INT) engine=InnoDB;
3040---enable_result_log
3041-
3042---connection default
3043---echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
3044---disconnect additional
3045---source include/wait_condition.inc
3046---source include/log_stop.inc
3047---source include/percona_slow_extended_error_on_quit.inc
3048-################################################################################
3049---source include/log_start.inc
3050-
3051---connect(additional,localhost,root,,)
3052---connection additional
3053-
3054- SET log_slow_verbosity=innodb;
3055- SET long_query_time= 0;
3056-
3057---disable_result_log
3058- INSERT INTO t SELECT * FROM t ORDER BY RAND();
3059---enable_result_log
3060-
3061---connection default
3062---echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
3063---disconnect additional
3064---source include/wait_condition.inc
3065---source include/log_stop.inc
3066---source include/percona_slow_extended_error_on_quit.inc
3067-################################################################################
3068---source include/log_start.inc
3069-
3070---connect(additional,localhost,root,,)
3071---connection additional
3072-
3073- SET log_slow_verbosity=innodb;
3074- SET long_query_time= 0;
3075-
3076---disable_result_log
3077- SELECT * FROM t;
3078---enable_result_log
3079-
3080---connection default
3081---echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit")
3082---disconnect additional
3083---source include/wait_condition.inc
3084---source include/log_stop.inc
3085---source include/percona_slow_extended_error_on_quit.inc
3086-################################################################################
3087-
3088-DROP TABLE t;
3089
3090=== added file 'Percona-Server/mysql-test/t/percona_slow_extended_log_error.test'
3091--- Percona-Server/mysql-test/t/percona_slow_extended_log_error.test 1970-01-01 00:00:00 +0000
3092+++ Percona-Server/mysql-test/t/percona_slow_extended_log_error.test 2013-01-21 06:27:51 +0000
3093@@ -0,0 +1,31 @@
3094+#
3095+# Test last_errno in extended slow query log
3096+#
3097+
3098+--disable_warnings
3099+DROP TABLE IF EXISTS t1;
3100+--enable_warnings
3101+
3102+SET SESSION min_examined_row_limit=0;
3103+SET long_query_time=0;
3104+
3105+--let log_file=percona.slow_extended.log_error_1
3106+--source include/log_start.inc
3107+CREATE TABLE t1(a INT);
3108+--source include/log_stop.inc
3109+--let grep_pattern = ^.*Last_errno: 0 .*\$
3110+--source include/log_grep.inc
3111+
3112+--let log_file=percona.slow_extended.log_error_2
3113+--source include/log_start.inc
3114+--error ER_TABLE_EXISTS_ERROR
3115+CREATE TABLE t1(a INT);
3116+--source include/log_stop.inc
3117+--let grep_pattern = ^.*Last_errno: 1050 .*\$
3118+--source include/log_grep.inc
3119+
3120+DROP TABLE t1;
3121+
3122+SET long_query_time=default;
3123+SET SESSION min_examined_row_limit=default;
3124+--source include/log_cleanup.inc
3125
3126=== removed file 'Percona-Server/mysql-test/t/percona_slow_extended_log_error.test'
3127--- Percona-Server/mysql-test/t/percona_slow_extended_log_error.test 2012-04-18 23:25:38 +0000
3128+++ Percona-Server/mysql-test/t/percona_slow_extended_log_error.test 1970-01-01 00:00:00 +0000
3129@@ -1,15 +0,0 @@
3130---let log_file=percona.slow_extended.log_error
3131-SET long_query_time=0;
3132---disable_warnings
3133-DROP TABLE IF EXISTS t1;
3134---enable_warnings
3135-CREATE TABLE t(a INT);
3136---source include/log_start.inc
3137-
3138---error ER_TABLE_EXISTS_ERROR
3139-CREATE TABLE t(a INT);
3140-
3141---source include/log_stop.inc
3142---let grep_pattern = Last_errno: 1050
3143---source include/log_grep.inc
3144-DROP TABLE t;
3145
3146=== modified file 'Percona-Server/mysql-test/t/percona_slow_query_log_rate.test'
3147--- Percona-Server/mysql-test/t/percona_slow_query_log_rate.test 2012-04-18 23:25:38 +0000
3148+++ Percona-Server/mysql-test/t/percona_slow_query_log_rate.test 2013-01-21 06:27:51 +0000
3149@@ -1,16 +1,23 @@
3150---source include/have_debug.inc
3151---let log_file=percona.slow_extended.log_slow_rate_limit
3152+# Force deterministic session and query ids
3153+--source include/restart_mysqld.inc
3154
3155-SET GLOBAL long_query_time=1;
3156+SET GLOBAL long_query_time=0;
3157
3158 SET GLOBAL log_slow_rate_type='session';
3159 SET GLOBAL log_slow_rate_limit=3;
3160+--let log_file=percona.slow_extended.log_slow_rate_limit_1
3161 --source include/percona_slow_query_log_rate.inc
3162
3163+# This is restart is necessary because of the variable possible number of session
3164+# disconnect checks at the end of the previous test
3165+--source include/restart_mysqld.inc
3166+
3167 SET GLOBAL log_slow_rate_type='query';
3168 SET GLOBAL log_slow_rate_limit=2;
3169+--let log_file=percona.slow_extended.log_slow_rate_limit_2
3170 --source include/percona_slow_query_log_rate.inc
3171
3172 SET GLOBAL long_query_time=default;
3173 SET GLOBAL log_slow_rate_type=default;
3174 SET GLOBAL log_slow_rate_limit=default;
3175+--source include/log_cleanup.inc
3176
3177=== added file 'Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test'
3178--- Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test 1970-01-01 00:00:00 +0000
3179+++ Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test 2013-01-21 06:27:51 +0000
3180@@ -0,0 +1,21 @@
3181+#
3182+# Test slow_query_log_timestamp_always variable. It's missing tests for FALSE value that
3183+# the log entries with the same timestamp are indeed not timestamped, but this is
3184+# impossible to test in MTR without debug injections.
3185+#
3186+SET SESSION min_examined_row_limit=0;
3187+SET SESSION long_query_time=0;
3188+SET GLOBAL slow_query_log_timestamp_always=TRUE;
3189+
3190+--let log_file=percona_slow_extended_query_log_1
3191+--source include/log_start.inc
3192+SELECT 1;
3193+SELECT 2;
3194+--source include/log_stop.inc
3195+--let grep_pattern= ^# Time: \d{6} (\d| )\d:\d\d:\d\d\$
3196+--source include/log_grep.inc
3197+
3198+SET GLOBAL slow_query_log_timestamp_always=default;
3199+SET SESSION long_query_time=default;
3200+SET SESSION min_examined_row_limit=default;
3201+--source include/log_cleanup.inc
3202
3203=== removed file 'Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test'
3204--- Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test 2012-04-18 23:25:38 +0000
3205+++ Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_always.test 1970-01-01 00:00:00 +0000
3206@@ -1,34 +0,0 @@
3207---source include/have_debug.inc
3208-
3209-SET long_query_time=2;
3210-SET GLOBAL slow_query_log_timestamp_always=ON;
3211---let log_file=percona.slow_extended.slow_query_log_timestamp_always
3212---source include/log_start.inc
3213-
3214-SET SESSION query_exec_time=2.1;
3215-SELECT 1;
3216-SELECT 1;
3217-SELECT 1;
3218-
3219-SET GLOBAL slow_query_log_timestamp_always=OFF;
3220-
3221-SET SESSION query_exec_time=2.1;
3222-SELECT 1;
3223-SELECT 1;
3224-SELECT 1;
3225-
3226-SET GLOBAL slow_query_log_timestamp_always=ON;
3227-
3228-SET SESSION query_exec_time=2.1;
3229-SELECT 1;
3230-SELECT 1;
3231-SELECT 1;
3232-
3233-SET SESSION query_exec_time=default;
3234-
3235---source include/log_stop.inc
3236-SET GLOBAL slow_query_log_timestamp_always=default;
3237-SET long_query_time=default;
3238-
3239---let grep_pattern = # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+
3240---source include/log_grep.inc
3241
3242=== added file 'Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test'
3243--- Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test 1970-01-01 00:00:00 +0000
3244+++ Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test 2013-01-21 06:27:51 +0000
3245@@ -0,0 +1,37 @@
3246+#
3247+# Test slow_query_log_timestamp_precision variable.
3248+#
3249+SET @old_slow_query_log_timestamp_always=@@slow_query_log_timestamp_always;
3250+SET SESSION min_examined_row_limit=0;
3251+SET long_query_time=0;
3252+SET GLOBAL slow_query_log_timestamp_always=TRUE;
3253+
3254+#
3255+# microsecond
3256+#
3257+SET GLOBAL slow_query_log_timestamp_precision='microsecond';
3258+
3259+--let log_file=percona_slow_extended_1
3260+--source include/log_start.inc
3261+SELECT 1;
3262+--source include/log_stop.inc
3263+--let grep_pattern= ^# Time: \d{6} (\d| )\d:\d\d:\d\d\.\d{6}\$
3264+--source include/log_grep.inc
3265+
3266+#
3267+# second
3268+#
3269+SET GLOBAL slow_query_log_timestamp_precision='second';
3270+
3271+--let log_file=percona_slow_extended_2
3272+--source include/log_start.inc
3273+SELECT 1;
3274+--source include/log_stop.inc
3275+--let grep_pattern= ^# Time: \d{6} (\d| )\d:\d\d:\d\d\$
3276+--source include/log_grep.inc
3277+
3278+SET long_query_time=default;
3279+SET SESSION min_examined_row_limit=default;
3280+SET GLOBAL slow_query_log_timestamp_always=@old_slow_query_log_timestamp_always;
3281+SET GLOBAL slow_query_log_timestamp_precision=default;
3282+--source include/log_cleanup.inc
3283
3284=== removed file 'Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test'
3285--- Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test 2012-04-18 23:25:38 +0000
3286+++ Percona-Server/mysql-test/t/percona_slow_query_log_timestamp_precision.test 1970-01-01 00:00:00 +0000
3287@@ -1,25 +0,0 @@
3288---source include/have_debug.inc
3289-
3290-SET long_query_time=2;
3291---let log_file=percona.slow_extended.slow_query_log_timestamp_precision
3292---source include/log_start.inc
3293-
3294-SET SESSION query_exec_time=2.1;
3295-
3296-SELECT 1;
3297-
3298-SET GLOBAL slow_query_log_timestamp_precision='microsecond';
3299-
3300-SELECT 1;
3301-
3302-SET SESSION query_exec_time=default;
3303-
3304---source include/log_stop.inc
3305-SET GLOBAL slow_query_log_timestamp_precision=default;
3306-SET long_query_time=default;
3307-
3308---let grep_pattern = # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+.[0-9]+
3309---source include/log_grep.inc
3310-
3311---let grep_pattern = # Time: [0-9]+[ ]+[0-9]+:[0-9]+:[0-9]+
3312---source include/log_grep.inc
3313
3314=== added file 'Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test'
3315--- Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test 1970-01-01 00:00:00 +0000
3316+++ Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test 2013-01-21 06:27:51 +0000
3317@@ -0,0 +1,31 @@
3318+--source include/have_debug.inc
3319+--source include/have_innodb.inc
3320+
3321+SET SESSION min_examined_row_limit=0;
3322+SET GLOBAL long_query_time=1;
3323+
3324+--let log_file=percona.slow_extended.slow_query_log_use_global_control
3325+--source include/log_start.inc
3326+
3327+SET SESSION query_exec_time=1.1;
3328+
3329+SELECT 1;
3330+
3331+SET GLOBAL log_slow_verbosity=innodb;
3332+SET GLOBAL slow_query_log_use_global_control="log_slow_verbosity,long_query_time";
3333+
3334+SELECT 1;
3335+
3336+SET SESSION query_exec_time=default;
3337+
3338+--source include/log_stop.inc
3339+
3340+SET GLOBAL slow_query_log_use_global_control='';
3341+SET GLOBAL log_slow_verbosity='';
3342+SET GLOBAL long_query_time=default;
3343+SET SESSION min_examined_row_limit=default;
3344+
3345+--let grep_pattern = No InnoDB statistics available for this query
3346+--source include/log_grep.inc
3347+
3348+--source include/log_cleanup.inc
3349
3350=== removed file 'Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test'
3351--- Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test 2012-04-18 23:25:38 +0000
3352+++ Percona-Server/mysql-test/t/percona_slow_query_log_use_global_control.test 1970-01-01 00:00:00 +0000
3353@@ -1,28 +0,0 @@
3354---source include/have_debug.inc
3355---source include/have_innodb.inc
3356-
3357-SET GLOBAL long_query_time=1;
3358-
3359---let log_file=percona.slow_extended.slow_query_log_use_global_control
3360---source include/log_start.inc
3361-
3362-SET SESSION query_exec_time=1.1;
3363-SELECT 1;
3364-
3365-SET GLOBAL log_slow_verbosity=innodb;
3366-SET GLOBAL slow_query_log_use_global_control="log_slow_verbosity,long_query_time";
3367-
3368-SELECT 1;
3369-
3370-SET SESSION query_exec_time=default;
3371-
3372---source include/log_stop.inc
3373-
3374-
3375-SET GLOBAL slow_query_log_use_global_control=default;
3376-SET GLOBAL log_slow_verbosity=default;
3377-SET GLOBAL long_query_time=default;
3378-
3379---let grep_pattern = No InnoDB statistics available for this query
3380---source include/log_grep.inc
3381-
3382
3383=== modified file 'Percona-Server/sql/event_scheduler.cc'
3384--- Percona-Server/sql/event_scheduler.cc 2012-09-17 13:08:32 +0000
3385+++ Percona-Server/sql/event_scheduler.cc 2013-01-21 06:27:51 +0000
3386@@ -195,7 +195,6 @@
3387 thd->client_capabilities|= CLIENT_MULTI_RESULTS;
3388 mysql_mutex_lock(&LOCK_thread_count);
3389 thd->thread_id= thd->variables.pseudo_thread_id= thread_id++;
3390- thd->write_to_slow_log= true;
3391 mysql_mutex_unlock(&LOCK_thread_count);
3392
3393 /*
3394
3395=== modified file 'Percona-Server/sql/log.cc'
3396--- Percona-Server/sql/log.cc 2013-01-09 23:45:25 +0000
3397+++ Percona-Server/sql/log.cc 2013-01-21 06:27:51 +0000
3398@@ -1220,7 +1220,7 @@
3399
3400 if (*slow_log_handler_list)
3401 {
3402- /* do not log slow queries from replication threads */
3403+ /* do not log slow queries from replication threads, unless requested */
3404 if (thd->slave_thread && !opt_log_slow_slave_statements)
3405 return 0;
3406
3407@@ -2709,6 +2709,9 @@
3408 char buff[80], *end;
3409 char query_time_buff[22+7], lock_time_buff[22+7];
3410 uint buff_len;
3411+ char sent_row_buff[21]; // max ulonglong val in dec is 20 digits
3412+ char examined_row_buff[21];
3413+ char affected_row_buff[21];
3414 end= buff;
3415
3416 if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))
3417@@ -2722,7 +2725,7 @@
3418 {
3419 ulonglong microsecond = current_utime % (1000 * 1000);
3420 buff_len= snprintf(buff, sizeof buff,
3421- "# Time: %02d%02d%02d %2d:%02d:%02d.%010lld\n",
3422+ "# Time: %02d%02d%02d %2d:%02d:%02d.%06lld\n",
3423 start.tm_year % 100, start.tm_mon + 1,
3424 start.tm_mday, start.tm_hour,
3425 start.tm_min, start.tm_sec,microsecond);
3426@@ -2751,28 +2754,49 @@
3427 /* For slow query log */
3428 sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
3429 sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0);
3430- DBUG_PRINT("info", ("Last_errno: %u", thd->last_errno));
3431+ /* Here and below sprintf is used because my_b_printf does not support %llu
3432+ natively. snprintf is not used as there is no way to overflow the buffer
3433+ for 64-bit integers and MySQL assumes it to be available on less systems
3434+ than sprintf. */
3435+ sprintf(sent_row_buff, "%llu", (ulonglong)thd->sent_row_count);
3436+ sprintf(examined_row_buff, "%llu", (ulonglong)thd->examined_row_count);
3437+ sprintf(affected_row_buff, "%llu", (thd->get_row_count_func() > 0)
3438+ ? (ulonglong) thd->get_row_count_func() : 0);
3439 if (my_b_printf(&log_file,
3440- "# Thread_id: %lu Schema: %s Last_errno: %u Killed: %u\n" \
3441- "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu Rows_affected: %lu Rows_read: %lu\n"
3442- "# Bytes_sent: %lu Tmp_tables: %lu Tmp_disk_tables: %lu Tmp_table_sizes: %lu\n",
3443+ "# Thread_id: %lu Schema: %s Last_errno: %d "
3444+ "Killed: %u\n"
3445+ "# Query_time: %s Lock_time: %s Rows_sent: %s "
3446+ "Rows_examined: %s Rows_affected: %s Rows_read: %s\n"
3447+ "# Bytes_sent: %lu",
3448 (ulong) thd->thread_id, (thd->db ? thd->db : ""),
3449 thd->last_errno, (uint) thd->killed,
3450- query_time_buff, lock_time_buff,
3451- (ulong) thd->sent_row_count,
3452- (ulong) thd->examined_row_count,
3453- ((long) thd->get_row_count_func() > 0 ) ? (ulong) thd->get_row_count_func() : 0,
3454- (ulong) thd->examined_row_count,
3455- (ulong) (thd->status_var.bytes_sent - thd->bytes_sent_old),
3456- (ulong) thd->tmp_tables_used,
3457- (ulong) thd->tmp_tables_disk_used,
3458- (ulong) thd->tmp_tables_size) == (uint) -1)
3459+ query_time_buff, lock_time_buff, sent_row_buff,
3460+ examined_row_buff, affected_row_buff, examined_row_buff,
3461+ (ulong) (thd->status_var.bytes_sent - thd->bytes_sent_old))
3462+ == (uint) -1)
3463 tmp_errno= errno;
3464
3465+ if (thd->variables.log_slow_verbosity & (1ULL << SLOG_V_QUERY_PLAN))
3466+ {
3467+ char tmp_tables_size_buff[21];
3468+ sprintf(tmp_tables_size_buff, "%llu", thd->tmp_tables_size);
3469+ if (my_b_printf(&log_file,
3470+ " Tmp_tables: %lu Tmp_disk_tables: %lu "
3471+ "Tmp_table_sizes: %s",
3472+ thd->tmp_tables_used, thd->tmp_tables_disk_used,
3473+ tmp_tables_size_buff) == (uint) -1)
3474+ {
3475+ tmp_errno= errno;
3476+ }
3477+ }
3478+ if (my_b_write(&log_file, (uchar*) "\n", 1))
3479+ tmp_errno= errno;
3480+
3481 #if defined(ENABLED_PROFILING)
3482 thd->profiling.print_current(&log_file);
3483 #endif
3484- if (thd->innodb_was_used)
3485+ if ((thd->variables.log_slow_verbosity & (1ULL << SLOG_V_INNODB))
3486+ && thd->innodb_was_used)
3487 {
3488 char buf[20];
3489 snprintf(buf, 20, "%llX", thd->innodb_trx_id);
3490@@ -2796,18 +2820,20 @@
3491 if ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_INNODB)) && thd->innodb_was_used)
3492 {
3493 char buf[3][20];
3494+ char io_read_buff[21];
3495 snprintf(buf[0], 20, "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0);
3496 snprintf(buf[1], 20, "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0);
3497 snprintf(buf[2], 20, "%.6f", thd->innodb_innodb_que_wait_timer / 1000000.0);
3498+ sprintf(io_read_buff, "%llu", thd->innodb_io_read);
3499 if (my_b_printf(&log_file,
3500- "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %lu InnoDB_IO_r_wait: %s\n" \
3501- "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n" \
3502+ "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %s "
3503+ "InnoDB_IO_r_wait: %s\n"
3504+ "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n"
3505 "# InnoDB_pages_distinct: %lu\n",
3506- (ulong) thd->innodb_io_reads,
3507- (ulong) thd->innodb_io_read,
3508- buf[0], buf[1], buf[2],
3509- (ulong) thd->innodb_page_access) == (uint) -1)
3510- tmp_errno=errno;
3511+ thd->innodb_io_reads, io_read_buff,
3512+ buf[0], buf[1], buf[2], thd->innodb_page_access)
3513+ == (uint) -1)
3514+ tmp_errno= errno;
3515 }
3516 else
3517 {
3518
3519=== modified file 'Percona-Server/sql/log_event.cc'
3520--- Percona-Server/sql/log_event.cc 2013-01-09 23:46:01 +0000
3521+++ Percona-Server/sql/log_event.cc 2013-01-21 06:27:51 +0000
3522@@ -3511,7 +3511,7 @@
3523 thd->enable_slow_log is set to the value of
3524 opt_log_slow_admin_statements).
3525 */
3526- thd->enable_slow_log= opt_log_slow_slave_statements;
3527+ thd->enable_slow_log= TRUE;
3528 }
3529 else
3530 {
3531
3532=== modified file 'Percona-Server/sql/slave.cc'
3533--- Percona-Server/sql/slave.cc 2012-09-17 13:08:32 +0000
3534+++ Percona-Server/sql/slave.cc 2013-01-21 06:27:51 +0000
3535@@ -2086,8 +2086,7 @@
3536 */
3537 thd->variables.max_allowed_packet= slave_max_allowed_packet;
3538 thd->slave_thread = 1;
3539- thd->enable_slow_log= opt_log_slow_slave_statements;
3540- thd->write_to_slow_log= opt_log_slow_slave_statements;
3541+ thd->enable_slow_log= TRUE;
3542 set_slave_thread_options(thd);
3543 thd->client_capabilities = CLIENT_LOCAL_FILES;
3544 mysql_mutex_lock(&LOCK_thread_count);
3545
3546=== modified file 'Percona-Server/sql/sql_class.cc'
3547--- Percona-Server/sql/sql_class.cc 2012-10-27 05:16:07 +0000
3548+++ Percona-Server/sql/sql_class.cc 2013-01-21 06:27:51 +0000
3549@@ -4112,11 +4112,6 @@
3550 }
3551 #endif /* DBUG_OFF */
3552 query_id= new_query_id;
3553- if (opt_slow_query_log_rate_type == SLOG_RT_QUERY)
3554- {
3555- const ulong& limit= variables.log_slow_rate_limit;
3556- write_to_slow_log= limit == 0 || (query_id % limit) == 0;
3557- }
3558 }
3559
3560 /** Assign a new value to thd->mysys_var. */
3561
3562=== modified file 'Percona-Server/sql/sql_class.h'
3563--- Percona-Server/sql/sql_class.h 2012-12-14 03:09:41 +0000
3564+++ Percona-Server/sql/sql_class.h 2013-01-21 06:27:51 +0000
3565@@ -80,14 +80,14 @@
3566 SLOG_RT_SESSION, SLOG_RT_QUERY
3567 };
3568 #define QPLAN_NONE 0
3569-#define QPLAN_QC 1 << 0
3570-#define QPLAN_QC_NO 1 << 1
3571-#define QPLAN_FULL_SCAN 1 << 2
3572-#define QPLAN_FULL_JOIN 1 << 3
3573-#define QPLAN_TMP_TABLE 1 << 4
3574-#define QPLAN_TMP_DISK 1 << 5
3575-#define QPLAN_FILESORT 1 << 6
3576-#define QPLAN_FILESORT_DISK 1 << 7
3577+#define QPLAN_QC_NO (1 << 0)
3578+#define QPLAN_FULL_SCAN (1 << 1)
3579+#define QPLAN_FULL_JOIN (1 << 2)
3580+#define QPLAN_TMP_TABLE (1 << 3)
3581+#define QPLAN_TMP_DISK (1 << 4)
3582+#define QPLAN_FILESORT (1 << 5)
3583+#define QPLAN_FILESORT_DISK (1 << 6)
3584+#define QPLAN_QC (1 << 7)
3585 enum enum_log_slow_filter {
3586 SLOG_F_QC_NO, SLOG_F_FULL_SCAN, SLOG_F_FULL_JOIN,
3587 SLOG_F_TMP_TABLE, SLOG_F_TMP_DISK, SLOG_F_FILESORT,
3588@@ -1670,18 +1670,6 @@
3589
3590 /*** Following variables used in slow_extended.patch ***/
3591 /*
3592- Variable write_to_slow_log:
3593- 1) initialized in
3594- * sql_connect.cc (log_slow_rate_limit support)
3595- * slave.cc (log_slow_slave_statements support)
3596- 2) The variable is initialized on the thread startup and remains
3597- constant afterwards. This will change when
3598- LP #712396 ("log_slow_slave_statements not work on replication
3599- threads without RESTART") is implemented.
3600- 3) An implementation of LP #688646 ("Make query sampling possible by query") should use it.
3601- */
3602- bool write_to_slow_log;
3603- /*
3604 Variable bytes_send_old saves value of thd->status_var.bytes_sent
3605 before query execution.
3606 */
3607
3608=== modified file 'Percona-Server/sql/sql_connect.cc'
3609--- Percona-Server/sql/sql_connect.cc 2013-01-09 23:45:25 +0000
3610+++ Percona-Server/sql/sql_connect.cc 2013-01-21 06:27:51 +0000
3611@@ -1417,14 +1417,6 @@
3612 MYSQL_CONNECTION_START(thd->thread_id, &thd->security_ctx->priv_user[0],
3613 (char *) thd->security_ctx->host_or_ip);
3614
3615- /*
3616- If rate limiting of slow log writes is enabled, decide whether to log this
3617- new thread's queries or not. Uses extremely simple algorithm. :)
3618- */
3619- const ulong& limit= thd->variables.log_slow_rate_limit;
3620- thd->write_to_slow_log= opt_slow_query_log_rate_type == SLOG_RT_SESSION &&
3621- (limit == 0 || (thd->thread_id % limit) == 0);
3622-
3623 prepare_new_connection_state(thd);
3624 return FALSE;
3625 }
3626
3627=== modified file 'Percona-Server/sql/sql_parse.cc'
3628--- Percona-Server/sql/sql_parse.cc 2013-01-09 23:45:25 +0000
3629+++ Percona-Server/sql/sql_parse.cc 2013-01-21 06:27:51 +0000
3630@@ -1535,7 +1535,7 @@
3631 /* Follow the slow log filter configuration. */
3632 if (thd->variables.log_slow_filter != 0 &&
3633 (!(thd->variables.log_slow_filter & thd->query_plan_flags) ||
3634- ((thd->variables.log_slow_filter & SLOG_F_QC_NO) &&
3635+ ((thd->variables.log_slow_filter & (1UL << SLOG_F_QC_NO)) &&
3636 (thd->query_plan_flags & QPLAN_QC))))
3637 DBUG_VOID_RETURN;
3638
3639@@ -1567,10 +1567,20 @@
3640 copy_global_to_session(thd, SLOG_UG_MIN_EXAMINED_ROW_LIMIT,
3641 &g.min_examined_row_limit);
3642
3643- /* Do not log this thread's queries due to rate limiting. */
3644- if (!thd->write_to_slow_log && (thd->variables.long_query_time >= 1000000
3645- || (ulong) query_exec_time < 1000000))
3646- DBUG_VOID_RETURN;
3647+ if (opt_slow_query_log_rate_type == SLOG_RT_QUERY
3648+ && thd->variables.log_slow_rate_limit
3649+ && thd->query_id % thd->variables.log_slow_rate_limit
3650+ && (thd->variables.long_query_time >= 1000000
3651+ || (ulong) query_exec_time < 1000000)) {
3652+ DBUG_VOID_RETURN;
3653+ }
3654+ if (opt_slow_query_log_rate_type == SLOG_RT_SESSION
3655+ && thd->variables.log_slow_rate_limit
3656+ && thd->thread_id % thd->variables.log_slow_rate_limit
3657+ && (thd->variables.long_query_time >= 1000000
3658+ || (ulong) query_exec_time < 1000000)) {
3659+ DBUG_VOID_RETURN;
3660+ }
3661
3662
3663 /*
3664
3665=== modified file 'Percona-Server/sql/sys_vars.cc'
3666--- Percona-Server/sql/sys_vars.cc 2012-10-17 03:47:45 +0000
3667+++ Percona-Server/sql/sys_vars.cc 2013-01-21 06:27:51 +0000
3668@@ -3205,7 +3205,8 @@
3669 const char *slow_query_log_timestamp_precision_name[]= { "second", "microsecond", 0 };
3670 static Sys_var_enum Sys_slow_query_log_timestamp_precision(
3671 "slow_query_log_timestamp_precision",
3672- "Log slow statements executed by stored procedure to the slow log if it is open. [second, microsecond]",
3673+ "Select the timestamp precision for use in the slow query log. "
3674+ "[second, microsecond]",
3675 GLOBAL_VAR(opt_slow_query_log_timestamp_precision), CMD_LINE(REQUIRED_ARG),
3676 slow_query_log_timestamp_precision_name, DEFAULT(SLOG_SECOND));
3677
3678
3679=== modified file 'Percona-Server/storage/innobase/handler/ha_innodb.cc'
3680--- Percona-Server/storage/innobase/handler/ha_innodb.cc 2013-01-18 03:34:53 +0000
3681+++ Percona-Server/storage/innobase/handler/ha_innodb.cc 2013-01-21 06:27:51 +0000
3682@@ -1779,7 +1779,7 @@
3683 trx->fake_changes = THDVAR(thd, fake_changes);
3684
3685 #ifdef EXTENDED_SLOWLOG
3686- if (thd_log_slow_verbosity(thd) & SLOG_V_INNODB) {
3687+ if (thd_log_slow_verbosity(thd) & (1ULL << SLOG_V_INNODB)) {
3688 trx->take_stats = TRUE;
3689 } else {
3690 trx->take_stats = FALSE;

Subscribers

People subscribed via source and target branches