当时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,时间上可以对的上.