背景：最近在做一台线上服务器IO负载情况的时候发现了以下现象：
24小时的IO_UTIL 的曲线看似风平浪静，毛刺较少
但当图片放大到半小时级别的时候发现IO_UTIL即磁盘使用率出现了规律性的波动，见下图：
本文就将从这个现象触发，探究出现这样规律性波动的原因。
Step1： 服务器上进行实时IO负载查看
通过iostat -x 1 每隔一秒对IO使用情况进行一次负载查看。可以看到UTIL有规律性的波动（10秒1次）。
且负载的主要来源在于写请求（负载高时，wsec/s 也同步升高）
又由于服务器是MySQL独占，所以比较容易的就可以将原因归结为是MySQL的数据刷写导致（log/data)。
看到这里大神们应该已经不难猜到是MySQL内部 src_master_thread 中10_seconds 循环捣的鬼了。
为了保证诊断思路的连贯性，接下来还是把当时的操作复述一遍。
root@db-mysql-tg03b.nh:/root>iostat -x 1 vgca0 |grep vgca0
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util vgca0 0.00 0.00 12.96 371.75 1562.56 24314.49 67.26 0.37 0.28 0.28 10.62 vgca0 0.00 0.00 2.00 2.00 40.00 138.00 44.50 0.00 1.00 1.00 0.40 vgca0 0.00 0.00 1.00 2.00 32.00 170.00 67.33 0.00 1.00 1.00 0.30 vgca0 0.00 0.00 3.00 2.00 96.00 130.00 45.20 0.00 0.80 0.80 0.40 vgca0 0.00 0.00 4.00 2.00 128.00 178.00 51.00 0.00 0.67 0.67 0.40 vgca0 0.00 0.00 1.00 5.00 32.00 170.00 33.67 0.00 0.83 0.83 0.50 vgca0 0.00 0.00 0.00 1868.00 0.00 101510.00 54.34 1.28 0.16 0.16 30.20 vgca0 0.00 0.00 7.00 2.00 200.00 130.00 36.67 0.10 12.78 12.78 11.50 vgca0 0.00 0.00 1.98 1.98 39.60 160.40 50.50 0.00 1.00 1.00 0.40 vgca0 0.00 0.00 6.00 2.00 168.00 170.00 42.25 0.00 0.88 0.88 0.70 vgca0 0.00 0.00 4.00 26.00 104.00 5026.00 171.00 0.02 0.73 0.73 2.20 vgca0 0.00 0.00 10.00 2.00 296.00 164.00 38.33 0.04 3.92 3.92 4.70 vgca0 0.00 0.00 1.00 2.00 8.00 138.00 48.67 0.00 1.00 1.00 0.30 vgca0 0.00 0.00 2.00 2.00 40.00 162.00 50.50 0.00 1.00 1.00 0.40 vgca0 0.00 0.00 3.00 2.00 72.00 170.00 48.40 0.00 0.80 0.80 0.40 vgca0 0.00 0.00 2.00 6.00 40.00 172.00 26.50 0.00 0.50 0.50 0.40 vgca0 0.00 0.00 2.00 601.00 40.00 32942.00 54.70 0.39 0.17 0.17 10.40 vgca0 0.00 0.00 2.00 1179.00 16.00 63932.00 54.15 0.82 0.17 0.17 19.90 vgca0 0.00 0.00 3.96 1.98 126.73 144.55 45.67 0.00 1.50 1.50 0.89 vgca0 0.00 0.00 3.00 2.00 96.00 170.00 53.20 0.00 1.00 1.00 0.50 vgca0 0.00 0.00 4.00 3.00 104.00 162.00 38.00 0.00 0.86 0.86 0.60 vgca0 0.00 0.00 1.00 2.00 8.00 138.00 48.67 0.00 0.33 0.33 0.10 vgca0 0.00 0.00 6.00 2.00 168.00 178.00 43.25 0.00 1.12 1.12 0.90 vgca0 0.00 0.00 5.00 2.00 136.00 138.00 39.14 0.00 0.86 0.86 0.60 vgca0 0.00 0.00 4.00 2.00 104.00 170.00 45.67 0.00 0.83 0.83 0.50 vgca0 0.00 0.00 2.00 2.00 40.00 162.00 50.50 0.00 1.00 1.00 0.40 vgca0 0.00 0.00 1.00 5.00 8.00 187.00 32.50 0.00 0.50 0.50 0.30 vgca0 0.00 0.00 7.00 1815.00 104.00 98762.00 54.26 1.31 0.25 0.25 45.50 vgca0 0.00 0.00 5.00 2.00 136.00 178.00 44.86 0.00 0.86 0.86 0.60
Step2： 确定MySQL write IO 来源
由于目前只知道是MySQL数据刷写导致，那么究竟是redo-log还是data page flush造成的现在还不知道。
innodb内部关于write的statistics还是比较有限的。因此比较粗暴的写了个类似于top的perl脚本 ，监控这些参数。
脚本如下，有兴趣的同学可以展开阅读
use strict; use warnings; use utf8; use DBI; my $CONFIG_SERVER_IP ='127.0.0.1'; my $CONFIG_SERVER_DB='test'; my $CONFIG_SERVER_PORT='3306'; my $CONFIG_SERVER_USER='user'; my $CONFIG_SERVER_PASS='password'; my $conf_dbh = DBI->connect("DBI:mysql:$CONFIG_SERVER_DB;host=$CONFIG_SERVER_IP;port=$CONFIG_SERVER_PORT", $CONFIG_SERVER_USER, $CONFIG_SERVER_PASS,{RaiseError => 1}) || die "Could not connect to database: $DBI::errstr"; my %last_value_hash; print "data_write\tdata_written\tdblwr_pages_written\tdblwr_writes\tlog_write_req\tos_log_fsync\tos_log_written\tpages_written\n"; while(1){ my $conf_sth = $conf_dbh->prepare("show global status like '%innodb%'") || die "Prepare error"; $conf_sth->execute(); while(my $row=$conf_sth->fetchrow_hashref){ my $name=$row->{Variable_name}; my $value=$row->{Value}; if( $name eq 'Innodb_data_writes' || $name eq 'Innodb_data_written' || $name eq 'Innodb_dblwr_pages_written' || $name eq 'Innodb_dblwr_writes' || $name eq 'Innodb_log_write_requests' || $name eq 'Innodb_os_log_fsyncs' || $name eq 'Innodb_os_log_written' || $name eq 'Innodb_pages_written'){ $last_value_hash{$name}=0 if( !defined($last_value_hash{$name}) ); my $value_step=$value-$last_value_hash{$name}; $last_value_hash{$name}=$value; print "$value_step\t"; } } print "\n"; sleep 1; }