配置环境,以创建负载场景
# git clone https://github.com/feiskyer/linux-perf-examples # cd linux-perf-examples/mysql-slow # make run // 启动与案例相关的容器 # docker ps // 确认三个容器都处在运行 // MySQL 需要做一些初始化工作,需要花费几分钟时间 # docker logs -f mysql // 查看 MySQL 的启动过程 // 执行下面的命令,确认它也已经正常运行 # curl http://127.0.0.1:10000/ Index Page // 初始化数据库,并插入 10000 条商品信息 # make init // 访问一下商品搜索的接口 # curl http://10.10.50.188/products/geektime // 这个接口返回的是空数据,而且处理时间超过 15 秒 // 继续执行下面的命令,制造负载以进行测试 # while true; do curl http://192.168.0.10:10000/products/geektime; sleep 5; done
第一步、运行 top 命令,观察资源使用情况
# top top - 12:02:15 up 6 days, 8:05, 1 user, load average: 0.66, 0.72, 0.59 Tasks: 137 total, 1 running, 81 sleeping, 0 stopped, 0 zombie %Cpu0 : 0.7 us, 1.3 sy, 0.0 ni, 35.9 id, 62.1 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu1 : 0.3 us, 0.7 sy, 0.0 ni, 84.7 id, 14.3 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem : 8169300 total, 7238472 free, 546132 used, 384696 buff/cache KiB Swap: 0 total, 0 free, 0 used. 7316952 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 27458 999 20 0 833852 57968 13176 S 1.7 0.7 0:12.40 mysqld 27617 root 20 0 24348 9216 4692 S 1.0 0.1 0:04.40 python 1549 root 20 0 236716 24568 9864 S 0.3 0.3 51:46.57 python3 22421 root 20 0 0 0 0 I 0.3 0.0 0:01.16 kworker/u // 两个 CPU 的 iowait 都比较高,特别是 CPU0,iowait 已经超过 60%。 // 各个进程, CPU 使用率并不高,最高的也只有 1.7% // => 问题应该还是出在 I/O 上
第二步、运行 iostat 命令,观察 I/O 的使用情况
# iostat -d -x 1 Device r/s w/s rkB/s wkB/s rrqm/s wrqm/s %rrqm %wrqm r_await w_await aqu-sz rareq-sz wareq-sz svctm %util ... sda 273.00 0.00 32568.00 0.00 0.00 0.00 0.00 0.00 7.90 0.00 1.16 119.30 0.00 3.56 97.20 // 磁盘 sda 每秒的读数据为 32 MB, 而 I/O 使用率高达 97% ,接近饱和 // 磁盘 sda 的读取确实碰到了性能瓶颈
第三步、运行 pidstat 命令,观察进程 I/O 使用情况
# pidstat -d 1 // -d 选项表示展示进程的 I/O 情况 12:04:11 UID PID kB_rd/s kB_wr/s kB_ccwr/s iodelay Command 12:04:12 999 27458 32640.00 0.00 0.00 0 mysqld 12:04:12 0 27617 4.00 4.00 0.00 3 python 12:04:12 0 27864 0.00 4.00 0.00 0 systemd-journal // 我们自然就找到了磁盘 I/O 瓶颈的根源,即 mysqld 进程
第四步、运行 strace 命令,分析进程的系统调用
# strace -f -p 27458 // -f 同时追踪 线程的数据读取情况 [pid 28014] read(38, "934EiwT363aak7VtqF1mHGa4LL4Dhbks"..., 131072) = 131072 [pid 28014] read(38, "hSs7KBDepBqA6m4ce6i6iUfFTeG9Ot9z"..., 20480) = 20480 [pid 28014] read(38, "NRhRjCSsLLBjTfdqiBRLvN9K6FRfqqLm"..., 131072) = 131072 [pid 28014] read(38, "AKgsik4BilLb7y6OkwQUjjqGeCTQTaRl"..., 24576) = 24576 [pid 28014] read(38, "hFMHx7FzUSqfFI22fQxWCpSnDmRjamaW"..., 131072) = 131072 [pid 28014] read(38, "ajUzLmKqivcDJSkiw7QWf2ETLgvQIpfC"..., 20480) = 20480 # lsof -p 27458 // -p 参数需要指定进程号,不能指定线程 COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME ... mysqld 27458 999 38u REG 8,1 512440000 2601895 /var/lib/mysql/test/products.MYD // 38 后面的 u 表示, mysqld 以读写的方式访问文件 // 也就是说 mysql 正在读取 test 数据库的 productes 表,表引擎为 MyISAM // 检查数据库正在执行的语句 mysql> show full processlist; +----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+ | 27 | root | localhost | test | Query | 0 | init | show full processlist | | 28 | root | 127.0.0.1:42262 | test | Query | 1 | Sending data | select * from products where productName='geektime' | +----+------+-----------------+------+---------+------+--------------+-----------------------------------------------------+ 2 rows in set (0.00 sec) // 检查语句查询是否使用索引 mysql> explain select * from products where productName='geektime'; +----+-------------+----------+------+---------------+------+---------+------+-------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+----------+------+---------------+------+---------+------+-------+-------------+ | 1 | SIMPLE | products | ALL | NULL | NULL | NULL | NULL | 10000 | Using where | +----+-------------+----------+------+---------------+------+---------+------+-------+-------------+ 1 row in set (0.00 sec) // 根据这些信息,我们可以确定,这条查询语句压根儿没有使用索引
第五步、问题处理
我们就可以给 productName 建立索引,以解决问题(这里不再展开)。
创建索引之后可以进行测试,以检查请求的响应时间是否变短。
从系统缓存来看这个问题
虽然 MySQL 会读取文件系统中的文件,但是操作系统存在缓存。那就是说一段时间后,products.MYD 应该缓存到内存中,不会再有 I/O 压力。也就是说,开始的几个请求可能会比较慢,但是后面的请求会非常快。
使用 vmstat 命令你会观察到,IO 一直存在,这很显然是不正常的。我们应该从那个角度观测系统缓存的释放?
在这个案例中,我们已经知道 DataService 是干扰服务,因为该服务会 echo 1 > /proc/sys/vm/drop_caches 释放页缓存,导致不断读取。
参考文献