通过performance_schema获取造成死锁的事务语句（转）

数据库日常维护中我们经常遇到死锁的问题，由于无法获取造成死锁的事务内执行过的语句，对我们死锁的分析造成很大的困难。但是在MySQL 5.7中我们可以利用performance_schema来获取这些语句，为我们解决死锁问题提供了一个新的思路，下面我们将解释这种方法的使用。

一、开启相关统计的方法

如果打开performance_schema选项来收集执行过的语句和事务会有性能损失，一般建议需要的时候开启，然后在线关闭掉。

（1） 在my.cnf中设置打开、关闭performance_schema选项随数据库启动
#设置setup_instruments表收集相关statement event
performance-schema-instrument='statement/%=ON'  
#开启events_statements_current表存储当前连接线程执行的最后一条statement event信息               
performance-schema-consumer-events-statements-current=ON   
#开启events-statements-history表默认存储每个线程最近10条statement event信息 
performance-schema-consumer-events-statements-history=ON        
#开启events-statements-history-long表默认存储最近10000条语句event信息
performance-schema-consumer-events-statements-history-long=ON   

performance-schema-consumer-statements-digest=ON       
         
#设置setup_instruments表收集transaction event
performance-schema-instrument='transaction=ON'    
#开启events_transactions_current表存储当前连接线程执行的transaction event信息              
performance-schema-consumer-events-transactions-current=ON      
#开启events_transactions_history表默认存储每个线程最近10条transaction event信息
performance-schema-consumer-events-transactions-history=ON   
#开启events_statements_history_long表默认存储最近10000条语句event信息。   
performance-schema-consumer-events-transactions-history-long=ON
（2） 在my.cnf中设置关闭performance_schema选项语句和事务收集
performance-schema-instrument='statement/%=OFF'              
performance-schema-consumer-events-statements-current=OFF
performance-schema-consumer-events-statements-history=OFF
performance-schema-consumer-events-statements-history-long=OFF
performance-schema-consumer-statements-digest=OFF

performance-schema-instrument='transaction=OFF'
performance-schema-consumer-events-transactions-current=OFF
performance-schema-consumer-events-transactions-history=OFF
performance-schema-consumer-events-transactions-history-long=OFF
（3） 在线打开performance_schema选项收集执行过的语句和事务
update setup_consumers set ENABLED='yes' where name like 'events_statements%';     
update setup_consumers set ENABLED='yes' where name like 'events_transactions%';   
update setup_consumers set ENABLED='yes' where name like 'statements-digest';      
update setup_instruments set ENABLED='yes'，TIMED='yes' where name ='transaction';
（4） 在线关闭performance_schema选项收集执行过的语句和事务
update setup_consumers set ENABLED='no' where name like 'events_statements%';     
update setup_consumers set ENABLED='no' where name like 'events_transactions%';   
update setup_consumers set ENABLED='no' where name like 'statements-digest';      
update setup_instruments set ENABLED='no'，TIMED='no' where name ='transaction';
（5） 相关参数
  • performance_schema_events_statements_history_size：定义events_statements_history表中每个线程最大行数，静态参数，修改需要重启实例。
  • performance_schema_events_statements_history_long_size：定义events_statements_history_long表最大行数，静态参数，修改需要重启实例。
  • performance_schema_events_transactions_history_size：定义events_transactions_history表每个线程最大行数，静态参数，修改需要重启实例。
  • performance_schema_events_transactions_history_long_size：定义events_transactions_history_long表最大行数，静态参数，修改需要重启实例。

二、根据死锁信息来获取造成死锁的语句

下面是一个典型的死锁日志：

*** (1) TRANSACTION:

TRANSACTION 897551, ACTIVE 48 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1136, 3 row lock(s)
MySQL thread id 4, OS thread handle 140029509830400, query id 123 localhost root 
statistics
select * from t1 where id=1 for update
2019-07-09T10:29:40.710270+08:00 3 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO 
BE GRANTED:

RECORD LOCKS space id 591 page no 3 n bits 80 index PRIMARY of table `txc_test`.`t1` 
trx id 897551 lock_mode X locks rec but not gap waiting
......

2019-07-09T10:29:40.711199+08:00 3 [Note] InnoDB: *** (2) TRANSACTION:

TRANSACTION 897550, ACTIVE 62 sec starting index read
mysql tables in use 1, locked 1
5 lock struct(s), heap size 1136, 3 row lock(s)
MySQL thread id 3, OS thread handle 140029510035200, query id 124 localhost root 
statistics
select * from t2 where id=1 for update
2019-07-09T10:29:40.711364+08:00 3 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 591 page no 3 n bits 80 index PRIMARY of table `txc_test`.`t1` 
trx id 897550 lock_mode X locks rec but not gap
......
2019-07-09T10:29:40.712249+08:00 3 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO
BE GRANTED:

RECORD LOCKS space id 592 page no 3 n bits 80 index PRIMARY of table `txc_test`.`t2`
trx id 897550 lock_mode X locks rec but not gap waiting
......
2019-07-09T10:29:40.713153+08:00 3 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)
（1）通过events_statements_history_long来查询死锁语句
  • 事务1

在死锁日志中我们可以看到导致死锁的最后一个语句是‘select * from t1 where id=1 for update’，那么我们就可以使用它来查询events_statements_history_long表。

mysql> select THREAD_ID,EVENT_ID,END_EVENT_ID,EVENT_NAME,SOURCE,SQL_TEXT,DIGEST,
CURRENT_SCHEMA,NESTING_EVENT_ID,NESTING_EVENT_TYPE, MESSAGE_TEXT,timer_start 
from events_statements_history_long where sql_text like 
'select * from t1 where id=1 for update' \G
*************************** 1. row ***************************
         THREAD_ID: 37       
          EVENT_ID: 98
      END_EVENT_ID: 106
        EVENT_NAME: statement/sql/select
            SOURCE: socket_connection.cc:101
          SQL_TEXT: select * from t1 where id=1 for update
            DIGEST: be26f0b8bee2ac2bb34e9c651d655e7c
    CURRENT_SCHEMA: txc_test
  NESTING_EVENT_ID: 96
NESTING_EVENT_TYPE: TRANSACTION
      MESSAGE_TEXT: NULL
       timer_start: 266799699801000
*************************** 2. row ***************************
         THREAD_ID: 38
          EVENT_ID: 35
      END_EVENT_ID: 37
        EVENT_NAME: statement/sql/select
            SOURCE: socket_connection.cc:101
          SQL_TEXT: select * from t1 where id=1 for update
            DIGEST: be26f0b8bee2ac2bb34e9c651d655e7c
    CURRENT_SCHEMA: txc_test
  NESTING_EVENT_ID: 19
NESTING_EVENT_TYPE: TRANSACTION
      MESSAGE_TEXT: NULL
  • 事务2

在死锁日志中我们可以看到导致死锁的最后一个语句是‘select * from t2 where id=1 for update’，那么我们就可以使用它来查询events_statements_history_long表。

 mysql> select THREAD_ID,EVENT_ID,END_EVENT_ID,EVENT_NAME,SOURCE,SQL_TEXT,DIGEST,
CURRENT_SCHEMA,NESTING_EVENT_ID,NESTING_EVENT_TYPE, MESSAGE_TEXT 
from events_statements_history_long where sql_text like 
'select * from t2 where id=1 for update' \G
*************************** 1. row ***************************
(event关联的线程id)
         THREAD_ID: 38                                          
          EVENT_ID: 21                                       
      END_EVENT_ID: 29                                          
        EVENT_NAME: statement/sql/select                      
            SOURCE: socket_connection.cc:101                  
(执行的sql语句信息)
          SQL_TEXT: select * from t2 where id=1 for update      
            DIGEST: 315b4a6a8f7424bc7591256a8937a213 
    CURRENT_SCHEMA: txc_test                                
(父语句event id)  
  NESTING_EVENT_ID: 19                                                                                
NESTING_EVENT_TYPE: TRANSACTION
      MESSAGE_TEXT: NULL
(event开始时间(从实例启动到现在的时间差)，单位皮秒)
       timer_start: 280428752972000                             
*************************** 2. row ***************************
(event关联的线程id)
         THREAD_ID: 37                                          
          EVENT_ID: 112
      END_EVENT_ID: 114
        EVENT_NAME: statement/sql/select
            SOURCE: socket_connection.cc:101
(执行的sql语句信息)
          SQL_TEXT: select * from t2 where id=1 for update      
            DIGEST: 315b4a6a8f7424bc7591256a8937a213
    CURRENT_SCHEMA: txc_test
  NESTING_EVENT_ID: 96
NESTING_EVENT_TYPE: TRANSACTION
      MESSAGE_TEXT: Deadlock found when trying to get lock; try restarting transaction
(event开始时间(从实例启动到现在的时间差)，单位皮秒)
       timer_start: 328978250011000

虽然我们根据死锁日志进行了语句查询，但是我们发现没法确认哪一个是事务1，哪一个是事务2。不过我们可以通过MESSAGE_TEXT中的信息‘Deadlock found when trying to get lock; try restarting transaction’，确认THREAD_ID：37为事务2，THREAD_ID: 38为事务1的线程，因为我们的死锁日志显示事务2被回滚掉了。需要注意这里的THREAD_ID是performance_schema内部使用的，和我们平时show processlist访问的PROCESSLIST_ID不一样。它是一个performance_schema内部的计数器源码如下：

PFS_thread* create_thread(PFS_thread_class *klass, const void *identity,
                          ulonglong processlist_id){
  PFS_thread *pfs;
  pfs_dirty_state dirty_state;
  pfs= global_thread_container.allocate(& dirty_state);  if (pfs != NULL)
  {
    pfs->m_thread_internal_id=
      PFS_atomic::add_u64(&thread_internal_id_counter.m_u64, 1);
    pfs->m_parent_thread_internal_id= 0;
    pfs->m_processlist_id= static_cast<ulong>(processlist_id);
（2）提取信息
  • 事务1

最后一条语句的END_EVENT_ID=37
最后一条语句的NESTING_EVENT_ID=19
THREAD_ID=38

因此我们可以通过如下语句得出经历的所有语句如下：

 mysql> select THREAD_ID,EVENT_ID,END_EVENT_ID,EVENT_NAME,SOURCE,SQL_TEXT,DIGEST,
CURRENT_SCHEMA,NESTING_EVENT_ID,NESTING_EVENT_TYPE, MESSAGE_TEXT,timer_start 
from events_statements_history_long where thread_id=38 and END_EVENT_ID>=19 and 
END_EVENT_ID <=37 \G

*************************** 1. row ***************************
         THREAD_ID: 38                                           
          EVENT_ID: 18                                            
      END_EVENT_ID: 19                                                                                        
        EVENT_NAME: statement/sql/begin
            SOURCE: socket_connection.cc:101
          SQL_TEXT: begin                                        
            DIGEST: f57daa74a09445d1e1c496f28fe6d906
    CURRENT_SCHEMA: txc_test
  NESTING_EVENT_ID: NULL
NESTING_EVENT_TYPE: NULL                                       
      MESSAGE_TEXT: NULL
       timer_start: 274749880798000                          
*************************** 2. row ***************************
         THREAD_ID: 38
          EVENT_ID: 21
      END_EVENT_ID: 29
        EVENT_NAME: statement/sql/select
            SOURCE: socket_connection.cc:101
          SQL_TEXT: select * from t2 where id=1 for update
            DIGEST: 315b4a6a8f7424bc7591256a8937a213
    CURRENT_SCHEMA: txc_test
  NESTING_EVENT_ID: 19
NESTING_EVENT_TYPE: TRANSACTION
      MESSAGE_TEXT: NULL
       timer_start: 280428752972000
*************************** 3. row *************************

相关文章：

猜你喜欢
相关资源
相似解决方案
热门标签
Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode