]> git.pld-linux.org Git - packages/mysql.git/blame - mysql-microslow_innodb.patch
projects / packages / mysql.git / blame
? search:
summary | shortlog | log | commit | commitdiff | tree
blob | blame (incremental) | history | HEAD
automake fix
[packages/mysql.git] / mysql-microslow_innodb.patch
CommitLineData
36400f81 1diff -ruN a/include/my_getopt.h b/include/my_getopt.h
89b96684
ER		 2--- a/include/my_getopt.h Tue Jul 28 23:39:12 2009 -0700
3+++ b/include/my_getopt.h Tue Jul 28 23:42:44 2009 -0700
6f73e838
ER		 4@@ -28,7 +28,8 @@
5 #define GET_ULL 8
6 #define GET_STR 9
7 #define GET_STR_ALLOC 10
8-#define GET_DISABLED 11
45532174 9+#define GET_MICROTIME 11
6f73e838
ER		 10+#define GET_DISABLED 12
11
12 #define GET_ASK_ADDR 128
13 #define GET_TYPE_MASK 127
36400f81 14diff -ruN a/include/my_time.h b/include/my_time.h
89b96684
ER		 15--- a/include/my_time.h Tue Jul 28 23:39:12 2009 -0700
16+++ b/include/my_time.h Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 17@@ -140,7 +140,7 @@
18 int my_date_to_str(const MYSQL_TIME *l_time, char *to);
19 int my_datetime_to_str(const MYSQL_TIME *l_time, char *to);
20 int my_TIME_to_str(const MYSQL_TIME *l_time, char *to);
21-
22+ulonglong my_timer(ulonglong *ltime, ulonglong frequency);
23 C_MODE_END
24
25 #endif /* _my_time_h_ */
36400f81 26diff -ruN a/innobase/buf/buf0buf.c b/innobase/buf/buf0buf.c
89b96684
ER		 27--- a/innobase/buf/buf0buf.c Tue Jul 28 23:39:12 2009 -0700
28+++ b/innobase/buf/buf0buf.c Tue Jul 28 23:42:44 2009 -0700
45532174 29@@ -37,6 +37,10 @@
833f2639
ER		 30 #include "log0log.h"
31 #include "trx0undo.h"
32 #include "srv0srv.h"
45532174 33+#include "trx0trx.h"
6f73e838
ER		 34+
35+/* prototypes for new functions added to ha_innodb.cc */
36+trx_t* innobase_get_trx();
833f2639
ER		 37
38 /*
39 IMPLEMENTATION OF THE BUFFER POOL
45532174 40@@ -1086,6 +1090,36 @@
833f2639
ER		 41 return(block);
42 }
43
44+inline void _increment_page_get_statistics(buf_block_t* block, trx_t* trx)
45+{
46+ ulint block_hash;
47+ ulint block_hash_byte;
48+ byte block_hash_offset;
49+
50+ ut_ad(block);
51+
6f73e838 52+ if (!srv_slow_log || !trx || !trx->take_stats)
833f2639
ER		 53+ return;
54+
6f73e838
ER		 55+ if (!trx->distinct_page_access_hash) {
56+ trx->distinct_page_access_hash = mem_alloc(DPAH_SIZE);
57+ memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
58+ }
59+
833f2639
ER		 60+ block_hash = ut_hash_ulint((block->space << 20) + block->space +
61+ block->offset, DPAH_SIZE << 3);
62+ block_hash_byte = block_hash >> 3;
63+ block_hash_offset = (byte) block_hash & 0x07;
64+ if (block_hash_byte < 0 || block_hash_byte >= DPAH_SIZE)
65+ fprintf(stderr, "!!! block_hash_byte = %lu block_hash_offset = %lu !!!\n", block_hash_byte, block_hash_offset);
66+ if (block_hash_offset < 0 || block_hash_offset > 7)
67+ fprintf(stderr, "!!! block_hash_byte = %lu block_hash_offset = %lu !!!\n", block_hash_byte, block_hash_offset);
68+ if ((trx->distinct_page_access_hash[block_hash_byte] & ((byte) 0x01 << block_hash_offset)) == 0)
69+ trx->distinct_page_access++;
70+ trx->distinct_page_access_hash[block_hash_byte] |= (byte) 0x01 << block_hash_offset;
71+ return;
72+}
73+
74 /************************************************************************
75 This is the general function used to get access to a database page. */
76
45532174 77@@ -1108,6 +1142,11 @@
833f2639
ER		 78 ulint fix_type;
79 ibool success;
80 ibool must_read;
6f73e838 81+ trx_t* trx = NULL;
833f2639
ER		 82+ ulint sec;
83+ ulint ms;
84+ ib_longlong start_time;
85+ ib_longlong finish_time;
86
87 ut_ad(mtr);
88 ut_ad((rw_latch == RW_S_LATCH)
45532174 89@@ -1119,6 +1158,9 @@
833f2639
ER		 90 #ifndef UNIV_LOG_DEBUG
91 ut_ad(!ibuf_inside() || ibuf_page(space, offset));
92 #endif
6f73e838
ER		 93+ if (srv_slow_log) {
94+ trx = innobase_get_trx();
95+ }
833f2639
ER		 96 buf_pool->n_page_gets++;
97 loop:
98 block = NULL;
45532174 99@@ -1148,7 +1190,7 @@
833f2639
ER		 100 return(NULL);
101 }
102
103- buf_read_page(space, offset);
104+ buf_read_page(space, offset, trx);
105
106 #ifdef UNIV_DEBUG
107 buf_dbg_counter++;
45532174 108@@ -1261,6 +1303,11 @@
833f2639
ER		 109 /* Let us wait until the read operation
110 completes */
111
6f73e838 112+ if (srv_slow_log && trx && trx->take_stats)
833f2639
ER		 113+ {
114+ ut_usectime(&sec, &ms);
115+ start_time = (ib_longlong)sec * 1000000 + ms;
116+ }
117 for (;;) {
118 mutex_enter(&block->mutex);
119
45532174 120@@ -1276,6 +1323,12 @@
833f2639
ER		 121 break;
122 }
45532174 123 }
6f73e838 124+ if (srv_slow_log && trx && trx->take_stats && start_time)
833f2639
ER		 125+ {
126+ ut_usectime(&sec, &ms);
127+ finish_time = (ib_longlong)sec * 1000000 + ms;
128+ trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
45532174 129+ }
833f2639
ER		 130 }
131
45532174
ER		 132 fix_type = MTR_MEMO_BUF_FIX;
133@@ -1296,12 +1349,17 @@
833f2639
ER		 134 /* In the case of a first access, try to apply linear
135 read-ahead */
136
137- buf_read_ahead_linear(space, offset);
138+ buf_read_ahead_linear(space, offset, trx);
139 }
140
141 #ifdef UNIV_IBUF_DEBUG
142 ut_a(ibuf_count_get(block->space, block->offset) == 0);
143 #endif
144+
6f73e838
ER		 145+ if (srv_slow_log) {
146+ _increment_page_get_statistics(block, trx);
147+ }
833f2639
ER		 148+
149 return(block->frame);
150 }
151
45532174 152@@ -1326,6 +1384,7 @@
833f2639
ER		 153 ibool accessed;
154 ibool success;
155 ulint fix_type;
6f73e838 156+ trx_t* trx = NULL;
833f2639
ER		 157
158 ut_ad(mtr && block);
159 ut_ad((rw_latch == RW_S_LATCH) || (rw_latch == RW_X_LATCH));
45532174 160@@ -1440,7 +1499,7 @@
833f2639
ER		 161 read-ahead */
162
163 buf_read_ahead_linear(buf_frame_get_space_id(guess),
164- buf_frame_get_page_no(guess));
165+ buf_frame_get_page_no(guess), trx);
166 }
167
168 #ifdef UNIV_IBUF_DEBUG
45532174 169@@ -1448,6 +1507,11 @@
833f2639
ER		 170 #endif
171 buf_pool->n_page_gets++;
45532174 172
6f73e838
ER		 173+ if (srv_slow_log) {
174+ trx = innobase_get_trx();
175+ _increment_page_get_statistics(block, trx);
176+ }
45532174 177+
833f2639
ER		 178 return(TRUE);
179 }
45532174
ER		 180
181@@ -1470,6 +1534,7 @@
833f2639
ER		 182 buf_block_t* block;
183 ibool success;
184 ulint fix_type;
6f73e838 185+ trx_t* trx = NULL;
833f2639
ER		 186
187 ut_ad(mtr);
188 ut_ad((rw_latch == RW_S_LATCH) || (rw_latch == RW_X_LATCH));
45532174 189@@ -1559,6 +1624,11 @@
833f2639
ER		 190 #endif
191 buf_pool->n_page_gets++;
45532174 192
6f73e838
ER		 193+ if (srv_slow_log) {
194+ trx = innobase_get_trx();
195+ _increment_page_get_statistics(block, trx);
196+ }
45532174 197+
833f2639
ER		 198 return(TRUE);
199 }
45532174 200
36400f81 201diff -ruN a/innobase/buf/buf0rea.c b/innobase/buf/buf0rea.c
89b96684
ER		 202--- a/innobase/buf/buf0rea.c Tue Jul 28 23:39:12 2009 -0700
203+++ b/innobase/buf/buf0rea.c Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 204@@ -70,7 +70,8 @@
205 treat the tablespace as dropped; this is a timestamp we
206 use to stop dangling page reads from a tablespace
207 which we have DISCARDed + IMPORTed back */
208- ulint offset) /* in: page number */
209+ ulint offset, /* in: page number */
210+ trx_t* trx)
211 {
212 buf_block_t* block;
213 ulint wake_later;
214@@ -140,10 +141,10 @@
215
216 ut_a(block->state == BUF_BLOCK_FILE_PAGE);
217
218- *err = fil_io(OS_FILE_READ | wake_later,
219+ *err = _fil_io(OS_FILE_READ | wake_later,
220 sync, space,
221 offset, 0, UNIV_PAGE_SIZE,
222- (void*)block->frame, (void*)block);
223+ (void*)block->frame, (void*)block, trx);
224 ut_a(*err == DB_SUCCESS);
225
226 if (sync) {
227@@ -174,8 +175,9 @@
228 the page at the given page number does not get
229 read even if we return a value > 0! */
230 ulint space, /* in: space id */
231- ulint offset) /* in: page number of a page which the current thread
232+ ulint offset, /* in: page number of a page which the current thread
233 wants to access */
234+ trx_t* trx)
235 {
236 ib_longlong tablespace_version;
237 buf_block_t* block;
238@@ -270,7 +272,7 @@
239 if (!ibuf_bitmap_page(i)) {
240 count += buf_read_page_low(&err, FALSE, ibuf_mode
241 | OS_AIO_SIMULATED_WAKE_LATER,
242- space, tablespace_version, i);
243+ space, tablespace_version, i, trx);
244 if (err == DB_TABLESPACE_DELETED) {
245 ut_print_timestamp(stderr);
246 fprintf(stderr,
247@@ -314,7 +316,8 @@
248 /* out: number of page read requests issued: this can
249 be > 1 if read-ahead occurred */
250 ulint space, /* in: space id */
251- ulint offset) /* in: page number */
252+ ulint offset, /* in: page number */
253+ trx_t* trx)
254 {
255 ib_longlong tablespace_version;
256 ulint count;
257@@ -323,13 +326,13 @@
258
259 tablespace_version = fil_space_get_version(space);
260
261- count = buf_read_ahead_random(space, offset);
262+ count = buf_read_ahead_random(space, offset, trx);
263
264 /* We do the i/o in the synchronous aio mode to save thread
265 switches: hence TRUE */
266
267 count2 = buf_read_page_low(&err, TRUE, BUF_READ_ANY_PAGE, space,
268- tablespace_version, offset);
269+ tablespace_version, offset, trx);
270 srv_buf_pool_reads+= count2;
271 if (err == DB_TABLESPACE_DELETED) {
272 ut_print_timestamp(stderr);
273@@ -374,8 +377,9 @@
274 /*==================*/
275 /* out: number of page read requests issued */
276 ulint space, /* in: space id */
277- ulint offset) /* in: page number of a page; NOTE: the current thread
278+ ulint offset, /* in: page number of a page; NOTE: the current thread
279 must want access to this page (see NOTE 3 above) */
280+ trx_t* trx)
281 {
282 ib_longlong tablespace_version;
283 buf_block_t* block;
284@@ -556,7 +560,7 @@
285 if (!ibuf_bitmap_page(i)) {
286 count += buf_read_page_low(&err, FALSE, ibuf_mode
287 | OS_AIO_SIMULATED_WAKE_LATER,
288- space, tablespace_version, i);
289+ space, tablespace_version, i, trx);
290 if (err == DB_TABLESPACE_DELETED) {
291 ut_print_timestamp(stderr);
292 fprintf(stderr,
293@@ -625,10 +629,10 @@
294 for (i = 0; i < n_stored; i++) {
295 if ((i + 1 == n_stored) && sync) {
296 buf_read_page_low(&err, TRUE, BUF_READ_ANY_PAGE,
297- space_ids[i], space_versions[i], page_nos[i]);
298+ space_ids[i], space_versions[i], page_nos[i], NULL);
299 } else {
300 buf_read_page_low(&err, FALSE, BUF_READ_ANY_PAGE,
301- space_ids[i], space_versions[i], page_nos[i]);
302+ space_ids[i], space_versions[i], page_nos[i], NULL);
303 }
304
305 if (err == DB_TABLESPACE_DELETED) {
306@@ -704,11 +708,11 @@
307
308 if ((i + 1 == n_stored) && sync) {
309 buf_read_page_low(&err, TRUE, BUF_READ_ANY_PAGE, space,
310- tablespace_version, page_nos[i]);
311+ tablespace_version, page_nos[i], NULL);
312 } else {
313 buf_read_page_low(&err, FALSE, BUF_READ_ANY_PAGE
314 | OS_AIO_SIMULATED_WAKE_LATER,
315- space, tablespace_version, page_nos[i]);
316+ space, tablespace_version, page_nos[i], NULL);
317 }
318 }
319
36400f81 320diff -ruN a/innobase/fil/fil0fil.c b/innobase/fil/fil0fil.c
89b96684
ER		 321--- a/innobase/fil/fil0fil.c Tue Jul 28 23:39:12 2009 -0700
322+++ b/innobase/fil/fil0fil.c Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 323@@ -3527,7 +3527,7 @@
324 node->name, node->handle, buf,
325 offset_low, offset_high,
326 UNIV_PAGE_SIZE * n_pages,
327- NULL, NULL);
328+ NULL, NULL, NULL);
329 #endif
330 if (success) {
331 node->size += n_pages;
332@@ -3851,7 +3851,7 @@
333 Reads or writes data. This operation is asynchronous (aio). */
334
335 ulint
336-fil_io(
337+_fil_io(
338 /*===*/
339 /* out: DB_SUCCESS, or DB_TABLESPACE_DELETED
340 if we are trying to do i/o on a tablespace
341@@ -3877,8 +3877,9 @@
342 void* buf, /* in/out: buffer where to store read data
343 or from where to write; in aio this must be
344 appropriately aligned */
345- void* message) /* in: message for aio handler if non-sync
346+ void* message, /* in: message for aio handler if non-sync
347 aio used, else ignored */
348+ trx_t* trx)
349 {
350 fil_system_t* system = fil_system;
351 ulint mode;
352@@ -4018,7 +4019,7 @@
353 #else
354 /* Queue the aio request */
355 ret = os_aio(type, mode | wake_later, node->name, node->handle, buf,
356- offset_low, offset_high, len, node, message);
357+ offset_low, offset_high, len, node, message, trx);
358 #endif
359 ut_a(ret);
360
36400f81 361diff -ruN a/innobase/include/buf0rea.h b/innobase/include/buf0rea.h
89b96684
ER		 362--- a/innobase/include/buf0rea.h Tue Jul 28 23:39:12 2009 -0700
363+++ b/innobase/include/buf0rea.h Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 364@@ -10,6 +10,7 @@
365 #define buf0rea_h
366
367 #include "univ.i"
368+#include "trx0types.h"
369 #include "buf0types.h"
370
371 /************************************************************************
372@@ -25,7 +26,8 @@
373 /* out: number of page read requests issued: this can
374 be > 1 if read-ahead occurred */
375 ulint space, /* in: space id */
376- ulint offset);/* in: page number */
377+ ulint offset, /* in: page number */
378+ trx_t* trx);
379 /************************************************************************
380 Applies linear read-ahead if in the buf_pool the page is a border page of
381 a linear read-ahead area and all the pages in the area have been accessed.
382@@ -55,8 +57,9 @@
383 /*==================*/
384 /* out: number of page read requests issued */
385 ulint space, /* in: space id */
386- ulint offset);/* in: page number of a page; NOTE: the current thread
387+ ulint offset, /* in: page number of a page; NOTE: the current thread
388 must want access to this page (see NOTE 3 above) */
389+ trx_t* trx);
390 /************************************************************************
391 Issues read requests for pages which the ibuf module wants to read in, in
392 order to contract the insert buffer tree. Technically, this function is like
36400f81 393diff -ruN a/innobase/include/fil0fil.h b/innobase/include/fil0fil.h
89b96684
ER		 394--- a/innobase/include/fil0fil.h Tue Jul 28 23:39:12 2009 -0700
395+++ b/innobase/include/fil0fil.h Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 396@@ -534,8 +534,11 @@
397 /************************************************************************
398 Reads or writes data. This operation is asynchronous (aio). */
399
400+#define fil_io(type, sync, space_id, block_offset, byte_offset, len, buf, message) \
401+ _fil_io(type, sync, space_id, block_offset, byte_offset, len, buf, message, NULL)
402+
403 ulint
404-fil_io(
405+_fil_io(
406 /*===*/
407 /* out: DB_SUCCESS, or DB_TABLESPACE_DELETED
408 if we are trying to do i/o on a tablespace
409@@ -561,8 +564,9 @@
410 void* buf, /* in/out: buffer where to store read data
411 or from where to write; in aio this must be
412 appropriately aligned */
413- void* message); /* in: message for aio handler if non-sync
414+ void* message, /* in: message for aio handler if non-sync
415 aio used, else ignored */
416+ trx_t* trx);
417 /************************************************************************
418 Reads data from a space to a buffer. Remember that the possible incomplete
419 blocks at the end of file are ignored: they are not taken into account when
36400f81 420diff -ruN a/innobase/include/os0file.h b/innobase/include/os0file.h
89b96684
ER		 421--- a/innobase/include/os0file.h Tue Jul 28 23:39:12 2009 -0700
422+++ b/innobase/include/os0file.h Tue Jul 28 23:42:44 2009 -0700
45532174 423@@ -11,6 +11,8 @@
833f2639
ER		 424
425 #include "univ.i"
833f2639 426
45532174
ER		 427+#include "trx0types.h"
428+
833f2639
ER		 429 #ifndef __WIN__
430 #include <dirent.h>
45532174 431 #include <sys/stat.h>
833f2639
ER		 432@@ -421,8 +423,11 @@
433 /***********************************************************************
434 Requests a synchronous read operation. */
435
436+#define os_file_read(file, buf, offset, offset_high, n) \
437+ _os_file_read(file, buf, offset, offset_high, n, NULL)
438+
439 ibool
440-os_file_read(
441+_os_file_read(
442 /*=========*/
443 /* out: TRUE if request was
444 successful, FALSE if fail */
445@@ -432,7 +437,8 @@
446 offset where to read */
447 ulint offset_high,/* in: most significant 32 bits of
448 offset */
449- ulint n); /* in: number of bytes to read */
450+ ulint n, /* in: number of bytes to read */
451+ trx_t* trx);
452 /***********************************************************************
453 Rewind file to its start, read at most size - 1 bytes from it to str, and
454 NUL-terminate str. All errors are silently ignored. This function is
455@@ -584,7 +590,8 @@
456 can be used to identify a completed aio
457 operation); if mode is OS_AIO_SYNC, these
458 are ignored */
459- void* message2);
460+ void* message2,
461+ trx_t* trx);
462 /****************************************************************************
463 Wakes up all async i/o threads so that they know to exit themselves in
464 shutdown. */
36400f81 465diff -ruN a/innobase/include/srv0srv.h b/innobase/include/srv0srv.h
89b96684
ER		 466--- a/innobase/include/srv0srv.h Tue Jul 28 23:39:12 2009 -0700
467+++ b/innobase/include/srv0srv.h Tue Jul 28 23:42:44 2009 -0700
45532174 468@@ -27,6 +27,8 @@
6f73e838
ER		 469 #define SRV_AUTO_EXTEND_INCREMENT \
470 (srv_auto_extend_increment * ((1024 * 1024) / UNIV_PAGE_SIZE))
6f73e838 471
45532174
ER		 472+extern ibool srv_slow_log;
473+
6f73e838
ER		 474 /* This is set to TRUE if the MySQL user has set it in MySQL */
475 extern ibool srv_lower_case_table_names;
45532174 476
36400f81 477diff -ruN a/innobase/include/trx0trx.h b/innobase/include/trx0trx.h
89b96684
ER		 478--- a/innobase/include/trx0trx.h Tue Jul 28 23:39:12 2009 -0700
479+++ b/innobase/include/trx0trx.h Tue Jul 28 23:42:44 2009 -0700
36400f81 480@@ -666,6 +666,17 @@
833f2639
ER		 481 /*------------------------------*/
482 char detailed_error[256]; /* detailed error message for last
483 error, or empty. */
484+ /*------------------------------*/
833f2639
ER		 485+ ulint io_reads;
486+ ib_longlong io_read;
487+ ulint io_reads_wait_timer;
488+ ib_longlong lock_que_wait_ustarted;
489+ ulint lock_que_wait_timer;
490+ ulint innodb_que_wait_timer;
491+ ulint distinct_page_access;
492+#define DPAH_SIZE 8192
493+ byte* distinct_page_access_hash;
6f73e838 494+ ibool take_stats;
833f2639
ER		 495 };
496
497 #define TRX_MAX_N_THREADS 32 /* maximum number of concurrent
36400f81 498diff -ruN a/innobase/lock/lock0lock.c b/innobase/lock/lock0lock.c
89b96684
ER		 499--- a/innobase/lock/lock0lock.c Tue Jul 28 23:39:12 2009 -0700
500+++ b/innobase/lock/lock0lock.c Tue Jul 28 23:42:44 2009 -0700
36400f81 501@@ -1781,6 +1781,8 @@
833f2639
ER		 502 {
503 lock_t* lock;
504 trx_t* trx;
505+ ulint sec;
506+ ulint ms;
507
508 #ifdef UNIV_SYNC_DEBUG
509 ut_ad(mutex_own(&kernel_mutex));
36400f81 510@@ -1836,6 +1838,10 @@
833f2639
ER		 511 trx->que_state = TRX_QUE_LOCK_WAIT;
512 trx->was_chosen_as_deadlock_victim = FALSE;
513 trx->wait_started = time(NULL);
6f73e838
ER		 514+ if (srv_slow_log && trx->take_stats) {
515+ ut_usectime(&sec, &ms);
516+ trx->lock_que_wait_ustarted = (ib_longlong)sec * 1000000 + ms;
517+ }
833f2639
ER		 518
519 ut_a(que_thr_stop(thr));
520
36400f81 521@@ -3489,7 +3495,9 @@
833f2639
ER		 522 {
523 lock_t* lock;
524 trx_t* trx;
525-
526+ ulint sec;
527+ ulint ms;
528+
529 #ifdef UNIV_SYNC_DEBUG
530 ut_ad(mutex_own(&kernel_mutex));
531 #endif /* UNIV_SYNC_DEBUG */
36400f81 532@@ -3539,6 +3547,10 @@
833f2639
ER		 533 return(DB_SUCCESS);
534 }
6f73e838
ER		 535
536+ if (srv_slow_log && trx->take_stats) {
537+ ut_usectime(&sec, &ms);
538+ trx->lock_que_wait_ustarted = (ib_longlong)sec * 1000000 + ms;
539+ }
833f2639
ER		 540 trx->que_state = TRX_QUE_LOCK_WAIT;
541 trx->was_chosen_as_deadlock_victim = FALSE;
542 trx->wait_started = time(NULL);
36400f81 543diff -ruN a/innobase/os/os0file.c b/innobase/os/os0file.c
89b96684
ER		 544--- a/innobase/os/os0file.c Tue Jul 28 23:39:12 2009 -0700
545+++ b/innobase/os/os0file.c Tue Jul 28 23:42:44 2009 -0700
45532174 546@@ -14,6 +14,8 @@
833f2639
ER		 547 #include "srv0start.h"
548 #include "fil0fil.h"
549 #include "buf0buf.h"
550+#include "trx0sys.h"
45532174 551+#include "trx0trx.h"
833f2639
ER		 552
553 #if defined(UNIV_HOTBACKUP) && defined(__WIN__)
554 /* Add includes for the _stat() call to compile on Windows */
45532174 555@@ -1903,9 +1905,13 @@
833f2639
ER		 556 #ifndef __WIN__
557 /***********************************************************************
558 Does a synchronous read operation in Posix. */
559+
560+#define os_file_pread(file, buf, n, offset, offset_high) \
561+ _os_file_pread(file, buf, n, offset, offset_high, NULL);
562+
563 static
564 ssize_t
565-os_file_pread(
566+_os_file_pread(
567 /*==========*/
568 /* out: number of bytes read, -1 if error */
569 os_file_t file, /* in: handle to a file */
45532174 570@@ -1913,12 +1919,17 @@
833f2639
ER		 571 ulint n, /* in: number of bytes to read */
572 ulint offset, /* in: least significant 32 bits of file
573 offset from where to read */
574- ulint offset_high) /* in: most significant 32 bits of
833f2639 575+ ulint offset_high, /* in: most significant 32 bits of
36400f81 576 offset */
833f2639
ER		 577+ trx_t* trx)
578 {
579 off_t offs;
580 ssize_t n_bytes;
581-
582+ ulint sec;
583+ ulint ms;
584+ ib_longlong start_time;
585+ ib_longlong finish_time;
586+
587 ut_a((offset & 0xFFFFFFFFUL) == offset);
588
589 /* If off_t is > 4 bytes in size, then we assume we can pass a
45532174 590@@ -1937,7 +1948,13 @@
833f2639
ER		 591 }
592
593 os_n_file_reads++;
594-
6f73e838 595+ if (srv_slow_log && trx && trx->take_stats)
833f2639
ER		 596+ {
597+ trx->io_reads++;
598+ trx->io_read += n;
599+ ut_usectime(&sec, &ms);
600+ start_time = (ib_longlong)sec * 1000000 + ms;
601+ }
602 #if defined(HAVE_PREAD) && !defined(HAVE_BROKEN_PREAD)
603 os_mutex_enter(os_file_count_mutex);
604 os_file_n_pending_preads++;
45532174 605@@ -1951,6 +1968,13 @@
833f2639
ER		 606 os_n_pending_reads--;
607 os_mutex_exit(os_file_count_mutex);
608
6f73e838 609+ if (srv_slow_log && trx && trx->take_stats && start_time)
833f2639
ER		 610+ {
611+ ut_usectime(&sec, &ms);
612+ finish_time = (ib_longlong)sec * 1000000 + ms;
613+ trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
614+ }
615+
616 return(n_bytes);
617 #else
618 {
45532174 619@@ -1981,6 +2005,13 @@
833f2639
ER		 620 os_n_pending_reads--;
621 os_mutex_exit(os_file_count_mutex);
45532174 622
6f73e838 623+ if (srv_slow_log && trx && trx->take_stats && start_time)
833f2639
ER		 624+ {
625+ ut_usectime(&sec, &ms);
626+ finish_time = (ib_longlong)sec * 1000000 + ms;
627+ trx->io_reads_wait_timer += (ulint)(finish_time - start_time);
628+ }
45532174 629+
833f2639
ER		 630 return(ret);
631 }
45532174
ER		 632 #endif
633@@ -2103,7 +2134,7 @@
833f2639
ER		 634 Requests a synchronous positioned read operation. */
635
636 ibool
637-os_file_read(
638+_os_file_read(
639 /*=========*/
640 /* out: TRUE if request was
641 successful, FALSE if fail */
45532174 642@@ -2113,7 +2144,8 @@
833f2639
ER		 643 offset where to read */
644 ulint offset_high, /* in: most significant 32 bits of
645 offset */
646- ulint n) /* in: number of bytes to read */
647+ ulint n, /* in: number of bytes to read */
648+ trx_t* trx)
649 {
650 #ifdef __WIN__
651 BOOL ret;
45532174 652@@ -2177,7 +2209,7 @@
833f2639
ER		 653 os_bytes_read_since_printout += n;
654
655 try_again:
656- ret = os_file_pread(file, buf, n, offset, offset_high);
657+ ret = _os_file_pread(file, buf, n, offset, offset_high, trx);
658
659 if ((ulint)ret == n) {
660
45532174 661@@ -3137,7 +3169,8 @@
833f2639
ER		 662 offset */
663 ulint offset_high, /* in: most significant 32 bits of
664 offset */
665- ulint len) /* in: length of the block to read or write */
666+ ulint len, /* in: length of the block to read or write */
667+ trx_t* trx)
668 {
669 os_aio_slot_t* slot;
670 #ifdef WIN_ASYNC_IO
45532174 671@@ -3390,7 +3423,8 @@
833f2639
ER		 672 can be used to identify a completed aio
673 operation); if mode is OS_AIO_SYNC, these
674 are ignored */
675- void* message2)
676+ void* message2,
677+ trx_t* trx)
678 {
679 os_aio_array_t* array;
680 os_aio_slot_t* slot;
45532174 681@@ -3429,8 +3463,8 @@
833f2639
ER		 682 wait in the Windows case. */
683
684 if (type == OS_FILE_READ) {
685- return(os_file_read(file, buf, offset,
686- offset_high, n));
687+ return(_os_file_read(file, buf, offset,
688+ offset_high, n, trx));
689 }
690
691 ut_a(type == OS_FILE_WRITE);
45532174 692@@ -3463,8 +3497,13 @@
833f2639
ER		 693 ut_error;
694 }
695
696+ if (trx && type == OS_FILE_READ)
697+ {
698+ trx->io_reads++;
699+ trx->io_read += n;
700+ }
701 slot = os_aio_array_reserve_slot(type, array, message1, message2, file,
702- name, buf, offset, offset_high, n);
703+ name, buf, offset, offset_high, n, trx);
704 if (type == OS_FILE_READ) {
705 if (os_aio_use_native_aio) {
706 #ifdef WIN_ASYNC_IO
36400f81 707diff -ruN a/innobase/srv/srv0srv.c b/innobase/srv/srv0srv.c
89b96684
ER		 708--- a/innobase/srv/srv0srv.c Tue Jul 28 23:39:12 2009 -0700
709+++ b/innobase/srv/srv0srv.c Tue Jul 28 23:42:44 2009 -0700
45532174 710@@ -48,6 +48,8 @@
6f73e838
ER		 711 #include "srv0start.h"
712 #include "row0mysql.h"
833f2639 713
45532174
ER		 714+ibool srv_slow_log = 0;
715+
6f73e838
ER		 716 /* This is set to TRUE if the MySQL user has set it in MySQL; currently
717 affects only FOREIGN KEY definition parsing */
45532174
ER		 718 ibool srv_lower_case_table_names = FALSE;
719@@ -1002,6 +1004,10 @@
833f2639
ER		 720 ibool has_slept = FALSE;
721 srv_conc_slot_t* slot = NULL;
722 ulint i;
723+ ib_longlong start_time = 0L;
724+ ib_longlong finish_time = 0L;
725+ ulint sec;
726+ ulint ms;
727
728 /* If trx has 'free tickets' to enter the engine left, then use one
729 such ticket */
45532174 730@@ -1060,6 +1066,7 @@
833f2639
ER		 731 if (SRV_THREAD_SLEEP_DELAY > 0)
732 {
733 os_thread_sleep(SRV_THREAD_SLEEP_DELAY);
734+ trx->innodb_que_wait_timer += SRV_THREAD_SLEEP_DELAY;
735 }
736
737 trx->op_info = "";
45532174 738@@ -1115,12 +1122,23 @@
833f2639
ER		 739 /* Go to wait for the event; when a thread leaves InnoDB it will
740 release this thread */
741
6f73e838
ER		 742+ if (srv_slow_log && trx->take_stats) {
743+ ut_usectime(&sec, &ms);
744+ start_time = (ib_longlong)sec * 1000000 + ms;
745+ }
833f2639
ER		 746+
747 trx->op_info = "waiting in InnoDB queue";
748
749 os_event_wait(slot->event);
750
751 trx->op_info = "";
45532174 752
6f73e838
ER		 753+ if (srv_slow_log && trx->take_stats && start_time) {
754+ ut_usectime(&sec, &ms);
755+ finish_time = (ib_longlong)sec * 1000000 + ms;
756+ trx->innodb_que_wait_timer += (ulint)(finish_time - start_time);
757+ }
45532174 758+
833f2639
ER		 759 os_fast_mutex_lock(&srv_conc_mutex);
760
45532174 761 srv_conc_n_waiting_threads--;
36400f81 762diff -ruN a/innobase/trx/trx0trx.c b/innobase/trx/trx0trx.c
89b96684
ER		 763--- a/innobase/trx/trx0trx.c Tue Jul 28 23:39:12 2009 -0700
764+++ b/innobase/trx/trx0trx.c Tue Jul 28 23:42:44 2009 -0700
6f73e838 765@@ -190,6 +190,15 @@
833f2639
ER		 766 trx->global_read_view_heap = mem_heap_create(256);
767 trx->global_read_view = NULL;
768 trx->read_view = NULL;
769+
770+ trx->io_reads = 0;
771+ trx->io_read = 0;
772+ trx->io_reads_wait_timer = 0;
773+ trx->lock_que_wait_timer = 0;
774+ trx->innodb_que_wait_timer = 0;
775+ trx->distinct_page_access = 0;
776+ trx->distinct_page_access_hash = NULL;
6f73e838 777+ trx->take_stats = FALSE;
833f2639
ER		 778
779 /* Set X/Open XA transaction identification to NULL */
780 memset(&trx->xid, 0, sizeof(trx->xid));
6f73e838 781@@ -230,6 +239,11 @@
833f2639
ER		 782
783 trx->mysql_process_no = os_proc_get_number();
784
6f73e838
ER		 785+ if (srv_slow_log && trx->take_stats) {
786+ trx->distinct_page_access_hash = mem_alloc(DPAH_SIZE);
787+ memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
788+ }
833f2639
ER		 789+
790 return(trx);
791 }
792
6f73e838 793@@ -366,6 +380,12 @@
833f2639
ER		 794 /*===============*/
795 trx_t* trx) /* in, own: trx object */
796 {
797+ if (trx->distinct_page_access_hash)
798+ {
799+ mem_free(trx->distinct_page_access_hash);
800+ trx->distinct_page_access_hash= NULL;
801+ }
802+
803 thr_local_free(trx->mysql_thread_id);
804
805 mutex_enter(&kernel_mutex);
6f73e838
ER		 806@@ -389,6 +409,12 @@
807 /*====================*/
808 trx_t* trx) /* in, own: trx object */
809 {
810+ if (trx->distinct_page_access_hash)
811+ {
812+ mem_free(trx->distinct_page_access_hash);
813+ trx->distinct_page_access_hash= NULL;
814+ }
815+
816 mutex_enter(&kernel_mutex);
817
818 trx_free(trx);
819@@ -1064,7 +1090,10 @@
833f2639
ER		 820 trx_t* trx) /* in: transaction */
821 {
822 que_thr_t* thr;
823-
824+ ulint sec;
825+ ulint ms;
826+ ib_longlong now;
827+
828 #ifdef UNIV_SYNC_DEBUG
829 ut_ad(mutex_own(&kernel_mutex));
830 #endif /* UNIV_SYNC_DEBUG */
6f73e838 831@@ -1080,6 +1109,11 @@
833f2639
ER		 832 thr = UT_LIST_GET_FIRST(trx->wait_thrs);
833 }
834
6f73e838
ER		 835+ if (srv_slow_log && trx->take_stats) {
836+ ut_usectime(&sec, &ms);
837+ now = (ib_longlong)sec * 1000000 + ms;
838+ trx->lock_que_wait_timer += (ulint)(now - trx->lock_que_wait_ustarted);
839+ }
833f2639
ER		 840 trx->que_state = TRX_QUE_RUNNING;
841 }
842
6f73e838 843@@ -1093,6 +1127,9 @@
833f2639
ER		 844 trx_t* trx) /* in: transaction in the TRX_QUE_LOCK_WAIT state */
845 {
846 que_thr_t* thr;
847+ ulint sec;
848+ ulint ms;
849+ ib_longlong now;
850
851 #ifdef UNIV_SYNC_DEBUG
852 ut_ad(mutex_own(&kernel_mutex));
6f73e838 853@@ -1109,6 +1146,11 @@
833f2639
ER		 854 thr = UT_LIST_GET_FIRST(trx->wait_thrs);
855 }
856
6f73e838
ER		 857+ if (srv_slow_log && trx->take_stats) {
858+ ut_usectime(&sec, &ms);
859+ now = (ib_longlong)sec * 1000000 + ms;
860+ trx->lock_que_wait_timer += (ulint)(now - trx->lock_que_wait_ustarted);
861+ }
833f2639
ER		 862 trx->que_state = TRX_QUE_RUNNING;
863 }
864
36400f81 865diff -ruN a/mysys/my_getopt.c b/mysys/my_getopt.c
89b96684
ER		 866--- a/mysys/my_getopt.c Tue Jul 28 23:39:12 2009 -0700
867+++ b/mysys/my_getopt.c Tue Jul 28 23:42:44 2009 -0700
45532174
ER		 868@@ -827,7 +827,8 @@
869 #endif
870 break;
871 default:
872- DBUG_ASSERT((optp->var_type & GET_TYPE_MASK) == GET_ULL);
873+ DBUG_ASSERT((optp->var_type & GET_TYPE_MASK) == GET_ULL
874+ || (optp->var_type & GET_TYPE_MASK) == GET_MICROTIME);
875 break;
876 }
877
89b96684 878@@ -1061,6 +1062,9 @@
6f73e838
ER		 879 case GET_ULONG:
880 printf("%lu\n", *((ulong*) value));
881 break;
45532174
ER		 882+ case GET_MICROTIME:
883+ printf("%6f\n", ((double)(*((longlong*) value))) / 1000000.0);
6f73e838
ER		 884+ break;
885 case GET_LL:
886 printf("%s\n", llstr(*((longlong*) value), buff));
887 break;
36400f81 888diff -ruN /dev/null b/patch_info/microslow_innodb.info
833f2639 889--- /dev/null Thu Jan 01 00:00:00 1970 +0000
89b96684 890+++ b/patch_info/microslow_innodb.info Tue Jul 28 23:42:44 2009 -0700
6f73e838 891@@ -0,0 +1,15 @@
833f2639
ER		 892+File=microslow_innodb.patch
893+Name=Extended statistics in slow.log
dcc72bc6 894+Version=1.2
833f2639
ER		 895+Author=Percona <info@percona.com>
896+License=GPL
897+Comment=
6f73e838
ER		 898+Changelog
899+2008-11-26
900+YK: Fix inefficient determination of trx, Make not to call useless gettimeofday when don't use slow log. Make log_slow_queries dynamic (bool).
901+
902+2008-11-07
903+VT: Moved log_slow_rate_limit in SHOW VARIABLE into right place
904+
905+2008-11
906+Arjen Lentz: Fixups (backward compatibility) by Arjen Lentz <arjen@openquery.com.au>
36400f81 907diff -ruN a/scripts/mysqldumpslow.sh b/scripts/mysqldumpslow.sh
89b96684
ER		 908--- a/scripts/mysqldumpslow.sh Tue Jul 28 23:39:12 2009 -0700
909+++ b/scripts/mysqldumpslow.sh Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 910@@ -83,8 +83,8 @@
911 s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//;
912 my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('','');
913
914- s/^# Query_time: (\d+) Lock_time: (\d+) Rows_sent: (\d+).*\n//;
915- my ($t, $l, $r) = ($1, $2, $3);
916+ s/^# Query_time: (\d+(\.\d+)?) Lock_time: (\d+(\.\d+)?) Rows_sent: (\d+(\.\d+)?).*\n//;
917+ my ($t, $l, $r) = ($1, $3, $5);
918 $t -= $l unless $opt{l};
919
920 # remove fluff that mysqld writes to log when it (re)starts:
36400f81 921diff -ruN a/sql-common/my_time.c b/sql-common/my_time.c
89b96684
ER		 922--- a/sql-common/my_time.c Tue Jul 28 23:39:12 2009 -0700
923+++ b/sql-common/my_time.c Tue Jul 28 23:42:44 2009 -0700
36400f81 924@@ -1251,3 +1251,37 @@
833f2639
ER		 925 return 0;
926 }
927
928+/*
929+ int my_timer(ulonglong *ltime, ulonglong frequency)
930+
931+ For performance measurement this function returns the number
932+ of microseconds since the epoch (SVr4, BSD 4.3, POSIX 1003.1-2001)
933+ or system start (Windows platforms).
934+
935+ For windows platforms frequency value (obtained via
936+ QueryPerformanceFrequency) has to be specified. The global frequency
937+ value is set in mysqld.cc.
938+
939+ If Windows platform doesn't support QueryPerformanceFrequency we will
940+ obtain the time via GetClockCount, which supports microseconds only.
941+*/
942+
943+ulonglong my_timer(ulonglong *ltime, ulonglong frequency)
944+{
945+ ulonglong newtime= 0;
946+#ifdef __WIN__
947+ if (frequency)
948+ {
949+ QueryPerformanceCounter((LARGE_INTEGER *)&newtime);
950+ newtime/= (frequency * 1000000);
951+ } else
952+ newtime= (GetTickCount() * 1000; /* GetTickCount only returns milliseconds */
953+#else
954+ struct timeval t;
dcc72bc6
ER		 955+ if (gettimeofday(&t, NULL) != -1)
956+ newtime= (ulonglong)t.tv_sec * 1000000 + t.tv_usec;
833f2639
ER		 957+#endif
958+ if (ltime)
959+ *ltime= newtime;
960+ return newtime;
961+}
36400f81 962diff -ruN a/sql/filesort.cc b/sql/filesort.cc
89b96684
ER		 963--- a/sql/filesort.cc Tue Jul 28 23:39:12 2009 -0700
964+++ b/sql/filesort.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 965@@ -182,6 +182,7 @@
833f2639
ER		 966 {
967 statistic_increment(thd->status_var.filesort_scan_count, &LOCK_status);
968 }
969+ thd->query_plan_flags|= QPLAN_FILESORT;
970 #ifdef CAN_TRUST_RANGE
971 if (select && select->quick && select->quick->records > 0L)
972 {
36400f81 973@@ -247,6 +248,7 @@
833f2639
ER		 974 }
975 else
976 {
977+ thd->query_plan_flags|= QPLAN_FILESORT_DISK;
978 if (table_sort.buffpek && table_sort.buffpek_len < maxbuffer)
979 {
980 x_free(table_sort.buffpek);
36400f81 981@@ -1118,6 +1120,7 @@
833f2639
ER		 982
983 statistic_increment(current_thd->status_var.filesort_merge_passes,
984 &LOCK_status);
985+ current_thd->query_plan_fsort_passes++;
986 if (param->not_killable)
987 {
988 killed= &not_killable;
36400f81 989diff -ruN a/sql/ha_innodb.cc b/sql/ha_innodb.cc
89b96684
ER		 990--- a/sql/ha_innodb.cc Tue Jul 28 23:39:12 2009 -0700
991+++ b/sql/ha_innodb.cc Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 992@@ -1,3 +1,4 @@
993+
994 /* Copyright (C) 2000-2005 MySQL AB & Innobase Oy
995
996 This program is free software; you can redistribute it and/or modify
36400f81 997@@ -804,9 +805,34 @@
6f73e838
ER		 998 trx->check_unique_secondary = TRUE;
999 }
1000
1001+ if (thd->variables.log_slow_verbosity & SLOG_V_INNODB) {
1002+ trx->take_stats = TRUE;
1003+ } else {
1004+ trx->take_stats = FALSE;
1005+ }
1006+
1007 return(trx);
1008 }
1009
1010+/*************************************************************************
1011+Gets current trx. */
1012+extern "C"
1013+trx_t*
1014+innobase_get_trx()
1015+{
1016+ THD *thd=current_thd;
1017+ if (likely(thd != 0)) {
1018+ return((trx_t*) thd->ha_data[innobase_hton.slot]);
1019+ } else {
1020+ return(NULL);
1021+ }
1022+}
1023+
1024+void
1025+innobase_update_var_slow_log()
1026+{
1027+ srv_slow_log = (ibool) opt_slow_log;
1028+}
1029
1030 /*************************************************************************
1031 Construct ha_innobase handler. */
36400f81 1032@@ -1309,6 +1335,8 @@
6f73e838
ER		 1033
1034 /* -------------- Log files ---------------------------*/
6f73e838 1035
45532174
ER		 1036+ srv_slow_log = (ibool) opt_slow_log;
1037+
6f73e838
ER		 1038 /* The default dir for log files is the datadir of MySQL */
1039
45532174 1040 if (!innobase_log_group_home_dir) {
36400f81 1041@@ -4687,6 +4715,12 @@
6f73e838
ER		 1042 trx->check_unique_secondary = FALSE;
1043 }
1044
1045+ if (thd->variables.log_slow_verbosity & SLOG_V_INNODB) {
1046+ trx->take_stats = TRUE;
1047+ } else {
1048+ trx->take_stats = FALSE;
1049+ }
1050+
1051 if (lower_case_table_names) {
1052 srv_lower_case_table_names = TRUE;
1053 } else {
36400f81 1054@@ -4959,6 +4993,12 @@
6f73e838
ER		 1055 trx->check_unique_secondary = FALSE;
1056 }
1057
1058+ if (thd->variables.log_slow_verbosity & SLOG_V_INNODB) {
1059+ trx->take_stats = TRUE;
1060+ } else {
1061+ trx->take_stats = FALSE;
1062+ }
1063+
1064 name_len = strlen(name);
1065
1066 assert(name_len < 1000);
36400f81 1067@@ -5046,6 +5086,12 @@
6f73e838
ER		 1068 trx->check_foreigns = FALSE;
1069 }
1070
1071+ if (current_thd->variables.log_slow_verbosity & SLOG_V_INNODB) {
1072+ trx->take_stats = TRUE;
1073+ } else {
1074+ trx->take_stats = FALSE;
1075+ }
1076+
1077 error = row_drop_database_for_mysql(namebuf, trx);
1078 my_free(namebuf, MYF(0));
1079
36400f81 1080@@ -5112,6 +5158,12 @@
6f73e838 1081 trx->check_foreigns = FALSE;
45532174
ER		 1082 }
1083
6f73e838
ER		 1084+ if (current_thd->variables.log_slow_verbosity & SLOG_V_INNODB) {
1085+ trx->take_stats = TRUE;
1086+ } else {
1087+ trx->take_stats = FALSE;
45532174
ER		 1088+ }
1089+
6f73e838 1090 name_len1 = strlen(from);
45532174
ER		 1091 name_len2 = strlen(to);
1092
36400f81 1093@@ -6119,6 +6171,7 @@
833f2639
ER		 1094 {
1095 row_prebuilt_t* prebuilt = (row_prebuilt_t*) innobase_prebuilt;
1096 trx_t* trx;
1097+ int i;
1098
1099 DBUG_ENTER("ha_innobase::external_lock");
1100 DBUG_PRINT("enter",("lock_type: %d", lock_type));
36400f81 1101@@ -6242,7 +6295,24 @@
833f2639
ER		 1102
1103 if (trx->n_mysql_tables_in_use == 0) {
1104
1105- trx->mysql_n_tables_locked = 0;
1106+ current_thd->innodb_was_used = TRUE;
1107+ current_thd->innodb_io_reads += trx->io_reads;
1108+ current_thd->innodb_io_read += trx->io_read;
1109+ current_thd->innodb_io_reads_wait_timer += trx->io_reads_wait_timer;
1110+ current_thd->innodb_lock_que_wait_timer += trx->lock_que_wait_timer;
1111+ current_thd->innodb_innodb_que_wait_timer += trx->innodb_que_wait_timer;
1112+ current_thd->innodb_page_access += trx->distinct_page_access;
1113+
1114+ trx->io_reads = 0;
1115+ trx->io_read = 0;
1116+ trx->io_reads_wait_timer = 0;
1117+ trx->lock_que_wait_timer = 0;
1118+ trx->innodb_que_wait_timer = 0;
1119+ trx->distinct_page_access = 0;
1120+ if (trx->distinct_page_access_hash)
1121+ memset(trx->distinct_page_access_hash, 0, DPAH_SIZE);
1122+
1123+ trx->mysql_n_tables_locked = 0;
1124 prebuilt->used_in_HANDLER = FALSE;
1125
1126 if (!(thd->options & (OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN))) {
36400f81 1127diff -ruN a/sql/ha_innodb.h b/sql/ha_innodb.h
89b96684
ER		 1128--- a/sql/ha_innodb.h Tue Jul 28 23:39:12 2009 -0700
1129+++ b/sql/ha_innodb.h Tue Jul 28 23:42:44 2009 -0700
45532174 1130@@ -271,6 +271,8 @@
6f73e838
ER		 1131
1132 int innobase_start_trx_and_assign_read_view(THD* thd);
1133
1134+void innobase_update_var_slow_log();
1135+
1136 /***********************************************************************
1137 This function is used to prepare X/Open XA distributed transaction */
1138
36400f81 1139diff -ruN a/sql/log.cc b/sql/log.cc
89b96684
ER		 1140--- a/sql/log.cc Tue Jul 28 23:39:12 2009 -0700
1141+++ b/sql/log.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 1142@@ -2291,11 +2291,12 @@
833f2639
ER		 1143 */
1144
1145 bool MYSQL_LOG::write(THD *thd,const char *query, uint query_length,
1146- time_t query_start_arg)
1147+ time_t query_start_arg, ulonglong query_start_timer)
1148 {
1149 bool error=0;
1150 time_t current_time;
6f73e838 1151- if (!is_open())
833f2639 1152+ ulonglong current_timer;
6f73e838 1153+ if (!opt_slow_log || !is_open())
833f2639
ER		 1154 return 0;
1155 DBUG_ENTER("MYSQL_LOG::write");
6f73e838 1156
36400f81 1157@@ -2305,7 +2306,8 @@
833f2639
ER		 1158 int tmp_errno=0;
1159 char buff[80],*end;
1160 end=buff;
1161- if (!(thd->options & OPTION_UPDATE_LOG))
1162+ if (!(thd->options & OPTION_UPDATE_LOG) &&
1163+ !(thd->slave_thread && opt_log_slow_slave_statements))
1164 {
1165 VOID(pthread_mutex_unlock(&LOCK_log));
1166 DBUG_RETURN(0);
36400f81 1167@@ -2335,22 +2337,72 @@
833f2639
ER		 1168 if (my_b_printf(&log_file, "# User@Host: %s[%s] @ %s [%s]\n",
1169 sctx->priv_user ?
1170 sctx->priv_user : "",
1171- sctx->user ? sctx->user : "",
1172+ sctx->user ? sctx->user : (thd->slave_thread ? "SQL_SLAVE" : ""),
1173 sctx->host ? sctx->host : "",
1174 sctx->ip ? sctx->ip : "") ==
1175 (uint) -1)
1176 tmp_errno=errno;
1177 }
1178- if (query_start_arg)
1179+ if (query_start_timer)
1180 {
1181+ char buf[5][20];
1182+ ulonglong current_timer= my_timer(&current_timer, frequency);
dcc72bc6
ER		 1183+ snprintf(buf[0], 20, "%.6f", (current_timer ? (current_timer - query_start_timer):0) / 1000000.0);
1184+ snprintf(buf[1], 20, "%.6f", (thd->timer_after_lock - query_start_timer) / 1000000.0);
833f2639
ER		 1185+ if (!query_length)
1186+ {
1187+ thd->sent_row_count= thd->examined_row_count= 0;
dcc72bc6 1188+ thd->row_count= 0;
833f2639
ER		 1189+ thd->innodb_was_used= FALSE;
1190+ thd->query_plan_flags= QPLAN_NONE;
1191+ thd->query_plan_fsort_passes= 0;
1192+ }
1193+
1194 /* For slow query log */
1195 if (my_b_printf(&log_file,
1196- "# Query_time: %lu Lock_time: %lu Rows_sent: %lu Rows_examined: %lu\n",
1197- (ulong) (current_time - query_start_arg),
1198- (ulong) (thd->time_after_lock - query_start_arg),
1199+ "# Thread_id: %lu Schema: %s\n" \
6f73e838 1200+ "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu Rows_affected: %lu Rows_read: %lu\n",
833f2639
ER		 1201+ (ulong) thd->thread_id, (thd->db ? thd->db : ""),
1202+ buf[0], buf[1],
1203 (ulong) thd->sent_row_count,
6f73e838
ER		 1204- (ulong) thd->examined_row_count) == (uint) -1)
1205+ (ulong) thd->examined_row_count,
1206+ ((long) thd->row_count_func > 0 ) ? (ulong) thd->row_count_func : 0,
1207+ (ulong) thd->row_count) == (uint) -1)
833f2639
ER		 1208 tmp_errno=errno;
1209+ if ((thd->variables.log_slow_verbosity & SLOG_V_QUERY_PLAN) &&
1210+ my_b_printf(&log_file,
1211+ "# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s Tmp_table_on_disk: %s\n" \
1212+ "# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n",
1213+ ((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"),
1214+ ((thd->query_plan_flags & QPLAN_FULL_SCAN) ? "Yes" : "No"),
1215+ ((thd->query_plan_flags & QPLAN_FULL_JOIN) ? "Yes" : "No"),
1216+ ((thd->query_plan_flags & QPLAN_TMP_TABLE) ? "Yes" : "No"),
1217+ ((thd->query_plan_flags & QPLAN_TMP_DISK) ? "Yes" : "No"),
1218+ ((thd->query_plan_flags & QPLAN_FILESORT) ? "Yes" : "No"),
1219+ ((thd->query_plan_flags & QPLAN_FILESORT_DISK) ? "Yes" : "No"),
1220+ thd->query_plan_fsort_passes) == (uint) -1)
1221+ tmp_errno=errno;
1222+ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) && thd->innodb_was_used)
1223+ {
dcc72bc6
ER		 1224+ snprintf(buf[2], 20, "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0);
1225+ snprintf(buf[3], 20, "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0);
1226+ snprintf(buf[4], 20, "%.6f", thd->innodb_innodb_que_wait_timer / 1000000.0);
833f2639
ER		 1227+ if (my_b_printf(&log_file,
1228+ "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %lu InnoDB_IO_r_wait: %s\n" \
1229+ "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n" \
1230+ "# InnoDB_pages_distinct: %lu\n",
1231+ (ulong) thd->innodb_io_reads,
1232+ (ulong) thd->innodb_io_read,
1233+ buf[2], buf[3], buf[4],
1234+ (ulong) thd->innodb_page_access) == (uint) -1)
1235+ tmp_errno=errno;
1236+ }
1237+ else
1238+ {
1239+ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) &&
1240+ my_b_printf(&log_file,"# No InnoDB statistics available for this query\n") == (uint) -1)
1241+ tmp_errno=errno;
1242+ }
1243 }
1244 if (thd->db && strcmp(thd->db,db))
1245 { // Database changed
36400f81 1246diff -ruN a/sql/log_event.cc b/sql/log_event.cc
89b96684
ER		 1247--- a/sql/log_event.cc Tue Jul 28 23:39:12 2009 -0700
1248+++ b/sql/log_event.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 1249@@ -2070,6 +2070,7 @@
833f2639
ER		 1250 /* Execute the query (note that we bypass dispatch_command()) */
1251 const char* found_semicolon= NULL;
1252 mysql_parse(thd, thd->query, thd->query_length, &found_semicolon);
1253+ log_slow_statement(thd);
1254
1255 }
1256 else
36400f81 1257diff -ruN a/sql/mysql_priv.h b/sql/mysql_priv.h
89b96684
ER		 1258--- a/sql/mysql_priv.h Tue Jul 28 23:39:12 2009 -0700
1259+++ b/sql/mysql_priv.h Tue Jul 28 23:42:44 2009 -0700
45532174 1260@@ -507,6 +507,78 @@
833f2639
ER		 1261
1262 #define STRING_BUFFER_USUAL_SIZE 80
45532174 1263
833f2639
ER		 1264+/* Slow log */
1265+
1266+struct msl_opts
1267+{
1268+ ulong val;
1269+ const char *name;
1270+};
1271+
1272+#define SLOG_V_MICROTIME 1 << 0
1273+#define SLOG_V_QUERY_PLAN 1 << 1
1274+#define SLOG_V_INNODB 1 << 2
1275+/* ... */
1276+#define SLOG_V_INVALID 1 << 31
1277+#define SLOG_V_NONE SLOG_V_MICROTIME
1278+
1279+static const struct msl_opts slog_verb[]=
1280+{
1281+ /* Basic flags */
1282+
1283+ { SLOG_V_MICROTIME, "microtime" },
1284+ { SLOG_V_QUERY_PLAN, "query_plan" },
1285+ { SLOG_V_INNODB, "innodb" },
1286+
1287+ /* End of baisc flags */
1288+
1289+ { 0, "" },
1290+
1291+ /* Complex flags */
1292+
1293+ { SLOG_V_MICROTIME, "minimal" },
1294+ { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN, "standard" },
1295+ { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN|SLOG_V_INNODB, "full" },
1296+
1297+ /* End of complex flags */
1298+
1299+ { SLOG_V_INVALID, (char *)0 }
1300+};
1301+
1302+#define QPLAN_NONE 0
1303+#define QPLAN_QC 1 << 0
1304+#define QPLAN_QC_NO 1 << 1
1305+#define QPLAN_FULL_SCAN 1 << 2
1306+#define QPLAN_FULL_JOIN 1 << 3
1307+#define QPLAN_TMP_TABLE 1 << 4
1308+#define QPLAN_TMP_DISK 1 << 5
1309+#define QPLAN_FILESORT 1 << 6
1310+#define QPLAN_FILESORT_DISK 1 << 7
1311+/* ... */
1312+#define QPLAN_MAX 1 << 31
1313+
1314+#define SLOG_F_QC_NO QPLAN_QC_NO
1315+#define SLOG_F_FULL_SCAN QPLAN_FULL_SCAN
1316+#define SLOG_F_FULL_JOIN QPLAN_FULL_JOIN
1317+#define SLOG_F_TMP_TABLE QPLAN_TMP_TABLE
1318+#define SLOG_F_TMP_DISK QPLAN_TMP_DISK
1319+#define SLOG_F_FILESORT QPLAN_FILESORT
1320+#define SLOG_F_FILESORT_DISK QPLAN_FILESORT_DISK
1321+#define SLOG_F_INVALID 1 << 31
1322+#define SLOG_F_NONE 0
1323+
1324+static const struct msl_opts slog_filter[]=
1325+{
1326+ { SLOG_F_QC_NO, "qc_miss" },
1327+ { SLOG_F_FULL_SCAN, "full_scan" },
1328+ { SLOG_F_FULL_JOIN, "full_join" },
1329+ { SLOG_F_TMP_TABLE, "tmp_table" },
1330+ { SLOG_F_TMP_DISK, "tmp_table_on_disk" },
1331+ { SLOG_F_FILESORT, "filesort" },
1332+ { SLOG_F_FILESORT_DISK, "filesort_on_disk" },
1333+ { SLOG_F_INVALID, (char *)0 }
1334+};
45532174 1335+
833f2639
ER		 1336 enum enum_parsing_place
1337 {
45532174
ER		 1338 NO_MATTER,
1339@@ -1365,6 +1437,7 @@
6f73e838
ER		 1340 extern bool using_update_log, opt_large_files, server_id_supplied;
1341 extern bool opt_update_log, opt_bin_log, opt_error_log;
1342 extern my_bool opt_log, opt_slow_log, opt_log_queries_not_using_indexes;
1343+extern char *opt_slow_logname;
1344 extern bool opt_disable_networking, opt_skip_show_db;
1345 extern my_bool opt_character_set_client_handshake;
1346 extern bool volatile abort_loop, shutdown_in_progress, grant_option;
45532174 1347@@ -1376,7 +1449,8 @@
833f2639
ER		 1348 extern my_bool opt_enable_named_pipe, opt_sync_frm, opt_allow_suspicious_udfs;
1349 extern my_bool opt_secure_auth;
1350 extern char* opt_secure_file_priv;
1351-extern my_bool opt_log_slow_admin_statements;
1352+extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements;
dcc72bc6 1353+extern my_bool opt_use_global_long_query_time;
833f2639
ER		 1354 extern my_bool sp_automatic_privileges, opt_noacl;
1355 extern my_bool opt_old_style_user_limits, trust_function_creators;
1356 extern uint opt_crash_binlog_innodb;
36400f81 1357diff -ruN a/sql/mysqld.cc b/sql/mysqld.cc
89b96684
ER		 1358--- a/sql/mysqld.cc Tue Jul 28 23:39:12 2009 -0700
1359+++ b/sql/mysqld.cc Tue Jul 28 23:42:44 2009 -0700
45532174 1360@@ -176,7 +176,6 @@
833f2639
ER		 1361 static void getvolumeID(BYTE *volumeName);
1362 #endif /* __NETWARE__ */
833f2639 1363
45532174 1364-
833f2639
ER		 1365 #ifdef _AIX41
1366 int initgroups(const char *,unsigned int);
45532174
ER		 1367 #endif
1368@@ -411,10 +410,13 @@
833f2639
ER		 1369 my_bool opt_secure_auth= 0;
1370 char* opt_secure_file_priv= 0;
1371 my_bool opt_log_slow_admin_statements= 0;
1372+my_bool opt_log_slow_slave_statements= 0;
dcc72bc6 1373+my_bool opt_use_global_long_query_time= 0;
833f2639
ER		 1374 my_bool lower_case_file_system= 0;
1375 my_bool opt_large_pages= 0;
1376 uint opt_large_page_size= 0;
6f73e838
ER		 1377 my_bool opt_old_style_user_limits= 0, trust_function_creators= 0;
1378+char* opt_slow_logname= 0;
1379 /*
1380 True if there is at least one per-hour limit for some user, so we should
1381 check them before each query (and possibly reset counters when hour is
45532174 1382@@ -509,6 +511,7 @@
833f2639
ER		 1383 Ge_creator ge_creator;
1384 Le_creator le_creator;
1385
1386+ulonglong frequency= 0;
1387
1388 FILE *bootstrap_file;
1389 int bootstrap_error;
45532174 1390@@ -588,7 +591,7 @@
6f73e838
ER		 1391 static int cleanup_done;
1392 static ulong opt_specialflag, opt_myisam_block_size;
1393 static char *opt_logname, *opt_update_logname, *opt_binlog_index_name;
1394-static char *opt_slow_logname, *opt_tc_heuristic_recover;
1395+static char *opt_tc_heuristic_recover;
1396 static char *mysql_home_ptr, *pidfile_name_ptr;
1397 static char **defaults_argv;
1398 static char *opt_bin_logname;
36400f81 1399@@ -3700,6 +3703,8 @@
833f2639
ER		 1400 unireg_abort(1);
1401 }
1402 }
1403+ if (!QueryPerformanceFrequency((LARGE_INTEGER *)&frequency))
1404+ frequency= 0;
1405 #endif /* __WIN__ */
1406
1407 if (init_common_variables(MYSQL_CONFIG_NAME,
36400f81 1408@@ -4963,7 +4968,7 @@
833f2639
ER		 1409 OPT_INTERACTIVE_TIMEOUT, OPT_JOIN_BUFF_SIZE,
1410 OPT_KEY_BUFFER_SIZE, OPT_KEY_CACHE_BLOCK_SIZE,
1411 OPT_KEY_CACHE_DIVISION_LIMIT, OPT_KEY_CACHE_AGE_THRESHOLD,
1412- OPT_LONG_QUERY_TIME,
1413+ OPT_LONG_QUERY_TIME, OPT_MIN_EXAMINED_ROW_LIMIT,
1414 OPT_LOWER_CASE_TABLE_NAMES, OPT_MAX_ALLOWED_PACKET,
1415 OPT_MAX_BINLOG_CACHE_SIZE, OPT_MAX_BINLOG_SIZE,
1416 OPT_MAX_CONNECTIONS, OPT_MAX_CONNECT_ERRORS,
36400f81 1417@@ -5055,11 +5060,18 @@
833f2639
ER		 1418 OPT_TIMED_MUTEXES,
1419 OPT_OLD_STYLE_USER_LIMITS,
1420 OPT_LOG_SLOW_ADMIN_STATEMENTS,
1421+ OPT_LOG_SLOW_SLAVE_STATEMENTS,
1422+ OPT_LOG_SLOW_RATE_LIMIT,
1423+ OPT_LOG_SLOW_VERBOSITY,
1424+ OPT_LOG_SLOW_FILTER,
1425 OPT_TABLE_LOCK_WAIT_TIMEOUT,
6f73e838 1426 OPT_PLUGIN_DIR,
833f2639
ER		 1427 OPT_PORT_OPEN_TIMEOUT,
1428 OPT_MERGE,
6f73e838
ER		 1429 OPT_PROFILING,
1430+ OPT_SLOW_LOG,
1431+ OPT_SLOW_QUERY_LOG_FILE,
dcc72bc6 1432+ OPT_USE_GLOBAL_LONG_QUERY_TIME,
6f73e838
ER		 1433 OPT_INNODB_ROLLBACK_ON_TIMEOUT,
1434 OPT_SECURE_FILE_PRIV,
1435 OPT_KEEP_FILES_ON_CREATE,
36400f81 1436@@ -5459,10 +5471,19 @@
833f2639
ER		 1437 (gptr*) &opt_log_slow_admin_statements,
1438 (gptr*) &opt_log_slow_admin_statements,
6f73e838 1439 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
833f2639
ER		 1440+ {"log-slow-slave-statements", OPT_LOG_SLOW_SLAVE_STATEMENTS,
1441+ "Log slow replicated statements to the slow log if it is open.",
1442+ (gptr*) &opt_log_slow_slave_statements,
1443+ (gptr*) &opt_log_slow_slave_statements,
6f73e838 1444+ 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
833f2639
ER		 1445 {"log-slow-queries", OPT_SLOW_QUERY_LOG,
1446 "Log slow queries to this log file. Defaults logging to hostname-slow.log file. Must be enabled to activate other slow log options.",
6f73e838
ER		 1447 (gptr*) &opt_slow_logname, (gptr*) &opt_slow_logname, 0, GET_STR, OPT_ARG,
1448 0, 0, 0, 0, 0, 0},
45532174
ER		 1449+ {"slow_query_log_file", OPT_SLOW_QUERY_LOG_FILE,
1450+ "Log slow queries to given log file. Defaults logging to hostname-slow.log. Must be enabled to activate other slow log options.",
1451+ (gptr*) &opt_slow_logname, (gptr*) &opt_slow_logname, 0, GET_STR, OPT_ARG,
1452+ 0, 0, 0, 0, 0, 0},
6f73e838 1453 {"log-tc", OPT_LOG_TC,
45532174
ER		 1454 "Path to transaction coordinator log (used for transactions that affect "
1455 "more than one storage engine, when binary log is disabled)",
36400f81 1456@@ -5826,6 +5847,9 @@
6f73e838
ER		 1457 "Tells the slave thread to continue replication when a query returns an error from the provided list.",
1458 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, 0, 0, 0},
1459 #endif
1460+ {"slow-query-log", OPT_SLOW_LOG,
1461+ "Enable|disable slow query log", (gptr*) &opt_slow_log,
1462+ (gptr*) &opt_slow_log, 0, GET_BOOL, OPT_ARG, 0, 0, 0, 0, 0, 0},
1463 {"socket", OPT_SOCKET, "Socket file to use for connection.",
1464 (gptr*) &mysqld_unix_port, (gptr*) &mysqld_unix_port, 0, GET_STR,
1465 REQUIRED_ARG, 0, 0, 0, 0, 0, 0},
36400f81 1466@@ -6128,11 +6152,31 @@
833f2639
ER		 1467 (gptr*) 0,
1468 0, (GET_ULONG | GET_ASK_ADDR) , REQUIRED_ARG, 100,
1469 1, 100, 0, 1, 0},
6f73e838
ER		 1470- {"long_query_time", OPT_LONG_QUERY_TIME,
1471- "Log all queries that have taken more than long_query_time seconds to execute to file.",
1472- (gptr*) &global_system_variables.long_query_time,
1473- (gptr*) &max_system_variables.long_query_time, 0, GET_ULONG,
1474- REQUIRED_ARG, 10, 1, LONG_TIMEOUT, 0, 1, 0},
833f2639
ER		 1475+ {"log_slow_filter", OPT_LOG_SLOW_FILTER,
1476+ "Log only the queries that followed certain execution plan. Multiple flags allowed in a comma-separated string. [qc_miss, full_scan, full_join, tmp_table, tmp_table_on_disk, filesort, filesort_on_disk]",
1477+ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_F_NONE, 0, 0},
1478+ {"log_slow_rate_limit", OPT_LOG_SLOW_RATE_LIMIT,
1479+ "Rate limit statement writes to slow log to only those from every (1/log_slow_rate_limit) session.",
1480+ (gptr*) &global_system_variables.log_slow_rate_limit,
1481+ (gptr*) &max_system_variables.log_slow_rate_limit, 0, GET_ULONG,
6f73e838 1482+ REQUIRED_ARG, 1, 1, LONG_MAX, 0, 1L, 0},
833f2639
ER		 1483+ {"log_slow_verbosity", OPT_LOG_SLOW_VERBOSITY,
1484+ "Choose how verbose the messages to your slow log will be. Multiple flags allowed in a comma-separated string. [microtime, query_plan, innodb]",
1485+ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_V_MICROTIME, 0, 0},
6f73e838
ER		 1486+ {"long_query_time", OPT_LONG_QUERY_TIME,
1487+ "Log all queries that have taken more than long_query_time seconds to execute to file.",
1488+ (gptr*) &global_system_variables.long_query_time,
45532174 1489+ (gptr*) &max_system_variables.long_query_time, 0, GET_MICROTIME,
833f2639
ER		 1490+ REQUIRED_ARG, 10000000, 0, LONG_TIMEOUT * 1000000, 0, 1, 0},
1491+ {"min_examined_row_limit", OPT_MIN_EXAMINED_ROW_LIMIT,
1492+ "Don't log queries which examine less than min_examined_row_limit rows to file.",
1493+ (gptr*) &global_system_variables.min_examined_row_limit,
1494+ (gptr*) &max_system_variables.min_examined_row_limit, 0, GET_ULONG,
6f73e838 1495+ REQUIRED_ARG, 0, 0, LONG_MAX, 0, 1L, 0},
dcc72bc6
ER		 1496+ {"use_global_long_query_time", OPT_USE_GLOBAL_LONG_QUERY_TIME,
1497+ "Control always use global long_query_time or local long_query_time.",
1498+ (gptr*) &opt_use_global_long_query_time, (gptr*) &opt_use_global_long_query_time,
1499+ 0, GET_BOOL, NO_ARG, 0, 0, 1, 0, 1, 0},
833f2639
ER		 1500 {"lower_case_table_names", OPT_LOWER_CASE_TABLE_NAMES,
1501 "If set to 1 table names are stored in lowercase on disk and table names will be case-insensitive. Should be set to 2 if you are using a case insensitive file system",
1502 (gptr*) &lower_case_table_names,
36400f81 1503@@ -6915,7 +6959,11 @@
833f2639
ER		 1504 global_system_variables.max_join_size= (ulonglong) HA_POS_ERROR;
1505 max_system_variables.max_join_size= (ulonglong) HA_POS_ERROR;
1506 global_system_variables.old_passwords= 0;
1507-
6f73e838
ER		 1508+ global_system_variables.long_query_time = 10000000;
1509+ max_system_variables.long_query_time = LONG_TIMEOUT * 1000000;
833f2639
ER		 1510+ global_system_variables.log_slow_verbosity= SLOG_V_MICROTIME;
1511+ global_system_variables.log_slow_filter= SLOG_F_NONE;
1512+
1513 /*
1514 Default behavior for 4.1 and 5.0 is to treat NULL values as unequal
1515 when collecting index statistics for MyISAM tables.
36400f81 1516@@ -7386,6 +7434,35 @@
833f2639
ER		 1517 case OPT_BOOTSTRAP:
1518 opt_noacl=opt_bootstrap=1;
1519 break;
1520+ case OPT_LOG_SLOW_FILTER:
1521+ if ((global_system_variables.log_slow_filter=
1522+ msl_flag_resolve_by_name(slog_filter, argument,
1523+ SLOG_F_NONE, SLOG_F_INVALID)) == SLOG_F_INVALID)
1524+ {
6f73e838 1525+ fprintf(stderr,"Invalid argument in log_slow_filter: %s\n", argument);
833f2639
ER		 1526+ exit(1);
1527+ }
1528+ break;
1529+ case OPT_LOG_SLOW_VERBOSITY:
1530+ if ((global_system_variables.log_slow_verbosity=
1531+ msl_flag_resolve_by_name(slog_verb, argument,
1532+ SLOG_V_NONE, SLOG_V_INVALID)) == SLOG_V_INVALID)
1533+ {
6f73e838
ER		 1534+ fprintf(stderr,"Invalid argument in log_slow_verbosity: %s\n", argument);
1535+ exit(1);
1536+ }
1537+ break;
1538+ case OPT_LONG_QUERY_TIME:
1539+ {
1540+ double doubleslow = strtod(argument,NULL);
1541+ if (doubleslow < 0 || doubleslow > (LONG_TIMEOUT))
1542+ {
1543+ fprintf(stderr,"Out of range long_query_time value: %s\n", argument);
833f2639
ER		 1544+ exit(1);
1545+ }
6f73e838 1546+ global_system_variables.long_query_time = (ulonglong) (doubleslow * 1000000);
833f2639 1547+ break;
6f73e838 1548+ }
833f2639
ER		 1549 case OPT_STORAGE_ENGINE:
1550 {
1551 if ((enum db_type)((global_system_variables.table_type=
36400f81 1552@@ -7718,10 +7795,14 @@
833f2639
ER		 1553 if (opt_bdb)
1554 sql_print_warning("this binary does not contain BDB storage engine");
1555 #endif
1556- if ((opt_log_slow_admin_statements || opt_log_queries_not_using_indexes) &&
1557+ if ((opt_log_slow_admin_statements || opt_log_queries_not_using_indexes ||
1558+ opt_log_slow_slave_statements) &&
1559 !opt_slow_log)
1560- sql_print_warning("options --log-slow-admin-statements and --log-queries-not-using-indexes have no effect if --log-slow-queries is not set");
1561-
1562+ {
1563+ sql_print_warning("options --log-slow-admin-statements, --log-slow-slave-statements and --log-queries-not-using-indexes have no effect if --log-slow-queries is not set");
1564+ opt_log_slow_slave_statements= FALSE;
1565+ }
1566+
1567 if (argc > 0)
1568 {
1569 fprintf(stderr, "%s: Too many arguments (first extra is '%s').\nUse --help to get a list of available options\n", my_progname, *argv);
36400f81 1570diff -ruN a/sql/set_var.cc b/sql/set_var.cc
89b96684
ER		 1571--- a/sql/set_var.cc Tue Jul 28 23:39:12 2009 -0700
1572+++ b/sql/set_var.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 1573@@ -218,9 +218,13 @@
833f2639
ER		 1574 sys_log_queries_not_using_indexes("log_queries_not_using_indexes",
1575 &opt_log_queries_not_using_indexes);
1576 sys_var_thd_ulong sys_log_warnings("log_warnings", &SV::log_warnings);
1577-sys_var_thd_ulong sys_long_query_time("long_query_time",
6f73e838 1578+sys_var_thd_microtime sys_long_query_time("long_query_time",
833f2639 1579 &SV::long_query_time);
dcc72bc6
ER		 1580+sys_var_bool_ptr sys_use_global_long_query_time("use_global_long_query_time",
1581+ &opt_use_global_long_query_time);
833f2639 1582 sys_var_bool_const_ptr sys_log_slow("log_slow_queries", &opt_slow_log);
6f73e838
ER		 1583+sys_var_log_slow sys_slow_query_log("slow_query_log", &opt_slow_log);
1584+sys_var_const_str_ptr sys_slow_query_log_file("slow_query_log_file", &opt_slow_logname);
833f2639 1585 sys_var_thd_bool sys_low_priority_updates("low_priority_updates",
6f73e838
ER		 1586 &SV::low_priority_updates,
1587 fix_low_priority_updates);
36400f81 1588@@ -284,6 +288,8 @@
833f2639
ER		 1589 &SV::max_tmp_tables);
1590 sys_var_long_ptr sys_max_write_lock_count("max_write_lock_count",
1591 &max_write_lock_count);
1592+sys_var_thd_ulong sys_min_examined_row_limit("min_examined_row_limit",
1593+ &SV::min_examined_row_limit);
1594 sys_var_thd_ulong sys_multi_range_count("multi_range_count",
1595 &SV::multi_range_count);
1596 sys_var_long_ptr sys_myisam_data_pointer_size("myisam_data_pointer_size",
36400f81 1597@@ -328,6 +334,20 @@
833f2639
ER		 1598 sys_var_bool_ptr sys_relay_log_purge("relay_log_purge",
1599 &relay_log_purge);
1600 #endif
1601+sys_var_thd_ulong sys_log_slow_rate_limit("log_slow_rate_limit",
1602+ &SV::log_slow_rate_limit);
1603+sys_var_thd_msl_flag sys_log_slow_filter("log_slow_filter",
1604+ &SV::log_slow_filter,
1605+ SLOG_F_NONE,
1606+ SLOG_F_NONE,
1607+ SLOG_F_INVALID,
1608+ slog_filter);
1609+sys_var_thd_msl_flag sys_log_slow_verbosity("log_slow_verbosity",
1610+ &SV::log_slow_verbosity,
1611+ SLOG_V_NONE,
1612+ SLOG_V_MICROTIME,
1613+ SLOG_V_INVALID,
1614+ slog_verb);
1615 sys_var_long_ptr sys_rpl_recovery_rank("rpl_recovery_rank",
1616 &rpl_recovery_rank);
1617 sys_var_long_ptr sys_query_cache_size("query_cache_size",
36400f81 1618@@ -702,6 +722,10 @@
833f2639
ER		 1619 &sys_log_off,
1620 &sys_log_queries_not_using_indexes,
1621 &sys_log_slow,
1622+ &sys_log_slow_filter,
1623+ &sys_log_slow_rate_limit,
1624+ &sys_log_slow_verbosity,
dcc72bc6 1625+ &sys_use_global_long_query_time,
833f2639
ER		 1626 &sys_log_update,
1627 &sys_log_warnings,
1628 &sys_long_query_time,
36400f81 1629@@ -725,6 +749,7 @@
833f2639
ER		 1630 &sys_max_tmp_tables,
1631 &sys_max_user_connections,
1632 &sys_max_write_lock_count,
1633+ &sys_min_examined_row_limit,
1634 &sys_multi_range_count,
1635 &sys_myisam_data_pointer_size,
1636 &sys_myisam_max_sort_file_size,
36400f81 1637@@ -779,6 +804,8 @@
6f73e838
ER		 1638 &sys_slave_skip_counter,
1639 #endif
1640 &sys_slow_launch_time,
1641+ &sys_slow_query_log,
1642+ &sys_slow_query_log_file,
1643 &sys_sort_buffer,
1644 &sys_sql_big_tables,
1645 &sys_sql_low_priority_updates,
36400f81 1646@@ -1000,8 +1027,11 @@
833f2639
ER		 1647 {"log_slave_updates", (char*) &opt_log_slave_updates, SHOW_MY_BOOL},
1648 #endif
1649 {sys_log_slow.name, (char*) &sys_log_slow, SHOW_SYS},
1650+ {sys_log_slow_filter.name, (char*) &sys_log_slow_filter, SHOW_SYS},
6f73e838 1651+ {sys_log_slow_rate_limit.name, (char*) &sys_log_slow_rate_limit, SHOW_SYS},
833f2639
ER		 1652+ {sys_log_slow_verbosity.name, (char*) &sys_log_slow_verbosity, SHOW_SYS},
1653 {sys_log_warnings.name, (char*) &sys_log_warnings, SHOW_SYS},
6f73e838
ER		 1654- {sys_long_query_time.name, (char*) &sys_long_query_time, SHOW_SYS},
1655+ {sys_long_query_time.name, (char*) &sys_long_query_time, SHOW_MICROTIME},
833f2639 1656 {sys_low_priority_updates.name, (char*) &sys_low_priority_updates, SHOW_SYS},
6f73e838
ER		 1657 {"lower_case_file_system", (char*) &lower_case_file_system, SHOW_MY_BOOL},
1658 {"lower_case_table_names", (char*) &lower_case_table_names, SHOW_INT},
36400f81 1659@@ -1028,6 +1058,7 @@
833f2639
ER		 1660 {sys_max_tmp_tables.name, (char*) &sys_max_tmp_tables, SHOW_SYS},
1661 {sys_max_user_connections.name,(char*) &sys_max_user_connections, SHOW_SYS},
1662 {sys_max_write_lock_count.name, (char*) &sys_max_write_lock_count,SHOW_SYS},
1663+ {sys_min_examined_row_limit.name, (char*) &sys_min_examined_row_limit, SHOW_SYS},
1664 {sys_multi_range_count.name, (char*) &sys_multi_range_count, SHOW_SYS},
1665 {sys_myisam_data_pointer_size.name, (char*) &sys_myisam_data_pointer_size, SHOW_SYS},
1666 {sys_myisam_max_sort_file_size.name, (char*) &sys_myisam_max_sort_file_size,
36400f81 1667@@ -1116,6 +1147,8 @@
6f73e838
ER		 1668 {sys_slave_trans_retries.name,(char*) &sys_slave_trans_retries, SHOW_SYS},
1669 #endif
1670 {sys_slow_launch_time.name, (char*) &sys_slow_launch_time, SHOW_SYS},
1671+ {sys_slow_query_log.name, (char*) &sys_slow_query_log, SHOW_SYS},
1672+ {sys_slow_query_log_file.name,(char*) &sys_slow_query_log_file, SHOW_SYS},
1673 #ifdef HAVE_SYS_UN_H
1674 {"socket", (char*) &mysqld_unix_port, SHOW_CHAR_PTR},
1675 #endif
36400f81 1676@@ -1156,6 +1189,7 @@
dcc72bc6
ER		 1677 {sys_tx_isolation.name, (char*) &sys_tx_isolation, SHOW_SYS},
1678 {sys_updatable_views_with_limit.name,
1679 (char*) &sys_updatable_views_with_limit,SHOW_SYS},
1680+ {sys_use_global_long_query_time.name, (char*) &sys_use_global_long_query_time, SHOW_SYS},
1681 {sys_version.name, (char*) &sys_version, SHOW_SYS},
1682 #ifdef HAVE_BERKELEY_DB
1683 {sys_version_bdb.name, (char*) &sys_version_bdb, SHOW_SYS},
36400f81 1684@@ -1784,6 +1818,17 @@
833f2639
ER		 1685 }
1686
6f73e838 1687
833f2639
ER		 1688+bool sys_var_thd_microtime::check(THD *thd, set_var *var)
1689+{
1690+ if (var->value->result_type() == DECIMAL_RESULT)
1691+ var->save_result.ulonglong_value= (ulonglong)(var->value->val_real() * 1000000);
6f73e838
ER		 1692+ else
1693+ var->save_result.ulonglong_value= (ulonglong)(var->value->val_int() * 1000000);
1694+
833f2639
ER		 1695+ return 0;
1696+}
1697+
833f2639 1698+
6f73e838
ER		 1699 bool sys_var_thd_bool::update(THD *thd, set_var *var)
1700 {
1701 if (var->type == OPT_GLOBAL)
36400f81 1702@@ -1940,6 +1985,19 @@
6f73e838
ER		 1703 pthread_mutex_unlock(&LOCK_global_system_variables);
1704 return new Item_int(value);
45532174 1705 }
6f73e838
ER		 1706+ case SHOW_MICROTIME:
1707+ {
1708+ longlong value;
1709+ char buff[80];
1710+ int len;
833f2639 1711+
6f73e838
ER		 1712+ pthread_mutex_lock(&LOCK_global_system_variables);
1713+ value= *(longlong*) value_ptr(thd, var_type, base);
1714+ pthread_mutex_unlock(&LOCK_global_system_variables);
833f2639 1715+
6f73e838
ER		 1716+ len = snprintf(buff, 80, "%f", ((double) value) / 1000000.0);
1717+ return new Item_float(buff,len);
45532174 1718+ }
6f73e838
ER		 1719 case SHOW_HA_ROWS:
1720 {
45532174 1721 ha_rows value;
36400f81 1722@@ -2772,6 +2830,30 @@
6f73e838
ER		 1723 }
1724
1725
1726+bool sys_var_log_slow::update(THD *thd, set_var *var)
1727+{
1728+ bool ret;
833f2639 1729+
6f73e838
ER		 1730+ pthread_mutex_lock(&LOCK_global_system_variables);
1731+ if (var->save_result.ulong_value)
833f2639 1732+ {
6f73e838
ER		 1733+ if(!mysql_slow_log.is_open())
1734+ {
1735+ mysql_slow_log.open_slow_log(opt_slow_logname);
1736+ }
833f2639 1737+ }
6f73e838 1738+ pthread_mutex_unlock(&LOCK_global_system_variables);
833f2639 1739+
6f73e838
ER		 1740+ ret = sys_var_bool_ptr::update(thd, var);
1741+
1742+#ifdef HAVE_INNOBASE_DB
1743+ innobase_update_var_slow_log();
1744+#endif
1745+
1746+ return(ret);
833f2639 1747+}
6f73e838
ER		 1748+
1749+
1750 #ifdef HAVE_REPLICATION
1751 bool sys_var_slave_skip_counter::check(THD *thd, set_var *var)
833f2639 1752 {
36400f81 1753@@ -3568,6 +3650,191 @@
833f2639
ER		 1754 #endif
1755 }
1756
1757+/* Slow log stuff */
1758+
1759+ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len)
1760+{
1761+ ulong i;
1762+
1763+ for (i=0; opts[i].name; i++)
1764+ {
1765+ if (!my_strnncoll(&my_charset_latin1,
1766+ (const uchar *)name, len,
1767+ (const uchar *)opts[i].name, strlen(opts[i].name)))
1768+ return opts[i].val;
1769+ }
1770+ return opts[i].val;
1771+}
1772+
1773+ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
1774+ const ulong none_val, const ulong invalid_val)
1775+{
1776+ const char *p, *e;
1777+ ulong val= none_val;
1778+
1779+ if (!*names_list)
1780+ return val;
1781+
1782+ for (p= e= names_list; ; e++)
1783+ {
1784+ ulong i;
1785+
1786+ if (*e != ',' && *e)
1787+ continue;
1788+ for (i=0; opts[i].name; i++)
1789+ {
1790+ if (!my_strnncoll(&my_charset_latin1,
1791+ (const uchar *)p, e - p,
1792+ (const uchar *)opts[i].name, strlen(opts[i].name)))
1793+ {
1794+ val= val | opts[i].val;
1795+ break;
1796+ }
1797+ }
1798+ if (opts[i].val == invalid_val)
1799+ return invalid_val;
1800+ if (!*e)
1801+ break;
1802+ p= e + 1;
1803+ }
1804+ return val;
1805+}
1806+
1807+const char *msl_option_get_name(const struct msl_opts *opts, ulong val)
1808+{
1809+ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
1810+ {
1811+ if (opts[i].val == val)
1812+ return opts[i].name;
1813+ }
1814+ return "*INVALID*";
1815+}
1816+
1817+char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val)
1818+{
1819+ uint offset= 0;
1820+
1821+ *buf= '\0';
1822+ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
1823+ {
1824+ if (opts[i].val & val)
1825+ offset+= snprintf(buf+offset, STRING_BUFFER_USUAL_SIZE - offset - 1,
1826+ "%s%s", (offset ? "," : ""), opts[i].name);
1827+ }
1828+ return buf;
1829+}
1830+
1831+/****************************************************************************
1832+ Functions to handle log_slow_verbosity
1833+****************************************************************************/
1834+
1835+/* Based upon sys_var::check_enum() */
1836+
1837+bool sys_var_thd_msl_option::check(THD *thd, set_var *var)
1838+{
1839+ char buff[STRING_BUFFER_USUAL_SIZE];
1840+ String str(buff, sizeof(buff), &my_charset_latin1), *res;
1841+
1842+ if (var->value->result_type() == STRING_RESULT)
1843+ {
1844+ ulong verb= this->invalid_val;
1845+ if (!(res=var->value->val_str(&str)) ||
1846+ (var->save_result.ulong_value=
1847+ (ulong) (verb= msl_option_resolve_by_name(this->opts, res->ptr(), res->length()))) == this->invalid_val)
1848+ goto err;
1849+ return 0;
1850+ }
1851+
1852+err:
1853+ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
1854+ return 1;
1855+}
1856+
1857+byte *sys_var_thd_msl_option::value_ptr(THD *thd, enum_var_type type,
1858+ LEX_STRING *base)
1859+{
1860+ ulong val;
1861+ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
1862+ thd->variables.*offset);
1863+ const char *verbosity= msl_option_get_name(this->opts, val);
1864+ return (byte *) verbosity;
1865+}
1866+
1867+
1868+void sys_var_thd_msl_option::set_default(THD *thd, enum_var_type type)
1869+{
1870+ if (type == OPT_GLOBAL)
1871+ global_system_variables.*offset= (ulong) this->default_val;
1872+ else
1873+ thd->variables.*offset= (ulong) (global_system_variables.*offset);
1874+}
1875+
1876+
1877+bool sys_var_thd_msl_option::update(THD *thd, set_var *var)
1878+{
1879+ if (var->type == OPT_GLOBAL)
1880+ global_system_variables.*offset= var->save_result.ulong_value;
1881+ else
1882+ thd->variables.*offset= var->save_result.ulong_value;
1883+ return 0;
1884+}
1885+
1886+/****************************************************************************
1887+ Functions to handle log_slow_filter
1888+****************************************************************************/
1889+
1890+/* Based upon sys_var::check_enum() */
1891+
1892+bool sys_var_thd_msl_flag::check(THD *thd, set_var *var)
1893+{
1894+ char buff[2 * STRING_BUFFER_USUAL_SIZE];
1895+ String str(buff, sizeof(buff), &my_charset_latin1), *res;
1896+
1897+ if (var->value->result_type() == STRING_RESULT)
1898+ {
1899+ ulong filter= this->none_val;
1900+ if (!(res=var->value->val_str(&str)) ||
1901+ (var->save_result.ulong_value=
1902+ (ulong) (filter= msl_flag_resolve_by_name(this->flags, res->ptr(), this->none_val,
1903+ this->invalid_val))) == this->invalid_val)
1904+ goto err;
1905+ return 0;
1906+ }
1907+
1908+err:
1909+ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
1910+ return 1;
1911+}
1912+
1913+byte *sys_var_thd_msl_flag::value_ptr(THD *thd, enum_var_type type,
1914+ LEX_STRING *base)
1915+{
1916+ ulong val;
1917+ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
1918+ thd->variables.*offset);
1919+ msl_flag_get_name(this->flags, this->flags_string, val);
1920+ return (byte *) this->flags_string;
1921+}
1922+
1923+
1924+void sys_var_thd_msl_flag::set_default(THD *thd, enum_var_type type)
1925+{
1926+ if (type == OPT_GLOBAL)
1927+ global_system_variables.*offset= (ulong) this->default_val;
1928+ else
1929+ thd->variables.*offset= (ulong) (global_system_variables.*offset);
1930+}
1931+
1932+
1933+bool sys_var_thd_msl_flag::update(THD *thd, set_var *var)
1934+{
1935+ if (var->type == OPT_GLOBAL)
1936+ global_system_variables.*offset= var->save_result.ulong_value;
1937+ else
1938+ thd->variables.*offset= var->save_result.ulong_value;
1939+ return 0;
1940+}
1941+
1942 /****************************************************************************
1943 Functions to handle table_type
1944 ****************************************************************************/
36400f81 1945diff -ruN a/sql/set_var.h b/sql/set_var.h
89b96684
ER		 1946--- a/sql/set_var.h Tue Jul 28 23:39:12 2009 -0700
1947+++ b/sql/set_var.h Tue Jul 28 23:42:44 2009 -0700
6f73e838 1948@@ -132,6 +132,7 @@
833f2639
ER		 1949 };
1950
1951
1952+
1953 class sys_var_ulonglong_ptr :public sys_var
1954 {
1955 public:
6f73e838
ER		 1956@@ -168,6 +169,13 @@
1957 bool check_update_type(Item_result type) { return 0; }
1958 };
1959
1960+class sys_var_log_slow :public sys_var_bool_ptr
1961+{
1962+public:
1963+ sys_var_log_slow(const char *name_arg, my_bool *value_arg)
1964+ :sys_var_bool_ptr(name_arg, value_arg) {}
1965+ bool update(THD *thd, set_var *var);
1966+};
1967
1968 class sys_var_bool_const_ptr : public sys_var
1969 {
1970@@ -340,7 +348,6 @@
833f2639
ER		 1971 }
1972 };
1973
1974-
1975 class sys_var_thd_ulong :public sys_var_thd
1976 {
1977 sys_check_func check_func;
6f73e838 1978@@ -360,7 +367,6 @@
833f2639
ER		 1979 byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
1980 };
1981
6f73e838 1982-
833f2639
ER		 1983 class sys_var_thd_ha_rows :public sys_var_thd
1984 {
6f73e838 1985 public:
45532174 1986@@ -378,7 +384,6 @@
833f2639
ER		 1987 byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
1988 };
833f2639 1989
45532174 1990-
833f2639
ER		 1991 class sys_var_thd_ulonglong :public sys_var_thd
1992 {
45532174 1993 public:
6f73e838 1994@@ -407,6 +412,19 @@
833f2639
ER		 1995 }
1996 };
1997
6f73e838
ER		 1998+class sys_var_thd_microtime :public sys_var_thd_ulonglong
1999+{
2000+public:
2001+ sys_var_thd_microtime(const char *name_arg, ulonglong SV::*offset_arg)
2002+ :sys_var_thd_ulonglong(name_arg, offset_arg)
2003+ {}
2004+ SHOW_TYPE show_type() { return SHOW_MICROTIME; }
2005+ bool check(THD *thd, set_var *var);
2006+ bool check_update_type(Item_result type)
2007+ {
2008+ return type != INT_RESULT && type != DECIMAL_RESULT;
2009+ }
2010+};
2011
833f2639
ER		 2012 class sys_var_thd_bool :public sys_var_thd
2013 {
45532174 2014@@ -478,6 +496,66 @@
833f2639
ER		 2015 };
2016
45532174 2017
833f2639
ER		 2018+class sys_var_thd_msl_option :public sys_var_thd
2019+{
2020+protected:
2021+ ulong SV::*offset;
2022+ const ulong none_val;
2023+ const ulong default_val;
2024+ const ulong invalid_val;
2025+ const struct msl_opts *opts;
2026+public:
2027+ sys_var_thd_msl_option(const char *name_arg, ulong SV::*offset_arg,
2028+ const ulong none_val_arg,
2029+ const ulong default_val_arg,
2030+ const ulong invalid_val_arg,
2031+ const struct msl_opts *opts_arg)
2032+ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
2033+ default_val(default_val_arg), invalid_val(invalid_val_arg),
2034+ opts(opts_arg)
2035+ {}
2036+ bool check(THD *thd, set_var *var);
2037+ SHOW_TYPE show_type() { return SHOW_CHAR; }
2038+ bool check_update_type(Item_result type)
2039+ {
2040+ return type != STRING_RESULT; /* Only accept strings */
2041+ }
2042+ void set_default(THD *thd, enum_var_type type);
2043+ bool update(THD *thd, set_var *var);
2044+ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
2045+};
2046+
2047+
2048+class sys_var_thd_msl_flag :public sys_var_thd
2049+{
2050+protected:
2051+ char flags_string[2 * STRING_BUFFER_USUAL_SIZE];
2052+ ulong SV::*offset;
2053+ const ulong none_val;
2054+ const ulong default_val;
2055+ const ulong invalid_val;
2056+ const struct msl_opts *flags;
2057+public:
2058+ sys_var_thd_msl_flag(const char *name_arg, ulong SV::*offset_arg,
2059+ const ulong none_val_arg,
2060+ const ulong default_val_arg,
2061+ const ulong invalid_val_arg,
2062+ const struct msl_opts *flags_arg)
2063+ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
2064+ default_val(default_val_arg), invalid_val(invalid_val_arg),
2065+ flags(flags_arg)
2066+ {}
2067+ bool check(THD *thd, set_var *var);
2068+ SHOW_TYPE show_type() { return SHOW_CHAR; }
2069+ bool check_update_type(Item_result type)
2070+ {
2071+ return type != STRING_RESULT; /* Only accept strings */
2072+ }
2073+ void set_default(THD *thd, enum_var_type type);
2074+ bool update(THD *thd, set_var *var);
2075+ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
2076+};
45532174 2077+
833f2639
ER		 2078 class sys_var_thd_storage_engine :public sys_var_thd
2079 {
45532174 2080 protected:
89b96684 2081@@ -1109,3 +1187,11 @@
833f2639
ER		 2082 bool process_key_caches(int (* func) (const char *name, KEY_CACHE *));
2083 void delete_elements(I_List<NAMED_LIST> *list,
2084 void (*free_element)(const char*, gptr));
2085+
2086+/* Slow log functions */
2087+
2088+ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len);
2089+ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
2090+ const ulong none_val, const ulong invalid_val);
2091+const char *msl_option_get_name(const struct msl_opts *opts, ulong val);
2092+char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val);
36400f81 2093diff -ruN a/sql/slave.cc b/sql/slave.cc
89b96684
ER		 2094--- a/sql/slave.cc Tue Jul 28 23:39:12 2009 -0700
2095+++ b/sql/slave.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 2096@@ -2981,6 +2981,12 @@
833f2639
ER		 2097 + MAX_LOG_EVENT_HEADER; /* note, incr over the global not session var */
2098 thd->slave_thread = 1;
2099 set_slave_thread_options(thd);
2100+ if (opt_log_slow_slave_statements)
2101+ {
2102+ thd->enable_slow_log= TRUE;
2103+ /* Slave thread is excluded from rate limiting the slow log writes. */
2104+ thd->write_to_slow_log= TRUE;
2105+ }
2106 thd->client_capabilities = CLIENT_LOCAL_FILES;
2107 thd->real_id=pthread_self();
2108 pthread_mutex_lock(&LOCK_thread_count);
36400f81 2109diff -ruN a/sql/sql_cache.cc b/sql/sql_cache.cc
89b96684
ER		 2110--- a/sql/sql_cache.cc Tue Jul 28 23:39:12 2009 -0700
2111+++ b/sql/sql_cache.cc Tue Jul 28 23:42:44 2009 -0700
45532174 2112@@ -1402,6 +1402,7 @@
833f2639
ER		 2113
2114 thd->limit_found_rows = query->found_rows();
2115 thd->status_var.last_query_cost= 0.0;
2116+ thd->query_plan_flags|= QPLAN_QC;
2117
2118 BLOCK_UNLOCK_RD(query_block);
2119 DBUG_RETURN(1); // Result sent to client
45532174 2120@@ -1409,6 +1410,7 @@
833f2639
ER		 2121 err_unlock:
2122 STRUCT_UNLOCK(&structure_guard_mutex);
2123 err:
2124+ thd->query_plan_flags|= QPLAN_QC_NO;
2125 DBUG_RETURN(0); // Query was not cached
2126 }
2127
36400f81 2128diff -ruN a/sql/sql_class.cc b/sql/sql_class.cc
89b96684
ER		 2129--- a/sql/sql_class.cc Tue Jul 28 23:39:12 2009 -0700
2130+++ b/sql/sql_class.cc Tue Jul 28 23:42:44 2009 -0700
45532174
ER		 2131@@ -190,7 +190,7 @@
2132 table_map_for_update(0),
2133 global_read_lock(0), is_fatal_error(0),
833f2639
ER		 2134 transaction_rollback_request(0), is_fatal_sub_stmt_error(0),
2135- rand_used(0), time_zone_used(0),
2136+ rand_used(0), time_zone_used(0), user_timer(0),
2137 last_insert_id_used(0), last_insert_id_used_bin_log(0), insert_id_used(0),
2138 clear_next_insert_id(0), in_lock_tables(0), bootstrap(0),
2139 derived_tables_processing(FALSE), spcont(NULL),
36400f81 2140@@ -2253,6 +2253,12 @@
833f2639
ER		 2141 backup->cuted_fields= cuted_fields;
2142 backup->client_capabilities= client_capabilities;
2143 backup->savepoints= transaction.savepoints;
2144+ backup->innodb_io_reads= innodb_io_reads;
2145+ backup->innodb_io_read= innodb_io_read;
2146+ backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
2147+ backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
2148+ backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
2149+ backup->innodb_page_access= innodb_page_access;
2150
2151 if (!lex->requires_prelocking() || is_update_query(lex->sql_command))
2152 options&= ~OPTION_BIN_LOG;
36400f81 2153@@ -2269,7 +2275,13 @@
833f2639
ER		 2154 sent_row_count= 0;
2155 cuted_fields= 0;
2156 transaction.savepoints= 0;
2157-
2158+ innodb_io_reads= 0;
2159+ innodb_io_read= 0;
2160+ innodb_io_reads_wait_timer= 0;
2161+ innodb_lock_que_wait_timer= 0;
2162+ innodb_innodb_que_wait_timer= 0;
2163+ innodb_page_access= 0;
2164+
2165 /* Surpress OK packets in case if we will execute statements */
2166 net.no_send_ok= TRUE;
2167 }
36400f81 2168@@ -2322,6 +2334,12 @@
833f2639
ER		 2169 */
2170 examined_row_count+= backup->examined_row_count;
2171 cuted_fields+= backup->cuted_fields;
2172+ innodb_io_reads+= backup->innodb_io_reads;
2173+ innodb_io_read+= backup->innodb_io_read;
2174+ innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
2175+ innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
2176+ innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
2177+ innodb_page_access+= backup->innodb_page_access;
2178 }
2179
2180
3d10d797
ER		 2181--- mysql-5.0.92/sql/sql_class.h Tue Jul 28 23:39:12 2009 -0700
2182+++ mysql-5.0.92/sql/sql_class.h Tue Jul 28 23:42:44 2009 -0700
6f73e838 2183@@ -43,6 +43,7 @@
833f2639
ER		 2184 extern char internal_table_name[2];
2185 extern char empty_c_string[1];
2186 extern const char **errmesg;
833f2639 2187+extern ulonglong frequency;
833f2639 2188
36400f81
ER		 2189 extern bool volatile shutdown_in_progress;
2190
2191@@ -323,7 +324,7 @@
833f2639
ER		 2192 bool write(THD *thd, enum enum_server_command command,
2193 const char *format, ...) ATTRIBUTE_FORMAT(printf, 4, 5);
2194 bool write(THD *thd, const char *query, uint query_length,
2195- time_t query_start=0);
2196+ time_t query_start=0, ulonglong query_start_timer=0);
2197 bool write(Log_event* event_info); // binary log write
2198 bool write(THD *thd, IO_CACHE *cache, Log_event *commit_event);
2199
36400f81 2200@@ -529,13 +530,14 @@
833f2639
ER		 2201 ulong auto_increment_increment, auto_increment_offset;
2202 ulong bulk_insert_buff_size;
2203 ulong join_buff_size;
2204- ulong long_query_time;
2205+ ulonglong long_query_time;
2206 ulong max_allowed_packet;
2207 ulong max_error_count;
2208 ulong max_length_for_sort_data;
2209 ulong max_sort_length;
2210 ulong max_tmp_tables;
2211 ulong max_insert_delayed_threads;
2212+ ulong min_examined_row_limit;
2213 ulong multi_range_count;
2214 ulong myisam_repair_threads;
2215 ulong myisam_sort_buff_size;
36400f81 2216@@ -551,10 +553,13 @@
833f2639 2217 ulong preload_buff_size;
6f73e838 2218 ulong profiling_history_size;
833f2639
ER		 2219 ulong query_cache_type;
2220+ ulong log_slow_rate_limit;
2221 ulong read_buff_size;
2222 ulong read_rnd_buff_size;
2223 ulong div_precincrement;
2224 ulong sortbuff_size;
2225+ ulong log_slow_filter;
2226+ ulong log_slow_verbosity;
2227 ulong table_type;
2228 ulong tx_isolation;
2229 ulong completion_type;
36400f81 2230@@ -1127,6 +1132,12 @@
833f2639
ER		 2231 uint in_sub_stmt;
2232 bool enable_slow_log, insert_id_used, clear_next_insert_id;
2233 bool last_insert_id_used;
2234+ ulong innodb_io_reads;
2235+ ulonglong innodb_io_read;
2236+ ulong innodb_io_reads_wait_timer;
2237+ ulong innodb_lock_que_wait_timer;
2238+ ulong innodb_innodb_que_wait_timer;
2239+ ulong innodb_page_access;
2240 my_bool no_send_ok;
2241 SAVEPOINT *savepoints;
2242 };
36400f81 2243@@ -1183,6 +1194,11 @@
833f2639
ER		 2244 class THD :public Statement,
2245 public Open_tables_state
2246 {
2247+private:
2248+ inline ulonglong query_start_timer() { return start_timer; }
2249+ inline void set_timer() { if (user_timer) start_timer=timer_after_lock=user_timer; else timer_after_lock=my_timer(&start_timer, frequency); }
2250+ inline void end_timer() { my_timer(&start_timer, frequency); }
2251+ inline void lock_timer() { my_timer(&timer_after_lock, frequency); }
2252 public:
2253 /*
2254 Constant for THD::where initialization in the beginning of every query.
36400f81 2255@@ -1299,10 +1315,24 @@
833f2639
ER		 2256 */
2257 const char *where;
2258 time_t start_time,time_after_lock,user_time;
2259+ ulonglong start_timer,timer_after_lock, user_timer;
2260 time_t connect_time,thr_create_time; // track down slow pthread_create
2261 thr_lock_type update_lock_default;
2262 Delayed_insert *di;
2263
2264+ bool write_to_slow_log;
2265+
2266+ bool innodb_was_used;
2267+ ulong innodb_io_reads;
2268+ ulonglong innodb_io_read;
2269+ ulong innodb_io_reads_wait_timer;
2270+ ulong innodb_lock_que_wait_timer;
2271+ ulong innodb_innodb_que_wait_timer;
2272+ ulong innodb_page_access;
2273+
2274+ ulong query_plan_flags;
2275+ ulong query_plan_fsort_passes;
2276+
2277 /* <> 0 if we are inside of trigger or stored function. */
2278 uint in_sub_stmt;
2279
3d10d797 2280@@ -1732,11 +1732,11 @@
833f2639
ER		 2281 sql_print_information("time() failed with %d", errno);
2282 }
2283
2284- inline time_t query_start() { query_start_used=1; return start_time; }
2285- inline void set_time() { if (user_time) start_time=time_after_lock=user_time; else { safe_time(&start_time); time_after_lock= start_time; }}
2286- inline void end_time() { safe_time(&start_time); }
2287- inline void set_time(time_t t) { time_after_lock=start_time=user_time=t; }
2288- inline void lock_time() { safe_time(&time_after_lock); }
2289+ inline time_t query_start() { query_start_timer(); query_start_used=1; return start_time; }
2290+ inline void set_time() { set_timer(); if (user_time) start_time=time_after_lock=user_time; else { safe_time(&start_time); time_after_lock= start_time; }}
2291+ inline void end_time() { end_timer(); safe_time(&start_time); }
2292+ inline void set_time(time_t t) { set_timer(); time_after_lock=start_time=user_time=t; }
2293+ inline void lock_time() { lock_timer(); safe_time(&time_after_lock); }
3d10d797
ER		 2294 /*TODO: this will be obsolete when we have support for 64 bit my_time_t */
2295 inline bool is_valid_time()
2296 {
36400f81 2297diff -ruN a/sql/sql_parse.cc b/sql/sql_parse.cc
89b96684
ER		 2298--- a/sql/sql_parse.cc Tue Jul 28 23:39:12 2009 -0700
2299+++ b/sql/sql_parse.cc Tue Jul 28 23:42:44 2009 -0700
833f2639
ER		 2300@@ -20,6 +20,7 @@
2301 #include <m_ctype.h>
2302 #include <myisam.h>
2303 #include <my_dir.h>
2304+#include <my_time.h>
2305
2306 #ifdef HAVE_INNOBASE_DB
2307 #include "ha_innodb.h"
36400f81 2308@@ -1233,6 +1234,15 @@
833f2639
ER		 2309 my_net_set_read_timeout(net, thd->variables.net_read_timeout);
2310 my_net_set_write_timeout(net, thd->variables.net_write_timeout);
2311
2312+ /*
2313+ If rate limiting of slow log writes is enabled, decide whether to log this
2314+ new thread's queries or not. Uses extremely simple algorithm. :)
2315+ */
2316+ thd->write_to_slow_log= FALSE;
2317+ if (thd->variables.log_slow_rate_limit <= 1 ||
2318+ (thd->thread_id % thd->variables.log_slow_rate_limit) == 0)
2319+ thd->write_to_slow_log= TRUE;
2320+
2321 while (!net->error && net->vio != 0 &&
2322 !(thd->killed == THD::KILL_CONNECTION))
2323 {
36400f81 2324@@ -2394,28 +2404,57 @@
833f2639
ER		 2325 return; // Don't set time for sub stmt
2326
2327 start_of_query= thd->start_time;
45532174 2328- thd->end_time(); // Set start time
833f2639 2329+ ulonglong start_of_query_timer= thd->start_timer;
45532174
ER		 2330+ thd->end_time(); // Set start timea
2331+
833f2639
ER		 2332+
2333+ /* Follow the slow log filter configuration. */
45532174 2334+ if (thd->variables.log_slow_filter != SLOG_F_NONE &&
833f2639 2335+ (!(thd->variables.log_slow_filter & thd->query_plan_flags) ||
45532174 2336+ ((thd->variables.log_slow_filter & SLOG_F_QC_NO) &&
833f2639
ER		 2337+ (thd->query_plan_flags & QPLAN_QC))))
2338+ return;
2339+
2340+ /*
45532174
ER		 2341+ Low long_query_time value most likely means user is debugging stuff and even
2342+ though some thread's queries are not supposed to be logged b/c of the rate
2343+ limit, if one of them takes long enough (>= 1 second) it will be sensible
833f2639
ER		 2344+ to make an exception and write to slow log anyway.
2345+ */
45532174 2346+
dcc72bc6
ER		 2347+ if (opt_use_global_long_query_time)
2348+ thd->variables.long_query_time = global_system_variables.long_query_time;
833f2639
ER		 2349+
2350+ /* Do not log this thread's queries due to rate limiting. */
45532174
ER		 2351+ if (thd->write_to_slow_log != TRUE
2352+ && (thd->variables.long_query_time >= 1000000
2353+ || (ulong) (thd->start_timer - thd->timer_after_lock) < 1000000))
833f2639 2354+ return;
8d64228d 2355+
45532174 2356
833f2639
ER		 2357 /*
2358 Do not log administrative statements unless the appropriate option is
2359 set; do not log into slow log if reading from backup.
2360 */
2361- if (thd->enable_slow_log && !thd->user_time)
2362+ if (thd->enable_slow_log &&
2363+ (!thd->user_time || (thd->slave_thread && opt_log_slow_slave_statements))
2364+ )
45532174 2365+
833f2639 2366 {
6f73e838 2367 thd_proc_info(thd, "logging slow query");
833f2639 2368
529deea8
AM		 2369- if ((thd->start_time > thd->time_after_lock &&
2370- (ulong) (thd->start_time - thd->time_after_lock) >
45532174 2371- thd->variables.long_query_time) ||
a709df28 2372- ((thd->server_status &
45532174
ER		 2373- (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
2374- opt_log_queries_not_using_indexes &&
2375- /* == SQLCOM_END unless this is a SHOW command */
a709df28 2376- thd->lex->orig_sql_command == SQLCOM_END))
45532174
ER		 2377+ if (((ulong) (thd->start_timer - thd->timer_after_lock) >=
2378+ thd->variables.long_query_time ||
89b96684 2379+ (thd->server_status &
45532174
ER		 2380+ (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
2381+ opt_log_queries_not_using_indexes &&
2382+ /* == SQLCOM_END unless this is a SHOW command */
89b96684 2383+ thd->lex->orig_sql_command == SQLCOM_END) &&
45532174 2384+ thd->examined_row_count >= thd->variables.min_examined_row_limit)
833f2639 2385 {
6f73e838 2386 thd_proc_info(thd, "logging slow query");
833f2639
ER		 2387 thd->status_var.long_query_count++;
2388- mysql_slow_log.write(thd, thd->query, thd->query_length, start_of_query);
2389+ mysql_slow_log.write(thd, thd->query, thd->query_length, start_of_query, start_of_query_timer);
2390 }
2391 }
2392 }
36400f81 2393@@ -2710,6 +2749,8 @@
45532174
ER		 2394 context.resolve_in_table_list_only((TABLE_LIST*)select_lex->
2395 table_list.first);
2396
2397+ /* Reset the counter at all cases for the extended slow query log */
2398+ thd->row_count= 1;
2399 /*
2400 Reset warning count for each query that uses tables
2401 A better approach would be to reset this for any commands
36400f81 2402@@ -6233,6 +6274,15 @@
45532174
ER		 2403 thd->total_warn_count=0; // Warnings for this query
2404 thd->rand_used= 0;
2405 thd->sent_row_count= thd->examined_row_count= 0;
2406+ thd->innodb_was_used= FALSE;
2407+ thd->innodb_io_reads= 0;
2408+ thd->innodb_io_read= 0;
2409+ thd->innodb_io_reads_wait_timer= 0;
2410+ thd->innodb_lock_que_wait_timer= 0;
2411+ thd->innodb_innodb_que_wait_timer= 0;
2412+ thd->innodb_page_access= 0;
2413+ thd->query_plan_flags= QPLAN_NONE;
2414+ thd->query_plan_fsort_passes= 0;
2415 }
2416 DBUG_VOID_RETURN;
2417 }
36400f81 2418diff -ruN a/sql/sql_select.cc b/sql/sql_select.cc
89b96684
ER		 2419--- a/sql/sql_select.cc Tue Jul 28 23:39:12 2009 -0700
2420+++ b/sql/sql_select.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 2421@@ -6371,8 +6371,11 @@
833f2639
ER		 2422 {
2423 join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
2424 if (statistics)
2425+ {
2426 statistic_increment(join->thd->status_var.select_scan_count,
2427 &LOCK_status);
2428+ join->thd->query_plan_flags|= QPLAN_FULL_SCAN;
2429+ }
2430 }
2431 }
2432 else
36400f81 2433@@ -6387,8 +6390,11 @@
833f2639
ER		 2434 {
2435 join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
2436 if (statistics)
2437+ {
2438 statistic_increment(join->thd->status_var.select_full_join_count,
2439 &LOCK_status);
2440+ join->thd->query_plan_flags|= QPLAN_FULL_JOIN;
2441+ }
2442 }
2443 }
2444 if (!table->no_keyread)
36400f81 2445@@ -9464,6 +9470,7 @@
833f2639
ER		 2446 (ulong) rows_limit,test(group)));
2447
2448 statistic_increment(thd->status_var.created_tmp_tables, &LOCK_status);
2449+ thd->query_plan_flags|= QPLAN_TMP_TABLE;
2450
2451 if (use_temp_pool && !(test_flags & TEST_KEEP_TMP_TABLES))
2452 temp_pool_slot = bitmap_set_next(&temp_pool);
36400f81 2453@@ -10325,6 +10332,7 @@
833f2639
ER		 2454 }
2455 statistic_increment(table->in_use->status_var.created_tmp_disk_tables,
2456 &LOCK_status);
2457+ table->in_use->query_plan_flags|= QPLAN_TMP_DISK;
2458 table->s->db_record_offset= 1;
2459 DBUG_RETURN(0);
2460 err:
36400f81 2461diff -ruN a/sql/sql_show.cc b/sql/sql_show.cc
89b96684
ER		 2462--- a/sql/sql_show.cc Tue Jul 28 23:39:12 2009 -0700
2463+++ b/sql/sql_show.cc Tue Jul 28 23:42:44 2009 -0700
36400f81 2464@@ -1558,6 +1558,12 @@
833f2639
ER		 2465 case SHOW_LONGLONG:
2466 end= longlong10_to_str(*(longlong*) value, buff, 10);
45532174 2467 break;
833f2639 2468+ case SHOW_MICROTIME:
6f73e838
ER		 2469+ show_type= ((sys_var*) value)->show_type();
2470+ value= (char*) ((sys_var*) value)->value_ptr(thd, value_type,
2471+ &null_lex_str);
2472+ end= buff + sprintf(buff, "%f", (((double) (*(ulonglong*)value))) / 1000000.0);
45532174 2473+ break;
833f2639
ER		 2474 case SHOW_HA_ROWS:
2475 end= longlong10_to_str((longlong) *(ha_rows*) value, buff, 10);
45532174 2476 break;
36400f81 2477diff -ruN a/sql/structs.h b/sql/structs.h
89b96684
ER		 2478--- a/sql/structs.h Tue Jul 28 23:39:12 2009 -0700
2479+++ b/sql/structs.h Tue Jul 28 23:42:44 2009 -0700
36400f81 2480@@ -174,8 +174,8 @@
833f2639
ER		 2481 enum SHOW_TYPE
2482 {
2483 SHOW_UNDEF,
2484- SHOW_LONG, SHOW_LONGLONG, SHOW_INT, SHOW_CHAR, SHOW_CHAR_PTR,
6f73e838 2485- SHOW_DOUBLE_STATUS,
990729de 2486+ SHOW_LONG, SHOW_LONGLONG, SHOW_MICROTIME, SHOW_INT, SHOW_CHAR, SHOW_CHAR_PTR,
6f73e838 2487+ SHOW_DOUBLE_STATUS,
a1c5b050 2488 SHOW_BOOL, SHOW_MY_BOOL, SHOW_OPENTABLES, SHOW_STARTTIME, SHOW_QUERIES,
833f2639 2489 SHOW_LONG_CONST, SHOW_INT_CONST, SHOW_HAVE, SHOW_SYS, SHOW_HA_ROWS,
6f73e838 2490 SHOW_VARS,
MySQL: a very fast and reliable SQL database engine
This page took 0.351276 seconds and 4 git commands to generate.