Slow query log to file now displays queries with microsecond precission

--long-query-time is now given in seconds with microseconds as decimals
--min_examined_row_limit added for slow query log
long_query_time user variable is now double with 6 decimals
Added functions to get time in microseconds
Added faster time() functions for system that has gethrtime()  (Solaris)
We now do less time() calls.
Added field->in_read_set() and field->in_write_set() for easier field manipulation by handlers
set_var.cc and my_getopt() can now handle DOUBLE variables.
All time() calls changed to my_time()
my_time() now does retry's if time() call fails.
Added debug function for stopping in mysql_admin_table() when tables are locked
Some trivial function and struct variable renames to avoid merge errors.
Fixed compiler warnings
Initialization of some time variables on windows moved to my_init() 


include/my_getopt.h:
  Added support for double arguments
include/my_sys.h:
  Fixed wrong type to packfrm()
  Added new my_time functions
include/mysql/plugin.h:
  Added support for DOUBLE
libmysql/CMakeLists.txt:
  Added new time functions
libmysql/Makefile.shared:
  Added new time functions
mysql-test/r/variables.result:
  Testing of long_query_time
mysql-test/t/variables.test:
  Testing of long_query_time
mysys/charset.c:
  Fixed compiler warnings
mysys/default_modify.c:
  Fixed compiler warnings
mysys/hash.c:
  Fixed compiler warnings
mysys/mf_getdate.c:
  Use my_time()
mysys/mf_iocache2.c:
  Fixed compiler warnings
mysys/mf_pack.c:
  Fixed compiler warnings
mysys/mf_path.c:
  Fixed compiler warnings
mysys/my_append.c:
  Fixed compiler warnings
mysys/my_compress.c:
  Fixed compiler warnings
mysys/my_copy.c:
  Fixed compiler warnings
mysys/my_gethwaddr.c:
  Fixed compiler warnings
mysys/my_getopt.c:
  Added support for double arguments
mysys/my_getsystime.c:
  Added functions to get time in microseconds.
  Added faster time() functions for system that has gethrtime()  (Solaris)
  Moved windows initialization code to my_init()
mysys/my_init.c:
  Added initializing of variables needed for windows time functions
mysys/my_static.c:
  Added variables needed for windows time functions
mysys/my_static.h:
  Added variables needed for windows time functions
mysys/my_thr_init.c:
  Added THR_LOCK_time, used for faster my_time()
mysys/mysys_priv.h:
  Added THR_LOCK_time, used for faster my_time()
mysys/thr_alarm.c:
  time() -> my_time()
sql/event_data_objects.cc:
  end_time() -> set_current_time()
sql/event_queue.cc:
  end_time() -> set_current_time()
sql/event_scheduler.cc:
  Fixed compiler warnings
sql/field.h:
  Added field->in_read_set() and field->in_write_set() for easier field manipulation by handlers
sql/item.h:
  Added decimal to Item_float(double)
sql/item_cmpfunc.h:
  Added decimal to Item_float(double)
sql/item_timefunc.cc:
  time() -> my_time()
sql/item_xmlfunc.cc:
  Fixed compiler warning
sql/lock.cc:
  lock_time() -> set_time_after_lock()
sql/log.cc:
  Timing in slow query log to file is now done in microseconds
  Changed some while() loops to for() loops.
  Fixed indentation
  time() -> my_time()
sql/log.h:
  Slow query logging is now done based on microseconds
sql/log_event.cc:
  time() -> my_time()
  Fixed arguments to new Item_float()
sql/mysql_priv.h:
  Fixed compiler warnings
  Added opt_log_slow_slave_statements
sql/mysqld.cc:
  Added --log_slow_slave_statements and --min_examined_row_limit
  --long-query-time now takes a double argument with microsecond resolution
  Don't write shutdown message when using --help
  Removed not needed \n
  Thread create time and connect time is now done in microseconds
  time() -> my_time()
  Avoid some time() calls
sql/net_serv.cc:
  Fixed compiler warnings
sql/parse_file.cc:
  time() -> my_time()
sql/set_var.cc:
  Added support for DOUBLE variables
  Added support for variables that are given in seconds with microsecond resolution
sql/set_var.h:
  Added support for variables that are given in seconds with microsecond resolution
sql/slave.cc:
  Allow logging of slave queries to slow query log if 'opt_log_slow_slave_statements' is given
  time() -> my_time()
sql/sql_cache.h:
  Fixed compiler warning()
sql/sql_class.cc:
  Initialize new THD variables
sql/sql_class.h:
  long_query_time is now in microseconds
  Added min_examined_row_limit
  Reordered some THD elements for higher efficency
  Added timers in microseconds (connect_utime, thr_create_utime, start_utime and utime_after_lock)
  Start of query is now recorded both in seconds and in microseconds.
  Following renames was made for more clarity and avoid merge problems from earlier versions:
  connect_time -> connect_utime
  thr_create_time -> thr_create_utime
  end_time()  -> set_current_time()
  lock_time() -> set_time_after_lock()
  
  Added THD::start_utime, which is start of query in microseconds from some arbitary time
  Added function THD::current_utime()
  
  Removed safe_time() as retry's are handled in my_time()
sql/sql_connect.cc:
  User resources are now using microsecond resolution
sql/sql_insert.cc:
  end_time() -> set_current_time()
sql-common/client.c:
  time() -> my_time()
sql/sql_parse.cc:
  Testing if we should print to slow_query_log() is now done with microsecond precission.
  If min_examined_row_limit is given, only log queries to slow query log that has examined more rows than this.
sql/sql_select.cc:
  Simplify code now that Item_float() takes decimals as argument
sql/sql_show.cc:
  time() -> my_time()
  Added support for SYS_DOUBLE
sql/sql_table.cc:
  Added debug function for stopping in mysql_admin_table() when tables are locked
sql/structs.h:
  intime -> reset_utime

1 files changed, 33 insertions, 30 deletions

diff --git a/sql/sql_class.h b/sql/sql_class.h
index 7fa66893f69..6c3400ef08c 100644
--- a/sql/sql_class.h
+++ b/sql/sql_class.h
@@ -249,18 +249,19 @@ struct system_variables
   ulonglong myisam_max_sort_file_size;
   ulonglong max_heap_table_size;
   ulonglong tmp_table_size;
+  ulonglong long_query_time;
   ha_rows select_limit;
   ha_rows max_join_size;
   ulong auto_increment_increment, auto_increment_offset;
   ulong bulk_insert_buff_size;
   ulong join_buff_size;
-  ulong 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;
@@ -1025,8 +1026,6 @@ public:
   Security_context main_security_ctx;
   Security_context *security_ctx;
 
-  /* remote (peer) port */
-  uint16 peer_port;
   /*
     Points to info-string that we show in SHOW PROCESSLIST
     You are supposed to update thd->proc_info only if you have coded
@@ -1034,6 +1033,14 @@ public:
   */
   const char *proc_info;
 
+  /*
+    Used in error messages to tell user in what part of MySQL we found an
+    error. E. g. when where= "having clause", if fix_fields() fails, user
+    will know that the error was in having clause.
+  */
+  const char *where;
+
+  double tmp_double_value;                    /* Used in set_var.cc */
   ulong client_capabilities;		/* What the client supports */
   ulong max_client_packet_length;
 
@@ -1055,14 +1062,12 @@ public:
   enum enum_server_command command;
   uint32     server_id;
   uint32     file_id;			// for LOAD DATA INFILE
-  /*
-    Used in error messages to tell user in what part of MySQL we found an
-    error. E. g. when where= "having clause", if fix_fields() fails, user
-    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
+  /* remote (peer) port */
+  uint16 peer_port;
+  time_t     start_time, user_time;
+  ulonglong  connect_utime, thr_create_utime; // track down slow pthread_create
+  ulonglong  start_utime, utime_after_lock;
+  
   thr_lock_type update_lock_default;
   Delayed_insert *di;
 
@@ -1570,27 +1575,25 @@ public:
     proc_info = old_msg;
     pthread_mutex_unlock(&mysys_var->mutex);
   }
-
-  static inline void safe_time(time_t *t)
+  inline time_t query_start() { query_start_used=1; return start_time; }
+  inline void set_time()
   {
-    /**
-       Wrapper around time() which retries on error (-1)
-
-       @details
-       This is needed because, despite the documentation, time() may fail
-       in some circumstances.  Here we retry time() until it succeeds, and
-       log the failure so that performance problems related to this can be
-       identified.
-    */
-    while(unlikely(time(t) == ((time_t) -1)))
-      sql_print_information("time() failed with %d", errno);
+    if (user_time)
+    {
+      start_time= user_time;
+      start_utime= utime_after_lock= my_micro_time();
+    }
+    else
+      start_utime= utime_after_lock= my_micro_time_and_time(&start_time);
   }
-
-  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 void	set_current_time()    { start_time= my_time(MY_WME); }
+  inline void	set_time(time_t t)
+  {
+    start_time= user_time= t;
+    start_utime= utime_after_lock= my_micro_time();
+  }
+  void set_time_after_lock()  { utime_after_lock= my_micro_time(); }
+  ulonglong current_utime()  { return my_micro_time(); }
   inline ulonglong found_rows(void)
   {
     return limit_found_rows;