MariaDB

Merge lp:~maria-captains/maria/slow-extended-patch into lp:~maria-captains/maria/5.1-converting

  1. slow-extended-patch
  2. Merge into 5.1-converting
Proposed by Vadim Tkachenko
Status: Rejected
Rejected by: Sergei Golubchik
Proposed branch: lp:~maria-captains/maria/slow-extended-patch
Merge into: lp:~maria-captains/maria/5.1-converting
Diff against target: None lines
To merge this branch: bzr merge lp:~maria-captains/maria/slow-extended-patch
Reviewer Review Type Date Requested Status
Maria-captains Pending
Review via email: mp+6840@code.launchpad.net
To post a comment you must log in.
Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

Merge contains patch
http://www.percona.com/docs/wiki/patches:microslow_innodb
(not InnoDB part, all InnoDB related things will be included in XtraDB)

Revision history for this message
Sergei Golubchik (sergii) wrote :

proposal for the old lp:~maria-captains/maria/5.1-converting tree.
it the proposal is still relevant, please resubmit for the current tree

Unmerged revisions

2707. By Vadim Tkachenko

fix do_abi_check for slow_extended

2706. By Vadim Tkachenko

extended stats in slow.log

2705. By Kristian Nielsen

Fix ps_not_windows test for -all-static build which cannot load plugins.

2704. By Kristian Nielsen

After-merge fixes for problems seen in buildbot after merging MySQL-5.1.35.

 - Version number.
 - Valgrind false alarms in libz.
 - New variant of suppression for Valgrind warning in dlclose().
 - Fix double free() in plugin init error case.

2703. By Kristian Nielsen

Fix accessing ulong enum option as uint, failing on 64-bit big-endian.

2702. By Michael Widenius

Merge

2701. By Michael Widenius

Fixed problems in merge

2700. By Michael Widenius

Merge fixes.

2699. By Michael Widenius

Merged with mysql-5.1 tree.

2698. By Michael Widenius

bzr merge from guilhem's maria tree to our local 5.1

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'include/mysql/plugin.h'
2--- include/mysql/plugin.h 2008-04-28 16:24:05 +0000
3+++ include/mysql/plugin.h 2009-05-28 05:00:21 +0000
4@@ -687,6 +687,16 @@
5 const char *set_thd_proc_info(MYSQL_THD, const char * info, const char *func,
6 const char *file, const unsigned int line);
7
8+void increment_thd_innodb_stats(MYSQL_THD thd,
9+ long io_reads,
10+ long long io_read,
11+ long io_reads_wait_timer,
12+ long lock_que_wait_timer,
13+ long que_wait_timer,
14+ long page_access);
15+unsigned long thd_log_slow_verbosity(const MYSQL_THD thd);
16+int thd_opt_slow_log();
17+
18 /**
19 Create a temporary file.
20
21
22=== modified file 'include/mysql/plugin.h.pp'
23--- include/mysql/plugin.h.pp 2008-10-10 15:28:41 +0000
24+++ include/mysql/plugin.h.pp 2009-05-28 05:54:12 +0000
25@@ -123,6 +123,15 @@
26 void thd_inc_row_count(void* thd);
27 const char *set_thd_proc_info(void*, const char * info, const char *func,
28 const char *file, const unsigned int line);
29+void increment_thd_innodb_stats(void* thd,
30+ long io_reads,
31+ long long io_read,
32+ long io_reads_wait_timer,
33+ long lock_que_wait_timer,
34+ long que_wait_timer,
35+ long page_access);
36+unsigned long thd_log_slow_verbosity(const void* thd);
37+int thd_opt_slow_log();
38 int mysql_tmpfile(const char *prefix);
39 int thd_killed(const void* thd);
40 unsigned long thd_get_thread_id(const void* thd);
41
42=== modified file 'scripts/mysqldumpslow.sh'
43--- scripts/mysqldumpslow.sh 2009-02-24 08:07:40 +0000
44+++ scripts/mysqldumpslow.sh 2009-05-28 05:00:21 +0000
45@@ -83,8 +83,8 @@
46 s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//;
47 my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('','');
48
49- s/^# Query_time: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\n//;
50- my ($t, $l, $r) = ($1, $2, $3);
51+ s/^# Query_time: (\d+(\.\d+)?) Lock_time: (\d+(\.\d+)?) Rows_sent: (\d+(\.\d+)?).*\n//;
52+ my ($t, $l, $r) = ($1, $3, $5);
53 $t -= $l unless $opt{l};
54
55 # remove fluff that mysqld writes to log when it (re)starts:
56
57=== modified file 'sql/event_scheduler.cc'
58--- sql/event_scheduler.cc 2008-12-03 04:07:50 +0000
59+++ sql/event_scheduler.cc 2009-05-28 05:00:21 +0000
60@@ -192,6 +192,7 @@
61 thd->client_capabilities|= CLIENT_MULTI_RESULTS;
62 pthread_mutex_lock(&LOCK_thread_count);
63 thd->thread_id= thd->variables.pseudo_thread_id= thread_id++;
64+ thd->write_to_slow_log = TRUE;
65 pthread_mutex_unlock(&LOCK_thread_count);
66
67 /*
68
69=== modified file 'sql/filesort.cc'
70--- sql/filesort.cc 2009-05-06 12:03:24 +0000
71+++ sql/filesort.cc 2009-05-28 05:00:21 +0000
72@@ -188,6 +188,7 @@
73 {
74 status_var_increment(thd->status_var.filesort_scan_count);
75 }
76+ thd->query_plan_flags|= QPLAN_FILESORT;
77 #ifdef CAN_TRUST_RANGE
78 if (select && select->quick && select->quick->records > 0L)
79 {
80@@ -253,6 +254,7 @@
81 }
82 else
83 {
84+ thd->query_plan_flags|= QPLAN_FILESORT_DISK;
85 if (table_sort.buffpek && table_sort.buffpek_len < maxbuffer)
86 {
87 x_free(table_sort.buffpek);
88@@ -1199,6 +1201,7 @@
89 DBUG_ENTER("merge_buffers");
90
91 status_var_increment(current_thd->status_var.filesort_merge_passes);
92+ current_thd->query_plan_fsort_passes++;
93 if (param->not_killable)
94 {
95 killed= &not_killable;
96
97=== modified file 'sql/log.cc'
98--- sql/log.cc 2009-04-25 10:05:32 +0000
99+++ sql/log.cc 2009-05-28 05:00:21 +0000
100@@ -964,7 +964,7 @@
101 /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */
102 user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,
103 sctx->priv_user ? sctx->priv_user : "", "[",
104- sctx->user ? sctx->user : "", "] @ ",
105+ sctx->user ? sctx->user : (thd->slave_thread ? "SQL_SLAVE" : ""), "] @ ",
106 sctx->host ? sctx->host : "", " [",
107 sctx->ip ? sctx->ip : "", "]", NullS) -
108 user_host_buff);
109@@ -987,6 +987,15 @@
110 query_length= command_name[thd->command].length;
111 }
112
113+ if (!query_length)
114+ {
115+ thd->sent_row_count= thd->examined_row_count= 0;
116+ thd->row_count= 0;
117+ thd->innodb_was_used= FALSE;
118+ thd->query_plan_flags= QPLAN_NONE;
119+ thd->query_plan_fsort_passes= 0;
120+ }
121+
122 for (current_handler= slow_log_handler_list; *current_handler ;)
123 error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,
124 user_host_buff, user_host_len,
125@@ -2206,12 +2215,50 @@
126 sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);
127 sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0);
128 if (my_b_printf(&log_file,
129- "# Query_time: %s Lock_time: %s"
130- " Rows_sent: %lu Rows_examined: %lu\n",
131+ "# Thread_id: %lu Schema: %s\n" \
132+ "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu Rows_affected: %lu Rows_read: %lu\n",
133+ (ulong) thd->thread_id, (thd->db ? thd->db : ""),
134 query_time_buff, lock_time_buff,
135 (ulong) thd->sent_row_count,
136- (ulong) thd->examined_row_count) == (uint) -1)
137+ (ulong) thd->examined_row_count,
138+ ((long) thd->row_count_func > 0 ) ? (ulong) thd->row_count_func : 0,
139+ (ulong) thd->row_count) == (uint) -1)
140 tmp_errno= errno;
141+ if ((thd->variables.log_slow_verbosity & SLOG_V_QUERY_PLAN) &&
142+ my_b_printf(&log_file,
143+ "# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s Tmp_table_on_disk: %s\n" \
144+ "# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n",
145+ ((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"),
146+ ((thd->query_plan_flags & QPLAN_FULL_SCAN) ? "Yes" : "No"),
147+ ((thd->query_plan_flags & QPLAN_FULL_JOIN) ? "Yes" : "No"),
148+ ((thd->query_plan_flags & QPLAN_TMP_TABLE) ? "Yes" : "No"),
149+ ((thd->query_plan_flags & QPLAN_TMP_DISK) ? "Yes" : "No"),
150+ ((thd->query_plan_flags & QPLAN_FILESORT) ? "Yes" : "No"),
151+ ((thd->query_plan_flags & QPLAN_FILESORT_DISK) ? "Yes" : "No"),
152+ thd->query_plan_fsort_passes) == (uint) -1)
153+ tmp_errno=errno;
154+ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) && thd->innodb_was_used)
155+ {
156+ char buf[3][20];
157+ snprintf(buf[0], 20, "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0);
158+ snprintf(buf[1], 20, "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0);
159+ snprintf(buf[2], 20, "%.6f", thd->innodb_innodb_que_wait_timer / 1000000.0);
160+ if (my_b_printf(&log_file,
161+ "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %lu InnoDB_IO_r_wait: %s\n" \
162+ "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n" \
163+ "# InnoDB_pages_distinct: %lu\n",
164+ (ulong) thd->innodb_io_reads,
165+ (ulong) thd->innodb_io_read,
166+ buf[0], buf[1], buf[2],
167+ (ulong) thd->innodb_page_access) == (uint) -1)
168+ tmp_errno=errno;
169+ }
170+ else
171+ {
172+ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) &&
173+ my_b_printf(&log_file,"# No InnoDB statistics available for this query\n") == (uint) -1)
174+ tmp_errno=errno;
175+ }
176 if (thd->db && strcmp(thd->db, db))
177 { // Database changed
178 if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)
179
180=== modified file 'sql/mysql_priv.h'
181--- sql/mysql_priv.h 2009-04-25 10:05:32 +0000
182+++ sql/mysql_priv.h 2009-05-28 05:00:21 +0000
183@@ -614,6 +614,78 @@
184
185 #define STRING_BUFFER_USUAL_SIZE 80
186
187+/* Slow log */
188+
189+struct msl_opts
190+{
191+ ulong val;
192+ const char *name;
193+};
194+
195+#define SLOG_V_MICROTIME 1 << 0
196+#define SLOG_V_QUERY_PLAN 1 << 1
197+#define SLOG_V_INNODB 1 << 2
198+/* ... */
199+#define SLOG_V_INVALID 1 << 31
200+#define SLOG_V_NONE SLOG_V_MICROTIME
201+
202+static const struct msl_opts slog_verb[]=
203+{
204+ /* Basic flags */
205+
206+ { SLOG_V_MICROTIME, "microtime" },
207+ { SLOG_V_QUERY_PLAN, "query_plan" },
208+ { SLOG_V_INNODB, "innodb" },
209+
210+ /* End of baisc flags */
211+
212+ { 0, "" },
213+
214+ /* Complex flags */
215+
216+ { SLOG_V_MICROTIME, "minimal" },
217+ { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN, "standard" },
218+ { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN|SLOG_V_INNODB, "full" },
219+
220+ /* End of complex flags */
221+
222+ { SLOG_V_INVALID, (char *)0 }
223+};
224+
225+#define QPLAN_NONE 0
226+#define QPLAN_QC 1 << 0
227+#define QPLAN_QC_NO 1 << 1
228+#define QPLAN_FULL_SCAN 1 << 2
229+#define QPLAN_FULL_JOIN 1 << 3
230+#define QPLAN_TMP_TABLE 1 << 4
231+#define QPLAN_TMP_DISK 1 << 5
232+#define QPLAN_FILESORT 1 << 6
233+#define QPLAN_FILESORT_DISK 1 << 7
234+/* ... */
235+#define QPLAN_MAX 1 << 31
236+
237+#define SLOG_F_QC_NO QPLAN_QC_NO
238+#define SLOG_F_FULL_SCAN QPLAN_FULL_SCAN
239+#define SLOG_F_FULL_JOIN QPLAN_FULL_JOIN
240+#define SLOG_F_TMP_TABLE QPLAN_TMP_TABLE
241+#define SLOG_F_TMP_DISK QPLAN_TMP_DISK
242+#define SLOG_F_FILESORT QPLAN_FILESORT
243+#define SLOG_F_FILESORT_DISK QPLAN_FILESORT_DISK
244+#define SLOG_F_INVALID 1 << 31
245+#define SLOG_F_NONE 0
246+
247+static const struct msl_opts slog_filter[]=
248+{
249+ { SLOG_F_QC_NO, "qc_miss" },
250+ { SLOG_F_FULL_SCAN, "full_scan" },
251+ { SLOG_F_FULL_JOIN, "full_join" },
252+ { SLOG_F_TMP_TABLE, "tmp_table" },
253+ { SLOG_F_TMP_DISK, "tmp_table_on_disk" },
254+ { SLOG_F_FILESORT, "filesort" },
255+ { SLOG_F_FILESORT_DISK, "filesort_on_disk" },
256+ { SLOG_F_INVALID, (char *)0 }
257+};
258+
259 /*
260 Some defines for exit codes for ::is_equal class functions.
261 */
262@@ -1987,6 +2059,7 @@
263 extern my_bool opt_secure_auth;
264 extern char* opt_secure_file_priv;
265 extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements;
266+extern my_bool opt_use_global_long_query_time;
267 extern my_bool sp_automatic_privileges, opt_noacl;
268 extern my_bool opt_old_style_user_limits, trust_function_creators;
269 extern uint opt_crash_binlog_innodb;
270
271=== modified file 'sql/mysqld.cc'
272--- sql/mysqld.cc 2009-05-19 09:28:05 +0000
273+++ sql/mysqld.cc 2009-05-28 05:00:21 +0000
274@@ -464,6 +464,7 @@
275 char* opt_secure_file_priv= 0;
276 my_bool opt_log_slow_admin_statements= 0;
277 my_bool opt_log_slow_slave_statements= 0;
278+my_bool opt_use_global_long_query_time= 0;
279 my_bool lower_case_file_system= 0;
280 my_bool opt_large_pages= 0;
281 my_bool opt_myisam_use_mmap= 0;
282@@ -5751,6 +5752,9 @@
283 OPT_SECURE_FILE_PRIV,
284 OPT_MIN_EXAMINED_ROW_LIMIT,
285 OPT_LOG_SLOW_SLAVE_STATEMENTS,
286+ OPT_LOG_SLOW_RATE_LIMIT,
287+ OPT_LOG_SLOW_VERBOSITY,
288+ OPT_LOG_SLOW_FILTER,
289 OPT_DEBUG_CRC, OPT_DEBUG_ON, OPT_OLD_MODE,
290 OPT_TEST_IGNORE_WRONG_OPTIONS,
291 OPT_SLAVE_EXEC_MODE,
292@@ -5760,6 +5764,7 @@
293 OPT_DEADLOCK_TIMEOUT_LONG,
294 OPT_GENERAL_LOG_FILE,
295 OPT_SLOW_QUERY_LOG_FILE,
296+ OPT_USE_GLOBAL_LONG_QUERY_TIME,
297 OPT_IGNORE_BUILTIN_INNODB
298 };
299
300@@ -6742,6 +6747,21 @@
301 "The argument will be treated as a decimal value with microsecond precission.",
302 (uchar**) &long_query_time, (uchar**) &long_query_time, 0, GET_DOUBLE,
303 REQUIRED_ARG, 10, 0, LONG_TIMEOUT, 0, 0, 0},
304+ {"log_slow_filter", OPT_LOG_SLOW_FILTER,
305+ "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]",
306+ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_F_NONE, 0, 0},
307+ {"log_slow_rate_limit", OPT_LOG_SLOW_RATE_LIMIT,
308+ "Rate limit statement writes to slow log to only those from every (1/log_slow_rate_limit) session.",
309+ (uchar**) &global_system_variables.log_slow_rate_limit,
310+ (uchar**) &max_system_variables.log_slow_rate_limit, 0, GET_ULONG,
311+ REQUIRED_ARG, 1, 1, LONG_MAX, 0, 1L, 0},
312+ {"log_slow_verbosity", OPT_LOG_SLOW_VERBOSITY,
313+ "Choose how verbose the messages to your slow log will be. Multiple flags allowed in a comma-separated string. [microtime, query_plan, innodb]",
314+ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_V_MICROTIME, 0, 0},
315+ {"use_global_long_query_time", OPT_USE_GLOBAL_LONG_QUERY_TIME,
316+ "Control always use global long_query_time or local long_query_time.",
317+ (uchar**) &opt_use_global_long_query_time, (uchar**) &opt_use_global_long_query_time,
318+ 0, GET_BOOL, NO_ARG, 0, 0, 1, 0, 1, 0},
319 {"lower_case_table_names", OPT_LOWER_CASE_TABLE_NAMES,
320 "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",
321 (uchar**) &lower_case_table_names,
322@@ -7843,6 +7863,9 @@
323 global_system_variables.old_passwords= 0;
324 global_system_variables.old_alter_table= 0;
325 global_system_variables.binlog_format= BINLOG_FORMAT_UNSPEC;
326+
327+ global_system_variables.log_slow_verbosity= SLOG_V_MICROTIME;
328+ global_system_variables.log_slow_filter= SLOG_F_NONE;
329 /*
330 Default behavior for 4.1 and 5.0 is to treat NULL values as unequal
331 when collecting index statistics for MyISAM tables.
332@@ -8350,6 +8373,24 @@
333 case OPT_BOOTSTRAP:
334 opt_noacl=opt_bootstrap=1;
335 break;
336+ case OPT_LOG_SLOW_FILTER:
337+ if ((global_system_variables.log_slow_filter=
338+ msl_flag_resolve_by_name(slog_filter, argument,
339+ SLOG_F_NONE, SLOG_F_INVALID)) == SLOG_F_INVALID)
340+ {
341+ fprintf(stderr,"Invalid argument in log_slow_filter: %s\n", argument);
342+ exit(1);
343+ }
344+ break;
345+ case OPT_LOG_SLOW_VERBOSITY:
346+ if ((global_system_variables.log_slow_verbosity=
347+ msl_flag_resolve_by_name(slog_verb, argument,
348+ SLOG_V_NONE, SLOG_V_INVALID)) == SLOG_V_INVALID)
349+ {
350+ fprintf(stderr,"Invalid argument in log_slow_verbosity: %s\n", argument);
351+ exit(1);
352+ }
353+ break;
354 case OPT_SERVER_ID:
355 server_id_supplied = 1;
356 break;
357
358=== modified file 'sql/set_var.cc'
359--- sql/set_var.cc 2009-05-19 09:28:05 +0000
360+++ sql/set_var.cc 2009-05-28 05:00:21 +0000
361@@ -899,6 +899,22 @@
362 QUERY_LOG_GENERAL);
363 static sys_var_log_state sys_var_slow_query_log(&vars, "slow_query_log", &opt_slow_log,
364 QUERY_LOG_SLOW);
365+static sys_var_thd_ulong sys_log_slow_rate_limit(&vars, "log_slow_rate_limit",
366+ &SV::log_slow_rate_limit);
367+static sys_var_thd_msl_flag sys_log_slow_filter(&vars, "log_slow_filter",
368+ &SV::log_slow_filter,
369+ SLOG_F_NONE,
370+ SLOG_F_NONE,
371+ SLOG_F_INVALID,
372+ slog_filter);
373+static sys_var_thd_msl_flag sys_log_slow_verbosity(&vars, "log_slow_verbosity",
374+ &SV::log_slow_verbosity,
375+ SLOG_V_NONE,
376+ SLOG_V_MICROTIME,
377+ SLOG_V_INVALID,
378+ slog_verb);
379+static sys_var_bool_ptr sys_use_global_long_query_time(&vars, "use_global_long_query_time",
380+ &opt_use_global_long_query_time);
381 /* Synonym of "slow_query_log" for consistency with SHOW VARIABLES output */
382 static sys_var_log_state sys_var_log_slow(&vars, "log_slow_queries",
383 &opt_slow_log, QUERY_LOG_SLOW);
384@@ -3699,6 +3715,192 @@
385 #endif
386 }
387
388+/* Slow log stuff */
389+
390+ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len)
391+{
392+ ulong i;
393+
394+ for (i=0; opts[i].name; i++)
395+ {
396+ if (!my_strnncoll(&my_charset_latin1,
397+ (const uchar *)name, len,
398+ (const uchar *)opts[i].name, strlen(opts[i].name)))
399+ return opts[i].val;
400+ }
401+ return opts[i].val;
402+}
403+
404+ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
405+ const ulong none_val, const ulong invalid_val)
406+{
407+ const char *p, *e;
408+ ulong val= none_val;
409+
410+ if (!*names_list)
411+ return val;
412+
413+ for (p= e= names_list; ; e++)
414+ {
415+ ulong i;
416+
417+ if (*e != ',' && *e)
418+ continue;
419+ for (i=0; opts[i].name; i++)
420+ {
421+ if (!my_strnncoll(&my_charset_latin1,
422+ (const uchar *)p, e - p,
423+ (const uchar *)opts[i].name, strlen(opts[i].name)))
424+ {
425+ val= val | opts[i].val;
426+ break;
427+ }
428+ }
429+ if (opts[i].val == invalid_val)
430+ return invalid_val;
431+ if (!*e)
432+ break;
433+ p= e + 1;
434+ }
435+ return val;
436+}
437+
438+const char *msl_option_get_name(const struct msl_opts *opts, ulong val)
439+{
440+ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
441+ {
442+ if (opts[i].val == val)
443+ return opts[i].name;
444+ }
445+ return "*INVALID*";
446+}
447+
448+char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val)
449+{
450+ uint offset= 0;
451+
452+ *buf= '\0';
453+ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
454+ {
455+ if (opts[i].val & val)
456+ offset+= snprintf(buf+offset, STRING_BUFFER_USUAL_SIZE - offset - 1,
457+ "%s%s", (offset ? "," : ""), opts[i].name);
458+ }
459+ return buf;
460+}
461+
462+/****************************************************************************
463+ Functions to handle log_slow_verbosity
464+****************************************************************************/
465+
466+/* Based upon sys_var::check_enum() */
467+
468+bool sys_var_thd_msl_option::check(THD *thd, set_var *var)
469+{
470+ char buff[STRING_BUFFER_USUAL_SIZE];
471+ String str(buff, sizeof(buff), &my_charset_latin1), *res;
472+
473+ if (var->value->result_type() == STRING_RESULT)
474+ {
475+ ulong verb= this->invalid_val;
476+ if (!(res=var->value->val_str(&str)) ||
477+ (var->save_result.ulong_value=
478+ (ulong) (verb= msl_option_resolve_by_name(this->opts, res->ptr(), res->length()))) == this->invalid_val)
479+ goto err;
480+ return 0;
481+ }
482+
483+err:
484+ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
485+ return 1;
486+}
487+
488+uchar *sys_var_thd_msl_option::value_ptr(THD *thd, enum_var_type type,
489+ LEX_STRING *base)
490+{
491+ ulong val;
492+ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
493+ thd->variables.*offset);
494+ const char *verbosity= msl_option_get_name(this->opts, val);
495+ return (uchar *) verbosity;
496+}
497+
498+
499+void sys_var_thd_msl_option::set_default(THD *thd, enum_var_type type)
500+{
501+ if (type == OPT_GLOBAL)
502+ global_system_variables.*offset= (ulong) this->default_val;
503+ else
504+ thd->variables.*offset= (ulong) (global_system_variables.*offset);
505+}
506+
507+
508+bool sys_var_thd_msl_option::update(THD *thd, set_var *var)
509+{
510+ if (var->type == OPT_GLOBAL)
511+ global_system_variables.*offset= var->save_result.ulong_value;
512+ else
513+ thd->variables.*offset= var->save_result.ulong_value;
514+ return 0;
515+}
516+
517+/****************************************************************************
518+ Functions to handle log_slow_filter
519+****************************************************************************/
520+
521+/* Based upon sys_var::check_enum() */
522+
523+bool sys_var_thd_msl_flag::check(THD *thd, set_var *var)
524+{
525+ char buff[2 * STRING_BUFFER_USUAL_SIZE];
526+ String str(buff, sizeof(buff), &my_charset_latin1), *res;
527+
528+ if (var->value->result_type() == STRING_RESULT)
529+ {
530+ ulong filter= this->none_val;
531+ if (!(res=var->value->val_str(&str)) ||
532+ (var->save_result.ulong_value=
533+ (ulong) (filter= msl_flag_resolve_by_name(this->flags, res->ptr(), this->none_val,
534+ this->invalid_val))) == this->invalid_val)
535+ goto err;
536+ return 0;
537+ }
538+
539+err:
540+ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
541+ return 1;
542+}
543+
544+uchar *sys_var_thd_msl_flag::value_ptr(THD *thd, enum_var_type type,
545+ LEX_STRING *base)
546+{
547+ ulong val;
548+ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
549+ thd->variables.*offset);
550+ msl_flag_get_name(this->flags, this->flags_string, val);
551+ return (uchar *) this->flags_string;
552+}
553+
554+
555+void sys_var_thd_msl_flag::set_default(THD *thd, enum_var_type type)
556+{
557+ if (type == OPT_GLOBAL)
558+ global_system_variables.*offset= (ulong) this->default_val;
559+ else
560+ thd->variables.*offset= (ulong) (global_system_variables.*offset);
561+}
562+
563+
564+bool sys_var_thd_msl_flag::update(THD *thd, set_var *var)
565+{
566+ if (var->type == OPT_GLOBAL)
567+ global_system_variables.*offset= var->save_result.ulong_value;
568+ else
569+ thd->variables.*offset= var->save_result.ulong_value;
570+ return 0;
571+}
572+
573+
574 /****************************************************************************
575 Functions to handle table_type
576 ****************************************************************************/
577
578=== modified file 'sql/set_var.h'
579--- sql/set_var.h 2009-04-25 10:05:32 +0000
580+++ sql/set_var.h 2009-05-28 05:00:21 +0000
581@@ -567,6 +567,66 @@
582 };
583
584
585+class sys_var_thd_msl_option :public sys_var_thd
586+{
587+protected:
588+ ulong SV::*offset;
589+ const ulong none_val;
590+ const ulong default_val;
591+ const ulong invalid_val;
592+ const struct msl_opts *opts;
593+public:
594+ sys_var_thd_msl_option(sys_var_chain *chain, const char *name_arg, ulong SV::*offset_arg,
595+ const ulong none_val_arg,
596+ const ulong default_val_arg,
597+ const ulong invalid_val_arg,
598+ const struct msl_opts *opts_arg)
599+ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
600+ default_val(default_val_arg), invalid_val(invalid_val_arg),
601+ opts(opts_arg)
602+ { chain_sys_var(chain); }
603+ bool check(THD *thd, set_var *var);
604+ SHOW_TYPE show_type() { return SHOW_CHAR; }
605+ bool check_update_type(Item_result type)
606+ {
607+ return type != STRING_RESULT; /* Only accept strings */
608+ }
609+ void set_default(THD *thd, enum_var_type type);
610+ bool update(THD *thd, set_var *var);
611+ uchar *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
612+};
613+
614+
615+class sys_var_thd_msl_flag :public sys_var_thd
616+{
617+protected:
618+ char flags_string[2 * STRING_BUFFER_USUAL_SIZE];
619+ ulong SV::*offset;
620+ const ulong none_val;
621+ const ulong default_val;
622+ const ulong invalid_val;
623+ const struct msl_opts *flags;
624+public:
625+ sys_var_thd_msl_flag(sys_var_chain *chain, const char *name_arg, ulong SV::*offset_arg,
626+ const ulong none_val_arg,
627+ const ulong default_val_arg,
628+ const ulong invalid_val_arg,
629+ const struct msl_opts *flags_arg)
630+ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
631+ default_val(default_val_arg), invalid_val(invalid_val_arg),
632+ flags(flags_arg)
633+ { chain_sys_var(chain); }
634+ bool check(THD *thd, set_var *var);
635+ SHOW_TYPE show_type() { return SHOW_CHAR; }
636+ bool check_update_type(Item_result type)
637+ {
638+ return type != STRING_RESULT; /* Only accept strings */
639+ }
640+ void set_default(THD *thd, enum_var_type type);
641+ bool update(THD *thd, set_var *var);
642+ uchar *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
643+};
644+
645 class sys_var_thd_storage_engine :public sys_var_thd
646 {
647 protected:
648@@ -1449,3 +1509,10 @@
649 bool process_key_caches(process_key_cache_t func);
650 void delete_elements(I_List<NAMED_LIST> *list,
651 void (*free_element)(const char*, uchar*));
652+
653+/* Slow log functions */
654+ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len);
655+ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
656+ const ulong none_val, const ulong invalid_val);
657+const char *msl_option_get_name(const struct msl_opts *opts, ulong val);
658+char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val);
659
660=== modified file 'sql/slave.cc'
661--- sql/slave.cc 2009-05-19 09:28:05 +0000
662+++ sql/slave.cc 2009-05-28 05:00:21 +0000
663@@ -1634,6 +1634,7 @@
664 + MAX_LOG_EVENT_HEADER; /* note, incr over the global not session var */
665 thd->slave_thread = 1;
666 thd->enable_slow_log= opt_log_slow_slave_statements;
667+ thd->write_to_slow_log= opt_log_slow_slave_statements;
668 set_slave_thread_options(thd);
669 thd->client_capabilities = CLIENT_LOCAL_FILES;
670 pthread_mutex_lock(&LOCK_thread_count);
671
672=== modified file 'sql/sql_cache.cc'
673--- sql/sql_cache.cc 2009-04-25 10:05:32 +0000
674+++ sql/sql_cache.cc 2009-05-28 05:00:21 +0000
675@@ -1530,6 +1530,7 @@
676
677 thd->limit_found_rows = query->found_rows();
678 thd->status_var.last_query_cost= 0.0;
679+ thd->query_plan_flags|= QPLAN_QC;
680 thd->main_da.disable_status();
681
682 BLOCK_UNLOCK_RD(query_block);
683@@ -1538,6 +1539,7 @@
684 err_unlock:
685 STRUCT_UNLOCK(&structure_guard_mutex);
686 err:
687+ thd->query_plan_flags|= QPLAN_QC_NO;
688 DBUG_RETURN(0); // Query was not cached
689 }
690
691
692=== modified file 'sql/sql_class.cc'
693--- sql/sql_class.cc 2009-05-19 09:28:05 +0000
694+++ sql/sql_class.cc 2009-05-28 05:00:21 +0000
695@@ -309,6 +309,34 @@
696 thd->row_count++;
697 }
698
699+extern "C"
700+void increment_thd_innodb_stats(THD* thd,long io_reads,
701+ long long io_read,
702+ long io_reads_wait_timer,
703+ long lock_que_wait_timer,
704+ long que_wait_timer,
705+ long page_access)
706+{
707+ thd->innodb_was_used = TRUE;
708+ thd->innodb_io_reads += io_reads;
709+ thd->innodb_io_read += io_read;
710+ thd->innodb_io_reads_wait_timer += io_reads_wait_timer;
711+ thd->innodb_lock_que_wait_timer += lock_que_wait_timer;
712+ thd->innodb_innodb_que_wait_timer += que_wait_timer;
713+ thd->innodb_page_access += page_access;
714+}
715+
716+extern "C"
717+unsigned long thd_log_slow_verbosity(const THD *thd)
718+{
719+ return (unsigned long) thd->variables.log_slow_verbosity;
720+}
721+
722+extern "C"
723+int thd_opt_slow_log()
724+{
725+ return (int) opt_slow_log;
726+}
727
728 /**
729 Dumps a text description of a thread, its security context
730@@ -3017,6 +3045,12 @@
731 first_successful_insert_id_in_prev_stmt;
732 backup->first_successful_insert_id_in_cur_stmt=
733 first_successful_insert_id_in_cur_stmt;
734+ backup->innodb_io_reads= innodb_io_reads;
735+ backup->innodb_io_read= innodb_io_read;
736+ backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
737+ backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
738+ backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
739+ backup->innodb_page_access= innodb_page_access;
740
741 if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) &&
742 !current_stmt_binlog_row_based)
743@@ -3036,6 +3070,12 @@
744 cuted_fields= 0;
745 transaction.savepoints= 0;
746 first_successful_insert_id_in_cur_stmt= 0;
747+ innodb_io_reads= 0;
748+ innodb_io_read= 0;
749+ innodb_io_reads_wait_timer= 0;
750+ innodb_lock_que_wait_timer= 0;
751+ innodb_innodb_que_wait_timer= 0;
752+ innodb_page_access= 0;
753 }
754
755
756@@ -3096,6 +3136,12 @@
757 */
758 examined_row_count+= backup->examined_row_count;
759 cuted_fields+= backup->cuted_fields;
760+ innodb_io_reads+= backup->innodb_io_reads;
761+ innodb_io_read+= backup->innodb_io_read;
762+ innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
763+ innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
764+ innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
765+ innodb_page_access+= backup->innodb_page_access;
766 }
767
768
769
770=== modified file 'sql/sql_class.h'
771--- sql/sql_class.h 2009-04-25 10:05:32 +0000
772+++ sql/sql_class.h 2009-05-28 05:00:21 +0000
773@@ -401,6 +401,17 @@
774 DATE_TIME_FORMAT *time_format;
775 my_bool sysdate_is_now;
776
777+ ulong log_slow_rate_limit;
778+ ulong log_slow_filter;
779+ ulong log_slow_verbosity;
780+
781+ ulong innodb_io_reads;
782+ ulonglong innodb_io_read;
783+ ulong innodb_io_reads_wait_timer;
784+ ulong innodb_lock_que_wait_timer;
785+ ulong innodb_innodb_que_wait_timer;
786+ ulong innodb_page_access;
787+
788 /* deadlock detection */
789 ulong wt_timeout_short, wt_deadlock_search_depth_short;
790 ulong wt_timeout_long, wt_deadlock_search_depth_long;
791@@ -998,6 +1009,14 @@
792 uint in_sub_stmt;
793 bool enable_slow_log;
794 bool last_insert_id_used;
795+
796+ ulong innodb_io_reads;
797+ ulonglong innodb_io_read;
798+ ulong innodb_io_reads_wait_timer;
799+ ulong innodb_lock_que_wait_timer;
800+ ulong innodb_innodb_que_wait_timer;
801+ ulong innodb_page_access;
802+
803 SAVEPOINT *savepoints;
804 };
805
806@@ -1358,6 +1377,19 @@
807 thr_lock_type update_lock_default;
808 Delayed_insert *di;
809
810+ bool write_to_slow_log;
811+
812+ bool innodb_was_used;
813+ ulong innodb_io_reads;
814+ ulonglong innodb_io_read;
815+ ulong innodb_io_reads_wait_timer;
816+ ulong innodb_lock_que_wait_timer;
817+ ulong innodb_innodb_que_wait_timer;
818+ ulong innodb_page_access;
819+
820+ ulong query_plan_flags;
821+ ulong query_plan_fsort_passes;
822+
823 /* <> 0 if we are inside of trigger or stored function. */
824 uint in_sub_stmt;
825 /* TRUE when the current top has SQL_LOG_BIN ON */
826
827=== modified file 'sql/sql_connect.cc'
828--- sql/sql_connect.cc 2009-04-25 10:05:32 +0000
829+++ sql/sql_connect.cc 2009-05-28 05:00:21 +0000
830@@ -1112,6 +1112,15 @@
831
832 prepare_new_connection_state(thd);
833
834+ /*
835+ If rate limiting of slow log writes is enabled, decide whether to log this
836+ new thread's queries or not. Uses extremely simple algorithm. :)
837+ */
838+ thd->write_to_slow_log= FALSE;
839+ if (thd->variables.log_slow_rate_limit <= 1 ||
840+ (thd->thread_id % thd->variables.log_slow_rate_limit) == 0)
841+ thd->write_to_slow_log= TRUE;
842+
843 while (!net->error && net->vio != 0 &&
844 !(thd->killed == THD::KILL_CONNECTION))
845 {
846
847=== modified file 'sql/sql_parse.cc'
848--- sql/sql_parse.cc 2009-04-25 10:05:32 +0000
849+++ sql/sql_parse.cc 2009-05-28 05:00:21 +0000
850@@ -1638,13 +1638,37 @@
851 if (unlikely(thd->in_sub_stmt))
852 DBUG_VOID_RETURN; // Don't set time for sub stmt
853
854+ /* Follow the slow log filter configuration. */
855+ if (thd->variables.log_slow_filter != SLOG_F_NONE &&
856+ (!(thd->variables.log_slow_filter & thd->query_plan_flags) ||
857+ ((thd->variables.log_slow_filter & SLOG_F_QC_NO) &&
858+ (thd->query_plan_flags & QPLAN_QC))))
859+ DBUG_VOID_RETURN;
860+
861+ /*
862+ Low long_query_time value most likely means user is debugging stuff and even
863+ though some thread's queries are not supposed to be logged b/c of the rate
864+ limit, if one of them takes long enough (>= 1 second) it will be sensible
865+ to make an exception and write to slow log anyway.
866+ */
867+
868+ ulonglong end_utime_of_query= thd->current_utime();
869+
870+ if (opt_use_global_long_query_time)
871+ thd->variables.long_query_time = global_system_variables.long_query_time;
872+
873+ /* Do not log this thread's queries due to rate limiting. */
874+ if (thd->write_to_slow_log != TRUE
875+ && (thd->variables.long_query_time >= 1000000
876+ || (ulong) (end_utime_of_query - thd->utime_after_lock) < 1000000))
877+ DBUG_VOID_RETURN;
878+
879 /*
880 Do not log administrative statements unless the appropriate option is
881 set; do not log into slow log if reading from backup.
882 */
883 if (thd->enable_slow_log && !thd->user_time)
884 {
885- ulonglong end_utime_of_query= thd->current_utime();
886 thd_proc_info(thd, "logging slow query");
887
888 if (((end_utime_of_query - thd->utime_after_lock) >
889@@ -2023,6 +2047,8 @@
890 context.resolve_in_table_list_only((TABLE_LIST*)select_lex->
891 table_list.first);
892
893+ /* Reset the counter at all cases for the extended slow query log */
894+ thd->row_count= 1;
895 /*
896 Reset warning count for each query that uses tables
897 A better approach would be to reset this for any commands
898@@ -5659,6 +5685,16 @@
899 thd->rand_used= 0;
900 thd->sent_row_count= thd->examined_row_count= 0;
901
902+ thd->innodb_was_used= FALSE;
903+ thd->innodb_io_reads= 0;
904+ thd->innodb_io_read= 0;
905+ thd->innodb_io_reads_wait_timer= 0;
906+ thd->innodb_lock_que_wait_timer= 0;
907+ thd->innodb_innodb_que_wait_timer= 0;
908+ thd->innodb_page_access= 0;
909+ thd->query_plan_flags= QPLAN_NONE;
910+ thd->query_plan_fsort_passes= 0;
911+
912 /*
913 Because we come here only for start of top-statements, binlog format is
914 constant inside a complex statement (using stored functions) etc.
915
916=== modified file 'sql/sql_select.cc'
917--- sql/sql_select.cc 2009-05-19 09:28:05 +0000
918+++ sql/sql_select.cc 2009-05-28 05:00:21 +0000
919@@ -6547,7 +6547,10 @@
920 {
921 join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
922 if (statistics)
923+ {
924 status_var_increment(join->thd->status_var.select_scan_count);
925+ join->thd->query_plan_flags|= QPLAN_FULL_SCAN;
926+ }
927 }
928 }
929 else
930@@ -6561,7 +6564,10 @@
931 {
932 join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
933 if (statistics)
934+ {
935 status_var_increment(join->thd->status_var.select_full_join_count);
936+ join->thd->query_plan_flags|= QPLAN_FULL_JOIN;
937+ }
938 }
939 }
940 if (!table->no_keyread)
941@@ -9724,6 +9730,7 @@
942 (ulong) rows_limit,test(group)));
943
944 status_var_increment(thd->status_var.created_tmp_tables);
945+ thd->query_plan_flags|= QPLAN_TMP_TABLE;
946
947 if (use_temp_pool && !(test_flags & TEST_KEEP_TMP_TABLES))
948 temp_pool_slot = bitmap_lock_set_next(&temp_pool);
949@@ -10610,6 +10617,7 @@
950 goto err;
951 }
952 status_var_increment(table->in_use->status_var.created_tmp_disk_tables);
953+ table->in_use->query_plan_flags|= QPLAN_TMP_DISK;
954 share->db_record_offset= 1;
955 DBUG_RETURN(0);
956 err:

Subscribers

People subscribed via source and target branches