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