[Pkg-mysql-commits] r1202 - trunk/debian/patches
Norbert Tretkowski
nobse at alioth.debian.org
Sat Apr 26 15:28:42 UTC 2008
Author: nobse
Date: 2008-04-26 15:28:42 +0000 (Sat, 26 Apr 2008)
New Revision: 1202
Added:
trunk/debian/patches/61_microslow.dpatch
Log:
Really add patch.
Added: trunk/debian/patches/61_microslow.dpatch
===================================================================
--- trunk/debian/patches/61_microslow.dpatch (rev 0)
+++ trunk/debian/patches/61_microslow.dpatch 2008-04-26 15:28:42 UTC (rev 1202)
@@ -0,0 +1,1350 @@
+#! /bin/sh /usr/share/dpatch/dpatch-run
+## 61_microslow.dpatch by Norbert Tretkowski <nobse at debian.org>
+
+ at DPATCH@
+diff -r 1cae91646da0 include/my_time.h
+--- a/include/my_time.h Thu Mar 27 11:55:26 2008 +0100
++++ b/include/my_time.h Mon Apr 07 14:28:43 2008 +0200
+@@ -140,7 +140,7 @@
+ int my_date_to_str(const MYSQL_TIME *l_time, char *to);
+ int my_datetime_to_str(const MYSQL_TIME *l_time, char *to);
+ int my_TIME_to_str(const MYSQL_TIME *l_time, char *to);
+-
++ulonglong my_timer(ulonglong *ltime, ulonglong frequency);
+ C_MODE_END
+
+ #endif /* _my_time_h_ */
+diff -r 1cae91646da0 scripts/mysqldumpslow.sh
+--- a/scripts/mysqldumpslow.sh Thu Mar 27 11:55:26 2008 +0100
++++ b/scripts/mysqldumpslow.sh Mon Apr 07 14:28:43 2008 +0200
+@@ -83,8 +83,8 @@
+ s/^#? Time: \d{6}\s+\d+:\d+:\d+.*\n//;
+ my ($user,$host) = s/^#? User\@Host:\s+(\S+)\s+\@\s+(\S+).*\n// ? ($1,$2) : ('','');
+
+- s/^# Query_time: (\d+) Lock_time: (\d+) Rows_sent: (\d+).*\n//;
+- my ($t, $l, $r) = ($1, $2, $3);
++ s/^# Query_time: (\d+(\.\d+)?) Lock_time: (\d+(\.\d+)?) Rows_sent: (\d+(\.\d+)?).*\n//;
++ my ($t, $l, $r) = ($1, $3, $5);
+ $t -= $l unless $opt{l};
+
+ # remove fluff that mysqld writes to log when it (re)starts:
+diff -r 1cae91646da0 sql-common/my_time.c
+--- a/sql-common/my_time.c Thu Mar 27 11:55:26 2008 +0100
++++ b/sql-common/my_time.c Mon Apr 07 14:28:43 2008 +0200
+@@ -1250,3 +1250,37 @@
+ return 0;
+ }
+
++/*
++ int my_timer(ulonglong *ltime, ulonglong frequency)
++
++ For performance measurement this function returns the number
++ of microseconds since the epoch (SVr4, BSD 4.3, POSIX 1003.1-2001)
++ or system start (Windows platforms).
++
++ For windows platforms frequency value (obtained via
++ QueryPerformanceFrequency) has to be specified. The global frequency
++ value is set in mysqld.cc.
++
++ If Windows platform doesn't support QueryPerformanceFrequency we will
++ obtain the time via GetClockCount, which supports microseconds only.
++*/
++
++ulonglong my_timer(ulonglong *ltime, ulonglong frequency)
++{
++ ulonglong newtime= 0;
++#ifdef __WIN__
++ if (frequency)
++ {
++ QueryPerformanceCounter((LARGE_INTEGER *)&newtime);
++ newtime/= (frequency * 1000000);
++ } else
++ newtime= (GetTickCount() * 1000; /* GetTickCount only returns milliseconds */
++#else
++ struct timeval t;
++ gettimeofday(&t, NULL);
++ newtime= (ulonglong)t.tv_sec * 1000000 + t.tv_usec;
++#endif
++ if (ltime)
++ *ltime= newtime;
++ return newtime;
++}
+diff -r 1cae91646da0 sql/filesort.cc
+--- a/sql/filesort.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/filesort.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -172,6 +172,7 @@
+ {
+ statistic_increment(thd->status_var.filesort_scan_count, &LOCK_status);
+ }
++ thd->query_plan_flags|= QPLAN_FILESORT;
+ #ifdef CAN_TRUST_RANGE
+ if (select && select->quick && select->quick->records > 0L)
+ {
+@@ -238,6 +239,7 @@
+ }
+ else
+ {
++ thd->query_plan_flags|= QPLAN_FILESORT_DISK;
+ if (!table_sort.buffpek && table_sort.buffpek_len < maxbuffer &&
+ !(table_sort.buffpek=
+ (byte *) read_buffpek_from_file(&buffpek_pointers, maxbuffer)))
+@@ -1059,6 +1061,7 @@
+
+ statistic_increment(current_thd->status_var.filesort_merge_passes,
+ &LOCK_status);
++ current_thd->query_plan_fsort_passes++;
+ if (param->not_killable)
+ {
+ killed= ¬_killable;
+diff -r 1cae91646da0 sql/log.cc
+--- a/sql/log.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/log.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -2037,10 +2037,11 @@
+ */
+
+ bool MYSQL_LOG::write(THD *thd,const char *query, uint query_length,
+- time_t query_start_arg)
++ time_t query_start_arg, ulonglong query_start_timer)
+ {
+ bool error=0;
+ time_t current_time;
++ ulonglong current_timer;
+ if (!is_open())
+ return 0;
+ DBUG_ENTER("MYSQL_LOG::write");
+@@ -2051,7 +2052,8 @@
+ int tmp_errno=0;
+ char buff[80],*end;
+ end=buff;
+- if (!(thd->options & OPTION_UPDATE_LOG))
++ if (!(thd->options & OPTION_UPDATE_LOG) &&
++ !(thd->slave_thread && opt_log_slow_slave_statements))
+ {
+ VOID(pthread_mutex_unlock(&LOCK_log));
+ DBUG_RETURN(0);
+@@ -2081,22 +2083,69 @@
+ if (my_b_printf(&log_file, "# User at Host: %s[%s] @ %s [%s]\n",
+ sctx->priv_user ?
+ sctx->priv_user : "",
+- sctx->user ? sctx->user : "",
++ sctx->user ? sctx->user : (thd->slave_thread ? "SQL_SLAVE" : ""),
+ sctx->host ? sctx->host : "",
+ sctx->ip ? sctx->ip : "") ==
+ (uint) -1)
+ tmp_errno=errno;
+ }
+- if (query_start_arg)
++ if (query_start_timer)
+ {
++ char buf[5][20];
++ ulonglong current_timer= my_timer(¤t_timer, frequency);
++ sprintf(buf[0], "%.6f", (current_timer - query_start_timer) / 1000000.0);
++ sprintf(buf[1], "%.6f", (thd->timer_after_lock - query_start_timer) / 1000000.0);
++ if (!query_length)
++ {
++ thd->sent_row_count= thd->examined_row_count= 0;
++ thd->innodb_was_used= FALSE;
++ thd->query_plan_flags= QPLAN_NONE;
++ thd->query_plan_fsort_passes= 0;
++ }
++
+ /* For slow query log */
+ if (my_b_printf(&log_file,
+- "# Query_time: %lu Lock_time: %lu Rows_sent: %lu Rows_examined: %lu\n",
+- (ulong) (current_time - query_start_arg),
+- (ulong) (thd->time_after_lock - query_start_arg),
++ "# Thread_id: %lu Schema: %s\n" \
++ "# Query_time: %s Lock_time: %s Rows_sent: %lu Rows_examined: %lu\n",
++ (ulong) thd->thread_id, (thd->db ? thd->db : ""),
++ buf[0], buf[1],
+ (ulong) thd->sent_row_count,
+ (ulong) thd->examined_row_count) == (uint) -1)
+ tmp_errno=errno;
++ if ((thd->variables.log_slow_verbosity & SLOG_V_QUERY_PLAN) &&
++ my_b_printf(&log_file,
++ "# QC_Hit: %s Full_scan: %s Full_join: %s Tmp_table: %s Tmp_table_on_disk: %s\n" \
++ "# Filesort: %s Filesort_on_disk: %s Merge_passes: %lu\n",
++ ((thd->query_plan_flags & QPLAN_QC) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_FULL_SCAN) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_FULL_JOIN) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_TMP_TABLE) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_TMP_DISK) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_FILESORT) ? "Yes" : "No"),
++ ((thd->query_plan_flags & QPLAN_FILESORT_DISK) ? "Yes" : "No"),
++ thd->query_plan_fsort_passes) == (uint) -1)
++ tmp_errno=errno;
++ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) && thd->innodb_was_used)
++ {
++ sprintf(buf[2], "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0);
++ sprintf(buf[3], "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0);
++ sprintf(buf[4], "%.6f", thd->innodb_innodb_que_wait_timer / 1000000.0);
++ if (my_b_printf(&log_file,
++ "# InnoDB_IO_r_ops: %lu InnoDB_IO_r_bytes: %lu InnoDB_IO_r_wait: %s\n" \
++ "# InnoDB_rec_lock_wait: %s InnoDB_queue_wait: %s\n" \
++ "# InnoDB_pages_distinct: %lu\n",
++ (ulong) thd->innodb_io_reads,
++ (ulong) thd->innodb_io_read,
++ buf[2], buf[3], buf[4],
++ (ulong) thd->innodb_page_access) == (uint) -1)
++ tmp_errno=errno;
++ }
++ else
++ {
++ if ((thd->variables.log_slow_verbosity & SLOG_V_INNODB) &&
++ my_b_printf(&log_file,"# No InnoDB statistics available for this query\n") == (uint) -1)
++ tmp_errno=errno;
++ }
+ }
+ if (thd->db && strcmp(thd->db,db))
+ { // Database changed
+diff -r 1cae91646da0 sql/log_event.cc
+--- a/sql/log_event.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/log_event.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -1905,6 +1905,7 @@
+ /* Execute the query (note that we bypass dispatch_command()) */
+ const char* found_semicolon= NULL;
+ mysql_parse(thd, thd->query, thd->query_length, &found_semicolon);
++ log_slow_statement(thd);
+
+ }
+ else
+diff -r 1cae91646da0 sql/my_time.c
+--- a/sql/my_time.c Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/my_time.c Mon Apr 07 14:28:43 2008 +0200
+@@ -1250,3 +1250,37 @@
+ return 0;
+ }
+
++/*
++ int my_timer(ulonglong *ltime, ulonglong frequency)
++
++ For performance measurement this function returns the number
++ of microseconds since the epoch (SVr4, BSD 4.3, POSIX 1003.1-2001)
++ or system start (Windows platforms).
++
++ For windows platforms frequency value (obtained via
++ QueryPerformanceFrequency) has to be specified. The global frequency
++ value is set in mysqld.cc.
++
++ If Windows platform doesn't support QueryPerformanceFrequency we will
++ obtain the time via GetClockCount, which supports microseconds only.
++*/
++
++ulonglong my_timer(ulonglong *ltime, ulonglong frequency)
++{
++ ulonglong newtime= 0;
++#ifdef __WIN__
++ if (frequency)
++ {
++ QueryPerformanceCounter((LARGE_INTEGER *)&newtime);
++ newtime/= (frequency / 1000000);
++ } else
++ newtime= (GetTickCount() * 1000); /* GetTickCount only returns milliseconds */
++#else
++ struct timeval t;
++ gettimeofday(&t, NULL);
++ newtime= (ulonglong)t.tv_sec * 1000000 + t.tv_usec;
++#endif
++ if (ltime)
++ *ltime= newtime;
++ return newtime;
++}
+diff -r 1cae91646da0 sql/mysql_priv.h
+--- a/sql/mysql_priv.h Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/mysql_priv.h Mon Apr 07 14:28:43 2008 +0200
+@@ -482,6 +482,78 @@
+ #define WEEK_FIRST_WEEKDAY 4
+
+ #define STRING_BUFFER_USUAL_SIZE 80
++
++/* Slow log */
++
++struct msl_opts
++{
++ ulong val;
++ char *name;
++};
++
++#define SLOG_V_MICROTIME 1 << 0
++#define SLOG_V_QUERY_PLAN 1 << 1
++#define SLOG_V_INNODB 1 << 2
++/* ... */
++#define SLOG_V_INVALID 1 << 31
++#define SLOG_V_NONE SLOG_V_MICROTIME
++
++static const struct msl_opts slog_verb[]=
++{
++ /* Basic flags */
++
++ { SLOG_V_MICROTIME, "microtime" },
++ { SLOG_V_QUERY_PLAN, "query_plan" },
++ { SLOG_V_INVALID, "innodb" },
++
++ /* End of baisc flags */
++
++ { 0, "" },
++
++ /* Complex flags */
++
++ { SLOG_V_MICROTIME, "minimal" },
++ { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN, "standard" },
++ { SLOG_V_INVALID, "full" },
++
++ /* End of complex flags */
++
++ { SLOG_V_INVALID, (char *)0 }
++};
++
++#define QPLAN_NONE 0
++#define QPLAN_QC 1 << 0
++#define QPLAN_QC_NO 1 << 1
++#define QPLAN_FULL_SCAN 1 << 2
++#define QPLAN_FULL_JOIN 1 << 3
++#define QPLAN_TMP_TABLE 1 << 4
++#define QPLAN_TMP_DISK 1 << 5
++#define QPLAN_FILESORT 1 << 6
++#define QPLAN_FILESORT_DISK 1 << 7
++/* ... */
++#define QPLAN_MAX 1 << 31
++
++#define SLOG_F_QC_NO QPLAN_QC_NO
++#define SLOG_F_FULL_SCAN QPLAN_FULL_SCAN
++#define SLOG_F_FULL_JOIN QPLAN_FULL_JOIN
++#define SLOG_F_TMP_TABLE QPLAN_TMP_TABLE
++#define SLOG_F_TMP_DISK QPLAN_TMP_DISK
++#define SLOG_F_FILESORT QPLAN_FILESORT
++#define SLOG_F_FILESORT_DISK QPLAN_FILESORT_DISK
++#define SLOG_F_INVALID 1 << 31
++#define SLOG_F_NONE 0
++
++static const struct msl_opts slog_filter[]=
++{
++ { SLOG_F_QC_NO, "qc_miss" },
++ { SLOG_F_FULL_SCAN, "full_scan" },
++ { SLOG_F_FULL_JOIN, "full_join" },
++ { SLOG_F_TMP_TABLE, "tmp_table" },
++ { SLOG_F_TMP_DISK, "tmp_table_on_disk" },
++ { SLOG_F_FILESORT, "filesort" },
++ { SLOG_F_FILESORT_DISK, "filesort_on_disk" },
++ { SLOG_F_INVALID, (char *)0 }
++};
+
+ enum enum_parsing_place
+ {
+@@ -1324,7 +1396,7 @@
+ extern my_bool opt_enable_named_pipe, opt_sync_frm, opt_allow_suspicious_udfs;
+ extern my_bool opt_secure_auth;
+ extern char* opt_secure_file_priv;
+-extern my_bool opt_log_slow_admin_statements;
++extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements;
+ extern my_bool sp_automatic_privileges, opt_noacl;
+ extern my_bool opt_old_style_user_limits, trust_function_creators;
+ extern uint opt_crash_binlog_innodb;
+diff -r 1cae91646da0 sql/mysqld.cc
+--- a/sql/mysqld.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/mysqld.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -169,7 +169,6 @@
+ static void getvolumeID(BYTE *volumeName);
+ #endif /* __NETWARE__ */
+
+-
+ #ifdef _AIX41
+ int initgroups(const char *,unsigned int);
+ #endif
+@@ -213,6 +212,7 @@
+ extern "C" int gethostname(char *name, int namelen);
+ #endif
+
++ulonglong frequency= 0;
+
+ /* Constants */
+
+@@ -384,6 +384,7 @@
+ my_bool opt_secure_auth= 0;
+ char* opt_secure_file_priv= 0;
+ my_bool opt_log_slow_admin_statements= 0;
++my_bool opt_log_slow_slave_statements= 0;
+ my_bool lower_case_file_system= 0;
+ my_bool opt_large_pages= 0;
+ uint opt_large_page_size= 0;
+@@ -3490,6 +3491,8 @@
+ unireg_abort(1);
+ }
+ }
++ if (!QueryPerformanceFrequency((LARGE_INTEGER *)&frequency))
++ frequency= 0;
+ #endif /* __WIN__ */
+
+ if (init_common_variables(MYSQL_CONFIG_NAME,
+@@ -4733,7 +4736,7 @@
+ OPT_INTERACTIVE_TIMEOUT, OPT_JOIN_BUFF_SIZE,
+ OPT_KEY_BUFFER_SIZE, OPT_KEY_CACHE_BLOCK_SIZE,
+ OPT_KEY_CACHE_DIVISION_LIMIT, OPT_KEY_CACHE_AGE_THRESHOLD,
+- OPT_LONG_QUERY_TIME,
++ OPT_LONG_QUERY_TIME, OPT_MIN_EXAMINED_ROW_LIMIT,
+ OPT_LOWER_CASE_TABLE_NAMES, OPT_MAX_ALLOWED_PACKET,
+ OPT_MAX_BINLOG_CACHE_SIZE, OPT_MAX_BINLOG_SIZE,
+ OPT_MAX_CONNECTIONS, OPT_MAX_CONNECT_ERRORS,
+@@ -4824,6 +4827,10 @@
+ OPT_TIMED_MUTEXES,
+ OPT_OLD_STYLE_USER_LIMITS,
+ OPT_LOG_SLOW_ADMIN_STATEMENTS,
++ OPT_LOG_SLOW_SLAVE_STATEMENTS,
++ OPT_LOG_SLOW_RATE_LIMIT,
++ OPT_LOG_SLOW_VERBOSITY,
++ OPT_LOG_SLOW_FILTER,
+ OPT_TABLE_LOCK_WAIT_TIMEOUT,
+ OPT_PORT_OPEN_TIMEOUT,
+ OPT_MERGE,
+@@ -5205,6 +5212,11 @@
+ "Log slow OPTIMIZE, ANALYZE, ALTER and other administrative statements to the slow log if it is open.",
+ (gptr*) &opt_log_slow_admin_statements,
+ (gptr*) &opt_log_slow_admin_statements,
++ 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
++ {"log-slow-slave-statements", OPT_LOG_SLOW_SLAVE_STATEMENTS,
++ "Log slow replicated statements to the slow log if it is open.",
++ (gptr*) &opt_log_slow_slave_statements,
++ (gptr*) &opt_log_slow_slave_statements,
+ 0, GET_BOOL, NO_ARG, 0, 0, 0, 0, 0, 0},
+ {"log-slow-queries", OPT_SLOW_QUERY_LOG,
+ "Log slow queries to this log file. Defaults logging to hostname-slow.log file. Must be enabled to activate other slow log options.",
+@@ -5868,11 +5880,27 @@
+ (gptr*) 0,
+ 0, (GET_ULONG | GET_ASK_ADDR) , REQUIRED_ARG, 100,
+ 1, 100, 0, 1, 0},
++ {"log_slow_filter", OPT_LOG_SLOW_FILTER,
++ "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]",
++ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_F_NONE, 0, 0},
++ {"log_slow_rate_limit", OPT_LOG_SLOW_RATE_LIMIT,
++ "Rate limit statement writes to slow log to only those from every (1/log_slow_rate_limit) session.",
++ (gptr*) &global_system_variables.log_slow_rate_limit,
++ (gptr*) &max_system_variables.log_slow_rate_limit, 0, GET_ULONG,
++ REQUIRED_ARG, 0, 1, ~0L, 0, 1L, 0},
++ {"log_slow_verbosity", OPT_LOG_SLOW_VERBOSITY,
++ "Choose how verbose the messages to your slow log will be. Multiple flags allowed in a comma-separated string. [microtime, query_plan]",
++ 0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_V_MICROTIME, 0, 0},
+ {"long_query_time", OPT_LONG_QUERY_TIME,
+ "Log all queries that have taken more than long_query_time seconds to execute to file.",
+ (gptr*) &global_system_variables.long_query_time,
+ (gptr*) &max_system_variables.long_query_time, 0, GET_ULONG,
+- REQUIRED_ARG, 10, 1, LONG_TIMEOUT, 0, 1, 0},
++ REQUIRED_ARG, 10000000, 0, LONG_TIMEOUT * 1000000, 0, 1, 0},
++ {"min_examined_row_limit", OPT_MIN_EXAMINED_ROW_LIMIT,
++ "Don't log queries which examine less than min_examined_row_limit rows to file.",
++ (gptr*) &global_system_variables.min_examined_row_limit,
++ (gptr*) &max_system_variables.min_examined_row_limit, 0, GET_ULONG,
++ REQUIRED_ARG, 0, 0, ~0L, 0, 1L, 0},
+ {"lower_case_table_names", OPT_LOWER_CASE_TABLE_NAMES,
+ "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",
+ (gptr*) &lower_case_table_names,
+@@ -6639,7 +6667,9 @@
+ global_system_variables.max_join_size= (ulonglong) HA_POS_ERROR;
+ max_system_variables.max_join_size= (ulonglong) HA_POS_ERROR;
+ global_system_variables.old_passwords= 0;
+-
++ global_system_variables.log_slow_verbosity= SLOG_V_MICROTIME;
++ global_system_variables.log_slow_filter= SLOG_F_NONE;
++
+ /*
+ Default behavior for 4.1 and 5.0 is to treat NULL values as unequal
+ when collecting index statistics for MyISAM tables.
+@@ -7100,6 +7130,24 @@
+ case OPT_BOOTSTRAP:
+ opt_noacl=opt_bootstrap=1;
+ break;
++ case OPT_LOG_SLOW_FILTER:
++ if ((global_system_variables.log_slow_filter=
++ msl_flag_resolve_by_name(slog_filter, argument,
++ SLOG_F_NONE, SLOG_F_INVALID)) == SLOG_F_INVALID)
++ {
++ fprintf(stderr,"Invalid argument to log_slow_filter\n");
++ exit(1);
++ }
++ break;
++ case OPT_LOG_SLOW_VERBOSITY:
++ if ((global_system_variables.log_slow_verbosity=
++ msl_flag_resolve_by_name(slog_verb, argument,
++ SLOG_V_NONE, SLOG_V_INVALID)) == SLOG_V_INVALID)
++ {
++ fprintf(stderr,"Invalid argument to log_slow_verbosity\n");
++ exit(1);
++ }
++ break;
+ case OPT_STORAGE_ENGINE:
+ {
+ if ((enum db_type)((global_system_variables.table_type=
+@@ -7422,10 +7470,14 @@
+ if (opt_bdb)
+ sql_print_warning("this binary does not contain BDB storage engine");
+ #endif
+- if ((opt_log_slow_admin_statements || opt_log_queries_not_using_indexes) &&
++ if ((opt_log_slow_admin_statements || opt_log_queries_not_using_indexes ||
++ opt_log_slow_slave_statements) &&
+ !opt_slow_log)
+- sql_print_warning("options --log-slow-admin-statements and --log-queries-not-using-indexes have no effect if --log-slow-queries is not set");
+-
++ {
++ 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");
++ opt_log_slow_slave_statements= FALSE;
++ }
++
+ if (argc > 0)
+ {
+ fprintf(stderr, "%s: Too many arguments (first extra is '%s').\nUse --help to get a list of available options\n", my_progname, *argv);
+diff -r 1cae91646da0 sql/set_var.cc
+--- a/sql/set_var.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/set_var.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -211,7 +211,7 @@
+ sys_log_queries_not_using_indexes("log_queries_not_using_indexes",
+ &opt_log_queries_not_using_indexes);
+ sys_var_thd_ulong sys_log_warnings("log_warnings", &SV::log_warnings);
+-sys_var_thd_ulong sys_long_query_time("long_query_time",
++sys_var_thd_ulonglong sys_long_query_time("long_query_time",
+ &SV::long_query_time);
+ sys_var_thd_bool sys_low_priority_updates("low_priority_updates",
+ &SV::low_priority_updates,
+@@ -276,6 +276,8 @@
+ &SV::max_tmp_tables);
+ sys_var_long_ptr sys_max_write_lock_count("max_write_lock_count",
+ &max_write_lock_count);
++sys_var_thd_ulong sys_min_examined_row_limit("min_examined_row_limit",
++ &SV::min_examined_row_limit);
+ sys_var_thd_ulong sys_multi_range_count("multi_range_count",
+ &SV::multi_range_count);
+ sys_var_long_ptr sys_myisam_data_pointer_size("myisam_data_pointer_size",
+@@ -319,6 +321,20 @@
+ sys_var_bool_ptr sys_relay_log_purge("relay_log_purge",
+ &relay_log_purge);
+ #endif
++sys_var_thd_ulong sys_log_slow_rate_limit("log_slow_rate_limit",
++ &SV::log_slow_rate_limit);
++sys_var_thd_msl_flag sys_log_slow_filter("log_slow_filter",
++ &SV::log_slow_filter,
++ SLOG_F_NONE,
++ SLOG_F_NONE,
++ SLOG_F_INVALID,
++ slog_filter);
++sys_var_thd_msl_flag sys_log_slow_verbosity("log_slow_verbosity",
++ &SV::log_slow_verbosity,
++ SLOG_V_NONE,
++ SLOG_V_MICROTIME,
++ SLOG_V_INVALID,
++ slog_verb);
+ sys_var_long_ptr sys_rpl_recovery_rank("rpl_recovery_rank",
+ &rpl_recovery_rank);
+ sys_var_long_ptr sys_query_cache_size("query_cache_size",
+@@ -674,6 +690,9 @@
+ &sys_log_binlog,
+ &sys_log_off,
+ &sys_log_queries_not_using_indexes,
++ &sys_log_slow_filter,
++ &sys_log_slow_rate_limit,
++ &sys_log_slow_verbosity,
+ &sys_log_update,
+ &sys_log_warnings,
+ &sys_long_query_time,
+@@ -697,6 +716,7 @@
+ &sys_max_tmp_tables,
+ &sys_max_user_connections,
+ &sys_max_write_lock_count,
++ &sys_min_examined_row_limit,
+ &sys_multi_range_count,
+ &sys_myisam_data_pointer_size,
+ &sys_myisam_max_sort_file_size,
+@@ -966,6 +986,8 @@
+ {"log_slave_updates", (char*) &opt_log_slave_updates, SHOW_MY_BOOL},
+ #endif
+ {"log_slow_queries", (char*) &opt_slow_log, SHOW_BOOL},
++ {sys_log_slow_filter.name, (char*) &sys_log_slow_filter, SHOW_SYS},
++ {sys_log_slow_verbosity.name, (char*) &sys_log_slow_verbosity, SHOW_SYS},
+ {sys_log_warnings.name, (char*) &sys_log_warnings, SHOW_SYS},
+ {sys_long_query_time.name, (char*) &sys_long_query_time, SHOW_SYS},
+ {sys_low_priority_updates.name, (char*) &sys_low_priority_updates, SHOW_SYS},
+@@ -994,6 +1016,7 @@
+ {sys_max_tmp_tables.name, (char*) &sys_max_tmp_tables, SHOW_SYS},
+ {sys_max_user_connections.name,(char*) &sys_max_user_connections, SHOW_SYS},
+ {sys_max_write_lock_count.name, (char*) &sys_max_write_lock_count,SHOW_SYS},
++ {sys_min_examined_row_limit.name, (char*) &sys_min_examined_row_limit, SHOW_SYS},
+ {sys_multi_range_count.name, (char*) &sys_multi_range_count, SHOW_SYS},
+ {sys_myisam_data_pointer_size.name, (char*) &sys_myisam_data_pointer_size, SHOW_SYS},
+ {sys_myisam_max_sort_file_size.name, (char*) &sys_myisam_max_sort_file_size,
+@@ -1050,6 +1073,7 @@
+ {sys_query_prealloc_size.name, (char*) &sys_query_prealloc_size, SHOW_SYS},
+ {sys_range_alloc_block_size.name, (char*) &sys_range_alloc_block_size,
+ SHOW_SYS},
++ {sys_log_slow_rate_limit.name, (char*) &sys_log_slow_rate_limit, SHOW_SYS},
+ {sys_read_buff_size.name, (char*) &sys_read_buff_size, SHOW_SYS},
+ {sys_readonly.name, (char*) &sys_readonly, SHOW_SYS},
+ {sys_read_rnd_buff_size.name,(char*) &sys_read_rnd_buff_size, SHOW_SYS},
+@@ -1587,6 +1611,53 @@
+ return (byte*) &(thd->variables.*offset);
+ }
+
++void sys_var_thd_microtime::set_default(THD *thd, enum_var_type type)
++{
++ pthread_mutex_lock(&LOCK_global_system_variables);
++ global_system_variables.*offset= (ulonglong) option_limits->def_value;
++ pthread_mutex_unlock(&LOCK_global_system_variables);
++}
++
++bool sys_var_thd_microtime::check(THD *thd, set_var *var)
++{
++ if (var->value->result_type() == DECIMAL_RESULT)
++ var->save_result.ulonglong_value= (ulonglong)(var->value->val_real() * 1000000);
++ else
++ var->save_result.ulonglong_value= (ulonglong)var->value->val_int() * 1000000;
++ return 0;
++}
++
++byte *sys_var_thd_microtime::value_ptr(THD *thd, enum_var_type type,
++ LEX_STRING *base)
++{
++ if (type == OPT_GLOBAL)
++ return (byte*) &(global_system_variables.*offset);
++ return (byte*) &(thd->variables.*offset);
++}
++
++bool sys_var_thd_microtime::update(THD *thd, set_var *var)
++{
++ ulonglong tmp= var->save_result.ulonglong_value;
++
++ if (tmp > max_system_variables.*offset)
++ tmp= max_system_variables.*offset;
++
++ if (option_limits)
++ tmp= getopt_ull_limit_value(tmp, option_limits);
++
++ /* Lock is needed to make things safe on 32 bit systems */
++ if (var->type == OPT_GLOBAL)
++ {
++ /* Lock is needed to make things safe on 32 bit systems */
++ pthread_mutex_lock(&LOCK_global_system_variables);
++ global_system_variables.*offset= tmp;
++ pthread_mutex_unlock(&LOCK_global_system_variables);
++ }
++ else
++ thd->variables.*offset= (ulonglong) tmp;
++
++ return 0;
++}
+
+ bool sys_var_thd_ha_rows::update(THD *thd, set_var *var)
+ {
+@@ -3398,6 +3469,191 @@
+ #endif
+ }
+
++/* Slow log stuff */
++
++ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len)
++{
++ ulong i;
++
++ for (i=0; opts[i].name; i++)
++ {
++ if (!my_strnncoll(&my_charset_latin1,
++ (const uchar *)name, len,
++ (const uchar *)opts[i].name, strlen(opts[i].name)))
++ return opts[i].val;
++ }
++ return opts[i].val;
++}
++
++ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
++ const ulong none_val, const ulong invalid_val)
++{
++ const char *p, *e;
++ ulong val= none_val;
++
++ if (!*names_list)
++ return val;
++
++ for (p= e= names_list; ; e++)
++ {
++ ulong i;
++
++ if (*e != ',' && *e)
++ continue;
++ for (i=0; opts[i].name; i++)
++ {
++ if (!my_strnncoll(&my_charset_latin1,
++ (const uchar *)p, e - p,
++ (const uchar *)opts[i].name, strlen(opts[i].name)))
++ {
++ val= val | opts[i].val;
++ break;
++ }
++ }
++ if (opts[i].val == invalid_val)
++ return invalid_val;
++ if (!*e)
++ break;
++ p= e + 1;
++ }
++ return val;
++}
++
++const char *msl_option_get_name(const struct msl_opts *opts, ulong val)
++{
++ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
++ {
++ if (opts[i].val == val)
++ return opts[i].name;
++ }
++ return "*INVALID*";
++}
++
++char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val)
++{
++ uint offset= 0;
++
++ *buf= '\0';
++ for (ulong i=0; opts[i].name && opts[i].name[0]; i++)
++ {
++ if (opts[i].val & val)
++ offset+= snprintf(buf+offset, STRING_BUFFER_USUAL_SIZE - offset - 1,
++ "%s%s", (offset ? "," : ""), opts[i].name);
++ }
++ return buf;
++}
++
++/****************************************************************************
++ Functions to handle log_slow_verbosity
++****************************************************************************/
++
++/* Based upon sys_var::check_enum() */
++
++bool sys_var_thd_msl_option::check(THD *thd, set_var *var)
++{
++ char buff[STRING_BUFFER_USUAL_SIZE];
++ String str(buff, sizeof(buff), &my_charset_latin1), *res;
++
++ if (var->value->result_type() == STRING_RESULT)
++ {
++ ulong verb= this->invalid_val;
++ if (!(res=var->value->val_str(&str)) ||
++ (var->save_result.ulong_value=
++ (ulong) (verb= msl_option_resolve_by_name(this->opts, res->ptr(), res->length()))) == this->invalid_val)
++ goto err;
++ return 0;
++ }
++
++err:
++ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
++ return 1;
++}
++
++byte *sys_var_thd_msl_option::value_ptr(THD *thd, enum_var_type type,
++ LEX_STRING *base)
++{
++ ulong val;
++ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
++ thd->variables.*offset);
++ const char *verbosity= msl_option_get_name(this->opts, val);
++ return (byte *) verbosity;
++}
++
++
++void sys_var_thd_msl_option::set_default(THD *thd, enum_var_type type)
++{
++ if (type == OPT_GLOBAL)
++ global_system_variables.*offset= (ulong) this->default_val;
++ else
++ thd->variables.*offset= (ulong) (global_system_variables.*offset);
++}
++
++
++bool sys_var_thd_msl_option::update(THD *thd, set_var *var)
++{
++ if (var->type == OPT_GLOBAL)
++ global_system_variables.*offset= var->save_result.ulong_value;
++ else
++ thd->variables.*offset= var->save_result.ulong_value;
++ return 0;
++}
++
++/****************************************************************************
++ Functions to handle log_slow_filter
++****************************************************************************/
++
++/* Based upon sys_var::check_enum() */
++
++bool sys_var_thd_msl_flag::check(THD *thd, set_var *var)
++{
++ char buff[2 * STRING_BUFFER_USUAL_SIZE];
++ String str(buff, sizeof(buff), &my_charset_latin1), *res;
++
++ if (var->value->result_type() == STRING_RESULT)
++ {
++ ulong filter= this->none_val;
++ if (!(res=var->value->val_str(&str)) ||
++ (var->save_result.ulong_value=
++ (ulong) (filter= msl_flag_resolve_by_name(this->flags, res->ptr(), this->none_val,
++ this->invalid_val))) == this->invalid_val)
++ goto err;
++ return 0;
++ }
++
++err:
++ my_error(ER_WRONG_ARGUMENTS, MYF(0), var->var->name);
++ return 1;
++}
++
++byte *sys_var_thd_msl_flag::value_ptr(THD *thd, enum_var_type type,
++ LEX_STRING *base)
++{
++ ulong val;
++ val= ((type == OPT_GLOBAL) ? global_system_variables.*offset :
++ thd->variables.*offset);
++ msl_flag_get_name(this->flags, this->flags_string, val);
++ return (byte *) this->flags_string;
++}
++
++
++void sys_var_thd_msl_flag::set_default(THD *thd, enum_var_type type)
++{
++ if (type == OPT_GLOBAL)
++ global_system_variables.*offset= (ulong) this->default_val;
++ else
++ thd->variables.*offset= (ulong) (global_system_variables.*offset);
++}
++
++
++bool sys_var_thd_msl_flag::update(THD *thd, set_var *var)
++{
++ if (var->type == OPT_GLOBAL)
++ global_system_variables.*offset= var->save_result.ulong_value;
++ else
++ thd->variables.*offset= var->save_result.ulong_value;
++ return 0;
++}
++
+ /****************************************************************************
+ Functions to handle table_type
+ ****************************************************************************/
+diff -r 1cae91646da0 sql/set_var.h
+--- a/sql/set_var.h Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/set_var.h Mon Apr 07 14:28:43 2008 +0200
+@@ -123,6 +123,7 @@
+ };
+
+
++
+ class sys_var_ulonglong_ptr :public sys_var
+ {
+ public:
+@@ -287,7 +288,6 @@
+ }
+ };
+
+-
+ class sys_var_thd_ulong :public sys_var_thd
+ {
+ sys_check_func check_func;
+@@ -307,6 +307,23 @@
+ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
+ };
+
++class sys_var_thd_microtime :public sys_var_thd
++{
++public:
++ ulonglong SV::*offset;
++ sys_var_thd_microtime(const char *name_arg, ulonglong SV::*offset_arg)
++ :sys_var_thd(name_arg), offset(offset_arg)
++ {}
++ bool update(THD *thd, set_var *var);
++ void set_default(THD *thd, enum_var_type type);
++ SHOW_TYPE type() { return SHOW_MICROTIME; }
++ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
++ bool check(THD *thd, set_var *var);
++ bool check_update_type(Item_result type)
++ {
++ return type != INT_RESULT && type != DECIMAL_RESULT;
++ }
++};
+
+ class sys_var_thd_ha_rows :public sys_var_thd
+ {
+@@ -324,7 +341,6 @@
+ SHOW_TYPE show_type() { return SHOW_HA_ROWS; }
+ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
+ };
+-
+
+ class sys_var_thd_ulonglong :public sys_var_thd
+ {
+@@ -353,7 +369,6 @@
+ }
+ };
+
+-
+ class sys_var_thd_bool :public sys_var_thd
+ {
+ public:
+@@ -423,6 +438,66 @@
+ ulong *length);
+ };
+
++
++class sys_var_thd_msl_option :public sys_var_thd
++{
++protected:
++ ulong SV::*offset;
++ const ulong none_val;
++ const ulong default_val;
++ const ulong invalid_val;
++ const struct msl_opts *opts;
++public:
++ sys_var_thd_msl_option(const char *name_arg, ulong SV::*offset_arg,
++ const ulong none_val_arg,
++ const ulong default_val_arg,
++ const ulong invalid_val_arg,
++ const struct msl_opts *opts_arg)
++ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
++ default_val(default_val_arg), invalid_val(invalid_val_arg),
++ opts(opts_arg)
++ {}
++ bool check(THD *thd, set_var *var);
++ SHOW_TYPE show_type() { return SHOW_CHAR; }
++ bool check_update_type(Item_result type)
++ {
++ return type != STRING_RESULT; /* Only accept strings */
++ }
++ void set_default(THD *thd, enum_var_type type);
++ bool update(THD *thd, set_var *var);
++ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
++};
++
++
++class sys_var_thd_msl_flag :public sys_var_thd
++{
++protected:
++ char flags_string[2 * STRING_BUFFER_USUAL_SIZE];
++ ulong SV::*offset;
++ const ulong none_val;
++ const ulong default_val;
++ const ulong invalid_val;
++ const struct msl_opts *flags;
++public:
++ sys_var_thd_msl_flag(const char *name_arg, ulong SV::*offset_arg,
++ const ulong none_val_arg,
++ const ulong default_val_arg,
++ const ulong invalid_val_arg,
++ const struct msl_opts *flags_arg)
++ :sys_var_thd(name_arg), offset(offset_arg), none_val(none_val_arg),
++ default_val(default_val_arg), invalid_val(invalid_val_arg),
++ flags(flags_arg)
++ {}
++ bool check(THD *thd, set_var *var);
++ SHOW_TYPE show_type() { return SHOW_CHAR; }
++ bool check_update_type(Item_result type)
++ {
++ return type != STRING_RESULT; /* Only accept strings */
++ }
++ void set_default(THD *thd, enum_var_type type);
++ bool update(THD *thd, set_var *var);
++ byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
++};
+
+ class sys_var_thd_storage_engine :public sys_var_thd
+ {
+@@ -1018,3 +1093,11 @@
+ bool process_key_caches(int (* func) (const char *name, KEY_CACHE *));
+ void delete_elements(I_List<NAMED_LIST> *list,
+ void (*free_element)(const char*, gptr));
++
++/* Slow log functions */
++
++ulong msl_option_resolve_by_name(const struct msl_opts *opts, const char *name, ulong len);
++ulong msl_flag_resolve_by_name(const struct msl_opts *opts, const char *names_list,
++ const ulong none_val, const ulong invalid_val);
++const char *msl_option_get_name(const struct msl_opts *opts, ulong val);
++char *msl_flag_get_name(const struct msl_opts *opts, char *buf, ulong val);
+diff -r 1cae91646da0 sql/slave.cc
+--- a/sql/slave.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/slave.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -2908,6 +2908,12 @@
+ + MAX_LOG_EVENT_HEADER; /* note, incr over the global not session var */
+ thd->slave_thread = 1;
+ set_slave_thread_options(thd);
++ if (opt_log_slow_slave_statements)
++ {
++ thd->enable_slow_log= TRUE;
++ /* Slave thread is excluded from rate limiting the slow log writes. */
++ thd->write_to_slow_log= TRUE;
++ }
+ thd->client_capabilities = CLIENT_LOCAL_FILES;
+ thd->real_id=pthread_self();
+ pthread_mutex_lock(&LOCK_thread_count);
+diff -r 1cae91646da0 sql/sql_cache.cc
+--- a/sql/sql_cache.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_cache.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -1341,6 +1341,7 @@
+
+ thd->limit_found_rows = query->found_rows();
+ thd->status_var.last_query_cost= 0.0;
++ thd->query_plan_flags|= QPLAN_QC;
+
+ BLOCK_UNLOCK_RD(query_block);
+ DBUG_RETURN(1); // Result sent to client
+@@ -1348,6 +1349,7 @@
+ err_unlock:
+ STRUCT_UNLOCK(&structure_guard_mutex);
+ err:
++ thd->query_plan_flags|= QPLAN_QC_NO;
+ DBUG_RETURN(0); // Query was not cached
+ }
+
+diff -r 1cae91646da0 sql/sql_class.cc
+--- a/sql/sql_class.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_class.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -174,7 +174,7 @@
+ lock_id(&main_lock_id),
+ user_time(0), in_sub_stmt(0), global_read_lock(0), is_fatal_error(0),
+ transaction_rollback_request(0), is_fatal_sub_stmt_error(0),
+- rand_used(0), time_zone_used(0),
++ rand_used(0), time_zone_used(0), user_timer(0),
+ last_insert_id_used(0), last_insert_id_used_bin_log(0), insert_id_used(0),
+ clear_next_insert_id(0), in_lock_tables(0), bootstrap(0),
+ derived_tables_processing(FALSE), spcont(NULL), m_lip(NULL)
+@@ -2163,6 +2163,12 @@
+ backup->cuted_fields= cuted_fields;
+ backup->client_capabilities= client_capabilities;
+ backup->savepoints= transaction.savepoints;
++ backup->innodb_io_reads= innodb_io_reads;
++ backup->innodb_io_read= innodb_io_read;
++ backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer;
++ backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer;
++ backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer;
++ backup->innodb_page_access= innodb_page_access;
+
+ if (!lex->requires_prelocking() || is_update_query(lex->sql_command))
+ options&= ~OPTION_BIN_LOG;
+@@ -2179,7 +2185,13 @@
+ sent_row_count= 0;
+ cuted_fields= 0;
+ transaction.savepoints= 0;
+-
++ innodb_io_reads= 0;
++ innodb_io_read= 0;
++ innodb_io_reads_wait_timer= 0;
++ innodb_lock_que_wait_timer= 0;
++ innodb_innodb_que_wait_timer= 0;
++ innodb_page_access= 0;
++
+ /* Surpress OK packets in case if we will execute statements */
+ net.no_send_ok= TRUE;
+ }
+@@ -2232,6 +2244,12 @@
+ */
+ examined_row_count+= backup->examined_row_count;
+ cuted_fields+= backup->cuted_fields;
++ innodb_io_reads+= backup->innodb_io_reads;
++ innodb_io_read+= backup->innodb_io_read;
++ innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer;
++ innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer;
++ innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer;
++ innodb_page_access+= backup->innodb_page_access;
+ }
+
+
+diff -r 1cae91646da0 sql/sql_class.h
+--- a/sql/sql_class.h Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_class.h Mon Apr 07 14:28:43 2008 +0200
+@@ -43,6 +43,13 @@
+ extern char internal_table_name[2];
+ extern char empty_c_string[1];
+ extern const char **errmesg;
++#ifdef __cplusplus
++__BEGIN_DECLS
++#endif
++extern ulonglong frequency;
++#ifdef __cplusplus
++__END_DECLS
++#endif
+
+ #define TC_LOG_PAGE_SIZE 8192
+ #define TC_LOG_MIN_SIZE (3*TC_LOG_PAGE_SIZE)
+@@ -308,7 +315,7 @@
+ bool write(THD *thd, enum enum_server_command command,
+ const char *format, ...) ATTRIBUTE_FORMAT(printf, 4, 5);
+ bool write(THD *thd, const char *query, uint query_length,
+- time_t query_start=0);
++ time_t query_start=0, ulonglong query_start_timer=0);
+ bool write(Log_event* event_info); // binary log write
+ bool write(THD *thd, IO_CACHE *cache, Log_event *commit_event);
+
+@@ -514,13 +521,14 @@
+ ulong auto_increment_increment, auto_increment_offset;
+ ulong bulk_insert_buff_size;
+ ulong join_buff_size;
+- ulong long_query_time;
++ ulonglong long_query_time;
+ ulong max_allowed_packet;
+ ulong max_error_count;
+ ulong max_length_for_sort_data;
+ ulong max_sort_length;
+ ulong max_tmp_tables;
+ ulong max_insert_delayed_threads;
++ ulong min_examined_row_limit;
+ ulong multi_range_count;
+ ulong myisam_repair_threads;
+ ulong myisam_sort_buff_size;
+@@ -536,10 +544,13 @@
+ ulong preload_buff_size;
+ ulong profiling_history_size;
+ ulong query_cache_type;
++ ulong log_slow_rate_limit;
+ ulong read_buff_size;
+ ulong read_rnd_buff_size;
+ ulong div_precincrement;
+ ulong sortbuff_size;
++ ulong log_slow_filter;
++ ulong log_slow_verbosity;
+ ulong table_type;
+ ulong tx_isolation;
+ ulong completion_type;
+@@ -1106,6 +1117,12 @@
+ uint in_sub_stmt;
+ bool enable_slow_log, insert_id_used, clear_next_insert_id;
+ bool last_insert_id_used;
++ ulong innodb_io_reads;
++ ulonglong innodb_io_read;
++ ulong innodb_io_reads_wait_timer;
++ ulong innodb_lock_que_wait_timer;
++ ulong innodb_innodb_que_wait_timer;
++ ulong innodb_page_access;
+ my_bool no_send_ok;
+ SAVEPOINT *savepoints;
+ };
+@@ -1162,6 +1179,11 @@
+ class THD :public Statement,
+ public Open_tables_state
+ {
++private:
++ inline ulonglong query_start_timer() { return start_timer; }
++ inline void set_timer() { if (user_timer) start_timer=timer_after_lock=user_timer; else timer_after_lock=my_timer(&start_timer, frequency); }
++ inline void end_timer() { my_timer(&start_timer, frequency); }
++ inline void lock_timer() { my_timer(&timer_after_lock, frequency); }
+ public:
+ /*
+ Constant for THD::where initialization in the beginning of every query.
+@@ -1270,10 +1292,24 @@
+ */
+ const char *where;
+ time_t start_time,time_after_lock,user_time;
++ ulonglong start_timer,timer_after_lock, user_timer;
+ time_t connect_time,thr_create_time; // track down slow pthread_create
+ thr_lock_type update_lock_default;
+ Delayed_insert *di;
+
++ bool write_to_slow_log;
++
++ bool innodb_was_used;
++ ulong innodb_io_reads;
++ ulonglong innodb_io_read;
++ ulong innodb_io_reads_wait_timer;
++ ulong innodb_lock_que_wait_timer;
++ ulong innodb_innodb_que_wait_timer;
++ ulong innodb_page_access;
++
++ ulong query_plan_flags;
++ ulong query_plan_fsort_passes;
++
+ /* <> 0 if we are inside of trigger or stored function. */
+ uint in_sub_stmt;
+
+@@ -1650,11 +1686,11 @@
+ sql_print_information("time() failed with %d", errno);
+ }
+
+- inline time_t query_start() { query_start_used=1; return start_time; }
+- inline void set_time() { if (user_time) start_time=time_after_lock=user_time; else { safe_time(&start_time); time_after_lock= start_time; }}
+- inline void end_time() { safe_time(&start_time); }
+- inline void set_time(time_t t) { time_after_lock=start_time=user_time=t; }
+- inline void lock_time() { safe_time(&time_after_lock); }
++ inline time_t query_start() { query_start_timer(); query_start_used=1; return start_time; }
++ 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; }}
++ inline void end_time() { end_timer(); safe_time(&start_time); }
++ inline void set_time(time_t t) { set_timer(); time_after_lock=start_time=user_time=t; }
++ inline void lock_time() { lock_timer(); safe_time(&time_after_lock); }
+ inline void insert_id(ulonglong id_arg)
+ {
+ last_insert_id= id_arg;
+diff -r 1cae91646da0 sql/sql_parse.cc
+--- a/sql/sql_parse.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_parse.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -20,6 +20,7 @@
+ #include <m_ctype.h>
+ #include <myisam.h>
+ #include <my_dir.h>
++#include <my_time.h>
+
+ #ifdef HAVE_INNOBASE_DB
+ #include "ha_innodb.h"
+@@ -1190,6 +1191,15 @@
+ my_net_set_read_timeout(net, thd->variables.net_read_timeout);
+ my_net_set_write_timeout(net, thd->variables.net_write_timeout);
+
++ /*
++ If rate limiting of slow log writes is enabled, decide whether to log this
++ new thread's queries or not. Uses extremely simple algorithm. :)
++ */
++ thd->write_to_slow_log= FALSE;
++ if (thd->variables.log_slow_rate_limit <= 1 ||
++ (thd->thread_id % thd->variables.log_slow_rate_limit) == 0)
++ thd->write_to_slow_log= TRUE;
++
+ while (!net->error && net->vio != 0 &&
+ !(thd->killed == THD::KILL_CONNECTION))
+ {
+@@ -2193,27 +2203,53 @@
+ return; // Don't set time for sub stmt
+
+ start_of_query= thd->start_time;
++ ulonglong start_of_query_timer= thd->start_timer;
+ thd->end_time(); // Set start time
++
++
++ /* Follow the slow log filter configuration. */
++ if (thd->variables.log_slow_filter != SLOG_F_NONE &&
++ (!(thd->variables.log_slow_filter & thd->query_plan_flags) ||
++ ((thd->variables.log_slow_filter & SLOG_F_QC_NO) &&
++ (thd->query_plan_flags & QPLAN_QC))))
++ return;
++
++ /*
++ Low long_query_time value most likely means user is debugging stuff and even
++ though some thread's queries are not supposed to be logged b/c of the rate
++ limit, if one of them takes long enough (>= 1 second) it will be sensible
++ to make an exception and write to slow log anyway.
++ */
++ if (thd->write_to_slow_log != TRUE && thd->variables.long_query_time < 1000000 &&
++ (ulong) (thd->start_timer - thd->timer_after_lock) >= 1000000)
++ thd->write_to_slow_log= TRUE;
++
++ /* Do not log this thread's queries due to rate limiting. */
++ if (thd->write_to_slow_log != TRUE)
++ return;
+
+ /*
+ Do not log administrative statements unless the appropriate option is
+ set; do not log into slow log if reading from backup.
+ */
+- if (thd->enable_slow_log && !thd->user_time)
++ if (thd->enable_slow_log &&
++ (!thd->user_time || (thd->slave_thread && opt_log_slow_slave_statements))
++ )
+ {
+ thd_proc_info(thd, "logging slow query");
+
+- if ((ulong) (thd->start_time - thd->time_after_lock) >
+- thd->variables.long_query_time ||
+- (thd->server_status &
+- (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
+- opt_log_queries_not_using_indexes &&
+- /* == SQLCOM_END unless this is a SHOW command */
+- thd->lex->orig_sql_command == SQLCOM_END)
++ if (((ulong) (thd->start_timer - thd->timer_after_lock) >=
++ thd->variables.long_query_time ||
++ (thd->server_status &
++ (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
++ opt_log_queries_not_using_indexes &&
++ /* == SQLCOM_END unless this is a SHOW command */
++ thd->lex->orig_sql_command == SQLCOM_END) &&
++ thd->examined_row_count >= thd->variables.min_examined_row_limit)
+ {
+ thd_proc_info(thd, "logging slow query");
+ thd->status_var.long_query_count++;
+- mysql_slow_log.write(thd, thd->query, thd->query_length, start_of_query);
++ mysql_slow_log.write(thd, thd->query, thd->query_length, start_of_query, start_of_query_timer);
+ }
+ }
+ }
+@@ -5887,6 +5923,16 @@
+ thd->total_warn_count=0; // Warnings for this query
+ thd->rand_used= 0;
+ thd->sent_row_count= thd->examined_row_count= 0;
++ thd->innodb_was_used= FALSE;
++ thd->innodb_io_reads= 0;
++ thd->innodb_io_read= 0;
++ thd->innodb_io_reads_wait_timer= 0;
++ thd->innodb_lock_que_wait_timer= 0;
++ thd->innodb_innodb_que_wait_timer= 0;
++ thd->innodb_page_access= 0;
++ thd->query_plan_flags= QPLAN_NONE;
++ thd->query_plan_fsort_passes= 0;
++
+ #ifdef ENABLED_PROFILING
+ thd->profiling.reset();
+ #endif
+diff -r 1cae91646da0 sql/sql_select.cc
+--- a/sql/sql_select.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_select.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -6203,8 +6203,11 @@
+ {
+ join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
+ if (statistics)
++ {
+ statistic_increment(join->thd->status_var.select_scan_count,
+ &LOCK_status);
++ join->thd->query_plan_flags|= QPLAN_FULL_SCAN;
++ }
+ }
+ }
+ else
+@@ -6219,8 +6222,11 @@
+ {
+ join->thd->server_status|=SERVER_QUERY_NO_INDEX_USED;
+ if (statistics)
++ {
+ statistic_increment(join->thd->status_var.select_full_join_count,
+ &LOCK_status);
++ join->thd->query_plan_flags|= QPLAN_FULL_JOIN;
++ }
+ }
+ }
+ if (!table->no_keyread)
+@@ -9228,6 +9234,7 @@
+ (ulong) rows_limit,test(group)));
+
+ statistic_increment(thd->status_var.created_tmp_tables, &LOCK_status);
++ thd->query_plan_flags|= QPLAN_TMP_TABLE;
+
+ if (use_temp_pool && !(test_flags & TEST_KEEP_TMP_TABLES))
+ temp_pool_slot = bitmap_set_next(&temp_pool);
+@@ -10088,6 +10095,7 @@
+ }
+ statistic_increment(table->in_use->status_var.created_tmp_disk_tables,
+ &LOCK_status);
++ table->in_use->query_plan_flags|= QPLAN_TMP_DISK;
+ table->s->db_record_offset= 1;
+ DBUG_RETURN(0);
+ err:
+diff -r 1cae91646da0 sql/sql_show.cc
+--- a/sql/sql_show.cc Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/sql_show.cc Mon Apr 07 14:28:43 2008 +0200
+@@ -1488,6 +1488,9 @@
+ value= ((char *) status_var + (ulonglong) value);
+ case SHOW_LONGLONG:
+ end= longlong10_to_str(*(longlong*) value, buff, 10);
++ break;
++ case SHOW_MICROTIME:
++ end= buff + sprintf(buff, "%.6f", (*(ulonglong*)value) / 1000000.0);
+ break;
+ case SHOW_HA_ROWS:
+ end= longlong10_to_str((longlong) *(ha_rows*) value, buff, 10);
+diff -r 1cae91646da0 sql/structs.h
+--- a/sql/structs.h Thu Mar 27 11:55:26 2008 +0100
++++ b/sql/structs.h Mon Apr 07 14:28:43 2008 +0200
+@@ -168,8 +168,8 @@
+ enum SHOW_TYPE
+ {
+ SHOW_UNDEF,
+- SHOW_LONG, SHOW_LONGLONG, SHOW_INT, SHOW_CHAR, SHOW_CHAR_PTR,
+- SHOW_DOUBLE_STATUS,
++ SHOW_LONG, SHOW_LONGLONG, SHOW_MICROTIME, SHOW_INT, SHOW_CHAR,
++ SHOW_CHAR_PTR, SHOW_DOUBLE_STATUS,
+ SHOW_BOOL, SHOW_MY_BOOL, SHOW_OPENTABLES, SHOW_STARTTIME, SHOW_QUESTION,
+ SHOW_LONG_CONST, SHOW_INT_CONST, SHOW_HAVE, SHOW_SYS, SHOW_HA_ROWS,
+ SHOW_VARS,
More information about the Pkg-mysql-commits
mailing list