iostat はどのように %util を算出しているか - ablog
でソースコードから追ってみたが静的な追跡だけだとしんどいので、動的な追跡もやってみた。
strace を使って iostat でオープンしているファイルを調べて、
[root@www****** ~]# strace -e open iostat -x open("/etc/ld.so.cache", O_RDONLY) = 3 open("/lib64/libc.so.6", O_RDONLY) = 3 open("/sys/devices/system/cpu", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3 open("/proc/diskstats", O_RDONLY) = 3 open("/etc/localtime", O_RDONLY) = 3 Linux 2.6.32-358.18.1.el6.x86_64 (www******.sakura.ne.jp) 09/25/13 _x86_64_ (2 CPU) open("/proc/uptime", O_RDONLY) = 3 open("/proc/stat", O_RDONLY) = 3 open("/proc/diskstats", O_RDONLY) = 3 open("/etc/sysconfig/sysstat.ioconf", O_RDONLY) = 4 avg-cpu: %user %nice %system %iowait %steal %idle 0.04 0.00 0.02 0.01 0.13 99.79 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util vda 0.02 2.05 0.11 0.17 3.47 17.76 75.47 0.00 4.68 1.46 0.04
やはり /proc/diskstats を参照しているので、SystemTap でプローブ・ポイントに /proc/diskstats を表示している block/genhd.c の diskstats_show 関数（1078行目）を指定して、バックトレースをとってみる。
[root@www****** ~]# cat diskstats_show.stp #!/usr/bin/stap -v probe kernel.statement("*@*block/genhd.c:1078") { print_backtrace() } [root@www****** ~]# ./diskstats_show.stp Pass 1: parsed user script and 86 library script(s) using 98704virt/24104res/2952shr/21504data kb, in 140usr/10sys/158real ms. Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 embed(s), 0 global(s) using 268908virt/79728res/17892shr/63468data kb, in 210usr/90sys/304real ms. Pass 3: using cached /root/.systemtap/cache/9e/stap_9e327733fab96b27495da4a3d840a827_969.c Pass 4: using cached /root/.systemtap/cache/9e/stap_9e327733fab96b27495da4a3d840a827_969.ko Pass 5: starting run.
ここで iostat を実行してやると、
[root@www****** ~]# iostat -x Linux 2.6.32-358.18.1.el6.x86_64 (www******.sakura.ne.jp) 09/25/13 _x86_64_ (2 CPU) avg-cpu: %user %nice %system %iowait %steal %idle 0.04 0.00 0.02 0.01 0.13 99.79 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util vda 0.02 2.05 0.11 0.17 3.47 17.76 75.47 0.00 4.68 1.46 0.04
どんとカーネルのコールスタックが表示される。
[root@www****** ~]# ./diskstats_show.stp Pass 1: parsed user script and 86 library script(s) using 98704virt/24104res/2952shr/21504data kb, in 140usr/10sys/158real ms. Pass 2: analyzed script: 1 probe(s), 1 function(s), 0 embed(s), 0 global(s) using 268908virt/79728res/17892shr/63468data kb, in 210usr/90sys/304real ms. Pass 3: using cached /root/.systemtap/cache/9e/stap_9e327733fab96b27495da4a3d840a827_969.c Pass 4: using cached /root/.systemtap/cache/9e/stap_9e327733fab96b27495da4a3d840a827_969.ko Pass 5: starting run. 0xffffffff81266660 : diskstats_show+0x20/0x4d0 [kernel] 0xffffffff811a5322 : seq_read+0xf2/0x400 [kernel] 0xffffffff811e997e : proc_reg_read+0x7e/0xc0 [kernel] 0xffffffff81181a95 : vfs_read+0xb5/0x1a0 [kernel] 0xffffffff81181bd1 : sys_read+0x51/0x90 [kernel] 0xffffffff8100b072 : system_call_fastpath+0x16/0x1b [kernel] 0xffffffff81266660 : diskstats_show+0x20/0x4d0 [kernel] 0xffffffff811a54b9 : seq_read+0x289/0x400 [kernel] 0xffffffff811e997e : proc_reg_read+0x7e/0xc0 [kernel] 0xffffffff81181a95 : vfs_read+0xb5/0x1a0 [kernel] 0xffffffff81181bd1 : sys_read+0x51/0x90 [kernel] 0xffffffff8100b072 : system_call_fastpath+0x16/0x1b [kernel] ... ^CPass 5: run completed in 0usr/30sys/17540real ms.
