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

ubuntu18

字数统计: 2k阅读时长: 10 min

 2021/09/01 

记录线上一次 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 调度算法:

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/fstab 是 systemd-remount-fs.service 负责挂载的。我们的分区肯定是它挂载的，所以在它后面去执行，大概下面这样：

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 速度：

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 了，测下

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

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信息