]>
Commit | Line | Data |
---|---|---|
b4e1fa2c AM |
1 | # name : slow_extended.patch |
2 | # introduced : 11 or before | |
3 | # maintainer : Oleg | |
4 | # | |
5 | #!!! notice !!! | |
6 | # Any small change to this file in the main branch | |
7 | # should be done or reviewed by the maintainer! | |
8 | diff -ruN a/include/mysql/plugin_audit.h.pp b/include/mysql/plugin_audit.h.pp | |
a9ee80b9 ER |
9 | --- a/include/mysql/plugin_audit.h.pp 2011-01-20 00:37:08.000000000 +0200 |
10 | +++ b/include/mysql/plugin_audit.h.pp 2011-02-21 22:57:48.816765777 +0200 | |
b4e1fa2c AM |
11 | @@ -178,6 +178,16 @@ |
12 | char *thd_security_context(void* thd, char *buffer, unsigned int length, | |
13 | unsigned int max_query_len); | |
14 | void thd_inc_row_count(void* thd); | |
15 | +void increment_thd_innodb_stats(void* thd, | |
16 | + unsigned long long trx_id, | |
17 | + long io_reads, | |
18 | + long long io_read, | |
19 | + long io_reads_wait_timer, | |
20 | + long lock_que_wait_timer, | |
21 | + long que_wait_timer, | |
22 | + long page_access); | |
23 | +unsigned long thd_log_slow_verbosity(const void* thd); | |
24 | +int thd_opt_slow_log(); | |
25 | int mysql_tmpfile(const char *prefix); | |
26 | int thd_killed(const void* thd); | |
27 | unsigned long thd_get_thread_id(const void* thd); | |
28 | diff -ruN a/include/mysql/plugin_auth.h.pp b/include/mysql/plugin_auth.h.pp | |
a9ee80b9 ER |
29 | --- a/include/mysql/plugin_auth.h.pp 2011-01-20 00:37:08.000000000 +0200 |
30 | +++ b/include/mysql/plugin_auth.h.pp 2011-02-21 22:57:48.816765777 +0200 | |
b4e1fa2c AM |
31 | @@ -178,6 +178,16 @@ |
32 | char *thd_security_context(void* thd, char *buffer, unsigned int length, | |
33 | unsigned int max_query_len); | |
34 | void thd_inc_row_count(void* thd); | |
35 | +void increment_thd_innodb_stats(void* thd, | |
36 | + unsigned long long trx_id, | |
37 | + long io_reads, | |
38 | + long long io_read, | |
39 | + long io_reads_wait_timer, | |
40 | + long lock_que_wait_timer, | |
41 | + long que_wait_timer, | |
42 | + long page_access); | |
43 | +unsigned long thd_log_slow_verbosity(const void* thd); | |
44 | +int thd_opt_slow_log(); | |
45 | int mysql_tmpfile(const char *prefix); | |
46 | int thd_killed(const void* thd); | |
47 | unsigned long thd_get_thread_id(const void* thd); | |
48 | diff -ruN a/include/mysql/plugin_ftparser.h.pp b/include/mysql/plugin_ftparser.h.pp | |
a9ee80b9 ER |
49 | --- a/include/mysql/plugin_ftparser.h.pp 2011-01-20 00:37:08.000000000 +0200 |
50 | +++ b/include/mysql/plugin_ftparser.h.pp 2011-02-21 22:57:48.816765777 +0200 | |
b4e1fa2c AM |
51 | @@ -131,6 +131,16 @@ |
52 | char *thd_security_context(void* thd, char *buffer, unsigned int length, | |
53 | unsigned int max_query_len); | |
54 | void thd_inc_row_count(void* thd); | |
55 | +void increment_thd_innodb_stats(void* thd, | |
56 | + unsigned long long trx_id, | |
57 | + long io_reads, | |
58 | + long long io_read, | |
59 | + long io_reads_wait_timer, | |
60 | + long lock_que_wait_timer, | |
61 | + long que_wait_timer, | |
62 | + long page_access); | |
63 | +unsigned long thd_log_slow_verbosity(const void* thd); | |
64 | +int thd_opt_slow_log(); | |
65 | int mysql_tmpfile(const char *prefix); | |
66 | int thd_killed(const void* thd); | |
67 | unsigned long thd_get_thread_id(const void* thd); | |
68 | diff -ruN a/include/mysql/plugin.h b/include/mysql/plugin.h | |
a9ee80b9 ER |
69 | --- a/include/mysql/plugin.h 2011-01-20 00:37:08.000000000 +0200 |
70 | +++ b/include/mysql/plugin.h 2011-02-21 22:57:48.817765600 +0200 | |
b4e1fa2c AM |
71 | @@ -536,6 +536,17 @@ |
72 | /* Increments the row counter, see THD::row_count */ | |
73 | void thd_inc_row_count(MYSQL_THD thd); | |
74 | ||
75 | +void increment_thd_innodb_stats(MYSQL_THD thd, | |
76 | + unsigned long long trx_id, | |
77 | + long io_reads, | |
78 | + long long io_read, | |
79 | + long io_reads_wait_timer, | |
80 | + long lock_que_wait_timer, | |
81 | + long que_wait_timer, | |
82 | + long page_access); | |
83 | +unsigned long thd_log_slow_verbosity(const MYSQL_THD thd); | |
84 | +int thd_opt_slow_log(); | |
85 | +#define EXTENDED_SLOWLOG | |
86 | /** | |
87 | Create a temporary file. | |
88 | ||
89 | diff -ruN a/patch_info/slow_extended.info b/patch_info/slow_extended.info | |
90 | --- a/patch_info/slow_extended.info 1970-01-01 03:00:00.000000000 +0300 | |
a9ee80b9 | 91 | +++ b/patch_info/slow_extended.info 2011-02-21 22:57:48.818765423 +0200 |
b4e1fa2c AM |
92 | @@ -0,0 +1,25 @@ |
93 | +File=slow_extended.patch | |
94 | +Name=Extended statistics in slow.log (not InnoDB part) | |
95 | +Version=1.3 | |
96 | +Author=Percona <info@percona.com> | |
97 | +License=GPL | |
98 | +Comment= | |
99 | +Changelog | |
100 | +2008-11-26 | |
101 | +YK: Fix inefficient determination of trx, Make not to call useless gettimeofday when don't use slow log. Make log_slow_queries dynamic (bool). | |
102 | + | |
103 | +2008-11-07 | |
104 | +VT: Moved log_slow_rate_limit in SHOW VARIABLE into right place | |
105 | + | |
106 | +2008-11 | |
107 | +Arjen Lentz: Fixups (backward compatibility) by Arjen Lentz <arjen@openquery.com.au> | |
108 | + | |
109 | +2010-07 | |
110 | +1) Fix overflow of query time and lock time (Bug 600360) (slow_extended_fix_overflow.patch merged) | |
111 | +2) Control global slow feature merged (control_global_slow.patch merged) | |
112 | +3) Microseconds in slow query log merged (microseconds_in_slow_query_log.patch merged) | |
113 | +4) Now use_global_long_query_time and use_global_log_slow_control are synonims. Add value "all" for use_global_log_slow_control (contol-global_slow-2.patch merged) | |
114 | +5) Fix innodb_stats on replication (Bug 600684) | |
115 | +6) Change variable types (system/command-line) | |
a9ee80b9 | 116 | +2011-01 |
b4e1fa2c | 117 | +Patch profiling_slow.patch was merged |
a9ee80b9 ER |
118 | +2011-02 |
119 | +Rename variables: | |
120 | +LOG_SLOW_TIMESTAMP_EVERY => SLOW_QUERY_LOG_TIMESTAMP_ALWAYS | |
121 | +LOG_WARNINGS_SILENCE => LOG_WARNINGS_SUPPRESS | |
122 | +SLOW_QUERY_LOG_MICROSECONDS_TIMESTAMP => SLOW_QUERY_LOG_TIMESTAMP_PRECISION=(SECOND,MICROSECOND) | |
123 | +USE_GLOBAL_LOG_SLOW_CONTROL => SLOW_QUERY_LOG_USE_GLOBAL_CONTROL | |
b4e1fa2c | 124 | diff -ruN a/scripts/mysqldumpslow.sh b/scripts/mysqldumpslow.sh |
a9ee80b9 ER |
125 | --- a/scripts/mysqldumpslow.sh 2011-01-20 00:37:09.000000000 +0200 |
126 | +++ b/scripts/mysqldumpslow.sh 2011-02-21 22:57:48.818765423 +0200 | |
d8778560 | 127 | @@ -101,8 +101,8 @@ |
b4e1fa2c AM |
128 | s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//; |
129 | my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('',''); | |
130 | ||
131 | - s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\n//; | |
132 | - my ($t, $l, $r) = ($1, $2, $3); | |
133 | + s/^# Query_time: (\d+(\.\d+)?) Lock_time: (\d+(\.\d+)?) Rows_sent: (\d+(\.\d+)?).*\n//; | |
134 | + my ($t, $l, $r) = ($1, $3, $5); | |
135 | $t -= $l unless $opt{l}; | |
136 | ||
137 | # remove fluff that mysqld writes to log when it (re)starts: | |
138 | diff -ruN a/sql/event_scheduler.cc b/sql/event_scheduler.cc | |
a9ee80b9 ER |
139 | --- a/sql/event_scheduler.cc 2011-01-20 00:37:09.000000000 +0200 |
140 | +++ b/sql/event_scheduler.cc 2011-02-21 22:57:48.819765246 +0200 | |
b4e1fa2c AM |
141 | @@ -195,6 +195,7 @@ |
142 | thd->client_capabilities|= CLIENT_MULTI_RESULTS; | |
143 | mysql_mutex_lock(&LOCK_thread_count); | |
144 | thd->thread_id= thd->variables.pseudo_thread_id= thread_id++; | |
145 | + thd->write_to_slow_log = TRUE; | |
146 | mysql_mutex_unlock(&LOCK_thread_count); | |
147 | ||
148 | /* | |
149 | diff -ruN a/sql/filesort.cc b/sql/filesort.cc | |
a9ee80b9 ER |
150 | --- a/sql/filesort.cc 2011-01-20 00:37:09.000000000 +0200 |
151 | +++ b/sql/filesort.cc 2011-02-21 22:57:48.821764892 +0200 | |
d8778560 | 152 | @@ -193,6 +193,7 @@ |
b4e1fa2c AM |
153 | { |
154 | status_var_increment(thd->status_var.filesort_scan_count); | |
155 | } | |
156 | + thd->query_plan_flags|= QPLAN_FILESORT; | |
157 | #ifdef CAN_TRUST_RANGE | |
158 | if (select && select->quick && select->quick->records > 0L) | |
159 | { | |
d8778560 | 160 | @@ -258,6 +259,7 @@ |
b4e1fa2c AM |
161 | } |
162 | else | |
163 | { | |
164 | + thd->query_plan_flags|= QPLAN_FILESORT_DISK; | |
165 | if (table_sort.buffpek && table_sort.buffpek_len < maxbuffer) | |
166 | { | |
167 | my_free(table_sort.buffpek); | |
d8778560 | 168 | @@ -1197,6 +1199,7 @@ |
b4e1fa2c AM |
169 | DBUG_ENTER("merge_buffers"); |
170 | ||
171 | status_var_increment(current_thd->status_var.filesort_merge_passes); | |
172 | + current_thd->query_plan_fsort_passes++; | |
173 | if (param->not_killable) | |
174 | { | |
175 | killed= ¬_killable; | |
176 | diff -ruN a/sql/log.cc b/sql/log.cc | |
a9ee80b9 ER |
177 | --- a/sql/log.cc 2011-01-20 00:37:09.000000000 +0200 |
178 | +++ b/sql/log.cc 2011-02-21 23:14:33.973714581 +0200 | |
d8778560 | 179 | @@ -715,11 +715,13 @@ |
b4e1fa2c AM |
180 | */ |
181 | ||
182 | bool Log_to_csv_event_handler:: | |
183 | - log_slow(THD *thd, time_t current_time, time_t query_start_arg, | |
184 | + log_slow(THD *thd, ulonglong current_utime, time_t query_start_arg, | |
185 | const char *user_host, uint user_host_len, | |
186 | ulonglong query_utime, ulonglong lock_utime, bool is_command, | |
187 | const char *sql_text, uint sql_text_len) | |
188 | { | |
189 | + time_t current_time= my_time_possible_from_micro(current_utime); | |
190 | + | |
191 | TABLE_LIST table_list; | |
192 | TABLE *table; | |
193 | bool result= TRUE; | |
d8778560 | 194 | @@ -935,14 +937,14 @@ |
b4e1fa2c AM |
195 | /** Wrapper around MYSQL_LOG::write() for slow log. */ |
196 | ||
197 | bool Log_to_file_event_handler:: | |
198 | - log_slow(THD *thd, time_t current_time, time_t query_start_arg, | |
199 | + log_slow(THD *thd, ulonglong current_utime, time_t query_start_arg, | |
200 | const char *user_host, uint user_host_len, | |
201 | ulonglong query_utime, ulonglong lock_utime, bool is_command, | |
202 | const char *sql_text, uint sql_text_len) | |
203 | { | |
204 | Silence_log_table_errors error_handler; | |
205 | thd->push_internal_handler(&error_handler); | |
206 | - bool retval= mysql_slow_log.write(thd, current_time, query_start_arg, | |
207 | + bool retval= mysql_slow_log.write(thd, current_utime, query_start_arg, | |
208 | user_host, user_host_len, | |
209 | query_utime, lock_utime, is_command, | |
210 | sql_text, sql_text_len); | |
d8778560 | 211 | @@ -1216,7 +1218,7 @@ |
b4e1fa2c AM |
212 | /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */ |
213 | user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE, | |
214 | sctx->priv_user ? sctx->priv_user : "", "[", | |
215 | - sctx->user ? sctx->user : "", "] @ ", | |
216 | + sctx->user ? sctx->user : (thd->slave_thread ? "SQL_SLAVE" : ""), "] @ ", | |
217 | sctx->host ? sctx->host : "", " [", | |
218 | sctx->ip ? sctx->ip : "", "]", NullS) - | |
219 | user_host_buff); | |
d8778560 | 220 | @@ -1224,8 +1226,22 @@ |
b4e1fa2c AM |
221 | current_time= my_time_possible_from_micro(current_utime); |
222 | if (thd->start_utime) | |
223 | { | |
224 | - query_utime= (current_utime - thd->start_utime); | |
225 | - lock_utime= (thd->utime_after_lock - thd->start_utime); | |
226 | + if(current_utime < thd->start_utime) | |
227 | + { | |
228 | + query_utime= 0; | |
229 | + } | |
230 | + else | |
231 | + { | |
232 | + query_utime= (current_utime - thd->start_utime); | |
233 | + } | |
234 | + if(thd->utime_after_lock < thd->start_utime) | |
235 | + { | |
236 | + lock_utime= 0; | |
237 | + } | |
238 | + else | |
239 | + { | |
240 | + lock_utime= (thd->utime_after_lock - thd->start_utime); | |
241 | + } | |
242 | } | |
243 | else | |
244 | { | |
d8778560 | 245 | @@ -1239,8 +1255,20 @@ |
b4e1fa2c AM |
246 | query_length= command_name[thd->command].length; |
247 | } | |
248 | ||
249 | + if (!query_length) | |
250 | + { | |
251 | + thd->sent_row_count= thd->examined_row_count= 0; | |
252 | + thd->sent_row_count= 0; | |
253 | + thd->bytes_sent_old= thd->status_var.bytes_sent; | |
254 | + thd->tmp_tables_used= thd->tmp_tables_disk_used= 0; | |
255 | + thd->tmp_tables_size= 0; | |
256 | + thd->innodb_was_used= FALSE; | |
257 | + thd->query_plan_flags= QPLAN_NONE; | |
258 | + thd->query_plan_fsort_passes= 0; | |
259 | + } | |
260 | + | |
261 | for (current_handler= slow_log_handler_list; *current_handler ;) | |
262 | - error= (*current_handler++)->log_slow(thd, current_time, thd->start_time, | |
263 | + error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time, | |
264 | user_host_buff, user_host_len, | |
265 | query_utime, lock_utime, is_command, | |
266 | query, query_length) || error; | |
d8778560 | 267 | @@ -2656,12 +2684,13 @@ |
b4e1fa2c AM |
268 | TRUE - error occured |
269 | */ | |
270 | ||
271 | -bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time, | |
272 | +bool MYSQL_QUERY_LOG::write(THD *thd, ulonglong current_utime, | |
273 | time_t query_start_arg, const char *user_host, | |
274 | uint user_host_len, ulonglong query_utime, | |
275 | ulonglong lock_utime, bool is_command, | |
276 | const char *sql_text, uint sql_text_len) | |
277 | { | |
278 | + time_t current_time= my_time_possible_from_micro(current_utime); | |
279 | bool error= 0; | |
280 | DBUG_ENTER("MYSQL_QUERY_LOG::write"); | |
281 | ||
d8778560 | 282 | @@ -2683,17 +2712,28 @@ |
b4e1fa2c AM |
283 | |
284 | if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT)) | |
285 | { | |
286 | - if (current_time != last_time) | |
a9ee80b9 | 287 | + if (opt_slow_query_log_timestamp_always || current_time != last_time) |
b4e1fa2c AM |
288 | { |
289 | last_time= current_time; | |
290 | struct tm start; | |
291 | localtime_r(¤t_time, &start); | |
292 | - | |
293 | - buff_len= my_snprintf(buff, sizeof buff, | |
294 | - "# Time: %02d%02d%02d %2d:%02d:%02d\n", | |
295 | - start.tm_year % 100, start.tm_mon + 1, | |
296 | - start.tm_mday, start.tm_hour, | |
297 | - start.tm_min, start.tm_sec); | |
a9ee80b9 | 298 | + if(opt_slow_query_log_timestamp_precision & SLOG_MICROSECOND) |
b4e1fa2c AM |
299 | + { |
300 | + ulonglong microsecond = current_utime % (1000 * 1000); | |
301 | + buff_len= snprintf(buff, sizeof buff, | |
302 | + "# Time: %02d%02d%02d %2d:%02d:%02d.%010lld\n", | |
303 | + start.tm_year % 100, start.tm_mon + 1, | |
304 | + start.tm_mday, start.tm_hour, | |
305 | + start.tm_min, start.tm_sec,microsecond); | |
306 | + } | |
307 | + else | |
308 | + { | |
309 | + buff_len= my_snprintf(buff, sizeof buff, | |
310 | + "# Time: %02d%02d%02d %2d:%02d:%02d\n", | |
311 | + start.tm_year % 100, start.tm_mon + 1, | |
312 | + start.tm_mday, start.tm_hour, | |
313 | + start.tm_min, start.tm_sec); | |
314 | + } | |
315 | ||
316 | /* Note that my_b_write() assumes it knows the length for this */ | |
317 | if (my_b_write(&log_file, (uchar*) buff, buff_len)) | |
a9ee80b9 | 318 | @@ -2711,12 +2752,69 @@ |
b4e1fa2c AM |
319 | sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0); |
320 | sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0); | |
321 | if (my_b_printf(&log_file, | |
322 | - "# Query_time: %s Lock_time: %s" | |
323 | - " Rows_sent: %lu Rows_examined: %lu\n", | |
324 | + "# Thread_id: %lu Schema: %s Last_errno: %u Killed: %u\n" \ | |
325 | + "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu Rows_affected: %lu Rows_read: %lu\n" | |
326 | + "# Bytes_sent: %lu Tmp_tables: %lu Tmp_disk_tables: %lu Tmp_table_sizes: %lu\n", | |
327 | + (ulong) thd->thread_id, (thd->db ? thd->db : ""), | |
328 | + thd->last_errno, (uint) thd->killed, | |
329 | query_time_buff, lock_time_buff, | |
330 | (ulong) thd->sent_row_count, | |
331 | - (ulong) thd->examined_row_count) == (uint) -1) | |
332 | + (ulong) thd->examined_row_count, | |
333 | + ((long) thd->get_row_count_func() > 0 ) ? (ulong) thd->get_row_count_func() : 0, | |
334 | + (ulong) thd->sent_row_count, | |
335 | + (ulong) (thd->status_var.bytes_sent - thd->bytes_sent_old), | |
336 | + (ulong) thd->tmp_tables_used, | |
337 | + (ulong) thd->tmp_tables_disk_used, | |
338 | + (ulong) thd->tmp_tables_size) == (uint) -1) | |
339 | tmp_errno= errno; | |
340 | + | |
341 | +#if defined(ENABLED_PROFILING) | |
342 | + thd->profiling.print_current(&log_file); | |
343 | +#endif | |
344 | + if (thd->innodb_was_used) | |
345 | + { | |
346 | + char buf[20]; | |
347 | + snprintf(buf, 20, "%llX", thd->innodb_trx_id); | |
348 | + if (my_b_printf(&log_file, | |
349 | + "# InnoDB_trx_id: %s\n", buf) == (uint) -1) | |
350 | + tmp_errno=errno; | |
351 | + } | |
352 | + if ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_QUERY_PLAN)) && | |
353 | + my_b_printf(&log_file, | |
354 | + "# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s Tmp_table_on_disk: %s\n" \ | |
355 | + "# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n", | |
356 | + ((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"), | |
357 | + ((thd->query_plan_flags & QPLAN_FULL_SCAN) ? "Yes" : "No"), | |
358 | + ((thd->query_plan_flags & QPLAN_FULL_JOIN) ? "Yes" : "No"), | |
359 | + ((thd->query_plan_flags & QPLAN_TMP_TABLE) ? "Yes" : "No"), | |
360 | + ((thd->query_plan_flags & QPLAN_TMP_DISK) ? "Yes" : "No"), | |
361 | + ((thd->query_plan_flags & QPLAN_FILESORT) ? "Yes" : "No"), | |
362 | + ((thd->query_plan_flags & QPLAN_FILESORT_DISK) ? "Yes" : "No"), | |
363 | + thd->query_plan_fsort_passes) == (uint) -1) | |
364 | + tmp_errno=errno; | |
365 | + if ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_INNODB)) && thd->innodb_was_used) | |
366 | + { | |
367 | + char buf[3][20]; | |
368 | + snprintf(buf[0], 20, "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0); | |
369 | + snprintf(buf[1], 20, "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0); | |
370 | + snprintf(buf[2], 20, "%.6f", thd->innodb_innodb_que_wait_timer / 1000000.0); | |
371 | + if (my_b_printf(&log_file, | |
372 | + "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %lu InnoDB_IO_r_wait: %s\n" \ | |
373 | + "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n" \ | |
374 | + "# InnoDB_pages_distinct: %lu\n", | |
375 | + (ulong) thd->innodb_io_reads, | |
376 | + (ulong) thd->innodb_io_read, | |
377 | + buf[0], buf[1], buf[2], | |
378 | + (ulong) thd->innodb_page_access) == (uint) -1) | |
379 | + tmp_errno=errno; | |
380 | + } | |
381 | + else | |
382 | + { | |
383 | + if ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_INNODB)) && | |
384 | + my_b_printf(&log_file,"# No InnoDB statistics available for this query\n") == (uint) -1) | |
385 | + tmp_errno=errno; | |
386 | + } | |
387 | + | |
388 | if (thd->db && strcmp(thd->db, db)) | |
389 | { // Database changed | |
390 | if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1) | |
391 | diff -ruN a/sql/log.h b/sql/log.h | |
a9ee80b9 ER |
392 | --- a/sql/log.h 2011-01-20 00:37:09.000000000 +0200 |
393 | +++ b/sql/log.h 2011-02-21 22:57:48.826764006 +0200 | |
b4e1fa2c AM |
394 | @@ -242,7 +242,7 @@ |
395 | uint user_host_len, int thread_id, | |
396 | const char *command_type, uint command_type_len, | |
397 | const char *sql_text, uint sql_text_len); | |
398 | - bool write(THD *thd, time_t current_time, time_t query_start_arg, | |
399 | + bool write(THD *thd, ulonglong current_time, time_t query_start_arg, | |
400 | const char *user_host, uint user_host_len, | |
401 | ulonglong query_utime, ulonglong lock_utime, bool is_command, | |
402 | const char *sql_text, uint sql_text_len); | |
403 | @@ -492,7 +492,7 @@ | |
404 | virtual bool init()= 0; | |
405 | virtual void cleanup()= 0; | |
406 | ||
407 | - virtual bool log_slow(THD *thd, time_t current_time, | |
408 | + virtual bool log_slow(THD *thd, ulonglong current_time, | |
409 | time_t query_start_arg, const char *user_host, | |
410 | uint user_host_len, ulonglong query_utime, | |
411 | ulonglong lock_utime, bool is_command, | |
412 | @@ -521,7 +521,7 @@ | |
413 | virtual bool init(); | |
414 | virtual void cleanup(); | |
415 | ||
416 | - virtual bool log_slow(THD *thd, time_t current_time, | |
417 | + virtual bool log_slow(THD *thd, ulonglong current_utime, | |
418 | time_t query_start_arg, const char *user_host, | |
419 | uint user_host_len, ulonglong query_utime, | |
420 | ulonglong lock_utime, bool is_command, | |
421 | @@ -553,7 +553,7 @@ | |
422 | virtual bool init(); | |
423 | virtual void cleanup(); | |
424 | ||
425 | - virtual bool log_slow(THD *thd, time_t current_time, | |
426 | + virtual bool log_slow(THD *thd, ulonglong current_utime, | |
427 | time_t query_start_arg, const char *user_host, | |
428 | uint user_host_len, ulonglong query_utime, | |
429 | ulonglong lock_utime, bool is_command, | |
430 | diff -ruN a/sql/mysqld.cc b/sql/mysqld.cc | |
a9ee80b9 ER |
431 | --- a/sql/mysqld.cc 2011-02-21 22:57:24.442081625 +0200 |
432 | +++ b/sql/mysqld.cc 2011-02-21 22:59:30.845699981 +0200 | |
b4e1fa2c AM |
433 | @@ -418,6 +418,10 @@ |
434 | char* opt_secure_file_priv; | |
435 | my_bool opt_log_slow_admin_statements= 0; | |
436 | my_bool opt_log_slow_slave_statements= 0; | |
437 | +my_bool opt_log_slow_sp_statements= 0; | |
a9ee80b9 ER |
438 | +my_bool opt_slow_query_log_timestamp_always= 0; |
439 | +ulonglong opt_slow_query_log_use_global_control= 0; | |
440 | +ulonglong opt_slow_query_log_timestamp_precision= 0; | |
b4e1fa2c AM |
441 | my_bool lower_case_file_system= 0; |
442 | my_bool opt_large_pages= 0; | |
443 | my_bool opt_super_large_pages= 0; | |
d8778560 | 444 | @@ -5784,10 +5788,10 @@ |
b4e1fa2c AM |
445 | "Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to " |
446 | "the slow log if it is open.", &opt_log_slow_admin_statements, | |
447 | &opt_log_slow_admin_statements, 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0}, | |
448 | - {"log-slow-slave-statements", 0, | |
449 | + /*{"log-slow-slave-statements", 0, | |
450 | "Log slow statements executed by slave thread to the slow log if it is open.", | |
451 | &opt_log_slow_slave_statements, &opt_log_slow_slave_statements, | |
452 | - 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0}, | |
453 | + 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},*/ | |
454 | {"log-slow-queries", OPT_SLOW_QUERY_LOG, | |
455 | "Log slow queries to a table or log file. Defaults logging to table " | |
456 | "mysql.slow_log or hostname-slow.log if --log-output=file is used. " | |
d8778560 | 457 | @@ -7179,6 +7183,10 @@ |
b4e1fa2c AM |
458 | |
459 | C_MODE_END | |
460 | ||
461 | +/* defined in sys_vars.cc */ | |
462 | +extern void init_log_slow_verbosity(); | |
a9ee80b9 | 463 | +extern void init_slow_query_log_use_global_control(); |
b4e1fa2c AM |
464 | + |
465 | /** | |
466 | Get server options from the command line, | |
467 | and perform related server initializations. | |
d8778560 | 468 | @@ -7318,6 +7326,8 @@ |
b4e1fa2c AM |
469 | global_system_variables.long_query_time= (ulonglong) |
470 | (global_system_variables.long_query_time_double * 1e6); | |
471 | ||
472 | + init_log_slow_verbosity(); | |
a9ee80b9 | 473 | + init_slow_query_log_use_global_control(); |
b4e1fa2c AM |
474 | if (opt_short_log_format) |
475 | opt_specialflag|= SPECIAL_SHORT_LOG_FORMAT; | |
476 | ||
477 | diff -ruN a/sql/mysqld.h b/sql/mysqld.h | |
a9ee80b9 ER |
478 | --- a/sql/mysqld.h 2011-02-21 22:57:24.398089415 +0200 |
479 | +++ b/sql/mysqld.h 2011-02-21 23:01:50.079045873 +0200 | |
b4e1fa2c AM |
480 | @@ -116,6 +116,10 @@ |
481 | extern char* opt_secure_backup_file_priv; | |
482 | extern size_t opt_secure_backup_file_priv_len; | |
483 | extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements; | |
484 | +extern my_bool opt_log_slow_sp_statements; | |
a9ee80b9 ER |
485 | +extern my_bool opt_slow_query_log_timestamp_always; |
486 | +extern ulonglong opt_slow_query_log_use_global_control; | |
487 | +extern ulonglong opt_slow_query_log_timestamp_precision; | |
b4e1fa2c AM |
488 | extern my_bool sp_automatic_privileges, opt_noacl; |
489 | extern my_bool opt_old_style_user_limits, trust_function_creators; | |
490 | extern uint opt_crash_binlog_innodb; | |
491 | diff -ruN a/sql/slave.cc b/sql/slave.cc | |
a9ee80b9 ER |
492 | --- a/sql/slave.cc 2011-01-20 00:37:09.000000000 +0200 |
493 | +++ b/sql/slave.cc 2011-02-21 22:57:48.834762590 +0200 | |
d8778560 | 494 | @@ -2038,6 +2038,7 @@ |
b4e1fa2c AM |
495 | + MAX_LOG_EVENT_HEADER; /* note, incr over the global not session var */ |
496 | thd->slave_thread = 1; | |
497 | thd->enable_slow_log= opt_log_slow_slave_statements; | |
498 | + thd->write_to_slow_log= opt_log_slow_slave_statements; | |
499 | set_slave_thread_options(thd); | |
500 | thd->client_capabilities = CLIENT_LOCAL_FILES; | |
501 | mysql_mutex_lock(&LOCK_thread_count); | |
502 | diff -ruN a/sql/sp_head.cc b/sql/sp_head.cc | |
a9ee80b9 ER |
503 | --- a/sql/sp_head.cc 2011-01-20 00:37:09.000000000 +0200 |
504 | +++ b/sql/sp_head.cc 2011-02-21 22:57:48.837762059 +0200 | |
b4e1fa2c AM |
505 | @@ -2151,7 +2151,7 @@ |
506 | DBUG_PRINT("info",(" %.*s: eval args done", (int) m_name.length, | |
507 | m_name.str)); | |
508 | } | |
509 | - if (!(m_flags & LOG_SLOW_STATEMENTS) && thd->enable_slow_log) | |
510 | + if (!(m_flags & LOG_SLOW_STATEMENTS || opt_log_slow_sp_statements) && thd->enable_slow_log) | |
511 | { | |
512 | DBUG_PRINT("info", ("Disabling slow log for the execution")); | |
513 | save_enable_slow_log= true; | |
514 | diff -ruN a/sql/sql_cache.cc b/sql/sql_cache.cc | |
a9ee80b9 ER |
515 | --- a/sql/sql_cache.cc 2011-01-20 00:37:09.000000000 +0200 |
516 | +++ b/sql/sql_cache.cc 2011-02-21 22:57:48.840761528 +0200 | |
b4e1fa2c AM |
517 | @@ -1756,6 +1756,7 @@ |
518 | response, we can't handle it anyway. | |
519 | */ | |
520 | (void) trans_commit_stmt(thd); | |
521 | + thd->query_plan_flags|= QPLAN_QC; | |
522 | if (!thd->stmt_da->is_set()) | |
523 | thd->stmt_da->disable_status(); | |
524 | ||
525 | @@ -1766,6 +1767,7 @@ | |
526 | err_unlock: | |
527 | unlock(); | |
528 | err: | |
529 | + thd->query_plan_flags|= QPLAN_QC_NO; | |
530 | MYSQL_QUERY_CACHE_MISS(thd->query()); | |
531 | DBUG_RETURN(0); // Query was not cached | |
532 | } | |
533 | diff -ruN a/sql/sql_class.cc b/sql/sql_class.cc | |
a9ee80b9 ER |
534 | --- a/sql/sql_class.cc 2011-01-20 00:37:09.000000000 +0200 |
535 | +++ b/sql/sql_class.cc 2011-02-21 22:57:48.843760997 +0200 | |
b4e1fa2c AM |
536 | @@ -367,6 +367,37 @@ |
537 | thd->warning_info->inc_current_row_for_warning(); | |
538 | } | |
539 | ||
540 | +extern "C" | |
541 | +void increment_thd_innodb_stats(THD* thd, | |
542 | + unsigned long long trx_id, | |
543 | + long io_reads, | |
544 | + long long io_read, | |
545 | + long io_reads_wait_timer, | |
546 | + long lock_que_wait_timer, | |
547 | + long que_wait_timer, | |
548 | + long page_access) | |
549 | +{ | |
550 | + thd->innodb_was_used = TRUE; | |
551 | + thd->innodb_trx_id = trx_id; | |
552 | + thd->innodb_io_reads += io_reads; | |
553 | + thd->innodb_io_read += io_read; | |
554 | + thd->innodb_io_reads_wait_timer += io_reads_wait_timer; | |
555 | + thd->innodb_lock_que_wait_timer += lock_que_wait_timer; | |
556 | + thd->innodb_innodb_que_wait_timer += que_wait_timer; | |
557 | + thd->innodb_page_access += page_access; | |
558 | +} | |
559 | + | |
560 | +extern "C" | |
561 | +unsigned long thd_log_slow_verbosity(const THD *thd) | |
562 | +{ | |
563 | + return (unsigned long) thd->variables.log_slow_verbosity; | |
564 | +} | |
565 | + | |
566 | +extern "C" | |
567 | +int thd_opt_slow_log() | |
568 | +{ | |
569 | + return (int) opt_slow_log; | |
570 | +} | |
571 | ||
572 | /** | |
573 | Dumps a text description of a thread, its security context | |
574 | @@ -661,6 +692,7 @@ | |
575 | *cond_hdl= NULL; | |
576 | return FALSE; | |
577 | } | |
578 | + last_errno= sql_errno; | |
579 | ||
580 | for (Internal_error_handler *error_handler= m_internal_handler; | |
581 | error_handler; | |
d8778560 | 582 | @@ -3389,6 +3421,12 @@ |
b4e1fa2c AM |
583 | first_successful_insert_id_in_prev_stmt; |
584 | backup->first_successful_insert_id_in_cur_stmt= | |
585 | first_successful_insert_id_in_cur_stmt; | |
586 | + backup->innodb_io_reads= innodb_io_reads; | |
587 | + backup->innodb_io_read= innodb_io_read; | |
588 | + backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer; | |
589 | + backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer; | |
590 | + backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer; | |
591 | + backup->innodb_page_access= innodb_page_access; | |
592 | ||
593 | if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) && | |
594 | !is_current_stmt_binlog_format_row()) | |
d8778560 | 595 | @@ -3409,6 +3447,14 @@ |
b4e1fa2c AM |
596 | cuted_fields= 0; |
597 | transaction.savepoints= 0; | |
598 | first_successful_insert_id_in_cur_stmt= 0; | |
599 | + last_errno= 0; | |
600 | + innodb_trx_id= 0; | |
601 | + innodb_io_reads= 0; | |
602 | + innodb_io_read= 0; | |
603 | + innodb_io_reads_wait_timer= 0; | |
604 | + innodb_lock_que_wait_timer= 0; | |
605 | + innodb_innodb_que_wait_timer= 0; | |
606 | + innodb_page_access= 0; | |
607 | } | |
608 | ||
609 | ||
d8778560 | 610 | @@ -3471,6 +3517,12 @@ |
b4e1fa2c AM |
611 | */ |
612 | examined_row_count+= backup->examined_row_count; | |
613 | cuted_fields+= backup->cuted_fields; | |
614 | + innodb_io_reads+= backup->innodb_io_reads; | |
615 | + innodb_io_read+= backup->innodb_io_read; | |
616 | + innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer; | |
617 | + innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer; | |
618 | + innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer; | |
619 | + innodb_page_access+= backup->innodb_page_access; | |
620 | DBUG_VOID_RETURN; | |
621 | } | |
622 | ||
623 | diff -ruN a/sql/sql_class.h b/sql/sql_class.h | |
a9ee80b9 ER |
624 | --- a/sql/sql_class.h 2011-02-21 22:57:24.423084989 +0200 |
625 | +++ b/sql/sql_class.h 2011-02-21 23:06:24.869371276 +0200 | |
626 | @@ -60,6 +60,33 @@ | |
b4e1fa2c AM |
627 | enum enum_duplicates { DUP_ERROR, DUP_REPLACE, DUP_UPDATE }; |
628 | enum enum_delay_key_write { DELAY_KEY_WRITE_NONE, DELAY_KEY_WRITE_ON, | |
629 | DELAY_KEY_WRITE_ALL }; | |
a9ee80b9 ER |
630 | +enum enum_slow_query_log_use_global_control { |
631 | + SLOG_UG_LOG_SLOW_FILTER, SLOG_UG_LOG_SLOW_RATE_LIMIT | |
632 | + , SLOG_UG_LOG_SLOW_VERBOSITY, SLOG_UG_LONG_QUERY_TIME | |
633 | + , SLOG_UG_MIN_EXAMINED_ROW_LIMIT, SLOG_UG_ALL | |
634 | +}; | |
b4e1fa2c AM |
635 | +enum enum_log_slow_verbosity { |
636 | + SLOG_V_MICROTIME, SLOG_V_QUERY_PLAN, SLOG_V_INNODB, | |
637 | + SLOG_V_PROFILING, SLOG_V_PROFILING_USE_GETRUSAGE, | |
638 | + SLOG_V_MINIMAL, SLOG_V_STANDARD, SLOG_V_FULL | |
639 | +}; | |
a9ee80b9 ER |
640 | +enum enum_slow_query_log_timestamp_precision { |
641 | + SLOG_SECOND, SLOG_MICROSECOND | |
642 | +}; | |
b4e1fa2c AM |
643 | +#define QPLAN_NONE 0 |
644 | +#define QPLAN_QC 1 << 0 | |
645 | +#define QPLAN_QC_NO 1 << 1 | |
646 | +#define QPLAN_FULL_SCAN 1 << 2 | |
647 | +#define QPLAN_FULL_JOIN 1 << 3 | |
648 | +#define QPLAN_TMP_TABLE 1 << 4 | |
649 | +#define QPLAN_TMP_DISK 1 << 5 | |
650 | +#define QPLAN_FILESORT 1 << 6 | |
651 | +#define QPLAN_FILESORT_DISK 1 << 7 | |
652 | +enum enum_log_slow_filter { | |
653 | + SLOG_F_QC_NO, SLOG_F_FULL_SCAN, SLOG_F_FULL_JOIN, | |
654 | + SLOG_F_TMP_TABLE, SLOG_F_TMP_DISK, SLOG_F_FILESORT, | |
655 | + SLOG_F_FILESORT_DISK | |
656 | +}; | |
657 | enum enum_slave_exec_mode { SLAVE_EXEC_MODE_STRICT, | |
658 | SLAVE_EXEC_MODE_IDEMPOTENT, | |
659 | SLAVE_EXEC_MODE_LAST_BIT}; | |
a9ee80b9 | 660 | @@ -508,6 +535,17 @@ |
b4e1fa2c AM |
661 | |
662 | my_bool sysdate_is_now; | |
663 | ||
664 | + ulong log_slow_rate_limit; | |
665 | + ulonglong log_slow_filter; | |
666 | + ulonglong log_slow_verbosity; | |
667 | + | |
668 | + ulong innodb_io_reads; | |
669 | + ulonglong innodb_io_read; | |
670 | + ulong innodb_io_reads_wait_timer; | |
671 | + ulong innodb_lock_que_wait_timer; | |
672 | + ulong innodb_innodb_que_wait_timer; | |
673 | + ulong innodb_page_access; | |
674 | + | |
675 | double long_query_time_double; | |
676 | ||
677 | } SV; | |
a9ee80b9 | 678 | @@ -1140,6 +1178,14 @@ |
b4e1fa2c AM |
679 | uint in_sub_stmt; |
680 | bool enable_slow_log; | |
681 | bool last_insert_id_used; | |
682 | + | |
683 | + ulong innodb_io_reads; | |
684 | + ulonglong innodb_io_read; | |
685 | + ulong innodb_io_reads_wait_timer; | |
686 | + ulong innodb_lock_que_wait_timer; | |
687 | + ulong innodb_innodb_que_wait_timer; | |
688 | + ulong innodb_page_access; | |
689 | + | |
690 | SAVEPOINT *savepoints; | |
691 | enum enum_check_fields count_cuted_fields; | |
692 | }; | |
a9ee80b9 | 693 | @@ -1575,6 +1621,26 @@ |
b4e1fa2c AM |
694 | thr_lock_type update_lock_default; |
695 | Delayed_insert *di; | |
696 | ||
697 | + bool write_to_slow_log; | |
698 | + | |
699 | + ulonglong bytes_sent_old; | |
700 | + ulong tmp_tables_used; | |
701 | + ulong tmp_tables_disk_used; | |
702 | + ulonglong tmp_tables_size; | |
703 | + bool innodb_was_used; | |
704 | + ulonglong innodb_trx_id; | |
705 | + ulong innodb_io_reads; | |
706 | + ulonglong innodb_io_read; | |
707 | + ulong innodb_io_reads_wait_timer; | |
708 | + ulong innodb_lock_que_wait_timer; | |
709 | + ulong innodb_innodb_que_wait_timer; | |
710 | + ulong innodb_page_access; | |
711 | + | |
712 | + ulong query_plan_flags; | |
713 | + ulong query_plan_fsort_passes; | |
714 | + | |
715 | + uint last_errno; | |
716 | + | |
717 | /* <> 0 if we are inside of trigger or stored function. */ | |
718 | uint in_sub_stmt; | |
719 | ||
720 | diff -ruN a/sql/sql_connect.cc b/sql/sql_connect.cc | |
a9ee80b9 ER |
721 | --- a/sql/sql_connect.cc 2011-01-20 00:37:09.000000000 +0200 |
722 | +++ b/sql/sql_connect.cc 2011-02-21 22:57:48.848760112 +0200 | |
d8778560 | 723 | @@ -741,6 +741,15 @@ |
b4e1fa2c AM |
724 | |
725 | prepare_new_connection_state(thd); | |
726 | ||
727 | + /* | |
728 | + If rate limiting of slow log writes is enabled, decide whether to log this | |
729 | + new thread's queries or not. Uses extremely simple algorithm. :) | |
730 | + */ | |
731 | + thd->write_to_slow_log= FALSE; | |
732 | + if (thd->variables.log_slow_rate_limit <= 1 || | |
733 | + (thd->thread_id % thd->variables.log_slow_rate_limit) == 0) | |
734 | + thd->write_to_slow_log= TRUE; | |
735 | + | |
736 | while (!net->error && net->vio != 0 && | |
737 | !(thd->killed == THD::KILL_CONNECTION)) | |
738 | { | |
739 | diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc | |
a9ee80b9 ER |
740 | --- a/sql/sql_parse.cc 2011-02-21 22:57:24.451080031 +0200 |
741 | +++ b/sql/sql_parse.cc 2011-02-21 22:57:48.852759404 +0200 | |
d8778560 | 742 | @@ -1431,7 +1431,6 @@ |
b4e1fa2c AM |
743 | DBUG_RETURN(error); |
744 | } | |
745 | ||
746 | - | |
747 | void log_slow_statement(THD *thd) | |
748 | { | |
749 | DBUG_ENTER("log_slow_statement"); | |
d8778560 | 750 | @@ -1444,6 +1443,42 @@ |
b4e1fa2c AM |
751 | if (unlikely(thd->in_sub_stmt)) |
752 | DBUG_VOID_RETURN; // Don't set time for sub stmt | |
753 | ||
754 | + /* Follow the slow log filter configuration. */ | |
755 | + if (thd->variables.log_slow_filter != 0 && | |
756 | + (!(thd->variables.log_slow_filter & thd->query_plan_flags) || | |
757 | + ((thd->variables.log_slow_filter & SLOG_F_QC_NO) && | |
758 | + (thd->query_plan_flags & QPLAN_QC)))) | |
759 | + DBUG_VOID_RETURN; | |
760 | + | |
761 | + /* | |
762 | + Low long_query_time value most likely means user is debugging stuff and even | |
763 | + though some thread's queries are not supposed to be logged b/c of the rate | |
764 | + limit, if one of them takes long enough (>= 1 second) it will be sensible | |
765 | + to make an exception and write to slow log anyway. | |
766 | + */ | |
767 | + | |
768 | + ulonglong end_utime_of_query= thd->current_utime(); | |
769 | +#define USE_GLOBAL_UPDATE(variable_name,enum_value_name) \ | |
a9ee80b9 | 770 | + if (opt_slow_query_log_use_global_control & (ULL(1) << enum_value_name)) \ |
b4e1fa2c AM |
771 | + { \ |
772 | + thd->variables. variable_name= \ | |
773 | + global_system_variables. variable_name; \ | |
774 | + } | |
775 | + USE_GLOBAL_UPDATE(log_slow_filter,SLOG_UG_LOG_SLOW_FILTER); | |
776 | + USE_GLOBAL_UPDATE(log_slow_rate_limit,SLOG_UG_LOG_SLOW_RATE_LIMIT); | |
777 | + USE_GLOBAL_UPDATE(log_slow_verbosity,SLOG_UG_LOG_SLOW_VERBOSITY); | |
778 | + USE_GLOBAL_UPDATE(long_query_time,SLOG_UG_LONG_QUERY_TIME); | |
779 | + USE_GLOBAL_UPDATE(long_query_time_double,SLOG_UG_LONG_QUERY_TIME); | |
780 | + USE_GLOBAL_UPDATE(min_examined_row_limit,SLOG_UG_MIN_EXAMINED_ROW_LIMIT); | |
781 | +#undef USE_GLOBAL_UPDATE | |
782 | + | |
783 | + /* Do not log this thread's queries due to rate limiting. */ | |
784 | + if (thd->write_to_slow_log != TRUE | |
785 | + && (thd->variables.long_query_time >= 1000000 | |
786 | + || (ulong) (end_utime_of_query - thd->utime_after_lock) < 1000000)) | |
787 | + DBUG_VOID_RETURN; | |
788 | + | |
789 | + | |
790 | /* | |
791 | Do not log administrative statements unless the appropriate option is | |
792 | set. | |
d8778560 | 793 | @@ -1819,6 +1854,9 @@ |
b4e1fa2c AM |
794 | context.resolve_in_table_list_only(select_lex-> |
795 | table_list.first); | |
796 | ||
797 | + /* Reset the counter at all cases for the extended slow query log */ | |
798 | + thd->sent_row_count= 0; | |
799 | + | |
800 | /* | |
801 | Reset warning count for each query that uses tables | |
802 | A better approach would be to reset this for any commands | |
d8778560 | 803 | @@ -5258,6 +5296,21 @@ |
b4e1fa2c AM |
804 | thd->rand_used= 0; |
805 | thd->sent_row_count= thd->examined_row_count= 0; | |
806 | ||
807 | + thd->bytes_sent_old= thd->status_var.bytes_sent; | |
808 | + thd->tmp_tables_used= thd->tmp_tables_disk_used= 0; | |
809 | + thd->tmp_tables_size= 0; | |
810 | + thd->innodb_was_used= FALSE; | |
811 | + thd->innodb_trx_id= 0; | |
812 | + thd->innodb_io_reads= 0; | |
813 | + thd->innodb_io_read= 0; | |
814 | + thd->innodb_io_reads_wait_timer= 0; | |
815 | + thd->innodb_lock_que_wait_timer= 0; | |
816 | + thd->innodb_innodb_que_wait_timer= 0; | |
817 | + thd->innodb_page_access= 0; | |
818 | + thd->query_plan_flags= QPLAN_NONE; | |
819 | + thd->query_plan_fsort_passes= 0; | |
820 | + thd->last_errno= 0; | |
821 | + | |
822 | thd->reset_current_stmt_binlog_format_row(); | |
823 | thd->binlog_unsafe_warning_flags= 0; | |
824 | ||
825 | diff -ruN a/sql/sql_select.cc b/sql/sql_select.cc | |
a9ee80b9 ER |
826 | --- a/sql/sql_select.cc 2011-02-21 22:57:24.411087114 +0200 |
827 | +++ b/sql/sql_select.cc 2011-02-21 22:57:48.867756749 +0200 | |
d8778560 | 828 | @@ -6872,7 +6872,10 @@ |
b4e1fa2c AM |
829 | { |
830 | join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED; | |
831 | if (statistics) | |
832 | + { | |
833 | status_var_increment(join->thd->status_var.select_scan_count); | |
834 | + join->thd->query_plan_flags|= QPLAN_FULL_SCAN; | |
835 | + } | |
836 | } | |
837 | } | |
838 | else | |
d8778560 | 839 | @@ -6886,7 +6889,10 @@ |
b4e1fa2c AM |
840 | { |
841 | join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED; | |
842 | if (statistics) | |
843 | + { | |
844 | status_var_increment(join->thd->status_var.select_full_join_count); | |
845 | + join->thd->query_plan_flags|= QPLAN_FULL_JOIN; | |
846 | + } | |
847 | } | |
848 | } | |
849 | if (!table->no_keyread) | |
d8778560 | 850 | @@ -10217,6 +10223,7 @@ |
b4e1fa2c AM |
851 | (ulong) rows_limit,test(group))); |
852 | ||
853 | status_var_increment(thd->status_var.created_tmp_tables); | |
854 | + thd->query_plan_flags|= QPLAN_TMP_TABLE; | |
855 | ||
856 | if (use_temp_pool && !(test_flags & TEST_KEEP_TMP_TABLES)) | |
857 | temp_pool_slot = bitmap_lock_set_next(&temp_pool); | |
d8778560 | 858 | @@ -11115,6 +11122,7 @@ |
b4e1fa2c AM |
859 | goto err; |
860 | } | |
861 | status_var_increment(table->in_use->status_var.created_tmp_disk_tables); | |
862 | + table->in_use->query_plan_flags|= QPLAN_TMP_DISK; | |
863 | share->db_record_offset= 1; | |
864 | DBUG_RETURN(0); | |
865 | err: | |
d8778560 | 866 | @@ -11133,6 +11141,14 @@ |
b4e1fa2c AM |
867 | save_proc_info=thd->proc_info; |
868 | thd_proc_info(thd, "removing tmp table"); | |
869 | ||
870 | + thd->tmp_tables_used++; | |
871 | + if (entry->file) | |
872 | + { | |
873 | + thd->tmp_tables_size += entry->file->stats.data_file_length; | |
874 | + if (entry->file->ht->db_type != DB_TYPE_HEAP) | |
875 | + thd->tmp_tables_disk_used++; | |
876 | + } | |
877 | + | |
878 | // Release latches since this can take a long time | |
879 | ha_release_temporary_latches(thd); | |
880 | ||
881 | diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc | |
a9ee80b9 ER |
882 | --- a/sql/sql_show.cc 2011-02-21 22:57:24.456079146 +0200 |
883 | +++ b/sql/sql_show.cc 2011-02-21 22:57:48.873755686 +0200 | |
b4e1fa2c AM |
884 | @@ -1942,8 +1942,17 @@ |
885 | table->field[4]->store(command_name[tmp->command].str, | |
886 | command_name[tmp->command].length, cs); | |
887 | /* MYSQL_TIME */ | |
888 | - table->field[5]->store((longlong)(tmp->start_time ? | |
889 | - now - tmp->start_time : 0), FALSE); | |
890 | + longlong value_in_time_column= 0; | |
891 | + if(tmp->start_time) | |
892 | + { | |
893 | + value_in_time_column = (now - tmp->start_time); | |
894 | + if(value_in_time_column > now) | |
895 | + { | |
896 | + value_in_time_column= 0; | |
897 | + } | |
898 | + } | |
899 | + table->field[5]->store(value_in_time_column, FALSE); | |
900 | + | |
901 | /* STATE */ | |
902 | if ((val= thread_state_info(tmp))) | |
903 | { | |
904 | diff -ruN a/sql/sys_vars.cc b/sql/sys_vars.cc | |
a9ee80b9 ER |
905 | --- a/sql/sys_vars.cc 2011-02-21 22:57:24.435082865 +0200 |
906 | +++ b/sql/sys_vars.cc 2011-02-21 23:10:51.177188840 +0200 | |
907 | @@ -2852,6 +2852,117 @@ | |
b4e1fa2c AM |
908 | DEFAULT(FALSE), NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(0), |
909 | ON_UPDATE(fix_log_state)); | |
910 | ||
911 | +const char *log_slow_filter_name[]= { "qc_miss", "full_scan", "full_join", | |
912 | + "tmp_table", "tmp_table_on_disk", "filesort", "filesort_on_disk", 0}; | |
913 | +static Sys_var_set Sys_log_slow_filter( | |
914 | + "log_slow_filter", | |
915 | + "Log only the queries that followed certain execution plan. " | |
916 | + "Multiple flags allowed in a comma-separated string. " | |
917 | + "[qc_miss, full_scan, full_join, tmp_table, tmp_table_on_disk, " | |
918 | + "filesort, filesort_on_disk]", | |
919 | + SESSION_VAR(log_slow_filter), CMD_LINE(REQUIRED_ARG), | |
920 | + log_slow_filter_name, DEFAULT(0)); | |
921 | +static Sys_var_ulong sys_log_slow_rate_limit( | |
922 | + "log_slow_rate_limit","Rate limit statement writes to slow log to only those from every (1/log_slow_rate_limit) session.", | |
923 | + SESSION_VAR(log_slow_rate_limit), CMD_LINE(REQUIRED_ARG), | |
924 | + VALID_RANGE(1, ULONG_MAX), DEFAULT(1), BLOCK_SIZE(1)); | |
925 | +const char* log_slow_verbosity_name[] = { | |
926 | + "microtime", "query_plan", "innodb", | |
927 | + "profiling", "profling_use_getrusage", | |
928 | + "minimal", "standard", "full", 0 | |
929 | +}; | |
930 | +static ulonglong update_log_slow_verbosity_replace(ulonglong value, ulonglong what, ulonglong by) | |
931 | +{ | |
932 | + if((value & what) == what) | |
933 | + { | |
934 | + value = value & (~what); | |
935 | + value = value | by; | |
936 | + } | |
937 | + return value; | |
938 | +} | |
939 | +void update_log_slow_verbosity(ulonglong* value_ptr) | |
940 | +{ | |
941 | + ulonglong &value = *value_ptr; | |
942 | + ulonglong microtime= ULL(1) << SLOG_V_MICROTIME; | |
943 | + ulonglong query_plan= ULL(1) << SLOG_V_QUERY_PLAN; | |
944 | + ulonglong innodb= ULL(1) << SLOG_V_INNODB; | |
945 | + ulonglong minimal= ULL(1) << SLOG_V_MINIMAL; | |
946 | + ulonglong standard= ULL(1) << SLOG_V_STANDARD; | |
947 | + ulonglong full= ULL(1) << SLOG_V_FULL; | |
948 | + value= update_log_slow_verbosity_replace(value,minimal,microtime); | |
949 | + value= update_log_slow_verbosity_replace(value,standard,microtime | query_plan); | |
950 | + value= update_log_slow_verbosity_replace(value,full,microtime | query_plan | innodb); | |
951 | +} | |
952 | +static bool update_log_slow_verbosity_helper(sys_var */*self*/, THD *thd, | |
953 | + enum_var_type type) | |
954 | +{ | |
955 | + if(type == OPT_SESSION) | |
956 | + { | |
957 | + update_log_slow_verbosity(&(thd->variables.log_slow_verbosity)); | |
958 | + } | |
959 | + else | |
960 | + { | |
961 | + update_log_slow_verbosity(&(global_system_variables.log_slow_verbosity)); | |
962 | + } | |
963 | + return false; | |
964 | +} | |
a9ee80b9 | 965 | +void init_slow_query_log_use_global_control() |
b4e1fa2c AM |
966 | +{ |
967 | + update_log_slow_verbosity(&(global_system_variables.log_slow_verbosity)); | |
968 | +} | |
969 | +static Sys_var_set Sys_log_slow_verbosity( | |
970 | + "log_slow_verbosity", | |
971 | + "Choose how verbose the messages to your slow log will be. " | |
972 | + "Multiple flags allowed in a comma-separated string. [microtime, query_plan, innodb, profiling, profiling_use_getrusage]", | |
973 | + SESSION_VAR(log_slow_verbosity), CMD_LINE(REQUIRED_ARG), | |
974 | + log_slow_verbosity_name, DEFAULT(SLOG_V_MICROTIME), | |
975 | + NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(0), | |
976 | + ON_UPDATE(update_log_slow_verbosity_helper)); | |
977 | +static Sys_var_mybool Sys_log_slow_slave_statements( | |
978 | + "log_slow_slave_statements", | |
979 | + "Log queries replayed be the slave SQL thread", | |
980 | + GLOBAL_VAR(opt_log_slow_slave_statements), CMD_LINE(OPT_ARG), | |
981 | + DEFAULT(FALSE)); | |
982 | +static Sys_var_mybool Sys_log_slow_sp_statements( | |
983 | + "log_slow_sp_statements", | |
984 | + "Log slow statements executed by stored procedure to the slow log if it is open.", | |
985 | + GLOBAL_VAR(opt_log_slow_sp_statements), CMD_LINE(OPT_ARG), | |
986 | + DEFAULT(TRUE)); | |
a9ee80b9 ER |
987 | +static Sys_var_mybool Sys_slow_query_log_timestamp_always( |
988 | + "slow_query_log_timestamp_always", | |
b4e1fa2c | 989 | + "Timestamp is printed for all records of the slow log even if they are same time.", |
a9ee80b9 | 990 | + GLOBAL_VAR(opt_slow_query_log_timestamp_always), CMD_LINE(OPT_ARG), |
b4e1fa2c | 991 | + DEFAULT(FALSE)); |
a9ee80b9 ER |
992 | +const char *slow_query_log_use_global_control_name[]= { "log_slow_filter", "log_slow_rate_limit", "log_slow_verbosity", "long_query_time", "min_examined_row_limit", "all", 0}; |
993 | +static bool update_slow_query_log_use_global_control(sys_var */*self*/, THD */*thd*/, | |
b4e1fa2c AM |
994 | + enum_var_type /*type*/) |
995 | +{ | |
a9ee80b9 | 996 | + if(opt_slow_query_log_use_global_control & (ULL(1) << SLOG_UG_ALL)) |
b4e1fa2c | 997 | + { |
a9ee80b9 | 998 | + opt_slow_query_log_use_global_control= |
b4e1fa2c AM |
999 | + SLOG_UG_LOG_SLOW_FILTER | SLOG_UG_LOG_SLOW_RATE_LIMIT | SLOG_UG_LOG_SLOW_VERBOSITY | |
1000 | + SLOG_UG_LONG_QUERY_TIME | SLOG_UG_MIN_EXAMINED_ROW_LIMIT; | |
1001 | + } | |
1002 | + return false; | |
1003 | +} | |
1004 | +void init_log_slow_verbosity() | |
1005 | +{ | |
a9ee80b9 | 1006 | + update_slow_query_log_use_global_control(0,0,OPT_GLOBAL); |
b4e1fa2c | 1007 | +} |
a9ee80b9 ER |
1008 | +static Sys_var_set Sys_slow_query_log_use_global_control( |
1009 | + "slow_query_log_use_global_control", | |
b4e1fa2c | 1010 | + "Choose flags, wich always use the global variables. Multiple flags allowed in a comma-separated string. [none, log_slow_filter, log_slow_rate_limit, log_slow_verbosity, long_query_time, min_examined_row_limit, all]", |
a9ee80b9 ER |
1011 | + GLOBAL_VAR(opt_slow_query_log_use_global_control), CMD_LINE(REQUIRED_ARG), |
1012 | + slow_query_log_use_global_control_name, DEFAULT(0), | |
b4e1fa2c | 1013 | + NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(0), |
a9ee80b9 ER |
1014 | + ON_UPDATE(update_slow_query_log_use_global_control)); |
1015 | +const char *slow_query_log_timestamp_precision_name[]= { "second", "microsecond", 0 }; | |
1016 | +static Sys_var_enum Sys_slow_query_log_timestamp_precision( | |
1017 | + "slow_query_log_timestamp_precision", | |
1018 | + "Log slow statements executed by stored procedure to the slow log if it is open. [second, microsecond]", | |
1019 | + GLOBAL_VAR(opt_slow_query_log_timestamp_precision), CMD_LINE(REQUIRED_ARG), | |
1020 | + slow_query_log_timestamp_precision_name, DEFAULT(SLOG_SECOND)); | |
b4e1fa2c AM |
1021 | + |
1022 | /* Synonym of "slow_query_log" for consistency with SHOW VARIABLES output */ | |
1023 | static Sys_var_mybool Sys_log_slow( | |
1024 | "log_slow_queries", | |
1025 | diff -ruN a/sql/sql_profile.cc b/sql/sql_profile.cc | |
a9ee80b9 ER |
1026 | --- a/sql/sql_profile.cc 2011-01-20 00:37:09.000000000 +0200 |
1027 | +++ b/sql/sql_profile.cc 2011-02-21 22:57:48.877754978 +0200 | |
b4e1fa2c AM |
1028 | @@ -243,7 +243,8 @@ |
1029 | { | |
1030 | time_usecs= (double) my_getsystime() / 10.0; /* 1 sec was 1e7, now is 1e6 */ | |
1031 | #ifdef HAVE_GETRUSAGE | |
1032 | - getrusage(RUSAGE_SELF, &rusage); | |
1033 | + if ((profile->get_profiling())->enabled_getrusage()) | |
1034 | + getrusage(RUSAGE_SELF, &rusage); | |
1035 | #elif defined(_WIN32) | |
1036 | FILETIME ftDummy; | |
1037 | // NOTE: Get{Process|Thread}Times has a granularity of the clock interval, | |
1038 | @@ -251,6 +252,19 @@ | |
1039 | // measurable by this function. | |
1040 | GetProcessTimes(GetCurrentProcess(), &ftDummy, &ftDummy, &ftKernel, &ftUser); | |
1041 | #endif | |
1042 | + | |
1043 | +#ifdef HAVE_CLOCK_GETTIME | |
1044 | + struct timespec tp; | |
1045 | + | |
1046 | + if (!(clock_gettime(CLOCK_THREAD_CPUTIME_ID, &tp))) | |
1047 | + { | |
1048 | + cpu_time_usecs= tp.tv_sec*1000000000.0 + tp.tv_nsec; | |
1049 | + } | |
1050 | + else | |
1051 | +#endif | |
1052 | + { | |
1053 | + cpu_time_usecs= 0; | |
1054 | + } | |
1055 | } | |
1056 | ||
1057 | ||
1058 | @@ -366,7 +380,8 @@ | |
1059 | finish_current_query(); | |
1060 | } | |
1061 | ||
1062 | - enabled= ((thd->variables.option_bits & OPTION_PROFILING) != 0); | |
1063 | + enabled= ((thd->variables.option_bits & OPTION_PROFILING) != 0) || | |
1064 | + ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_PROFILING)) != 0); | |
1065 | ||
1066 | if (! enabled) DBUG_VOID_RETURN; | |
1067 | ||
1068 | @@ -404,7 +419,8 @@ | |
1069 | status_change("ending", NULL, NULL, 0); | |
1070 | ||
1071 | if ((enabled) && /* ON at start? */ | |
1072 | - ((thd->variables.option_bits & OPTION_PROFILING) != 0) && /* and ON at end? */ | |
1073 | + (((thd->variables.option_bits & OPTION_PROFILING) != 0) || | |
1074 | + ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_PROFILING)) != 0)) && /* and ON at end? */ | |
1075 | (current->query_source != NULL) && | |
1076 | (! current->entries.is_empty())) | |
1077 | { | |
1078 | @@ -505,6 +521,118 @@ | |
1079 | DBUG_VOID_RETURN; | |
1080 | } | |
1081 | ||
1082 | +bool PROFILING::enabled_getrusage() | |
1083 | +{ | |
1084 | + return ((thd->variables.log_slow_verbosity & (ULL(1) << SLOG_V_PROFILING_USE_GETRUSAGE)) != 0); | |
1085 | +} | |
1086 | + | |
1087 | +/** | |
1088 | + For a given profile entry specified by a name and 2 time measurements, | |
1089 | + print its normalized name (i.e. with all spaces replaced with underscores) | |
1090 | + along with its wall clock and CPU time. | |
1091 | +*/ | |
1092 | + | |
1093 | +static void my_b_print_status(IO_CACHE *log_file, const char *status, | |
1094 | + PROF_MEASUREMENT *start, PROF_MEASUREMENT *stop) | |
1095 | +{ | |
1096 | + DBUG_ENTER("my_b_print_status"); | |
1097 | + DBUG_ASSERT(log_file != NULL && status != NULL); | |
1098 | + char query_time_buff[22+7]; | |
1099 | + const char *tmp; | |
1100 | + | |
1101 | + my_b_printf(log_file, "Profile_"); | |
1102 | + for (tmp= status; *tmp; tmp++) | |
1103 | + my_b_write_byte(log_file, *tmp == ' ' ? '_' : *tmp); | |
1104 | + | |
1105 | + snprintf(query_time_buff, sizeof(query_time_buff), "%.6f", | |
1106 | + (stop->time_usecs - start->time_usecs) / (1000.0 * 1000)); | |
1107 | + my_b_printf(log_file, ": %s ", query_time_buff); | |
1108 | + | |
1109 | + my_b_printf(log_file, "Profile_"); | |
1110 | + for (tmp= status; *tmp; tmp++) | |
1111 | + my_b_write_byte(log_file, *tmp == ' ' ? '_' : *tmp); | |
1112 | + my_b_printf(log_file, "_cpu: "); | |
1113 | + | |
1114 | + snprintf(query_time_buff, sizeof(query_time_buff), "%.6f", | |
1115 | + (stop->cpu_time_usecs - start->cpu_time_usecs) / | |
1116 | + (1000.0 * 1000 * 1000)); | |
1117 | + my_b_printf(log_file, "%s ", query_time_buff); | |
1118 | + | |
1119 | + DBUG_VOID_RETURN; | |
1120 | +} | |
1121 | + | |
1122 | +/** | |
1123 | + Print output for current query to file | |
1124 | +*/ | |
1125 | + | |
1126 | +int PROFILING::print_current(IO_CACHE *log_file) | |
1127 | +{ | |
1128 | + DBUG_ENTER("PROFILING::print_current"); | |
1129 | + ulonglong row_number= 0; | |
1130 | + | |
1131 | + QUERY_PROFILE *query; | |
1132 | + /* Get current query */ | |
1133 | + if (current == NULL) | |
1134 | + { | |
1135 | + DBUG_RETURN(0); | |
1136 | + } | |
1137 | + | |
1138 | + query= current; | |
1139 | + | |
1140 | + my_b_printf(log_file, "# "); | |
1141 | + | |
1142 | + void *entry_iterator; | |
1143 | + PROF_MEASUREMENT *entry= NULL, *previous= NULL, *first= NULL; | |
1144 | + /* ...and for each query, go through all its state-change steps. */ | |
1145 | + for (entry_iterator= query->entries.new_iterator(); | |
1146 | + entry_iterator != NULL; | |
1147 | + entry_iterator= query->entries.iterator_next(entry_iterator), | |
1148 | + previous=entry, row_number++) | |
1149 | + { | |
1150 | + entry= query->entries.iterator_value(entry_iterator); | |
1151 | + | |
1152 | + /* Skip the first. We count spans of fence, not fence-posts. */ | |
1153 | + if (previous == NULL) {first= entry; continue;} | |
1154 | + | |
1155 | + if (thd->lex->sql_command == SQLCOM_SHOW_PROFILE) | |
1156 | + { | |
1157 | + /* | |
1158 | + We got here via a SHOW command. That means that we stored | |
1159 | + information about the query we wish to show and that isn't | |
1160 | + in a WHERE clause at a higher level to filter out rows we | |
1161 | + wish to exclude. | |
1162 | + | |
1163 | + Because that functionality isn't available in the server yet, | |
1164 | + we must filter here, at the wrong level. Once one can con- | |
1165 | + struct where and having conditions at the SQL layer, then this | |
1166 | + condition should be ripped out. | |
1167 | + */ | |
1168 | + if (thd->lex->profile_query_id == 0) /* 0 == show final query */ | |
1169 | + { | |
1170 | + if (query != last) | |
1171 | + continue; | |
1172 | + } | |
1173 | + else | |
1174 | + { | |
1175 | + if (thd->lex->profile_query_id != query->profiling_query_id) | |
1176 | + continue; | |
1177 | + } | |
1178 | + } | |
1179 | + | |
1180 | + my_b_print_status(log_file, previous->status, previous, entry); | |
1181 | + } | |
1182 | + | |
1183 | + my_b_write_byte(log_file, '\n'); | |
1184 | + if ((entry != NULL) && (first != NULL)) | |
1185 | + { | |
1186 | + my_b_printf(log_file, "# "); | |
1187 | + my_b_print_status(log_file, "total", first, entry); | |
1188 | + my_b_write_byte(log_file, '\n'); | |
1189 | + } | |
1190 | + | |
1191 | + DBUG_RETURN(0); | |
1192 | +} | |
1193 | + | |
1194 | /** | |
1195 | Fill the information schema table, "query_profile", as defined in show.cc . | |
1196 | There are two ways to get to this function: Selecting from the information | |
1197 | diff -ruN a/sql/sql_profile.h b/sql/sql_profile.h | |
a9ee80b9 ER |
1198 | --- a/sql/sql_profile.h 2011-01-20 00:37:09.000000000 +0200 |
1199 | +++ b/sql/sql_profile.h 2011-02-21 22:57:48.878754801 +0200 | |
b4e1fa2c AM |
1200 | @@ -164,11 +164,15 @@ |
1201 | */ | |
1202 | class PROF_MEASUREMENT | |
1203 | { | |
1204 | -private: | |
1205 | - friend class QUERY_PROFILE; | |
1206 | - friend class PROFILING; | |
1207 | - | |
1208 | QUERY_PROFILE *profile; | |
1209 | + | |
1210 | + char *allocated_status_memory; | |
1211 | + | |
1212 | + void set_label(const char *status_arg, const char *function_arg, | |
1213 | + const char *file_arg, unsigned int line_arg); | |
1214 | + void clean_up(); | |
1215 | + | |
1216 | +public: | |
1217 | char *status; | |
1218 | #ifdef HAVE_GETRUSAGE | |
1219 | struct rusage rusage; | |
1220 | @@ -181,12 +185,7 @@ | |
1221 | unsigned int line; | |
1222 | ||
1223 | double time_usecs; | |
1224 | - char *allocated_status_memory; | |
1225 | - | |
1226 | - void set_label(const char *status_arg, const char *function_arg, | |
1227 | - const char *file_arg, unsigned int line_arg); | |
1228 | - void clean_up(); | |
1229 | - | |
1230 | + double cpu_time_usecs; | |
1231 | PROF_MEASUREMENT(); | |
1232 | PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char *status_arg); | |
1233 | PROF_MEASUREMENT(QUERY_PROFILE *profile_arg, const char *status_arg, | |
1234 | @@ -231,6 +230,11 @@ | |
1235 | ||
1236 | /* Show this profile. This is called by PROFILING. */ | |
1237 | bool show(uint options); | |
1238 | + | |
1239 | +public: | |
1240 | + | |
1241 | + inline PROFILING * get_profiling() { return profiling; }; | |
1242 | + | |
1243 | }; | |
1244 | ||
1245 | ||
1246 | @@ -276,9 +280,11 @@ | |
1247 | ||
1248 | /* SHOW PROFILES */ | |
1249 | bool show_profiles(); | |
1250 | + bool enabled_getrusage(); | |
1251 | ||
1252 | /* ... from INFORMATION_SCHEMA.PROFILING ... */ | |
1253 | int fill_statistics_info(THD *thd, TABLE_LIST *tables, Item *cond); | |
1254 | + int print_current(IO_CACHE *log_file); | |
1255 | }; | |
1256 | ||
1257 | # endif /* HAVE_PROFILING */ |