首页 > 代码库 > 为什么不记录慢查询?

为什么不记录慢查询?

㈠ 背景介绍:
  
  2014/8/18 13点37分收到前端说反馈有玩家掉线情况,检查CPU、慢查询、DB请求量,并未发现异常,DB表现一如往常。


㈡ 定位原因:

INSERT INTO t (col1, col2, col3, col4, col5, col6, col7) VALUES (‘3532082239485507011_130_99‘, ‘130_99‘, 130, 99, 3532082239485507011, 2172353000317425008, 29078) 

这个长事务执行 1个多小时没有退出,Kill 掉对应的进程,程序前端恢复正常


㈢ 处理思路:

  ⑴ 查询视图

select trx_id,trx_state,trx_started,trx_requested_lock_id,trx_weight,trx_mysql_thread_id from information_schema.innodb_trx where trx_state=‘RUNNING‘;

  ⑵ show engine innodb status\G; 关注Transactions部分提取SQL及事务信息
  

㈣ 我的疑问:


为什么这条执行了1个多小时的SQL没有被记录到慢查询日志中呢??


㈤ 原来如此:


Query_time - Lock_time > long_query_time  <===记录
Query_time - Lock_time < long_query_time  <===不记录



㈥ 模拟场景:


⑴ Query_time - Lock_time > long_query_time

Session_A:

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> select emp_no,hire_date from employees where emp_no=10170 for update;
+--------+------------+
| emp_no | hire_date  |
+--------+------------+
|  10170 | 1986-01-02 |
+--------+------------+
1 row in set (0.00 sec)

Session_B:

mysql> select emp_no,hire_date,sleep(3) from employees where emp_no=10170 for update;


过段时间在A做commit,B会执行、并被记录到slow log中:

# Time: 140818 22:37:31
# User@Host: root[root] @ localhost []  Id:     1
# Query_time: 3.049016  Lock_time: 0.018891 Rows_sent: 1  Rows_examined: 1
use employees;
SET timestamp=1408372651;
select emp_no,hire_date,sleep(3) from employees where emp_no=10170 for update;




⑵ Query_time - Lock_time < long_query_time

Session_A:

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> select emp_no,hire_date from employees where emp_no=10170 for update;
+--------+------------+
| emp_no | hire_date  |
+--------+------------+
|  10170 | 1986-01-02 |
+--------+------------+
1 row in set (0.00 sec)

Session_B:

mysql> select emp_no,hire_date from employees where emp_no=10170 for update;

过段时间在A做commit,B会执行、但不会被记录到slow log中


㈦ 我的收获:

我们日常做性能剖析实际上应该包括2个方面:

1)基于执行时间的分析

2)基于等待时间的分析


By water

Good Luck!