长话短说mysql slow log的query time

当时MySQL卡顿的时间只有62s，为什么这个时间却是427553s?

先看下慢日志：

# Time: 160601 15:09:52
# User@Host: slave[slave] @  [10.236.232.132]  Id: 5668740
# Query_time: 427536.674791  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0
SET timestamp=1464764992;
# administrator command: Binlog Dump;

慢日志的源码在log.cc:

/*
  Log a query to the slow log table
 
  SYNOPSIS
    log_slow()
    thd               THD of the query
    current_time      current timestamp
    query_start_arg   command start timestamp
    user_host         the pointer to the string with user@host info
    user_host_len     length of the user_host string. this is computed once
                      and passed to all general log event handlers
    query_time        Amount of time the query took to execute (in microseconds)    ###查询语句花费的时间,单位：微秒
    lock_time         Amount of time the query was locked (in microseconds)
    is_command        The flag, which determines, whether the sql_text is a
                      query or an administrator command (these are treated
                      differently by the old logging routines)
    sql_text          the very text of the query or administrator command
                      processed
    sql_text_len      the length of sql_text string
 
  DESCRIPTION
 
   Log a query to the slow log table
 
  RETURN
    FALSE - OK
    TRUE - error occured
*/
....
if (thd->start_utime)
    {
      query_utime= (current_utime - thd->start_utime); #query_utime=当前时间-线程开始时间
      lock_utime=  (thd->utime_after_lock - thd->start_utime);
    }

所以这个时间就可以解释了，这个binlog dump一共执行了427536.674791s，是正常的，这次记录慢查询的时间是：Time: 160601 15:09:52，因为上一次binlog记入的时间是：# Time: 160527 16:22:34,时间上可以对的上.