通过查询日志定位持有锁的SQL语句

千家信息网最后更新 2025年01月28日通过查询日志定位持有锁的SQL语句MYSQL 版本：
mysql> select version();
+------------+
| version() |
+------------+
| 5.6.27-log |
+------------+
1 row in set (0.00 sec)



1. 启用查询日志
mysql> SET GLOBAL general_log=1;
Query OK, 0 rows affected (0.02 sec)


mysql> show variables like 'general_log%';
+------------------+--------------------------------------------------+
| Variable_name | Value |
+------------------+--------------------------------------------------+
| general_log | ON |
| general_log_file | /app/oracle/oradata2/mysql-5.5.37/data/oradb.log |
+------------------+--------------------------------------------------+
2 rows in set (0.00 sec)


2. 查看MYSQL 线程信息
--MYSQL 线程1
mysql> show full processlist;
+----+------+-----------+------+---------+------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+-------+-----------------------+
| 1 | root | localhost | NULL | Query | 0 | init | show full processlist |
+----+------+-----------+------+---------+------+-------+-----------------------+
1 row in set (0.00 sec)


--MYSQL 线程2
mysql> show full processlist;
+----+------+-----------+------+---------+------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+-------+-----------------------+
| 1 | root | localhost | NULL | Sleep | 145 | | NULL |
| 2 | root | localhost | NULL | Query | 0 | init | show full processlist |
+----+------+-----------+------+---------+------+-------+-----------------------+
2 rows in set (0.00 sec)


--MYSQL 线程3

mysql> show full processlist;
+----+------+-----------+------+---------+------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+-------+-----------------------+
| 1 | root | localhost | NULL | Sleep | 189 | | NULL |
| 2 | root | localhost | NULL | Sleep | 44 | | NULL |
| 3 | root | localhost | NULL | Query | 0 | init | show full processlist |
+----+------+-----------+------+---------+------+-------+-----------------------+
3 rows in set (0.00 sec)


--MSYQL 线程4
mysql> show full processlist;
+----+------+-----------+------+---------+------+-------+-----------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+---------+------+-------+-----------------------+
| 1 | root | localhost | NULL | Sleep | 238 | | NULL |
| 2 | root | localhost | NULL | Sleep | 93 | | NULL |
| 3 | root | localhost | NULL | Sleep | 49 | | NULL |
| 4 | root | localhost | NULL | Query | 0 | init | show full processlist |
+----+------+-----------+------+---------+------+-------+-----------------------+
4 rows in set (0.00 sec)


--MYSQL 查询日志
[root@oradb data]# tail -f oradb.log
/app/oracle/oradata2/mysql-5.6.27/bin/mysqld, Version: 5.6.27-log (MySQL Community Server (GPL)). started with:
Tcp port: 3306 Unix socket: /tmp/mysql.sock
Time Id Command Argument
161116 10:48:57 1 Query show variables like 'general_log%'
161116 10:50:07 1 Query show full processlist
161116 10:52:24 2 Connect root@localhost on
2 Query select @@version_comment limit 1
161116 10:52:32 2 Query show full processlist
161116 10:53:09 3 Connect root@localhost on
3 Query select @@version_comment limit 1
161116 10:53:16 3 Query show full processlist
161116 10:53:57 4 Connect root@localhost on
4 Query select @@version_comment limit 1
161116 10:54:05 4 Query show full processlist


ID：表示MYSQL 线程ID


3. 使用查询日志找出持有锁造成阻塞的SQL
--MYSQL 线程1 执行更新，并且不提交事务持续持有锁
use test;
START TRANSACTION;
UPDATE t1 SET NAME='test11' WHERE id<11;

--MYSQL 线程2，被阻塞
use test;
START TRANSACTION;
UPDATE t1 SET NAME='test11' WHERE id<10;

--MYSQL 线程3，被阻塞
use test;
START TRANSACTION;
UPDATE t1 SET NAME='test11' WHERE id<9;



--查看锁阻塞信息
SELECT CONCAT('thread ',b.trx_mysql_thread_id,' from ',p.host) AS who_blocks,
IF(p.command="Sleep",p.time,0) AS idle_in_trx,
MAX(TIMESTAMPDIFF(SECOND,r.trx_wait_started,NOW())) AS max_wait_time,
COUNT(*) AS num_waiters
FROM information_schema.`INNODB_LOCK_WAITS` AS w
INNER JOIN information_schema.`INNODB_TRX` AS b ON b.trx_id=w.`blocking_trx_id`
INNER JOIN information_schema.`INNODB_TRX` AS r ON r.`trx_id`= w.`requesting_trx_id`
LEFT JOIN information_schema.`PROCESSLIST` AS p ON p.id= b.`trx_mysql_thread_id`
GROUP BY who_blocks ORDER BY num_waiters DESC\G

*************************** 1. row ***************************
who_blocks: thread 1 from localhost
idle_in_trx: 7
max_wait_time: 4
num_waiters: 2
*************************** 2. row ***************************
who_blocks: thread 2 from localhost
idle_in_trx: 0
max_wait_time: 2
num_waiters: 1
2 rows in set (0.11 sec)

我们看到 MSYQL 线程1 阻塞了 2 个 线程。


SELECT r.trx_id AS waiting_trx_id,r.`trx_mysql_thread_id` AS waiting_thread,
TIMESTAMPDIFF(SECOND,r.trx_wait_started,CURRENT_TIMESTAMP) AS wait_time,
r.`trx_query` AS waiting_query,l.`lock_table` AS waiting_table_lock,
b.trx_id AS blocking_trx_id,b.`trx_mysql_thread_id` AS blocking_thread,
SUBSTRING(p.host,1,INSTR(p.host,':')-1) AS blocking_host,
SUBSTRING(p.host,INSTR(p.host,':')+1) AS blocking_port,
IF(p.command="Sleep",p.time,0) AS idle_in_trx,
b.`trx_query` AS blocking_query
FROM information_schema.`INNODB_LOCK_WAITS` AS w
INNER JOIN information_schema.`INNODB_TRX` AS b ON b.trx_id=w.blocking_trx_id
INNER JOIN information_schema.`INNODB_TRX` AS r ON r.trx_id = w.requesting_trx_id
INNER JOIN information_schema.`INNODB_LOCKS` AS l ON w.requested_lock_id=l.lock_id
LEFT JOIN information_schema.`PROCESSLIST` AS p ON p.id=b.trx_mysql_thread_id
ORDER BY wait_time DESC


*************************** 1. row ***************************
waiting_trx_id: 17159
waiting_thread: 2
wait_time: 3
waiting_query: UPDATE t1 SET NAME='test11' WHERE id<10
waiting_table_lock: `test`.`t1`
blocking_trx_id: 17158
blocking_thread: 1
blocking_host:
blocking_port: localhost
idle_in_trx: 456
blocking_query: NULL
*************************** 2. row ***************************
waiting_trx_id: 17160
waiting_thread: 3
wait_time: 2
waiting_query: UPDATE t1 SET NAME='test11' WHERE id<9
waiting_table_lock: `test`.`t1`
blocking_trx_id: 17158
blocking_thread: 1
blocking_host:
blocking_port: localhost
idle_in_trx: 456
blocking_query: NULL
*************************** 3. row ***************************
waiting_trx_id: 17160
waiting_thread: 3
wait_time: 2
waiting_query: UPDATE t1 SET NAME='test11' WHERE id<9
waiting_table_lock: `test`.`t1`
blocking_trx_id: 17159
blocking_thread: 2
blocking_host:
blocking_port: localhost
idle_in_trx: 0
blocking_query: UPDATE t1 SET NAME='test11' WHERE id<10
3 rows in set (0.01 sec)

等待 T1 表上的锁

--查询日志
161116 11:00:30 1 Query SELECT DATABASE()
1 Init DB test
1 Query show databases
1 Query show tables
1 Field List t1
1 Query START TRANSACTION
161116 11:00:45 2 Query SELECT DATABASE()
2 Init DB test
2 Query show databases
2 Query show tables
2 Field List t1
2 Query START TRANSACTION
161116 11:00:51 3 Query SELECT DATABASE()
3 Init DB test
3 Query show databases
3 Query show tables
3 Field List t1
3 Query START TRANSACTION
161116 11:00:54 4 Query SELECT DATABASE()
4 Init DB test
4 Query show databases
4 Query show tables
4 Field List t1
4 Query START TRANSACTION
161116 11:01:53 1 Query UPDATE t1 SET NAME='test11' WHERE id<11
161116 11:01:56 2 Query UPDATE t1 SET NAME='test11' WHERE id<10
161116 11:01:58 3 Query UPDATE t1 SET NAME='test11' WHERE id<9
161116 11:02:00 4 Query SELECT CONCAT('thread ',b.trx_mysql_thread_id,' from ',p.host) AS who_blocks,
IF(p.command="Sleep",p.time,0) AS idle_in_trx,
MAX(TIMESTAMPDIFF(SECOND,r.trx_wait_started,NOW())) AS max_wait_time,
COUNT(*) AS num_waiters
FROM information_schema.`INNODB_LOCK_WAITS` AS w
INNER JOIN information_schema.`INNODB_TRX` AS b ON b.trx_id=w.`blocking_trx_id`
INNER JOIN information_schema.`INNODB_TRX` AS r ON r.`trx_id`= w.`requesting_trx_id`
LEFT JOIN information_schema.`PROCESSLIST` AS p ON p.id= b.`trx_mysql_thread_id`
GROUP BY who_blocks ORDER BY num_waiters DESC


通过查询日志结合上面查到的锁阻塞信息可以判断是 MSYQL 线程1 执行的UPDATE t1 SET NAME='test11' WHERE id<11
语句持有锁没提交事务，阻塞了线程2、3。
从查询日志的时间上可以看出来，线程1的SQL比线程2和3的SQL先执行。