~tsarev/percona-server/5.1_slow_extended_tests_fixes_2

# name       : slow_extended.patch

# introduced : 11 or before

# maintainer : Oleg

#

#!!! notice !!!

# Any small change to this file in the main branch

# should be done or reviewed by the maintainer!

--- a/include/mysql/plugin.h

+++ b/include/mysql/plugin.h

@@ -694,6 +694,17 @@

 /* Increments the row counter, see THD::row_count */

 void thd_inc_row_count(MYSQL_THD thd);

+void increment_thd_innodb_stats(MYSQL_THD thd,

+                    unsigned long long trx_id,

+                    long io_reads,

+                    long long io_read,

+                    long io_reads_wait_timer,

+                    long lock_que_wait_timer,

+                    long que_wait_timer,

+                    long page_access);

+unsigned long thd_log_slow_verbosity(const MYSQL_THD thd);

+int thd_opt_slow_log();

+#define EXTENDED_SLOWLOG

 /**

   Create a temporary file.

--- a/include/mysql/plugin.h.pp

+++ b/include/mysql/plugin.h.pp

@@ -122,6 +122,16 @@

 char *thd_security_context(void* thd, char *buffer, unsigned int length,

                            unsigned int max_query_len);

 void thd_inc_row_count(void* thd);

+void increment_thd_innodb_stats(void* thd,

+                    unsigned long long trx_id,

+                    long io_reads,

+                    long long io_read,

+                    long io_reads_wait_timer,

+                    long lock_que_wait_timer,

+                    long que_wait_timer,

+                    long page_access);

+unsigned long thd_log_slow_verbosity(const void* thd);

+int thd_opt_slow_log();

 int mysql_tmpfile(const char *prefix);

 int thd_killed(const void* thd);

 unsigned long thd_get_thread_id(const void* thd);

--- /dev/null

+++ b/patch_info/slow_extended.info

@@ -0,0 +1,24 @@

+File=slow_extended.patch

+Name=Extended statistics in slow.log (not InnoDB part)

+Version=1.3

+Author=Percona <info@percona.com>

+License=GPL

+Comment=

+Changelog

+2008-11-26

+YK: Fix inefficient determination of trx, Make not to call useless gettimeofday when don't use slow log. Make log_slow_queries dynamic (bool).

+

+2008-11-07

+VT: Moved log_slow_rate_limit in SHOW VARIABLE into right place

+

+2008-11

+Arjen Lentz: Fixups (backward compatibility) by Arjen Lentz <arjen@openquery.com.au>

+

+2010-07

+1) Fix overflow of query time and lock time (Bug 600360) (slow_extended_fix_overflow.patch merged)

+2) Control global slow feature merged (control_global_slow.patch merged)

+3) Microseconds in slow query log merged (microseconds_in_slow_query_log.patch merged)

+4) Now use_global_long_query_time and use_global_log_slow_control are synonims. Add value "all" for use_global_log_slow_control (contol-global_slow-2.patch merged)

+5) Fix innodb_stats on replication (Bug 600684)

+6) Change variable types (system/command-line)

+

--- a/scripts/mysqldumpslow.sh

+++ b/scripts/mysqldumpslow.sh

@@ -101,8 +101,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: ([0-9.]+)\s+Lock_time: ([0-9.]+)\s+Rows_sent: ([0-9.]+).*\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:

--- a/sql/event_scheduler.cc

+++ b/sql/event_scheduler.cc

@@ -193,6 +193,7 @@

   thd->client_capabilities|= CLIENT_MULTI_RESULTS;

   pthread_mutex_lock(&LOCK_thread_count);

   thd->thread_id= thd->variables.pseudo_thread_id= thread_id++;

+  thd->write_to_slow_log= TRUE;

   pthread_mutex_unlock(&LOCK_thread_count);

   /*

--- a/sql/filesort.cc

+++ b/sql/filesort.cc

@@ -190,6 +190,7 @@

   {

     status_var_increment(thd->status_var.filesort_scan_count);

   }

+  thd->query_plan_flags|= QPLAN_FILESORT;

 #ifdef CAN_TRUST_RANGE

   if (select && select->quick && select->quick->records > 0L)

   {

@@ -255,6 +256,7 @@

   }

   else

   {

+    thd->query_plan_flags|= QPLAN_FILESORT_DISK;

     if (table_sort.buffpek && table_sort.buffpek_len < maxbuffer)

     {

       x_free(table_sort.buffpek);

@@ -1203,6 +1205,7 @@

   DBUG_ENTER("merge_buffers");

   status_var_increment(current_thd->status_var.filesort_merge_passes);

+  current_thd->query_plan_fsort_passes++;

   if (param->not_killable)

   {

     killed= &not_killable;

--- a/sql/log.cc

+++ b/sql/log.cc

@@ -524,11 +524,13 @@

 */

 bool Log_to_csv_event_handler::

-  log_slow(THD *thd, time_t current_time, time_t query_start_arg,

+  log_slow(THD *thd, ulonglong current_utime, time_t query_start_arg,

            const char *user_host, uint user_host_len,

            ulonglong query_utime, ulonglong lock_utime, bool is_command,

            const char *sql_text, uint sql_text_len)

 {

+  time_t current_time= my_time_possible_from_micro(current_utime);

+

   TABLE_LIST table_list;

   TABLE *table;

   bool result= TRUE;

@@ -754,14 +756,14 @@

 /** Wrapper around MYSQL_LOG::write() for slow log. */

 bool Log_to_file_event_handler::

-  log_slow(THD *thd, time_t current_time, time_t query_start_arg,

+  log_slow(THD *thd, ulonglong current_utime, time_t query_start_arg,

            const char *user_host, uint user_host_len,

            ulonglong query_utime, ulonglong lock_utime, bool is_command,

            const char *sql_text, uint sql_text_len)

 {

   Silence_log_table_errors error_handler;

   thd->push_internal_handler(&error_handler);

-  bool retval= mysql_slow_log.write(thd, current_time, query_start_arg,

+  bool retval= mysql_slow_log.write(thd, current_utime, query_start_arg,

                                     user_host, user_host_len,

                                     query_utime, lock_utime, is_command,

                                     sql_text, sql_text_len);

@@ -987,7 +989,7 @@

     /* fill in user_host value: the format is "%s[%s] @ %s [%s]" */

     user_host_len= (strxnmov(user_host_buff, MAX_USER_HOST_SIZE,

                              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 : "", "]", NullS) -

                     user_host_buff);

@@ -995,8 +997,22 @@

     current_time= my_time_possible_from_micro(current_utime);

     if (thd->start_utime)

     {

-      query_utime= (current_utime - thd->start_utime);

-      lock_utime=  (thd->utime_after_lock - thd->start_utime);

+      if(current_utime < thd->start_utime)

+      {

+        query_utime= 0;

+      }

+      else

+      {

+        query_utime= (current_utime - thd->start_utime);

+      }

+      if(thd->utime_after_lock < thd->start_utime)

+      {

+        lock_utime= 0;

+      }

+      else

+      {

+        lock_utime= (thd->utime_after_lock - thd->start_utime);

+      }

     }

     else

     {

@@ -1010,8 +1026,21 @@

       query_length= command_name[thd->command].length;

     }

+    if (!query_length)

+    {

+      thd->sent_row_count= thd->examined_row_count= 0;

+      thd->row_count= 0;

+      thd->orig_row_count= 0;

+      thd->bytes_sent_old= thd->status_var.bytes_sent;

+      thd->tmp_tables_used= thd->tmp_tables_disk_used= 0;

+      thd->tmp_tables_size= 0;

+      thd->innodb_was_used= FALSE;

+      thd->query_plan_flags= QPLAN_NONE;

+      thd->query_plan_fsort_passes= 0;

+    }

+

     for (current_handler= slow_log_handler_list; *current_handler ;)

-      error= (*current_handler++)->log_slow(thd, current_time, thd->start_time,

+      error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time,

                                             user_host_buff, user_host_len,

                                             query_utime, lock_utime, is_command,

                                             query, query_length) || error;

@@ -2282,12 +2311,13 @@

     TRUE - error occured

 */

-bool MYSQL_QUERY_LOG::write(THD *thd, time_t current_time,

+bool MYSQL_QUERY_LOG::write(THD *thd, ulonglong current_utime,

                             time_t query_start_arg, const char *user_host,

                             uint user_host_len, ulonglong query_utime,

                             ulonglong lock_utime, bool is_command,

                             const char *sql_text, uint sql_text_len)

 {

+  time_t current_time= my_time_possible_from_micro(current_utime);

   bool error= 0;

   DBUG_ENTER("MYSQL_QUERY_LOG::write");

@@ -2309,17 +2339,28 @@

     if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT))

     {

-      if (current_time != last_time)

+      if (opt_log_slow_timestamp_every || current_time != last_time)

       {

         last_time= current_time;

         struct tm start;

         localtime_r(&current_time, &start);

-

-        buff_len= my_snprintf(buff, sizeof buff,

-                              "# Time: %02d%02d%02d %2d:%02d:%02d\n",

-                              start.tm_year % 100, start.tm_mon + 1,

-                              start.tm_mday, start.tm_hour,

-                              start.tm_min, start.tm_sec);

+	if(opt_slow_query_log_microseconds_timestamp)

+	{

+	  ulonglong microsecond = current_utime % (1000 * 1000);

+	  buff_len= snprintf(buff, sizeof buff,

+	    "# Time: %02d%02d%02d %2d:%02d:%02d.%010lld\n",

+            start.tm_year % 100, start.tm_mon + 1,

+	    start.tm_mday, start.tm_hour,

+	    start.tm_min, start.tm_sec,microsecond);

+	}

+	else

+	{

+	  buff_len= my_snprintf(buff, sizeof buff,

+	    "# Time: %02d%02d%02d %2d:%02d:%02d\n",

+            start.tm_year % 100, start.tm_mon + 1,

+	    start.tm_mday, start.tm_hour,

+	    start.tm_min, start.tm_sec);

+	}

         /* Note that my_b_write() assumes it knows the length for this */

         if (my_b_write(&log_file, (uchar*) buff, buff_len))

@@ -2337,12 +2378,64 @@

     sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0);

     sprintf(lock_time_buff,  "%.6f", ulonglong2double(lock_utime)/1000000.0);

     if (my_b_printf(&log_file,

-                    "# Query_time: %s  Lock_time: %s"

-                    " Rows_sent: %lu  Rows_examined: %lu\n",

+                    "# Thread_id: %lu  Schema: %s  Last_errno: %u  Killed: %u\n" \

+                    "# Query_time: %s  Lock_time: %s  Rows_sent: %lu  Rows_examined: %lu  Rows_affected: %lu  Rows_read: %lu\n"

+                    "# Bytes_sent: %lu  Tmp_tables: %lu  Tmp_disk_tables: %lu  Tmp_table_sizes: %lu\n",

+                    (ulong) thd->thread_id, (thd->db ? thd->db : ""),

+                    thd->last_errno, (uint) thd->killed,

                     query_time_buff, lock_time_buff,

                     (ulong) thd->sent_row_count,

-                    (ulong) thd->examined_row_count) == (uint) -1)

+                    (ulong) thd->examined_row_count,

+                    ((long) thd->row_count_func > 0 ) ? (ulong) thd->row_count_func : 0,

+                    thd->row_count - thd->orig_row_count + 1,

+                    (ulong) (thd->status_var.bytes_sent - thd->bytes_sent_old),

+                    (ulong) thd->tmp_tables_used,

+                    (ulong) thd->tmp_tables_disk_used,

+                    (ulong) thd->tmp_tables_size) == (uint) -1)

       tmp_errno= errno;

+    if (thd->innodb_was_used)

+    {

+      char buf[20];

+      snprintf(buf, 20, "%llX", thd->innodb_trx_id);

+      if (my_b_printf(&log_file,

+                    "# InnoDB_trx_id: %s\n", buf) == (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)

+    {

+      char buf[3][20];

+      snprintf(buf[0], 20, "%.6f", thd->innodb_io_reads_wait_timer / 1000000.0);

+      snprintf(buf[1], 20, "%.6f", thd->innodb_lock_que_wait_timer / 1000000.0);

+      snprintf(buf[2], 20, "%.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[0], buf[1], buf[2],

+                      (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

       if (my_b_printf(&log_file,"use %s;\n",thd->db) == (uint) -1)

--- a/sql/log.h

+++ b/sql/log.h

@@ -211,7 +211,7 @@

              uint user_host_len, int thread_id,

              const char *command_type, uint command_type_len,

              const char *sql_text, uint sql_text_len);

-  bool write(THD *thd, time_t current_time, time_t query_start_arg,

+  bool write(THD *thd, ulonglong current_utime, time_t query_start_arg,

              const char *user_host, uint user_host_len,

              ulonglong query_utime, ulonglong lock_utime, bool is_command,

              const char *sql_text, uint sql_text_len);

@@ -425,7 +425,7 @@

   virtual bool init()= 0;

   virtual void cleanup()= 0;

-  virtual bool log_slow(THD *thd, time_t current_time,

+  virtual bool log_slow(THD *thd, ulonglong current_utime,

                         time_t query_start_arg, const char *user_host,

                         uint user_host_len, ulonglong query_utime,

                         ulonglong lock_utime, bool is_command,

@@ -454,7 +454,7 @@

   virtual bool init();

   virtual void cleanup();

-  virtual bool log_slow(THD *thd, time_t current_time,

+  virtual bool log_slow(THD *thd, ulonglong current_utime,

                         time_t query_start_arg, const char *user_host,

                         uint user_host_len, ulonglong query_utime,

                         ulonglong lock_utime, bool is_command,

@@ -486,7 +486,7 @@

   virtual bool init();

   virtual void cleanup();

-  virtual bool log_slow(THD *thd, time_t current_time,

+  virtual bool log_slow(THD *thd, ulonglong current_utime,

                         time_t query_start_arg, const char *user_host,

                         uint user_host_len, ulonglong query_utime,

                         ulonglong lock_utime, bool is_command,

--- a/sql/log_event.cc

+++ b/sql/log_event.cc

@@ -3090,6 +3090,7 @@

   LEX_STRING new_db;

   int expected_error,actual_error= 0;

   HA_CREATE_INFO db_options;

+  bool process_log_slow_statement= false;

   /*

     Colleagues: please never free(thd->catalog) in MySQL. This would

@@ -3271,19 +3272,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);

-

-      /*

-        Resetting the enable_slow_log thd variable.

-

-        We need to reset it back to the opt_log_slow_slave_statements

-        value after the statement execution (and slow logging

-        is done). It might have changed if the statement was an

-        admin statement (in which case, down in mysql_parse execution

-        thd->enable_slow_log is set to the value of

-        opt_log_slow_admin_statements).

-      */

-      thd->enable_slow_log= opt_log_slow_slave_statements;

+      process_log_slow_statement= true;

     }

     else

     {

@@ -3428,11 +3417,27 @@

     don't suffer from these assignments to 0 as DROP TEMPORARY

     TABLE uses the db.table syntax.

   */

+  close_thread_tables(thd);      

+  if(process_log_slow_statement)

+  {

+      log_slow_statement(thd);

+

+      /*

+        Resetting the enable_slow_log thd variable.

+

+        We need to reset it back to the opt_log_slow_slave_statements

+        value after the statement execution (and slow logging

+        is done). It might have changed if the statement was an

+        admin statement (in which case, down in mysql_parse execution

+        thd->enable_slow_log is set to the value of

+        opt_log_slow_admin_statements).

+      */

+      thd->enable_slow_log= opt_log_slow_slave_statements;

+  }

   thd->catalog= 0;

   thd->set_db(NULL, 0);                 /* will free the current database */

   thd->set_query(NULL, 0);

   DBUG_PRINT("info", ("end: query= 0"));

-  close_thread_tables(thd);      

   /*

     As a disk space optimization, future masters will not log an event for

     LAST_INSERT_ID() if that function returned 0 (and thus they will be able

--- a/sql/mysql_priv.h

+++ b/sql/mysql_priv.h

@@ -638,6 +638,106 @@

 #define STRING_BUFFER_USUAL_SIZE 80

+/* Slow log */

+

+struct msl_opts

+{

+  ulong val;

+  const char *name;

+};

+

+/* use global log slow control */

+#define SLOG_UG_NONE                        (1UL << 0)

+#define SLOG_UG_LOG_SLOW_FILTER             (1UL << 1)

+#define SLOG_UG_LOG_SLOW_RATE_LIMIT         (1UL << 2)

+#define SLOG_UG_LOG_SLOW_VERBOSITY          (1UL << 3)

+#define SLOG_UG_LONG_QUERY_TIME             (1UL << 4)

+#define SLOG_UG_MIN_EXAMINED_ROW_LIMIT      (1UL << 5)

+#define SLOG_UG_ALL                         SLOG_UG_LOG_SLOW_FILTER | SLOG_UG_LOG_SLOW_RATE_LIMIT | SLOG_UG_LOG_SLOW_VERBOSITY | SLOG_UG_LONG_QUERY_TIME | SLOG_UG_MIN_EXAMINED_ROW_LIMIT

+/* ... */

+#define SLOG_UG_INVALID                     1##UL << 31

+

+static const struct msl_opts slog_use_global[]=

+  {

+    /* Basic flags */

+    { SLOG_UG_NONE                      , "none" },

+    { SLOG_UG_LOG_SLOW_FILTER           , "log_slow_filter" },

+    { SLOG_UG_LOG_SLOW_RATE_LIMIT       , "log_slow_rate_limit" },

+    { SLOG_UG_LOG_SLOW_VERBOSITY        , "log_slow_verbosity" },

+    { SLOG_UG_LONG_QUERY_TIME           , "long_query_time" },

+    { SLOG_UG_MIN_EXAMINED_ROW_LIMIT    , "min_examined_row_limit" },

+    /* ... */

+    { 0, "" },

+    /* Complex flags */

+    { SLOG_UG_ALL                       , "all" },

+    /* ... */

+    { SLOG_UG_INVALID                   , (char*)0 }

+  };

+

+#define SLOG_V_MICROTIME      1 << 0

+#define SLOG_V_QUERY_PLAN     1 << 1

+#define SLOG_V_INNODB         1 << 2

+/* ... */

+#define SLOG_V_INVALID        1##UL << 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_INNODB, "innodb" },

+

+  /* End of baisc flags */

+

+  { 0, "" },

+

+  /* Complex flags */

+

+  { SLOG_V_MICROTIME, "minimal" },

+  { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN, "standard" },

+  { SLOG_V_MICROTIME|SLOG_V_QUERY_PLAN|SLOG_V_INNODB, "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##UL << 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 }

+};

+

 /*

   Some defines for exit codes for ::is_equal class functions.

 */

@@ -2002,6 +2102,10 @@

 extern my_bool opt_secure_auth;

 extern char* opt_secure_file_priv;

 extern my_bool opt_log_slow_admin_statements, opt_log_slow_slave_statements;

+extern my_bool opt_log_slow_sp_statements;

+extern my_bool opt_log_slow_timestamp_every;

+extern my_bool opt_use_global_long_query_time;

+extern my_bool opt_slow_query_log_microseconds_timestamp;

 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;

--- a/sql/mysqld.cc

+++ b/sql/mysqld.cc

@@ -520,6 +520,10 @@

 char* opt_secure_file_priv= 0;

 my_bool opt_log_slow_admin_statements= 0;

 my_bool opt_log_slow_slave_statements= 0;

+my_bool opt_log_slow_sp_statements= 0;

+my_bool opt_log_slow_timestamp_every= 0;

+my_bool opt_use_global_long_query_time= 0;

+my_bool opt_slow_query_log_microseconds_timestamp= 0;

 my_bool lower_case_file_system= 0;

 my_bool opt_large_pages= 0;

 my_bool opt_myisam_use_mmap= 0;

@@ -5798,6 +5802,11 @@

   OPT_SECURE_FILE_PRIV,

   OPT_MIN_EXAMINED_ROW_LIMIT,

   OPT_LOG_SLOW_SLAVE_STATEMENTS,

+  OPT_LOG_SLOW_RATE_LIMIT,

+  OPT_LOG_SLOW_VERBOSITY,

+  OPT_LOG_SLOW_FILTER,

+  OPT_LOG_SLOW_SP_STATEMENTS,

+  OPT_LOG_SLOW_TIMESTAMP_EVERY,

 #if defined(ENABLED_DEBUG_SYNC)

   OPT_DEBUG_SYNC_TIMEOUT,

 #endif /* defined(ENABLED_DEBUG_SYNC) */

@@ -5805,6 +5814,9 @@

   OPT_SLAVE_EXEC_MODE,

   OPT_GENERAL_LOG_FILE,

   OPT_SLOW_QUERY_LOG_FILE,

+  OPT_USE_GLOBAL_LONG_QUERY_TIME,

+  OPT_USE_GLOBAL_LOG_SLOW_CONTROL,

+  OPT_SLOW_QUERY_LOG_MICROSECONDS_TIMESTAMP,

   OPT_IGNORE_BUILTIN_INNODB,

   OPT_BINLOG_DIRECT_NON_TRANS_UPDATE,

   OPT_DEFAULT_CHARACTER_SET_OLD,

@@ -6825,6 +6837,36 @@

    "microsecond precision.",

    &long_query_time, &long_query_time, 0, GET_DOUBLE,

    REQUIRED_ARG, 10, 0, LONG_TIMEOUT, 0, 0, 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.",

+    (uchar**) &global_system_variables.log_slow_rate_limit,

+    (uchar**) &max_system_variables.log_slow_rate_limit, 0, GET_ULONG,

+    REQUIRED_ARG, 1, 1, LONG_MAX, 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, innodb]",

+    0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_V_MICROTIME, 0, 0},

+  {"log_slow_sp_statements", OPT_LOG_SLOW_SP_STATEMENTS,

+   "Log slow statements executed by stored procedure to the slow log if it is open.",

+   (uchar**) &opt_log_slow_sp_statements, (uchar**) &opt_log_slow_sp_statements,

+   0, GET_BOOL, OPT_ARG, 1, 0, 1, 0, 1, 0},

+  {"log_slow_timestamp_every", OPT_LOG_SLOW_TIMESTAMP_EVERY,

+   "Timestamp is printed for all records of the slow log even if they are same time.",

+   (uchar**) &opt_log_slow_timestamp_every, (uchar**) &opt_log_slow_timestamp_every,

+   0, GET_BOOL, OPT_ARG, 0, 0, 1, 0, 1, 0},

+  {"use_global_log_slow_control", OPT_USE_GLOBAL_LOG_SLOW_CONTROL,

+    "Choose flags, wich always use the global variables. Multiple flags allowed in a comma-separated string. [none, log_slow_filter, log_slow_rate_limit, log_slow_verbosity, long_query_time, min_examined_row_limit, all]",

+   0, 0, 0, GET_STR, REQUIRED_ARG, 0, 0, 0, SLOG_UG_NONE, 0, 0},

+  {"use_global_long_query_time", OPT_USE_GLOBAL_LONG_QUERY_TIME,

+   "Control always use global long_query_time or local long_query_time.",

+   (uchar**) &opt_use_global_long_query_time, (uchar**) &opt_use_global_long_query_time,

+   0, GET_BOOL, OPT_ARG, 0, 0, 1, 0, 1, 0},

+  {"slow_query_log_microseconds_timestamp", OPT_SLOW_QUERY_LOG_MICROSECONDS_TIMESTAMP,

+   "Use microsecond time's precision in slow query log",

+   (uchar**) &opt_slow_query_log_microseconds_timestamp, (uchar**) &opt_slow_query_log_microseconds_timestamp,

+   0, GET_BOOL, OPT_ARG, 0, 0, 1, 0, 1, 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-"

@@ -7982,6 +8024,10 @@

   global_system_variables.old_passwords= 0;

   global_system_variables.old_alter_table= 0;

   global_system_variables.binlog_format= BINLOG_FORMAT_UNSPEC;

+

+  global_system_variables.log_slow_verbosity= SLOG_V_MICROTIME;

+  global_system_variables.use_global_log_slow_control= SLOG_UG_NONE;

+  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.

@@ -8485,6 +8531,44 @@

   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 in log_slow_filter: %s\n", argument);

+      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 in log_slow_verbosity: %s\n", argument);

+      exit(1);

+    }

+    break;

+  case OPT_USE_GLOBAL_LONG_QUERY_TIME:

+    use_global_long_query_time_update(opt_use_global_long_query_time);

+    break;

+  case OPT_USE_GLOBAL_LOG_SLOW_CONTROL:

+    {

+      ulong &v= global_system_variables.use_global_log_slow_control;

+      v= msl_flag_resolve_by_name(slog_use_global, argument, SLOG_UG_NONE, SLOG_UG_INVALID);

+      if (v != SLOG_UG_NONE)

+      {

+        v&= ~SLOG_UG_NONE;

+      }

+      if (v == SLOG_UG_INVALID)

+      {

+        fprintf(stderr,"Invalid argument in use_global_log_slow_control: %s\n", argument);

+        exit(1);

+      }

+      use_global_long_query_time_update

+        (global_system_variables.use_global_log_slow_control & SLOG_UG_LONG_QUERY_TIME);

+      break;

+    }

   case OPT_SERVER_ID:

     server_id_supplied = 1;

     break;

--- a/sql/set_var.cc

+++ b/sql/set_var.cc

@@ -162,6 +162,74 @@

 static sys_var_chain vars = { NULL, NULL };

+void use_global_long_query_time_update(bool enable)

+{

+  ulong &log_slow_control= global_system_variables.use_global_log_slow_control;

+  opt_use_global_long_query_time= enable;

+  if (enable)

+    log_slow_control|= SLOG_UG_LONG_QUERY_TIME;

+  else

+    log_slow_control&= ~SLOG_UG_LONG_QUERY_TIME;

+  log_slow_control&= ~SLOG_UG_NONE;

+  if (log_slow_control == 0)

+    log_slow_control= SLOG_UG_NONE;

+}

+

+class sys_var_use_global_long_query_time : public sys_var_bool_ptr

+{

+public:

+  sys_var_use_global_long_query_time()

+    :sys_var_bool_ptr(&vars,"use_global_long_query_time",&opt_use_global_long_query_time)

+  {

+    chain_sys_var(&vars);

+  }

+  virtual bool update(THD *thd, set_var *var)

+  {

+    bool result = sys_var_bool_ptr::update(thd,var);

+    sync();

+    return result;

+  }

+  virtual void set_default(THD *thd, enum_var_type type)

+  {

+    sys_var_bool_ptr::set_default(thd,type);

+    sync();

+  }

+private:

+  void sync()

+  {

+    use_global_long_query_time_update(opt_use_global_long_query_time);    

+  }

+};

+class sys_var_use_global_log_slow_control : public sys_var_thd_msl_flag_correct_none

+{

+ public:

+  sys_var_use_global_log_slow_control() : sys_var_thd_msl_flag_correct_none(

+								 &vars

+								 ,"use_global_log_slow_control"

+								 ,&SV::use_global_log_slow_control

+								 ,SLOG_UG_NONE,SLOG_UG_NONE,SLOG_UG_INVALID

+								 ,slog_use_global)

+    {

+    }

+  virtual bool update(THD *thd, set_var *var)

+  {

+    bool result = sys_var_thd_msl_flag_correct_none::update(thd,var);

+    sync();

+    return result;

+  }

+  virtual void set_default(THD *thd, enum_var_type type)

+  {

+    sys_var_thd_msl_flag_correct_none::set_default(thd,type);

+    sync();

+  }

+private:

+  void sync()

+  {

+    ulong const &variable= global_system_variables.use_global_log_slow_control;

+    use_global_long_query_time_update((variable & SLOG_UG_LONG_QUERY_TIME));

+  }

+};

+

 static sys_var_thd_ulong

 sys_auto_increment_increment(&vars, "auto_increment_increment",

                              &SV::auto_increment_increment, NULL, NULL,

@@ -901,6 +969,30 @@

                                       QUERY_LOG_GENERAL);

 static sys_var_log_state sys_var_slow_query_log(&vars, "slow_query_log", &opt_slow_log,

                                          QUERY_LOG_SLOW);

+static sys_var_thd_ulong      sys_log_slow_rate_limit(&vars, "log_slow_rate_limit",

+                                            &SV::log_slow_rate_limit);

+static sys_var_thd_msl_flag   sys_log_slow_filter(&vars, "log_slow_filter",

+                                      &SV::log_slow_filter,

+                                       SLOG_F_NONE,

+                                       SLOG_F_NONE,

+                                       SLOG_F_INVALID,

+                                       slog_filter);

+static sys_var_thd_msl_flag   sys_log_slow_verbosity(&vars, "log_slow_verbosity",

+                                      &SV::log_slow_verbosity,

+                                       SLOG_V_NONE,

+                                       SLOG_V_MICROTIME,

+                                       SLOG_V_INVALID,

+                                       slog_verb);

+static sys_var_use_global_log_slow_control sys_use_global_log_slow_control;

+static sys_var_bool_ptr       sys_log_slow_slave_statements(&vars, "log_slow_slave_statements",

+                                                            &opt_log_slow_slave_statements);

+static sys_var_bool_ptr       sys_log_slow_sp_statements(&vars, "log_slow_sp_statements",

+                                                         &opt_log_slow_sp_statements);

+static sys_var_bool_ptr       sys_log_slow_timestamp_every(&vars, "log_slow_timestamp_every",

+                                                           &opt_log_slow_timestamp_every);

+static sys_var_use_global_long_query_time sys_use_global_long_query_time;

+static sys_var_bool_ptr       sys_slow_query_log_microseconds_timestamp(&vars, "slow_query_log_microseconds_timestamp",

+                                                       &opt_slow_query_log_microseconds_timestamp);

 /* Synonym of "slow_query_log" for consistency with SHOW VARIABLES output */

 static sys_var_log_state sys_var_log_slow(&vars, "log_slow_queries",

                                           &opt_slow_log, QUERY_LOG_SLOW);

@@ -3711,6 +3803,203 @@

 #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;

+}

+

+uchar *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 (uchar *) 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;

+}

+

+uchar *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 (uchar *) 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;

+}

+bool sys_var_thd_msl_flag_correct_none::update(THD *thd, set_var *var)

+{

+  ulong result = var->save_result.ulong_value;

+  if (result != none_val)

+    result = result & (~none_val);

+  if (var->type == OPT_GLOBAL)

+    global_system_variables.*offset = result;

+  else

+    thd->variables.*offset = result;

+  return 0;

+}

+

+

 /****************************************************************************

  Functions to handle table_type

 ****************************************************************************/

--- a/sql/set_var.h

+++ b/sql/set_var.h

@@ -569,6 +569,82 @@

 };

+extern void use_global_long_query_time_update(bool enable);

+

+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(sys_var_chain *chain, 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)

+  { chain_sys_var(chain); }

+  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);

+  uchar *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(sys_var_chain *chain, 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)

+  { chain_sys_var(chain); }

+  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);

+  uchar *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);

+};

+