Merge lp:~laurynas-biveinis/percona-server/slow-log-fixes-5.5 into lp:percona-server/5.5
- slow-log-fixes-5.5
- Merge into 5.5
Proposed by
Laurynas Biveinis
Status: | Merged |
---|---|
Approved by: | Stewart Smith |
Approved revision: | no longer in the source branch. |
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 |
Related bugs: |
|
Reviewer | Review Type | Date Requested | Status |
---|---|---|---|
Stewart Smith (community) | Approve | ||
Review via email: mp+144058@code.launchpad.net |
Commit message
Description of the change
Merge multiple slow query log fixes from 5.1.
http://
To post a comment you must log in.
Revision history for this message
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; |