iostat はどのように %util を算出しているか(2)

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.