show processlist time负数的初探

作者简介：高鹏，笔名八怪。《深入理解MySQL主从原理》图书作者，同时运营个人公众号“MySQL学习”，持续分享遇到的有趣case以及代码解析！

本文主要解释一下下面两个语句的相应接口和时间计算方式。

• select * from information_schema.processlist;
• show processlist

一、show processlist

函数接口：mysqld_list_processes

栈帧：

#0  mysqld_list_processes (thd=0x7ffedc008250, user=0x0, verbose=false) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_show.cc:2370
#1  0x00000000015ccaab in mysql_execute_command (thd=0x7ffedc008250, first_level=true) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:3789
#2  0x00000000015d2fde in mysql_parse (thd=0x7ffedc008250, parser_state=0x7fffec5bd600) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:5901
#3  0x00000000015c6b72 in dispatch_command (thd=0x7ffedc008250, com_data=0x7fffec5bdd70, command=COM_QUERY)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1490
#4  0x00000000015c58ff in do_command (thd=0x7ffedc008250) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1021
#5  0x000000000170e578 in handle_connection (arg=0x5f4fe40) at /mysqldata/percona-server-locks-detail-5.7.22/sql/conn_handler/connection_handler_per_thread.cc:312
#6  0x0000000001945538 in pfs_spawn_thread (arg=0x6809be0) at /mysqldata/percona-server-locks-detail-5.7.22/storage/perfschema/pfs.cc:2190
#7  0x00007ffff7bcfaa1 in start_thread () from /lib64/libpthread.so.0
#8  0x00007ffff6b37c4d in clone () from /lib64/libc.so.6

其实这个时间很好理解如下：

• 服务器时间 - 命令发起的时间
• 从库SQL线程则是 服务器时间 - Event header的时间（来自主库）

因此出现负数是可能的。这里计算时间percona 和 官方版本 不同如下：

官方 5.6.25 .5.7.23 都是（可能出现负数）：

    if (thd_info->start_time)
          protocol->store_long ((longlong) (now - thd_info->start_time));

percona 5.7.22（避免出现负数用0代替）：

if (thd_info->start_time)
    {
          protocol->store_long ((thd_info->start_time > now) ? 0
                  : (longlong) (now - thd_info->start_time));    
    }

可以看到percona 对计算时间做了逻辑变化，负数会显示为0。关于负数的测试如下：

二、select * from information_schema.processlist;

函数接口：fill_schema_processlist

栈帧：

#0  Field_long::store (this=0x7ffedc0164c8, nr=-1783905, unsigned_val=false) at /mysqldata/percona-server-locks-detail-5.7.22/sql/field.cc:4121
#1  0x000000000165062d in Fill_process_list::operator() (this=0x7fffec5bb5f0, inspect_thd=0x67be360)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_show.cc:2591
#2  0x0000000000eef320 in Do_THD::operator() (this=0x7fffec5ba580, thd=0x67be360) at /mysqldata/percona-server-locks-detail-5.7.22/sql/mysqld_thd_manager.cc:46
#3  0x0000000000eefa0f in std::for_each (__first=0x7fffec5ba5d0, __last=0x7fffec5ba5e8, __f=...)
    at /usr/lib/gcc/x86_64-redhat-linux/4.4.7/../../../../include/c++/4.4.7/bits/stl_algo.h:4200
#4  0x0000000000eeeecc in Global_THD_manager::do_for_all_thd_copy (this=0x3003340, func=0x7fffec5bb5f0)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/mysqld_thd_manager.cc:262
#5  0x0000000001637280 in fill_schema_processlist (thd=0x7ffedc008250, tables=0x7ffedc0016a8, cond=0x0)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_show.cc:2608
#6  0x000000000164ce11 in do_fill_table (thd=0x7ffedc008250, table_list=0x7ffedc0016a8, qep_tab=0x7ffedc015d40)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_show.cc:8791
#7  0x000000000164d31b in get_schema_tables_result (join=0x7ffedc015660, executed_place=PROCESSED_BY_JOIN_EXEC)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_show.cc:8921
#8  0x0000000001621761 in JOIN::prepare_result (this=0x7ffedc015660) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_select.cc:909
#9  0x000000000157e699 in JOIN::exec (this=0x7ffedc015660) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_executor.cc:124
#10 0x0000000001620327 in handle_query (thd=0x7ffedc008250, lex=0x7ffedc00a880, result=0x7ffedc0025c8, added_options=0, removed_options=0)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_select.cc:185
#11 0x00000000015d1f77 in execute_sqlcom_select (thd=0x7ffedc008250, all_tables=0x7ffedc0016a8) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:5445
#12 0x00000000015ca380 in mysql_execute_command (thd=0x7ffedc008250, first_level=true) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:2939
#13 0x00000000015d2fde in mysql_parse (thd=0x7ffedc008250, parser_state=0x7fffec5bd600) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:5901
#14 0x00000000015c6b72 in dispatch_command (thd=0x7ffedc008250, com_data=0x7fffec5bdd70, command=COM_QUERY)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1490
#15 0x00000000015c58ff in do_command (thd=0x7ffedc008250) at /mysqldata/percona-server-locks-detail-5.7.22/sql/sql_parse.cc:1021
#16 0x000000000170e578 in handle_connection (arg=0x5f4fe40) at /mysqldata/percona-server-locks-detail-5.7.22/sql/conn_handler/connection_handler_per_thread.cc:312
#17 0x0000000001945538 in pfs_spawn_thread (arg=0x6809be0) at /mysqldata/percona-server-locks-detail-5.7.22/storage/perfschema/pfs.cc:2190
#18 0x00007ffff7bcfaa1 in start_thread () from /lib64/libpthread.so.0
#19 0x00007ffff6b37c4d in clone () from /lib64/libc.so.6

简单记录如下：

• Fill_process_list类 5.7
• fill_schema_processlist 函数 5.6

关于其中的Time来自如下处理，关于好像 -1 也是可能处出现的。

type_conversion_status Field_long::store(longlong nr, bool unsigned_val)
{
  ASSERT_COLUMN_MARKED_FOR_WRITE;  
  type_conversion_status error= TYPE_OK;  
  int32 res;  
  
  if (unsigned_flag)  
  {
      if (nr = (1LL << 32))    
      {
            res=(int32) (uint32) ~0L; //表达式-1      
            error= TYPE_WARN_OUT_OF_RANGE;    
      }    
      else
            res=(int32) (uint32) nr;  
   }  
   else  
   {
       if (nr < 0 && unsigned_val)    
       {
             nr= ((longlong) INT_MAX32) + 1;           // Generate overflow      
             error= TYPE_WARN_OUT_OF_RANGE;    
       }    
       if (nr < (longlong) INT_MIN32)     
       {
             res=(int32) INT_MIN32;      
             error= TYPE_WARN_OUT_OF_RANGE;    
       }    
       else if (nr > (longlong) INT_MAX32)    
       {
             res=(int32) INT_MAX32;      
             error= TYPE_WARN_OUT_OF_RANGE;    
       }    
       else
             res=(int32) nr;  
    }  
    if (error)
        set_warning(Sql_condition::SL_WARNING, ER_WARN_DATA_OUT_OF_RANGE, 1);
        
#ifdef WORDS_BIGENDIAN
  if (table->s->db_low_byte_first)  
  {
      int4store(ptr,res);  
  }  
  else
#endif
    longstore(ptr,res);  
  return error;
}

三、不同现象的测试

我们看到这里证明了上面的说法。他们来源不同。