bk commit into 5.0 tree (georg:1.1995)

[Georg Richter]

Below is the list of changes that have just been committed into a local
5.0 repository of georg. When georg does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet
  1.1995 05/08/16 11:54:21 georg@stripped +11 -0
  Implementation of WL #1277: Allow specify slow_query_time in fractions of seconds.
    
  Additionally a new status variable "min_examined_row_limit" was added,
  which prevents writing information to the slow query log, if number of
  rows < min_examined_row_limit.

  sql/structs.h
    1.49 05/08/16 11:54:15 georg@stripped +2 -2
    added new enum type SHOW_MICROTIME

  sql/sql_show.cc
    1.265 05/08/16 11:54:15 georg@stripped +3 -0
    Added output option for microtime values

  sql/sql_parse.cc
    1.470 05/08/16 11:54:15 georg@stripped +8 -5
    added timer support

  sql/sql_class.h
    1.259 05/08/16 11:54:15 georg@stripped +16 -8
    added support for timer values.

  sql/sql_class.cc
    1.201 05/08/16 11:54:15 georg@stripped +1 -1
    added initialization for user_timer

  sql/set_var.h
    1.70 05/08/16 11:54:15 georg@stripped +18 -3
    Added new class sys_var_thd_microtime for long_query_time. Values are internally
stored
    as longlong, input (SET VAR) and output (SHOW) accept/show double values.
    
    Added new variable min_examined_row_limit (request by PeterZ)

  sql/set_var.cc
    1.133 05/08/16 11:54:15 georg@stripped +52 -1
    Added new class sys_var_thd_microtime for long_query_time. Values are internally
stored
    as longlong, input (SET VAR) and output (SHOW) accept/show double values.
    
    Added new variable min_examined_row_limit (request by PeterZ)

  sql/mysqld.cc
    1.480 05/08/16 11:54:15 georg@stripped +11 -3
    added global variable frequency (will be initialised by QueryPerformanceFrequency)
    added new global variable "min_examind_row_limit" for filtering output in slow_log.

  sql/log.cc
    1.168 05/08/16 11:54:14 georg@stripped +10 -6
    added output for fractions of seconds (execution and lock time) in slow_log

  sql-common/my_time.c
    1.19 05/08/16 11:54:14 georg@stripped +34 -0
    added new function my_timer for performance measurement in microseconds

  include/my_time.h
    1.12 05/08/16 11:54:14 georg@stripped +1 -1
    added prototype for my_timer function (my_time.c)

# This is a BitKeeper patch.  What follows are the unified diffs for the
# set of deltas contained in the patch.  The rest of the patch, the part
# that BitKeeper cares about, is below these diffs.
# User:	georg
# Host:	lmy002.wdf.sap.corp
# Root:	/home/georg/work/mysql/mysql-5.0

--- 1.167/sql/log.cc	2005-07-31 11:49:47 +02:00
+++ 1.168/sql/log.cc	2005-08-16 11:54:14 +02:00
@@ -1862,10 +1862,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");
@@ -1892,7 +1893,7 @@
         localtime_r(&current_time,&tm_tmp);
         start=&tm_tmp;
         /* Note that my_b_write() assumes it knows the length for this */
-        sprintf(buff,"# Time: %02d%02d%02d %2d:%02d:%02d\n",
+        sprintf(buff,"# Time: %02d%02d%02d %2d:%02d:%02d ",
                 start->tm_year % 100,
                 start->tm_mon+1,
                 start->tm_mday,
@@ -1909,13 +1910,16 @@
                       thd->ip ? thd->ip : "") == (uint) -1)
         tmp_errno=errno;
     }
-    if (query_start_arg)
+    if (query_start_timer)
     {
+      char buf[2][20];
+      ulonglong current_timer= my_timer(&current_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);
       /* 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),
+                      "# Query_time: %s  Lock_time: %s  Rows_sent: %lu  Rows_examined:
%lu\n",
+                      buf[0], buf[1],
                       (ulong) thd->sent_row_count,
                       (ulong) thd->examined_row_count) == (uint) -1)
         tmp_errno=errno;

--- 1.479/sql/mysqld.cc	2005-08-12 22:56:12 +02:00
+++ 1.480/sql/mysqld.cc	2005-08-16 11:54:15 +02:00
@@ -165,7 +165,8 @@
 static void getvolumename();
 static void getvolumeID(BYTE *volumeName);
 #endif /* __NETWARE__ */
-  
+
+ulonglong frequency= 0;  
 
 #ifdef _AIX41
 int initgroups(const char *,unsigned int);
@@ -3135,6 +3136,8 @@
       unireg_abort(1);
     }
   }
+  if (!QueryPerformanceFrequency((LARGE_INTEGER *)&frequency))
+    frequency= 0;
 #endif /* __WIN__ */
 
   if (init_common_variables(MYSQL_CONFIG_NAME,
@@ -4334,7 +4337,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,
@@ -5371,7 +5374,12 @@
    "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, 1, 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, 1, ~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,

--- 1.200/sql/sql_class.cc	2005-08-14 23:19:58 +02:00
+++ 1.201/sql/sql_class.cc	2005-08-16 11:54:15 +02:00
@@ -175,7 +175,7 @@
    Open_tables_state(refresh_version),
    lock_id(&main_lock_id),
    user_time(0), in_sub_stmt(FALSE), global_read_lock(0), is_fatal_error(0),
-   rand_used(0), time_zone_used(0),
+   rand_used(0), time_zone_used(0), user_timer(0),
    last_insert_id_used(0), insert_id_used(0), clear_next_insert_id(0),
    in_lock_tables(0), bootstrap(0), derived_tables_processing(FALSE),
    spcont(NULL)

--- 1.258/sql/sql_class.h	2005-08-12 22:56:13 +02:00
+++ 1.259/sql/sql_class.h	2005-08-16 11:54:15 +02:00
@@ -42,6 +42,7 @@
 
 extern char internal_table_name[2];
 extern const char **errmesg;
+extern ulonglong frequency;
 
 #define TC_LOG_PAGE_SIZE   8192
 #define TC_LOG_MIN_SIZE    (3*TC_LOG_PAGE_SIZE)
@@ -307,7 +308,7 @@
   bool write(THD *thd, enum enum_server_command command,
 	     const char *format,...);
   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);
 
@@ -494,7 +495,7 @@
   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_heap_table_size;
@@ -502,6 +503,7 @@
   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;
@@ -1053,6 +1055,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:
 #ifdef EMBEDDED_LIBRARY
   struct st_mysql  *mysql;
@@ -1147,8 +1154,9 @@
     will know that the error was in having clause.
   */
   const char *where;
-  time_t     start_time,time_after_lock,user_time;
-  time_t     connect_time,thr_create_time; // track down slow pthread_create
+  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;
   my_bool    tablespace_op;	/* This is TRUE in DISCARD/IMPORT TABLESPACE */
@@ -1388,11 +1396,11 @@
     proc_info = old_msg;
     pthread_mutex_unlock(&mysys_var->mutex);
   }
-  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
time_after_lock=time(&start_time); }
-  inline void	end_time()    { time(&start_time); }
+  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 time_after_lock=time(&start_time); }
+  inline void	end_time()    { end_timer(); time(&start_time); }
   inline void	set_time(time_t t) { time_after_lock=start_time=user_time=t; }
-  inline void	lock_time()   { time(&time_after_lock); }
+  inline void	lock_time()   { lock_timer(); time(&time_after_lock); }
   inline void	insert_id(ulonglong id_arg)
   {
     last_insert_id= id_arg;

--- 1.469/sql/sql_parse.cc	2005-08-13 10:16:19 +02:00
+++ 1.470/sql/sql_parse.cc	2005-08-16 11:54:15 +02:00
@@ -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"
@@ -2044,6 +2045,7 @@
 void log_slow_statement(THD *thd)
 {
   time_t start_of_query=thd->start_time;
+  ulonglong start_of_query_timer= thd->start_timer;
   thd->end_time();				// Set start time
 
   /*
@@ -2054,14 +2056,15 @@
   {
     thd->proc_info="logging slow query";
 
-    if ((ulong) (thd->start_time - thd->time_after_lock) >
-	thd->variables.long_query_time ||
-	((thd->server_status &
+    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)) &&
-	 (specialflag & SPECIAL_LOG_QUERIES_NOT_USING_INDEXES)))
+      (specialflag & SPECIAL_LOG_QUERIES_NOT_USING_INDEXES))) &&
+      thd->examined_row_count >= thd->variables.min_examined_row_limit)
     {
       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);
     }
   }
 }

--- 1.264/sql/sql_show.cc	2005-08-12 18:27:51 +02:00
+++ 1.265/sql/sql_show.cc	2005-08-16 11:54:15 +02:00
@@ -1304,6 +1304,9 @@
         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);
           break;

--- 1.48/sql/structs.h	2005-06-16 09:11:48 +02:00
+++ 1.49/sql/structs.h	2005-08-16 11:54:15 +02:00
@@ -166,8 +166,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,

--- 1.11/include/my_time.h	2005-07-31 11:49:46 +02:00
+++ 1.12/include/my_time.h	2005-08-16 11:54:14 +02:00
@@ -88,7 +88,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_ */

--- 1.18/sql-common/my_time.c	2005-08-11 13:02:47 +02:00
+++ 1.19/sql-common/my_time.c	2005-08-16 11:54:14 +02:00
@@ -1047,3 +1047,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;
+}

--- 1.132/sql/set_var.cc	2005-08-11 18:01:36 +02:00
+++ 1.133/sql/set_var.cc	2005-08-16 11:54:15 +02:00
@@ -206,7 +206,7 @@
 sys_trust_routine_creators("log_bin_trust_routine_creators",
                            &trust_routine_creators);
 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_microtime   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,
@@ -265,6 +265,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",
@@ -623,6 +625,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,
@@ -884,6 +887,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,
@@ -1466,6 +1470,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)
 {

--- 1.69/sql/set_var.h	2005-07-28 21:39:07 +02:00
+++ 1.70/sql/set_var.h	2005-08-16 11:54:15 +02:00
@@ -92,6 +92,7 @@
 };
 
 
+
 class sys_var_ulonglong_ptr :public sys_var
 {
 public:
@@ -229,7 +230,6 @@
   }
 };
 
-
 class sys_var_thd_ulong :public sys_var_thd
 {
   sys_check_func check_func;
@@ -249,6 +249,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
 {
@@ -267,7 +284,6 @@
   byte *value_ptr(THD *thd, enum_var_type type, LEX_STRING *base);
 };
 
-
 class sys_var_thd_ulonglong :public sys_var_thd
 {
 public:
@@ -294,7 +310,6 @@
     return (only_global && type != OPT_GLOBAL);
   }
 };
-
 
 class sys_var_thd_bool :public sys_var_thd
 {