【重温mysql】七、死锁与innodb状态日志

时间 2019-11-26

原文原文链接

InnoDB 采起行级加锁策略，虽然行级加锁策略极大提升了程序的并发性能，但因为锁粒度的减少 InnoDB 执行某些操做的时候可能会同时占用多个行锁，加大了锁冲突的几率；不一样事务隔离级别对数据一致性要求不一样，如RR级别下增长的gap锁可能致使大量的锁冲突；同时不当的业务设计也可能形成死锁。死锁会占用系统资源阻塞请求，轻则影响 sql 执行效率拖慢系统，重则拖垮服务器致使服务不可用。所以咱们在使用过程当中须要尽可能避免死锁的发生，在遇到死锁时可以依据相关信息排查死锁加以防范。html

死锁机制

首先咱们来温习一下致使死锁的四个必要条件：node

互斥，一个资源每次只能被一个进程使用。
请求与占用，一个进程因请求资源而阻塞时，对已得到的资源保持不放。
不剥夺，进程已得到的资源，在该进程末使用完以前，不能强行剥夺。
循环等待，若干进程之间造成一种头尾相接的循环等待资源关系。

一样，InnoDB 中的死锁造成也须要知足上述四个条件。在 InnoDB 中形成死锁，那么必定是在多个线程同时操做同一份数据时才会产生，即存在两个或以上的事务，考虑以下场景，给定表test，表结构以下：mysql

CREATE TABLE `test` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `name` varchar(30) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB;
复制代码

预置数据以下：git

id	name
1	张三
2	李四
3	王五

如今按照以下操做，删除两条张三与李四两条数据：github

序号	事务1	状态	事务2	状态
1	begain transaction;
2	delete from test where id = 1;	执行成功，持有id=1的X锁
3			begain transaction;
4			delete from test where id = 2;	执行成功，持有id=2的X锁
5	delete from test where id = 2;	等待事务2释放锁
6			delete from test where id = 1;	等待事务1释放锁。系统检测到死锁，回滚事务2
7	commit;
8			commit;

在上述操做过程当中，咱们构造了一个很是典型的死锁条件，InnoDB 死锁机制检测到了死锁，会选择性回滚权重小的事务。经过语句能够查询死锁状态：算法

show engine innodb status;
复制代码

从上述执行过程咱们能够看出InnoDB 能够检测出死锁，那么 InnoDB 又是如何检测死锁的呢？

InnoDB 死锁策略

InnoDB 有两种死锁处理方式：sql

等待，直到超时（经过innodb_lock_wait_timeout参数控制）
死锁检测，主动回滚一条事务，让其余事务继续执行（innodb_deadlock_detect=on），该机制只适用于只有行锁的情形

InnoDB 中的死锁检测是经过Waiting For Graph算法实现的。在 InnoDB 中，会记录全部事务的锁造成一个以事务为顶点，锁为边的有向图。只需判断该有向图中是否存在回环，便可知道有无死锁存在。在上述死锁场景中，事务1在等待事务2释放ID=2的锁，而事务2也在等待事务1释放ID=1的锁，造成了回环结构，所以 InnoDB 判断系统中存在死锁。数据库

那么假设存在不少个事务，事务的相互等待，造成了一条很是长的等待链的时候InnoDB 将会如何处理呢？ 在这种状况下，当 InnoDB 等待图列表长度超出了 200 的时候，InnoDB 认为当中出现了死锁。此外当等待链上事务持有锁过多的时（须要对得到超过1,000,000个行锁），InnoDB 也认为当中出现了死锁。bash

InnoDB 检测到死锁后，是如何释放一个事务的呢？，InnoDB 经过事务权重来断定事务重要程度，权重低的会释放掉，事务权重通常是经过执行事务中的语句插入、更新、删除语句影响数据条数得出的，事务语句影响数据条数越小，该事务权重越低。服务器

InnoDB 状态分析

咱们能够经过以下语句来查看系统中是否存在死锁，如若存在死锁，状态日志将显示最后一次死锁信息，能够经过日志粗略查看死锁相关的事务与锁状况：

show engine innodb status;
复制代码

一个标准的状态日志以下：

=====================================
2019-11-19 23:19:23 0x7fa850f58700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 48 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 852151 srv_active, 0 srv_shutdown, 4608208 srv_idle
srv_master_thread log flush and writes: 5459518
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2440006
OS WAIT ARRAY INFO: signal count 2411688
RW-shared spins 0, rounds 1948637, OS waits 972484
RW-excl spins 0, rounds 1702845, OS waits 160434
RW-sx spins 4496, rounds 134826, OS waits 4138
Spin rounds per wait: 1948637.00 RW-shared, 1702845.00 RW-excl, 29.99 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-11-19 23:19:08 0x7fa860156700
*** (1) TRANSACTION:
TRANSACTION 25321837, ACTIVE 29 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 2348540, OS thread handle 140360898553600, query id 66353526 163.125.229.225 root updating
delete from test where id = 2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2266 page no 3 n bits 80 index PRIMARY of table `test`.`test` trx id 25321837 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 000001826186; asc     a ;;
 2: len 7; hex 65000001250c88; asc e   %  ;;
 3: len 6; hex e69d8ee59b9b; asc       ;;

*** (2) TRANSACTION:
TRANSACTION 25321862, ACTIVE 15 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 2348917, OS thread handle 140361143248640, query id 66353634 163.125.229.225 root updating
delete from test where id = 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 2266 page no 3 n bits 80 index PRIMARY of table `test`.`test` trx id 25321862 lock_mode X locks rec but not gap
Record lock, heap no 6 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 000001826186; asc     a ;;
 2: len 7; hex 65000001250c88; asc e   %  ;;
 3: len 6; hex e69d8ee59b9b; asc       ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2266 page no 3 n bits 80 index PRIMARY of table `test`.`test` trx id 25321862 lock_mode X locks rec but not gap waiting
Record lock, heap no 5 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 00000182616d; asc     am;;
 2: len 7; hex 58000001412fef; asc X   A/ ;;
 3: len 6; hex e5bca0e4b889; asc       ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 25321913
Purge done for trx's n:o < 25321911 undo n:o < 0 state: running but idle History list length 35 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421836854896032, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854885088, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854895120, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854891472, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854888736, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854886912, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854900592, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854898768, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854893296, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854892384, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854890560, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854886000, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 421836854883264, not started 0 lock struct(s), heap size 1136, 0 row lock(s) ---TRANSACTION 25321912, ACTIVE 0 sec 5 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2 MySQL thread id 2346328, OS thread handle 140360896157440, query id 66354003 47.98.152.73 root Trx read view will not see trx with id >= 25321911, sees < 25321837 ---TRANSACTION 25321837, ACTIVE 44 sec 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2 MySQL thread id 2348540, OS thread handle 140360898553600, query id 66353526 163.125.229.225 root -------- FILE I/O -------- I/O thread 0 state: waiting for completed aio requests (insert buffer thread) I/O thread 1 state: waiting for completed aio requests (log thread) I/O thread 2 state: waiting for completed aio requests (read thread) I/O thread 3 state: waiting for completed aio requests (read thread) I/O thread 4 state: waiting for completed aio requests (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (write thread) Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] , ibuf aio reads:, log i/o's:, sync i/o's: Pending flushes (fsync) log: 0; buffer pool: 0 846404 OS file reads, 16785073 OS file writes, 5999964 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 8.37 writes/s, 3.17 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 185, seg size 187, 28201 merges merged operations: insert 528, delete mark 7663041, delete 0 discarded operations: insert 0, delete mark 0, delete 0 Hash table size 138389, node heap has 31 buffer(s) Hash table size 138389, node heap has 2 buffer(s) Hash table size 138389, node heap has 3983 buffer(s) Hash table size 138389, node heap has 218 buffer(s) Hash table size 138389, node heap has 5 buffer(s) Hash table size 138389, node heap has 1 buffer(s) Hash table size 138389, node heap has 2 buffer(s) Hash table size 138389, node heap has 5 buffer(s) 139.08 hash searches/s, 4.46 non-hash searches/s --- LOG --- Log sequence number 24370884626 Log flushed up to 24370882478 Pages flushed up to 24370875924 Last checkpoint at 24370875333 0 pending log flushes, 0 pending chkp writes 9315962 log i/o's done, 2.31 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 549715968 Dictionary memory allocated 10240009 Buffer pool size 32764 Free buffers 1024 Database pages 27493 Old database pages 10128 Modified db pages 34 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 964069, not young 143276717 0.00 youngs/s, 0.00 non-youngs/s Pages read 845408, created 77961, written 6649614 0.00 reads/s, 0.04 creates/s, 5.40 writes/s Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 27493, unzip_LRU len: 0 I/O sum[276]:cur[1], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Process ID=1773, Main thread ID=140361173219072, state: sleeping Number of rows inserted 19006577, updated 853025, deleted 5584787, read 210247854332 0.85 inserts/s, 0.83 updates/s, 0.06 deletes/s, 21633.22 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT ============================ 复制代码

InnoDB 标准监控信息一共包含了输出头、主线程负载、信号量、死锁信息、事务信息、IO相关信息、插入缓冲和自适应哈希索引相关信息、日志信息、缓冲池和内存使用状况、行操做信息。经过这些内部状态信息咱们能够了解到InnoDB 内部实际的负载状况，对于数据库运维有着重要的做用。

输出头

标准监控信息输出头包含以下几个部分，显示了当前监控的查询时间、监控名称、本次输出与上次输出时间间隔秒数。

后台线程信息

该部分显示了后台 innodb 主线程的工做负载状况。通常来讲，srv_active 越大，srv_idle 越小代表当前mysql数据库压力不大。

信号量信息

信号量部分统计了线程空转次数以及等待获取互斥锁或读写锁信号量的次数。这里的互斥锁和读写锁指的是mysql中的Latch，主要目的为保证并发线程操做临界资源的正确性。若是有大量线程在等待信号量，多是因为磁盘 IO 性能瓶颈或 InnoDB 内部资源争夺激烈致使，而InnoDB 内部资源通常是因为并行查询过多或操做系统线程调度发生了问题。如若 os_waits 次数较高，代表 latch 争夺比较频繁。