首页  :: 新随笔  :: 管理

MySQL服务器CPU使用率高问题排查

Posted on 2022-10-31 20:38  高&玉  阅读(5316)  评论(0编辑  收藏  举报

环境

VMware Workstation 15.5
CentOS 7.6
CPU:4C
MEM:4G
日立机械硬盘7200转/s
MySQL 8.0.26

压测并分析

1. 使用sysbench脚本oltp_read_write.lua进行压测。

[root]# sysbench oltp_read_write.lua --db-driver=mysql --mysql-socket=/tmp/mysql.sock --mysql-user=root --mysql-password=My_password@3306 --mysql-db=oltp_read_write --tables=8 --table-size=1i000000 --report-interval=1 --threads=80 --time=3600 run

 

2. 使用top观察系统资源,OS负载不高,但是可以看到mysqld进程(PID:21828)的CPU使用率达到了232.6%,其内存使用率也达到了17.7%。

[root]# top
top - 15:02:39 up 20 days, 11:33,  2 users,  load average: 5.38, 4.54, 2.62
Tasks: 237 total,   1 running, 236 sleeping,   0 stopped,   0 zombie
%Cpu(s): 26.5 us, 37.6 sy,  0.0 ni, 32.4 id,  2.1 wa,  0.0 hi,  1.5 si,  0.0 st
KiB Mem :  3871244 total,   125252 free,  1175236 used,  2570756 buff/cache
KiB Swap:  8257532 total,  8010952 free,   246580 used.  2180416 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                  
21828 mysql     20   0 2836868 683324  11656 S 232.6 17.7 927:24.93 mysqld                                                                                                   
 7395 root      20   0 1173224  23584   3600 S  49.5  0.6   4:55.89 sysbench                                                                                                 
 8577 root      20   0  485624   2640    352 S   6.3  0.1   1911:53 sunloginclient                                                                                           
 8587 root       0 -20       0      0      0 S   2.3  0.0  56:09.40 kworker/2:1H                                                                                             
36645 root      20   0  784132  72748   4504 S   2.0  1.9  97:58.62 vmagent                                                                                                  
 4017 root       0 -20       0      0      0 S   1.3  0.0  20:33.42 kworker/0:1H                                                                                             
36642 root      20   0  718580  14048   4212 S   1.3  0.4  76:25.04 node_exporter                                                                                            
48501 maxscale  20   0  822020    776      0 S   1.0  0.0  78:19.49 maxscale                                                                                                 
 5736 root      20   0       0      0      0 S   0.7  0.0   0:01.48 kworker/1:0                                                                                              
 8019 root      20   0       0      0      0 S   0.7  0.0   0:02.00 kworker/3:0                                                                                              
 8366 root      20   0       0      0      0 S   0.7  0.0   0:05.16 kworker/2:0                                                                                              
 8586 root       0 -20       0      0      0 S   0.7  0.0  20:44.79 kworker/1:1H                                                                                             
60197 root      20   0       0      0      0 S   0.7  0.0   0:07.39 kworker/0:1                                                                                              
    3 root      20   0       0      0      0 S   0.3  0.0  37:20.60 ksoftirqd/0                                                                                              
    9 root      20   0       0      0      0 S   0.3  0.0 120:56.47 rcu_sched                                                                                                
 8316 root      20   0   90636     96      0 S   0.3  0.0  35:24.64 rngd                                                                                                     
46891 root      20   0 1249816  22788   4212 S   0.3  0.6  77:36.82 pmm-agent                                                                                                
    1 root      20   0  199604   2836   1292 S   0.0  0.1   7:24.69 systemd                                                                                                  
    2 root      20   0       0      0      0 S   0.0  0.0   0:02.29 kthreadd                                                                                                 
    5 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/0:0H                                                                                             
    7 root      rt   0       0      0      0 S   0.0  0.0   7:42.29 migration/0                                                                                              
    8 root      20   0       0      0      0 S   0.0  0.0   0:00.00 rcu_bh                                                                                                   
   10 root       0 -20       0      0      0 S   0.0  0.0   0:00.13 lru-add-drain                                                                                            
   11 root      rt   0       0      0      0 S   0.0  0.0   1:51.18 watchdog/0                                                                                               
   12 root      rt   0       0      0      0 S   0.0  0.0   1:59.07 watchdog/1                                                                                               
   13 root      rt   0       0      0      0 S   0.0  0.0   8:49.57 migration/1                                                                                              
   14 root      20   0       0      0      0 S   0.0  0.0  26:42.13 ksoftirqd/1                                                                                              
   16 root       0 -20       0      0      0 S   0.0  0.0   0:00.00 kworker/1:0H                                                                                             
   17 root      rt   0       0      0      0 S   0.0  0.0   2:47.86 watchdog/2  

3. 通过pidstata工具观察使用率高的进程

[root]# pidstat -u 1 10
Linux 3.10.0-957.el7.x86_64 (host71) 	10/18/2022 	_x86_64_	(4 CPU)
Average:      UID       PID    %usr %system  %guest    %CPU   CPU  Command
Average:        0      4017    0.00    0.96    0.00    0.96     -  kworker/0:1H
Average:        0      7264    0.00    0.96    0.00    0.96     -  xfsaild/sdb
Average:        0      7395   11.54   42.31    0.00   53.85     -  sysbench
Average:        0      8316    0.00    0.96    0.00    0.96     -  rngd
Average:        0      8577    0.00    8.65    0.00    8.65     -  sunloginclient
Average:        0      8586    0.00    0.96    0.00    0.96     -  kworker/1:1H
Average:        0      8587    0.00    1.92    0.00    1.92     -  kworker/2:1H
Average:       42      9696    0.96    0.00    0.00    0.96     -  gsd-color
Average:        0     16477    0.00    0.96    0.00    0.96     -  kworker/3:2
Average:        0     17316    0.00    0.96    0.00    0.96     -  kworker/2:2
Average:        0     19290    0.00    0.96    0.00    0.96     -  pidstat
Average:     1014     21828   96.15  100.00    0.00  100.00     -  mysqld
Average:        0     36645    0.96    0.00    0.00    0.96     -  vmagent
Average:     1020     48501    0.00    0.96    0.00    0.96     -  maxscale
Average:        0     60197    0.00    0.96    0.00    0.96     -  kworker/0:1

可以看到存在两个进程(mysqld、sysbench)的CPU使用率高:

  • sysbench(PID:7395)  目前使用的压测工具,可以忽略。
  • mysqld(PID:21828)   MySQL数据库的进程

 

4. 通过pidstat工具观察mysqld线程使用CPU的情况

[root]# pidstat -u -p 21828 -t 1 10
Average:      UID      TGID       TID    %usr %system  %guest    %CPU   CPU  Command
Average:     1014     21828         -   79.21  100.00    0.00  100.00     -  mysqld
Average:     1014         -     21828    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21832    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21833    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21834    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21835    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21836    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21837    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21838    0.00    2.97    0.00    2.97     -  |__mysqld
Average:     1014         -     21839    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21840    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21841    0.00    0.99    0.00    0.99     -  |__mysqld
Average:     1014         -     21842    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21843    0.00    1.98    0.00    1.98     -  |__mysqld
Average:     1014         -     21844    0.00    4.95    0.00    4.95     -  |__mysqld
Average:     1014         -     21845    0.00   13.86    0.00   13.86     -  |__mysqld
Average:     1014         -     21846    0.00    2.97    0.00    2.97     -  |__mysqld
Average:     1014         -     21847    0.00    7.92    0.00    7.92     -  |__mysqld
Average:     1014         -     21854    3.96    1.98    0.00    5.94     -  |__mysqld
Average:     1014         -     21855    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21856    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21868    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21869    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21870    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21871    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21872    0.00    0.00    0.00    0.00     -  |__xpl_worker1
Average:     1014         -     21873    0.00    0.00    0.00    0.00     -  |__xpl_worker0
Average:     1014         -     21874    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21875    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21879    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21880    0.00    1.98    0.00    1.98     -  |__mysqld
Average:     1014         -     21881    0.99    3.96    0.00    4.95     -  |__mysqld
Average:     1014         -     21882    0.99    0.00    0.00    0.99     -  |__mysqld
Average:     1014         -     21883    1.98    0.99    0.00    2.97     -  |__mysqld
Average:     1014         -     21884    0.99    0.00    0.00    0.99     -  |__mysqld
Average:     1014         -     21885    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21886    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21887    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21889    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     21915    2.97    3.96    0.00    6.93     -  |__mysqld
Average:     1014         -     22226    3.96    4.95    0.00    8.91     -  |__mysqld
Average:     1014         -     22824    3.96    5.94    0.00    9.90     -  |__mysqld
Average:     1014         -     22851    2.97    6.93    0.00    9.90     -  |__mysqld
Average:     1014         -     22986    3.96    3.96    0.00    7.92     -  |__mysqld
Average:     1014         -     22987    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     61497    4.95    3.96    0.00    8.91     -  |__mysqld
Average:     1014         -     61498    4.95    5.94    0.00   10.89     -  |__mysqld
Average:     1014         -     61506    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     61507    3.96    3.96    0.00    7.92     -  |__mysqld
Average:     1014         -      7413    4.95    3.96    0.00    8.91     -  |__mysqld
Average:     1014         -      7414    4.95    3.96    0.00    8.91     -  |__mysqld
Average:     1014         -      7415    3.96    3.96    0.00    7.92     -  |__mysqld
Average:     1014         -      7416    3.96    3.96    0.00    7.92     -  |__mysqld
Average:     1014         -      7417    4.95    4.95    0.00    9.90     -  |__mysqld
Average:     1014         -      7418    4.95    4.95    0.00    9.90     -  |__mysqld
Average:     1014         -      7419    3.96    3.96    0.00    7.92     -  |__mysqld
Average:     1014         -      7420    3.96    4.95    0.00    8.91     -  |__mysqld
Average:     1014         -      7459    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -      7474    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -      7475    0.00    0.00    0.00    0.00     -  |__mysqld
Average:     1014         -     24268    0.00    0.00    0.00    0.00     -  |__mysqld

从以上找出CPU使用率高的线程ID分别为:21845、61497、61498、61507、7413、7414、7415、7416、7417、7418、7419、7420

 

5. 查看MySQL端运行的线程

[mysql]# mysql -e "select * from performance_schema.threads\G" >> threads.log
[mysql]# mysql -e "select * from information_schema.processlist where command!='sleep';" >> processlist.log

 

6. 根据线程CPU使用率高的TID到threads.log中找出对应的PROCESSLIST_ID

TID=21845

          THREAD_ID: 16
               NAME: thread/innodb/log_flusher_thread
               TYPE: BACKGROUND
     PROCESSLIST_ID: NULL
   PROCESSLIST_USER: NULL
   PROCESSLIST_HOST: NULL
     PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: NULL
   PROCESSLIST_TIME: NULL
  PROCESSLIST_STATE: NULL
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: NULL
       THREAD_OS_ID: 21845
     RESOURCE_GROUP: SYS_default

TID=61497

          THREAD_ID: 29253
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29209
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 61497
     RESOURCE_GROUP: USR_default

TID=61498

          THREAD_ID: 29252
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29208
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 61498
     RESOURCE_GROUP: USR_default

TID=61507

          THREAD_ID: 29254
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29210
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: NULL
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 61507
     RESOURCE_GROUP: USR_default

TID=7413

          THREAD_ID: 29262
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29218
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7413
     RESOURCE_GROUP: USR_default
TID=7414
          THREAD_ID: 29261
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29217
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7414
     RESOURCE_GROUP: USR_default

TID=7415

          THREAD_ID: 29263
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29219
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7415
     RESOURCE_GROUP: USR_default

TID=7416

          THREAD_ID: 29260
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29216
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7416
     RESOURCE_GROUP: USR_default

TID=7417

          THREAD_ID: 29265
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29221
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7417
     RESOURCE_GROUP: USR_default

TID=7418

          THREAD_ID: 29267
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29223
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7418
     RESOURCE_GROUP: USR_default

TID=7419

          THREAD_ID: 29264
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29220
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7419
     RESOURCE_GROUP: USR_default

TID=7420

          THREAD_ID: 29266
               NAME: thread/sql/one_connection
               TYPE: FOREGROUND
     PROCESSLIST_ID: 29222
   PROCESSLIST_USER: root
   PROCESSLIST_HOST: localhost
     PROCESSLIST_DB: oltp_read_write
PROCESSLIST_COMMAND: Execute
   PROCESSLIST_TIME: 0
  PROCESSLIST_STATE: updating
   PROCESSLIST_INFO: NULL
   PARENT_THREAD_ID: 1
               ROLE: NULL
       INSTRUMENTED: YES
            HISTORY: YES
    CONNECTION_TYPE: Socket
       THREAD_OS_ID: 7420
     RESOURCE_GROUP: USR_default

TID=21845是一个日志刷新线程(log_flush_thread)
TID=61497对应的PROCESSLIST_ID=29209
TID=61498对应的PROCESSLIST_ID=29208
TID=61507对应的PROCESSLIST_ID=29210
TID=7413对应的PROCESSLIST_ID=29218
TID=7414对应的PROCESSLIST_ID=29217
TID=7415对应的PROCESSLIST_ID=29219
TID=7416对应的PROCESSLIST_ID=29216
TID=7417对应的PROCESSLIST_ID=29221
TID=7418对应的PROCESSLIST_ID=29223
TID=7419对应的PROCESSLIST_ID=29220
TID=7420对应的PROCESSLIST_ID=29222

 

根据PROCESSLIST_ID到threads.log文件中可找到执行的对应SQL,这是我sysbench压测产生的SQL

ID      USER    HOST    DB      COMMAND TIME    STATE   INFO
29216   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest1 SET k=k+1 WHERE id=1
29208   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest7 SET k=k+1 WHERE id=1
29209   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest7 SET k=k+1 WHERE id=1
29217   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest7 SET k=k+1 WHERE id=1
29210   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest3 SET c='86892096289-55268100156-49977086004-95111775123-47809684977-95288803217-79929940106-32606478052-93005686215-83477395161' WHERE id=1
29218   root    localhost       oltp_read_write Execute 0       waiting for handler commit      COMMIT
29211   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest1 SET k=k+1 WHERE id=1
29219   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest1 SET k=k+1 WHERE id=1
30035   root    localhost       NULL    Query   0       executing       select * from information_schema.processlist where command!='sleep'
29212   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest5 SET k=k+1 WHERE id=1
29220   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest6 SET k=k+1 WHERE id=1
5       event_scheduler localhost       NULL    Daemon  101701  Waiting on empty queue  NULL
29213   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest3 SET k=k+1 WHERE id=1
29221   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest7 SET k=k+1 WHERE id=1
29214   root    localhost       oltp_read_write Execute 0       starting        NULL
29222   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest1 SET k=k+1 WHERE id=1
29215   root    localhost       oltp_read_write Execute 0       updating        UPDATE sbtest2 SET c='03360150507-89156394155-52094014961-51061609068-55578750291-13070188494-81180566089-70681611361-30579611606-08092221350' WHERE id=1
29223   root    localhost       oltp_read_write Execute 0       waiting for handler commit      COMMIT