[老生常谈] MySQL高cpu排查思路

• 问题描述
• 解决思路
• 总结

问题描述

每个 MySQL DBA 都会遇到 MySQL 实例 CPU 使用率高情况,这时候都会说,是慢 SQL 导致的,这时候开发就会问 最近业务代码也没有什么变动啊,为什么突然就有慢 SQL 了,导致 CPU 使用率高呢? 这时候就展现 DBA 的时候技术的时刻,找到对应的 SQL

解决思路

分为两种情况：

1. 过去时刻 CPU 使用率高
2. 当前时刻 CPU 使用率高

过去时刻 cpu 使用率高

• 因为是过去时刻: 只能结合监控面板的 CPU 高时间范围,使用 percona-toolkit 中 pt-query-digest 分析 slow SQL

tips：pt-query-digest 可以指定时间范围

当前时刻 cpu 使用率高

• 简单介绍 top 命令

top - 17:36:05 up 81 days,  6:22,  3 users,  load average: 0.96, 1.56, 2.09
Tasks:  41 total,   1 running,  40 sleeping,   0 stopped,   0 zombie
%Cpu(s):  3.9 us,  5.1 sy,  0.0 ni, 91.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 16777216 total, 14533112 free,  2244104 used,        0 buff/cache
KiB Swap: 31250428 total, 31151356 free,    99072 used. 14533112 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 5522 ubuntu    20   0 12.108g 1.988g  34216 S   0.7 12.4   1:12.15 mysqld
    1 root      20   0   37516   5068   4020 S   0.0  0.0   4:19.83 systemd
  104 message+  20   0   42888   3744   3516 S   0.0  0.0   1:54.52 dbus-daemon
  112 syslog    20   0  256392   3584   2768 S   0.0  0.0   1:17.79 rsyslogd
  113 root      20   0  275768   5964   5600 S   0.0  0.0   1:42.68 accounts-daemon
  115 root      20   0   29008   2836   2732 S   0.0  0.0   0:16.84 cron
  117 daemon    20   0   26044   1924   1924 S   0.0  0.0   0:00.03 atd
  121 root      20   0   28544   2864   2720 S   0.0  0.0   0:42.47 systemd-logind
  138 root      20   0  277176   5640   5360 S   0.0  0.0   0:00.03 polkitd
  219 root      20   0   16120   2184   1976 S   0.0  0.0   0:00.13 dhclient
  296 root      20   0    5220     52     36 S   0.0  0.0   2:16.66 iscsid
  298 root      10 -10    5720   3536   2448 S   0.0  0.0  10:32.74 iscsid
  314 root      20   0  221500  11796  11668 S   0.0  0.1   3:55.05 php-fpm7.0
  337 root      20   0   15752   1948   1948 S   0.0  0.0   0:00.00 agetty

复制

• 关注项：

• 第一行重点关注 up 服务器运行时长以及 load average 显示 1,5,15 分钟主机负载情况,从中看出一段时间内的负载变化

• 第二行 主要关注 runing 个数以及 zombie 的个数,

• 第三行 服务器整体的 CPU 占比的情况

• us% : 用户空间占用 CPU 百分比,可能是无索引,group by,order by 无索引,慢 sql 多
• sys% :内核空间占用 CPU 百分比,可能是连接数过多,或者 numa 未关闭
• wa% :等待输入输出的 CPU 时间百分比,能是io 成为瓶颈,需要具体判断 io 慢在哪里

• 第四行和第五行的分别代表内存和 swap 的使用情况,重点关注是否使用 swap，如果使用 swap 会严重影响数据库的响应时间

• 从上面的输出大致能看出来 CPU 高的方向,详细了解可以 man top 查看信息 以根据上面的输出确定往某一个方向排查

• 下面具体介绍怎么精确抓到活跃的慢 sql
  
  

第一步: 找到 mysqld 进程

 ps -ef | grep mysqld | grep -v mysqld_safe | grep -v grep
ubuntu    9687  4181  0 14:42 ?        00:01:19 /opt/mysql/bin/mysqld --defaults-file=/etc/mysql/my.cnf --basedir=/opt/mysql --datadir=/data/mysql --plugin-dir=/opt/mysql/lib/plugin --log-error=/data/mysql-log/mysql-error/mysql-error.log --open-files-limit=655360 --pid-file=i-5fo26iq2.pid --socket=/data/mysql/mysql.sock --port=3306


复制

第二步: 查看使用 CPU 最高的线程 id

top -H -p 9687

复制

top - 19:03:52 up 28 days,  3:48,  2 users,  load average: 3.39, 3.30, 3.11
Threads: 313 total,   2 running, 311 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.2 us,  0.2 sy,  0.0 ni, 99.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  8388608 total,  1033668 free,  7354940 used,        0 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  1033668 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
38191 ubuntu    20   0 8996852 5.690g  14032 S 99.9 71.1   4:30.58 mysqld
42634 ubuntu    20   0 8996852 5.690g  14032 R 99.9 71.1   0:11.24 mysqld
42635 ubuntu    20   0 8996852 5.690g  14032 S 99.9 71.1   0:11.37 mysqld
42633 ubuntu    20   0 8996852 5.690g  14032 R 99.9 71.1   0:11.45 mysqld
 9712 ubuntu    20   0 8996852 5.690g  14032 S 99.9 71.1   1:07.07 mysqld
55070 ubuntu    20   0 8996852 5.690g  14032 S 99.9 71.1   1:55.31 mysqld
 9687 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   0:43.73 mysqld
 9688 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   0:00.00 mysqld
 9689 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:22.67 mysqld
 9690 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:22.41 mysqld
 9691 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:22.62 mysqld
 9692 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:22.49 mysqld
 9693 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:22.18 mysqld
 9694 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:21.23 mysqld
 9695 ubuntu    20   0 8996852 5.690g  14032 S  0.0 71.1   1:26.50 mysqld


复制

从上面的信息可以看到 CPU 使用率高的线程即为 PID,例如 38191

第三步: 登陆 MySQL 结合 performance_schema.threads 表查找对应的 SQL

mysql> select * from performance_schema.threads t1 ,information_schema.processlist t2  where   t1.PROCESSLIST_ID= t2.id and t1.THREAD_OS_ID=38191  \G
*************************** 1. row ***************************
          THREAD_ID: 1205384
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 1205350
   PROCESSLIST_USER: canal
   PROCESSLIST_HOST: 192.168.100.28
     PROCESSLIST_DB: test
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: Creating sort index
   PROCESSLIST_INFO: BEGIN
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: TCP/IP
       THREAD_OS_ID: 38191
                 ID: 1205350
               USER: canal
               HOST: 192.168.100.28:41556
                 DB: test
            COMMAND: Execute
               TIME: 0
              STATE: Creating sort index
               INFO: SELECT c FROM sbtest1 WHERE id BETWEEN 646151 AND 646250 ORDER BY c
            TIME_MS: 0
          ROWS_SENT: 0
      ROWS_EXAMINED: 0
1 row in set (0.00 sec)




复制

• 持续大量慢 SQL 导致数据库负载升高怎么解决呢

  答：建议使用 percona-toolkit 中的 pt-kill 进行分类 kill` 或者使用参数max_execution_time 自动kill slow sql
  
  复制

  建议谨慎使用

总结

• 提供数据库 CPU 使用率高解决思路
• 针对过去时刻 CPU 使用率高排查思路: 使用 pt-query-digest 分析对应时间 slow SQL
• 针对当前时刻 CPU 使用率高排查思路: 结合 top -p -H 输出最高线程 id 和performance_schema.threads.THREAD_OS_ID 找到当前的 slow SQL
• 介绍持续大量慢 SQL 解决思路
• 使用pt-kill 或者max_execution_time 

本文到此分享结束，如有不妥之处，请随时交流。最后，感谢阅读 : ）