zhangguanzhang's Blog

ubuntu18下io调度算法是cfq导致mysql非常慢

字数统计: 2k阅读时长: 10 min
2021/09/01 Share

记录线上一次 io 调度算法导致的 mysql 读写慢问题

问题由来

同样的部署包,都是容器化的,配置和宿主机也是一样在同一台机器上,虚机的盘存储也是同一个里,mysql 的 docker 镜像是一样,配置文件也是完全一样。
在 ubuntu16 上我们初始化 mysql 表时间为 x ,而在 ubuntu 18 上则是 2倍以上的时间,甚至 10 倍。
ubuntu 的 systemd-resolved 我们 k8s 已经处理了的。不存在啥反向解析问题。一开始 NUMA 绑定关系不一样,调整一样后还是存在,最后查到相关资料是和 io 调度算法有关系:

https://codeistry.wordpress.com/2020/01/16/ubuntu-18-04-poor-disk-read-performance/

解决

长话短说,ubuntu 16 是 deadline ,18 则是 cfq ,后者太平均了,不适合 mysql 这种 io 密集型的业务。noop 则适合 ssd 和 flash 之类的。

可以下面快照查看某个路径所在的 io 调度算法:

1
2
3
4
5
6
7
DB_DATA_PATH=/data/mysql_data

DEVICE=$( findmnt -T ${DB_DATA_PATH} -o SOURCE --noheadings )
DEVICE=${DEVICE##*/}
DEVICE=$( tr -d '0-9' <<< "${DEVICE}")
# 查看 io 调度算法
cat /sys/block/${DEVICE}/queue/scheduler

直接 echo deadline > /sys/block/sdb/queue/scheduler 可以调整,不需要重启,但是重启失效,而调整内核参数 elevator=deadline 的话则是全局,如果机器上其他块设备是 ssd 则不合适,所以我们可以用 systemd 的 oneshot 调整,/etc/fstabsystemd-remount-fs.service 负责挂载的。我们的分区肯定是它挂载的,所以在它后面去执行,大概下面这样:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
cat > /etc/systemd/system/mysql-block.service << EOF
[Unit]
Description=set block scheduler for mysql
After=systemd-remount-fs.service
[Service]
Environment="PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
Type=oneshot
ConditionPathExists=/sys/block/sdb
ExecStart=/bin/bash -c 'echo deadline > /sys/block/sdb/queue/scheduler'
RemainAfterExit=yes
[Install]
WantedBy=multi-user.target
EOF

systemctl enable mysql-block.service

如果底层是 ssd ,但是做了 raid,无法通过 rotational 来判断是不是 ssd,直插使用的话为 0 就是 ssd。可以下面查看

1
2
3
cat /sys/block/sda/queue/rotational
# or
lsblk -d -o name,rota

一些数据对比

我们机器系统盘和数据盘,系统盘没改,测试 io 速度:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
root@ubuntu1804:~# fio --name TEST --eta-newline=5s --filename=fio-tempfile.dat \
--rw=randwrite --size=500m --io_size=2g --blocksize=4k \
--ioengine=libaio --fsync=1 --iodepth=1 --direct=1 --numjobs=1 --runtime=60 --group_reporting

TEST: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.1
Starting 1 process
TEST: Laying out IO file (1 file / 500MiB)
Jobs: 1 (f=1): [w(1)][13.3%][r=0KiB/s,w=306KiB/s][r=0,w=76 IOPS][eta 00m:52s]
Jobs: 1 (f=1): [w(1)][23.3%][r=0KiB/s,w=361KiB/s][r=0,w=90 IOPS][eta 00m:46s]
Jobs: 1 (f=1): [w(1)][51.7%][r=0KiB/s,w=362KiB/s][r=0,w=90 IOPS][eta 00m:29s]
Jobs: 1 (f=1): [w(1)][61.7%][r=0KiB/s,w=172KiB/s][r=0,w=43 IOPS][eta 00m:23s]
Jobs: 1 (f=1): [w(1)][71.7%][r=0KiB/s,w=396KiB/s][r=0,w=99 IOPS][eta 00m:17s]
Jobs: 1 (f=1): [w(1)][81.7%][r=0KiB/s,w=436KiB/s][r=0,w=109 IOPS][eta 00m:11s]
Jobs: 1 (f=1): [w(1)][90.0%][r=0KiB/s,w=420KiB/s][r=0,w=105 IOPS][eta 00m:06s]
Jobs: 1 (f=1): [w(1)][100.0%][r=0KiB/s,w=416KiB/s][r=0,w=104 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=24257: Thu Sep 2 11:30:06 2021
write: IOPS=92, BW=370KiB/s (379kB/s)(21.7MiB/60006msec)
slat (usec): min=18, max=10744, avg=50.73, stdev=175.78
clat (usec): min=4, max=187002, avg=10094.71, stdev=7746.13
lat (usec): min=244, max=187062, avg=10146.12, stdev=7742.92
clat percentiles (msec):
| 1.00th=[ 9], 5.00th=[ 9], 10.00th=[ 9], 20.00th=[ 9],
| 30.00th=[ 9], 40.00th=[ 9], 50.00th=[ 9], 60.00th=[ 9],
| 70.00th=[ 10], 80.00th=[ 10], 90.00th=[ 12], 95.00th=[ 18],
| 99.00th=[ 42], 99.50th=[ 64], 99.90th=[ 107], 99.95th=[ 133],
| 99.99th=[ 188]
bw ( KiB/s): min= 3, max= 404, per=36.51%, avg=135.07, stdev=151.88, samples=97
iops : min= 0, max= 101, avg=33.30, stdev=38.04, samples=97
lat (usec) : 10=0.04%, 100=0.11%, 250=0.11%, 500=0.02%
lat (msec) : 10=88.37%, 20=7.97%, 50=2.56%, 100=0.68%, 250=0.14%
cpu : usr=0.33%, sys=0.79%, ctx=11118, majf=0, minf=10
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwt: total=0,5556,0, short=0,0,0, dropped=0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1

Run status group 0 (all jobs):
WRITE: bw=370KiB/s (379kB/s), 370KiB/s-370KiB/s (379kB/s-379kB/s), io=21.7MiB (22.8MB), run=60006-60006msec

Disk stats (read/write):
sda: ios=0/16781, merge=0/11771, ticks=0/63856, in_queue=63744, util=94.50%

iops avg 是 33.30 , /data 目录是已经调整成 deadline 了,测下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
root@ubuntu1804:~# cd /data/
root@ubuntu1804:/data# fio --name TEST --eta-newline=5s --filename=fio-tempfile.dat --rw=randwrite --size=500m --io_size=2g --blocksize=4k --ioengine=libaio --fsync=1 --iodepth=1 --direct=1 --numjobs=1 --runtime=60 --group_reporting

TEST: (g=0): rw=randwrite, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.1
Starting 1 process
TEST: Laying out IO file (1 file / 500MiB)
Jobs: 1 (f=1): [w(1)][11.7%][r=0KiB/s,w=4681KiB/s][r=0,w=1170 IOPS][eta 00m:53s]
Jobs: 1 (f=1): [w(1)][21.7%][r=0KiB/s,w=6553KiB/s][r=0,w=1638 IOPS][eta 00m:47s]
Jobs: 1 (f=1): [w(1)][31.1%][r=0KiB/s,w=4536KiB/s][r=0,w=1134 IOPS][eta 00m:42s]
Jobs: 1 (f=1): [w(1)][41.0%][r=0KiB/s,w=2516KiB/s][r=0,w=629 IOPS][eta 00m:36s]
Jobs: 1 (f=1): [w(1)][50.8%][r=0KiB/s,w=3772KiB/s][r=0,w=943 IOPS][eta 00m:30s]
Jobs: 1 (f=1): [w(1)][60.7%][r=0KiB/s,w=8476KiB/s][r=0,w=2119 IOPS][eta 00m:24s]
Jobs: 1 (f=1): [w(1)][85.0%][r=0KiB/s,w=7158KiB/s][r=0,w=1789 IOPS][eta 00m:09s]
Jobs: 1 (f=1): [w(1)][95.0%][r=0KiB/s,w=6984KiB/s][r=0,w=1746 IOPS][eta 00m:03s]
Jobs: 1 (f=1): [w(1)][100.0%][r=0KiB/s,w=3449KiB/s][r=0,w=862 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=26679: Thu Sep 2 11:32:17 2021
write: IOPS=1462, BW=5851KiB/s (5992kB/s)(343MiB/60010msec)
slat (usec): min=25, max=270564, avg=275.98, stdev=3972.28
clat (nsec): min=1240, max=190800k, avg=140324.02, stdev=2041880.18
lat (usec): min=71, max=283124, avg=416.73, stdev=4716.37
clat percentiles (usec):
| 1.00th=[ 44], 5.00th=[ 50], 10.00th=[ 53], 20.00th=[ 59],
| 30.00th=[ 73], 40.00th=[ 82], 50.00th=[ 87], 60.00th=[ 92],
| 70.00th=[ 99], 80.00th=[ 109], 90.00th=[ 129], 95.00th=[ 157],
| 99.00th=[ 334], 99.50th=[ 465], 99.90th=[ 4555], 99.95th=[ 31327],
| 99.99th=[105382]
bw ( KiB/s): min= 93, max=11799, per=72.15%, avg=4221.47, stdev=3043.93, samples=93
iops : min= 23, max= 2949, avg=1055.01, stdev=760.91, samples=93
lat (usec) : 2=0.04%, 4=0.11%, 10=0.19%, 20=0.07%, 50=5.46%
lat (usec) : 100=65.80%, 250=26.62%, 500=1.27%, 750=0.18%, 1000=0.06%
lat (msec) : 2=0.07%, 4=0.03%, 10=0.03%, 20=0.01%, 50=0.03%
lat (msec) : 100=0.02%, 250=0.01%
cpu : usr=1.95%, sys=43.40%, ctx=175616, majf=0, minf=39
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued rwt: total=0,87784,0, short=0,0,0, dropped=0,0,0
latency : target=0, window=0, percentile=100.00%, depth=1

Run status group 0 (all jobs):
WRITE: bw=5851KiB/s (5992kB/s), 5851KiB/s-5851KiB/s (5992kB/s-5992kB/s), io=343MiB (360MB), run=60010-60010msec

Disk stats (read/write):
sdb: ios=30/263733, merge=0/186890, ticks=948/55212, in_queue=55912, util=79.04%

iops avg 是 1055.01

blktrace

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
apt-get install blktrace
# 生成采集文件
blktrace -d /dev/sdb
# 合并成一个二进制文件
blkparse -i sdb -d sdb.blktrace.bin
# btt 协助统计分析
btt -i sdb.blktrace.bin -l sdb.d2c_latencybtt -i sdb.blktrace.bin -q sdb.q2c_latency

Q2G – 生成IO请求所消耗的时间,包括remap和split的时间
G2I – IO请求进入IO Scheduler所消耗的时间,包括merge的时间
I2D – IO请求在IO Scheduler中等待的时间
D2C – IO请求在driver和硬件上所消耗的时间
Q2C – 整个IO请求所消耗的时间(G2I + I2D + D2C = Q2C),相当于iostat的await
其中D2C可以作为硬件性能的指标,I2D可以作为IO Scheduler性能的指标
上述命令其实还会产生一些.dat文件,可以看到iops信息

参考

CATALOG
  1. 1. 问题由来
  2. 2. 解决
  3. 3. 一些数据对比
  4. 4. blktrace
  5. 5. 参考