环境
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