support high precision time in show processlist (I_S.processlist) (fa…

…cebook#1084) (facebook#1084)

Summary:
The time information from 'show processlist' and in
information_schema.processlist is at the granularity of a second.

This diff provides an override (system variable) to display the time at
the granularity of a micro-second (e.g, 0.001234).

The variable is session settable.

Reference patch: facebook@b840ad76249

Pull Request resolved: facebook#1084

Differential Revision: D19357091

Pulled By: mzait

include/my_systime.h

@@ -250,6 +250,12 @@ inline void my_micro_time_to_timeval(std::uint64_t micro_time, timeval *tm) {
   tm->tv_usec = static_cast<long>(micro_time % 1000000);
 }
 
+inline unsigned long long my_timeval_to_micro_time(
+    const struct my_timeval &tm) {
+  return (static_cast<unsigned long long int>(tm.m_tv_sec) * 1000000 +
+          tm.m_tv_usec);
+}
+
 void get_date(char *to, int flag, time_t date);
 
 #endif  // MY_SYSTIME_INCLUDED

mysql-test/r/create.result

@@ -1153,7 +1153,7 @@ t1	CREATE TABLE `t1` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=TMP_TABLE_ENGINE DEFAULT CHARSET=utf8mb3
@@ -1167,7 +1167,7 @@ t1	CREATE TEMPORARY TABLE `t1` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=TMP_TABLE_ENGINE DEFAULT CHARSET=utf8mb3

mysql-test/r/dd_is_compatibility_ci.result

@@ -127,7 +127,7 @@ t1	CREATE TABLE `t1` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3

mysql-test/r/dd_is_compatibility_cs.result

@@ -127,7 +127,7 @@ t1	CREATE TABLE `t1` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb3

mysql-test/r/high_precision_processlist.result

@@ -0,0 +1,18 @@
+SET @save.high_precision_processlist=@@session.high_precision_processlist;
+Test #1: variable is off (low precision)
+SET @@session.high_precision_processlist=OFF;
+SELECT case when time=round(time) then 'success' else 'failure' end status
+FROM information_schema.processlist WHERE user="root";
+status
+success
+Warnings:
+Warning	1287	'INFORMATION_SCHEMA.PROCESSLIST' is deprecated and will be removed in a future release. Please use performance_schema.processlist instead
+Test #2: variable is on (high precision)
+SET @@session.high_precision_processlist=ON;
+SELECT case when time!=round(time) then 'success' else 'failure' end status
+FROM information_schema.processlist WHERE user="root";
+status
+success
+Warnings:
+Warning	1287	'INFORMATION_SCHEMA.PROCESSLIST' is deprecated and will be removed in a future release. Please use performance_schema.processlist instead
+SET @@session.high_precision_processlist=@save.high_precision_processlist;

mysql-test/r/mysqld--help-notwin.result

@@ -509,6 +509,9 @@ The following options may be given as the first argument:
  without a GTID to be replicated and executed on all
  servers, and finally set all servers to GTID_MODE = ON.
  -?, --help          Display this help and exit.
+ --high-precision-processlist 
+ If set, MySQL will display the time in 1/1000000 of a
+ second precision
  --high-priority-ddl Setting this flag will allow DDL commands to kill
  conflicting connections (effective for admin user only).
  --high-priority-lock-wait-timeout=# 
@@ -2566,6 +2569,7 @@ group-replication-consistency EVENTUAL
 gtid-executed-compression-period 0
 gtid-mode OFF
 help TRUE
+high-precision-processlist FALSE
 high-priority-ddl FALSE
 high-priority-lock-wait-timeout 1
 histogram-generation-max-mem-size 20000000

mysql-test/suite/funcs_1/r/is_columns_is_cs.result

@@ -234,7 +234,7 @@ def	information_schema	PROCESSLIST	USER	2		NO	varchar	26	80	NULL	NULL	NULL	utf8m
 def	information_schema	PROCESSLIST	HOST	3		NO	varchar	87	261	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(261)			select			NULL
 def	information_schema	PROCESSLIST	DB	4		YES	varchar	21	64	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(64)			select			NULL
 def	information_schema	PROCESSLIST	COMMAND	5		NO	varchar	5	16	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(16)			select			NULL
-def	information_schema	PROCESSLIST	TIME	6		NO	int	NULL	NULL	NULL	NULL	NULL	NULL	NULL	int			select			NULL
+def	information_schema	PROCESSLIST	TIME	6		NO	double	NULL	NULL	NULL	NULL	NULL	NULL	NULL	double(22,0)			select			NULL
 def	information_schema	PROCESSLIST	STATE	7		YES	varchar	21	64	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(64)			select			NULL
 def	information_schema	PROCESSLIST	INFO	8		YES	varchar	21845	65535	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(65535)			select			NULL
 def	information_schema	QUERY_PERF_COUNTER	QUERY_TYPE	1		NO	varchar	84	254	NULL	NULL	NULL	utf8mb3	utf8mb3_general_ci	varchar(254)			select			NULL
@@ -910,7 +910,7 @@ NULL	information_schema	PROCESSLIST	ID	bigint	NULL	NULL	NULL	NULL	bigint unsigne
 3.0000	information_schema	PROCESSLIST	HOST	varchar	87	261	utf8mb3	utf8mb3_general_ci	varchar(261)
 3.0476	information_schema	PROCESSLIST	DB	varchar	21	64	utf8mb3	utf8mb3_general_ci	varchar(64)
 3.2000	information_schema	PROCESSLIST	COMMAND	varchar	5	16	utf8mb3	utf8mb3_general_ci	varchar(16)
-NULL	information_schema	PROCESSLIST	TIME	int	NULL	NULL	NULL	NULL	int
+NULL	information_schema	PROCESSLIST	TIME	double	NULL	NULL	NULL	NULL	double(22,0)
 3.0476	information_schema	PROCESSLIST	STATE	varchar	21	64	utf8mb3	utf8mb3_general_ci	varchar(64)
 3.0000	information_schema	PROCESSLIST	INFO	varchar	21845	65535	utf8mb3	utf8mb3_general_ci	varchar(65535)
 3.0238	information_schema	QUERY_PERF_COUNTER	QUERY_TYPE	varchar	84	254	utf8mb3	utf8mb3_general_ci	varchar(254)

mysql-test/suite/funcs_1/r/processlist_priv_no_prot.result

@@ -29,7 +29,7 @@ PROCESSLIST	CREATE TEMPORARY TABLE `PROCESSLIST` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=TMP_TABLE_ENGINE DEFAULT CHARSET=utf8mb3
@@ -110,7 +110,7 @@ PROCESSLIST	CREATE TEMPORARY TABLE `PROCESSLIST` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=TMP_TABLE_ENGINE DEFAULT CHARSET=utf8mb3

mysql-test/suite/funcs_1/r/processlist_val_no_prot.result

@@ -17,7 +17,7 @@ PROCESSLIST	CREATE TEMPORARY TABLE `PROCESSLIST` (
   `HOST` varchar(261) NOT NULL DEFAULT '',
   `DB` varchar(64) DEFAULT NULL,
   `COMMAND` varchar(16) NOT NULL DEFAULT '',
-  `TIME` int NOT NULL DEFAULT '0',
+  `TIME` double NOT NULL DEFAULT '0',
   `STATE` varchar(64) DEFAULT NULL,
   `INFO` longtext
 ) ENGINE=TMP_TABLE_ENGINE DEFAULT CHARSET=utf8mb3

mysql-test/suite/sys_vars/r/high_precision_processlist_basic.result

@@ -0,0 +1,20 @@
+Default value of high_precision_processlist is OFF
+SELECT @@session.high_precision_processlist;
+@@session.high_precision_processlist
+0
+Can set session value and is different from global
+set @@session.high_precision_processlist=on;
+SELECT @@session.high_precision_processlist;
+@@session.high_precision_processlist
+1
+SELECT @@global.high_precision_processlist;
+@@global.high_precision_processlist
+0
+Setting it globally does not affects the session value
+set @@global.high_precision_processlist = off;
+SELECT @@session.high_precision_processlist;
+@@session.high_precision_processlist
+1
+SELECT @@global.high_precision_processlist;
+@@global.high_precision_processlist
+0

mysql-test/suite/sys_vars/t/high_precision_processlist_basic.test

@@ -0,0 +1,23 @@
+-- source include/load_sysvars.inc
+
+####
+# Verify default value is OFF
+####
+--echo Default value of high_precision_processlist is OFF
+SELECT @@session.high_precision_processlist;
+
+####
+# Verify that this is a session variable
+####
+--echo Can set session value and is different from global
+set @@session.high_precision_processlist=on;
+SELECT @@session.high_precision_processlist;
+SELECT @@global.high_precision_processlist;
+
+####
+## Verify that setting it globally does not affect the session
+####
+--echo Setting it globally does not affects the session value
+set @@global.high_precision_processlist = off;
+SELECT @@session.high_precision_processlist;
+SELECT @@global.high_precision_processlist;

mysql-test/t/high_precision_processlist.test

@@ -0,0 +1,22 @@
+
+### the test relies on information_schema.processlist where
+### it is easier to process the time using SQL statements
+
+SET @save.high_precision_processlist=@@session.high_precision_processlist;
+
+### 1: use high precision time, round yields same value for sub-sec time
+--echo Test #1: variable is off (low precision)
+SET @@session.high_precision_processlist=OFF;
+
+SELECT case when time=round(time) then 'success' else 'failure' end status
+FROM information_schema.processlist WHERE user="root";
+
+### 2: use high precision time, round yields higher value for sub-sec time
+--echo Test #2: variable is on (high precision)
+SET @@session.high_precision_processlist=ON;
+
+SELECT case when time!=round(time) then 'success' else 'failure' end status
+FROM information_schema.processlist WHERE user="root";
+
+### restore the variable to its default value
+SET @@session.high_precision_processlist=@save.high_precision_processlist;

sql/sql_show.cc

@@ -2884,7 +2884,7 @@ class thread_info {
   thread_info()
       : thread_id(0),
         tid(0),
-        start_time_in_secs(0),
+        start_time_in_micro(0),
         command(0),
         user(nullptr),
         host(nullptr),
@@ -2894,7 +2894,7 @@ class thread_info {
 
   my_thread_id thread_id;
   ulong tid;
-  time_t start_time_in_secs;
+  unsigned long long start_time_in_micro;
   uint command;
   const char *user, *host, *db, *proc_info, *state_info;
   CSET_STRING query_string;
@@ -3178,7 +3178,8 @@ class List_process_list : public Do_THD_Impl {
     mysql_mutex_unlock(&inspect_thd->LOCK_thd_query);
 
     /* MYSQL_TIME */
-    thd_info->start_time_in_secs = inspect_thd->query_start_in_secs();
+    thd_info->start_time_in_micro = my_timeval_to_micro_time(
+        inspect_thd->query_start_timeval_trunc(DATETIME_MAX_DECIMALS));
 
     /* TID */
     thd_info->tid = inspect_thd->system_thread_id();
@@ -3214,8 +3215,13 @@ void mysqld_list_processes(THD *thd, const char *user, bool verbose,
   field_list.push_back(field = new Item_empty_string("db", NAME_CHAR_LEN));
   field->set_nullable(true);
   field_list.push_back(new Item_empty_string("Command", 16));
-  field_list.push_back(field = new Item_return_int("Time", 7, MYSQL_TYPE_LONG));
-  field->unsigned_flag = false;
+  if (thd->variables.high_precision_processlist)
+    field_list.push_back(new Item_return_int("Time", 6, MYSQL_TYPE_DOUBLE));
+  else {
+    field_list.push_back(field =
+                             new Item_return_int("Time", 7, MYSQL_TYPE_LONG));
+    field->unsigned_flag = false;
+  }
   field_list.push_back(field = new Item_empty_string("State", 30));
   field->set_nullable(true);
   field_list.push_back(field = new Item_empty_string("Info", max_query_length));
@@ -3236,7 +3242,8 @@ void mysqld_list_processes(THD *thd, const char *user, bool verbose,
   // Return list sorted by thread_id.
   std::sort(thread_infos.begin(), thread_infos.end(), thread_info_compare());
 
-  time_t now = time(nullptr);
+  unsigned long long time_now = my_micro_time();
+  long long time_delta;
   for (size_t ix = 0; ix < thread_infos.size(); ++ix) {
     thread_info *thd_info = thread_infos.at(ix);
     protocol->start_row();
@@ -3249,9 +3256,14 @@ void mysqld_list_processes(THD *thd, const char *user, bool verbose,
     else
       protocol->store(Command_names::str_session(thd_info->command).c_str(),
                       system_charset_info);
-    if (thd_info->start_time_in_secs)
-      protocol->store_long((longlong)(now - thd_info->start_time_in_secs));
-    else
+
+    time_delta = time_now - thd_info->start_time_in_micro;
+    if (thd->variables.high_precision_processlist &&
+        thd_info->start_time_in_micro) {
+      protocol->store_double((double)time_delta / 1000000, 6, 0);
+    } else if (thd_info->start_time_in_micro) {
+      protocol->store_long((long)(time_delta / 1000000));
+    } else
       protocol->store_null();
     protocol->store(thd_info->state_info, system_charset_info);
     protocol->store(thd_info->query_string.str(),
@@ -3449,12 +3461,16 @@ class Fill_process_list : public Do_THD_Impl {
     mysql_mutex_unlock(&inspect_thd->LOCK_thd_query);
 
     /* MYSQL_TIME */
-    if (inspect_thd->query_start_in_secs())
-      table->field[5]->store((longlong)(my_micro_time() / 1000000 -
-                                        inspect_thd->query_start_in_secs()),
-                             false);
+    long long time_delta =
+        my_micro_time() -
+        my_timeval_to_micro_time(
+            inspect_thd->query_start_timeval_trunc(DATETIME_MAX_DECIMALS));
+    if (inspect_thd->variables.high_precision_processlist)
+      table->field[5]->store((double)time_delta /
+                             1000000);  // precision in microseconds
     else
-      table->field[5]->store(0, false);
+      table->field[5]->store(
+          (double)(time_delta / 1000000));  // precision in seconds
 
     schema_table_store_record(m_client_thd, table);
   }
@@ -5359,7 +5375,7 @@ ST_FIELD_INFO processlist_fields_info[] = {
     {"HOST", HOST_AND_PORT_LENGTH, MYSQL_TYPE_STRING, 0, 0, "Host", 0},
     {"DB", NAME_CHAR_LEN, MYSQL_TYPE_STRING, 0, 1, "Db", 0},
     {"COMMAND", 16, MYSQL_TYPE_STRING, 0, 0, "Command", 0},
-    {"TIME", 7, MYSQL_TYPE_LONG, 0, 0, "Time", 0},
+    {"TIME", MAX_DOUBLE_STR_LENGTH, MYSQL_TYPE_DOUBLE, 0, 0, "Time", 0},
     {"STATE", 64, MYSQL_TYPE_STRING, 0, 1, "State", 0},
     {"INFO", PROCESS_LIST_INFO_WIDTH, MYSQL_TYPE_STRING, 0, 1, "Info", 0},
     {nullptr, 0, MYSQL_TYPE_STRING, 0, 0, nullptr, 0}};

sql/sys_vars.cc

@@ -8538,3 +8538,8 @@ static Sys_var_bool Sys_fast_integer_to_string(
     "fast_integer_to_string",
     "Optimized implementation of integer to string conversion",
     GLOBAL_VAR(fast_integer_to_string), CMD_LINE(OPT_ARG), DEFAULT(false));
+
+static Sys_var_bool Sys_high_precision_processlist(
+    "high_precision_processlist",
+    "If set, MySQL will display the time in 1/1000000 of a second precision",
+    SESSION_VAR(high_precision_processlist), CMD_LINE(OPT_ARG), DEFAULT(false));

sql/system_variables.h

@@ -238,6 +238,7 @@ struct System_variables {
   ulonglong long_query_time;
   bool end_markers_in_json;
   bool windowing_use_high_precision;
+  bool high_precision_processlist;
   /* A bitmap for switching optimizations on/off */
   ulonglong optimizer_switch;
   ulonglong optimizer_trace;           ///< bitmap to tune optimizer tracing