Mysql常见问题排查

594 阅读10分钟

CPU跑满

  • 死锁检测

    • 去查询死锁
  • 复杂的操作(join, group by, order by, 嵌套insert)

内存跑满

  • 死连接过多

    • (show processlist 查看sleep 数量, 直接断开), 可以去设置 wait_timeout的过期时间
  • 复杂的join语句

    • 给被join 的表加上索引,原join表先进行一些限制条件
  • 缓存设置有问题

    • 最重要的缓存是innodb_buffer_pool_size,一般设置为物理内存的 70%

IO瓶颈

  • 本身并发量就很大

    • 分库分表(垂直, 水平)
  • 日志的设置问题

    • 双1设置调整一下,几条再刷盘一次
  • SQL写法引起的磁盘IO过高,形成大量的磁盘临时表

    • 尽量采用内存临时表进行改善

sql 执行缓慢

一些设置

  • 通过慢查询日志进行分析

  • 打开慢查询记录

image.png

  • 设置慢查询时长

image.png

  • 设置存储位置

image.png

image.png

  • slow_query_log : 是否已经开启慢查询

  • slow_query_log_file : 慢查询日志文件路径

  • long_query_time : 超过多少秒的查询就写入日志

  • log_queries_not_using_indexes 如果值设置为ON,则会记录所有没有利用索引的查询(性能优化时开启此项,平时不要开启)

查看慢查询

image.png

通过 explain 进行优化分析

image.png

  • table:表示属于哪张数据表

  • type:最重要的参数,表示连接使用了何种类型。从最好到最差的连接类型为const,eq_reg,ref,range,index和ALL。

  • possible_keys:显示可能应用在这张表中的索引。如果为null,则表示没有可能的索引。

  • key:实际使用的索引。如果为null,则表示没有使用索引。

  • key_len:使用的索引的长度,在不损失精确性的情况下,长度越短越好。

  • ref:表示索引的哪一列被使用了,如果可能的话,是一个常数。

  • rows:Mysql认为必须检查的用来返回请求数据的行数。

通过 mysqldumpslow

  • 实际生产环境中MySQL出现查询慢的问题,为了分析慢查询,开启慢查询日志,并对日志进行分析。为了避免在生成环境中产生误操作,把记录的慢查询日志copy回来,到自己的电脑中进行分析。
[root@dras-test local]#mysqldumpslow -a -s t -t 2 /opt/slow_query_log.txt 

Reading mysql slow query log from /opt/slow_query_log.txt
Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), LibSvr[LibSvr]@[10.1.202.57]
  # Schema: information_schema  Last_errno: 0  Killed: 0
  # Query_time: 11.257168  Lock_time: 0.000141  Rows_sent: 366777  Rows_examined: 366777  Rows_affected: 0
  # Bytes_sent: 43251512
  SET timestamp=1492111317;
  SELECT * FROM `INNODB_BUFFER_PAGE_LRU`

Count: 1  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=0.0 (0), LibSvr[LibSvr]@[10.1.122.132]
  # Schema: el  Last_errno: 0  Killed: 0
  # Query_time: 4.471143  Lock_time: 0.000097  Rows_sent: 1  Rows_examined: 8018065  Rows_affected: 0
  # Bytes_sent: 1098
  SET timestamp=1490682921;
  SELECT `UserID`,`FileName`,`AdjunctGuid`,`LiteratureGuid`,`NoteGuid`,`AdjunctType`,`Md5`,`ID`,`ServerModifyTime`,`FileSize` FROM `el_user_adjunct_info` WHERE (`AdjunctGuid` = '4528cef4139846678cddf0d00170af9f.caj')

怎么找到死锁

  • SHOW ENGINE INNODB STATUS
  • 找到等待的锁的信息

案例

创建环境

CREATE TABLE hero (
    id INT,
    name VARCHAR(100),
    country varchar(100),
    PRIMARY KEY (id),
    KEY idx_name (name)
) Engine=InnoDB CHARSET=utf8;


INSERT INTO hero VALUES
    (1, 'l刘备', '蜀'),
    (3, 'z诸葛亮', '蜀'),
    (8, 'c曹操', '魏'),
    (15, 'x荀彧', '魏'),
    (20, 's孙权', '吴');
    
    

mysql> SELECT * FROM hero;
+----+------------+---------+
| id | name       | country |
+----+------------+---------+
|  1 | l刘备      ||
|  3 | z诸葛亮    ||
|  8 | c曹操      ||
| 15 | x荀彧      ||
| 20 | s孙权      ||
+----+------------+---------+
5 rows in set (0.00 sec)

产生死锁

image.png

查看死锁日志

mysql> SHOW ENGINE INNODB STATUS\G
...省略了好多其他信息
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-06-20 13:39:19 0x70000697e000
*** (1) TRANSACTION:
TRANSACTION 30477, ACTIVE 10 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1160, 2 row lock(s)
MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics
select * from hero where id = 3 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30477 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000003; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d0011d; asc        ;;
 3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
 4: len 3; hex e89c80; asc    ;;

*** (2) TRANSACTION:
TRANSACTION 30478, ACTIVE 8 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1160, 2 row lock(s)
MySQL thread id 3, OS thread handle 123145412927488, query id 47 localhost 127.0.0.1 root statistics
select * from hero where id = 1 for update
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000003; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d0011d; asc        ;;
 3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
 4: len 3; hex e89c80; asc    ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d00110; asc        ;;
 3: len 7; hex 6ce58898e5a487; asc l      ;;
 4: len 3; hex e89c80; asc    ;;

*** WE ROLL BACK TRANSACTION (2)
------------
...省略了好多其他信息

  • 我们只关心最近发生的死锁信息,所以就把以LATEST DETECTED DEADLOCK这一部分给单独提出来分析一下。下边我们就逐行看一下这个输出的死锁日志都是什么意思:

  • 首先看第一句:

2019-06-20 13:39:19 0x70000697e000
  • 这句话的意思就是死锁发生的时间是:2019-06-20 13:39:19,后边的一串十六进制0x70000697e000表示的操作系统为当前session分配的线程的线程id。

  • 然后是关于死锁发生时第一个事务的有关信息:

*** (1) TRANSACTION:

# 为事务分配的id为30477,事务处于ACTIVE状态已经10秒了,事务现在正在做的操作就是:“starting index read”
TRANSACTION 30477, ACTIVE 10 sec starting index read

# 此事务使用了1个表,为1个表上了锁(此处不是说为该表加了表锁,只要不是进行一致性读的表,都需要加锁,具体怎么加锁请看加锁语句分析或者小册章节)
mysql tables in use 1, locked 1

# 此事务处于LOCK WAIT状态,拥有3个锁结构(2个行锁结构,1个表级别X型意向锁结构,锁结构在小册中重点介绍过),heap size是为了存储锁结构而申请的内存大小(我们可以忽略),其中有2个行锁的结构
LOCK WAIT 3 lock struct(s), heap size 1160, 2 row lock(s)

# 本事务所在线程的id是2(MySQL自己命名的线程id),该线程在操作系统级别的id就是那一长串数字,当前查询的id为46(MySQL内部使用,可以忽略),还有用户名主机信息
MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics

# 本事务发生阻塞的语句
select * from hero where id = 3 for update

# 本事务当前在等待获取的锁:
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:

# 等待获取的表空间ID为151,页号为3,也就是表hero的PRIMAY索引中的某条记录的锁(n_bits是为了存储本页面的锁信息而分配的一串内存空间,小册中有详细介绍),该锁的类型是X型正经记录锁(rec but not gap)
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30477 lock_mode X locks rec but not gap waiting

# 该记录在页面中的heap_no为2,具体的记录信息如下:
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0

# 这是主键值
0: len 4; hex 80000003; asc     ;;

# 这是trx_id隐藏列
1: len 6; hex 000000007517; asc     u ;;

# 这是roll_pointer隐藏列
2: len 7; hex 80000001d0011d; asc        ;;

# 这是name列
3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;

# 这是country列
4: len 3; hex e89c80; asc    ;;

  • 从这个信息中可以看出,Session A中的事务为2条记录生成了锁结构,但是其中有一条记录上的X型正经记录锁(rec but not gap)并没有获取到,没有获取到锁的这条记录的位置是:表空间ID为151,页号为3,heap_no为2。当然,设计InnoDB的大叔还贴心的给出了这条记录的详细情况,它的主键值为80000003,这其实是InnoDB内部存储使用的格式,其实就代表数字3,也就是该事务在等待获取hero表聚簇索引主键值为3的那条记录的X型正经记录锁。

  • 然后是关于死锁发生时第二个事务的有关信息:
*** (2) TRANSACTION:
TRANSACTION 30478, ACTIVE 8 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1160, 2 row lock(s)
MySQL thread id 3, OS thread handle 123145412927488, query id 47 localhost 127.0.0.1 root statistics
select * from hero where id = 1 for update

# 表示该事务获取到的锁信息
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0

# 主键值为3
0: len 4; hex 80000003; asc     ;;
1: len 6; hex 000000007517; asc     u ;;
2: len 7; hex 80000001d0011d; asc        ;;
3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
4: len 3; hex e89c80; asc    ;;

# 表示该事务等待获取的锁信息
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0

# 主键值为1
0: len 4; hex 80000001; asc     ;;
1: len 6; hex 000000007517; asc     u ;;
2: len 7; hex 80000001d00110; asc        ;;
3: len 7; hex 6ce58898e5a487; asc l      ;;
4: len 3; hex e89c80; asc    ;;

  • 从上边的输出可以看出来,Session B中的事务获取了hero表聚簇索引主键值为3的记录的X型正经记录锁,等待获取hero表聚簇索引主键值为1的记录的X型正经记录锁(隐含的意思就是这个hero表聚簇索引主键值为1的记录的X型正经记录锁已经被SESSION A中的事务获取到了)。

  • 看最后一部分:

*** WE ROLL BACK TRANSACTION (2)

最终InnoDB存储引擎决定回滚第2个事务,也就是Session B中的那个事务。

参考