Enhanced I/O tracing via etruss

Description

The etruss utility is an enahced truss that uses microstate accounting to show the latency of system calls, and the amount of time spent waiting on I/O operations.

$ etruss -c myprog

syscall       cpu sec  elapsed     latency     wait   calls  errors
read             .396    4.964     .248237      77%      20
write            .488     .514     .025725       0%      20
open             .001     .001     .000142       0%      11      6
close            .000     .000     .000057       0%       5
brk              .000     .000     .000060       0%       4
fstat            .000     .000     .000051       0%       4
execve           .000     .000     .000000       0%       1
sigaction        .000     .000     .000050       0%       2
mmap             .000     .000     .000070       0%      10
munmap           .000     .000     .000068       0%       4
sysconfig        .000     .000     .000042       0%       1
creat64          .027     .027     .027119       0%       1
open64           .000     .000     .000125       0%       1
                -----    -----                          ---    ---
sys totals:      .915    5.509                           84      6
usr time:        .004
elapsed:        5.870

                       ---------- per I/O ----------     ---------- total ------------- 
syscall[file]          latency      iowait      size     wait      Kb/s   calls  errors
 read[3]               .248237     .228038   1048576      77%      3489      20
write[3]               .000000     .000000         0       0%         0       0
 read[5]               .000000     .000000         0       0%         0       0
write[5]               .025725     .000000   1048576       0%      3489      20

The example above shows that the test program myprog was reading and writing via two files. Writing to fd[5], which happened to be a file on disk was taking on average about 25ms, whilst reading was taking on average 250ms.

It can be seen from the read/write breakdown that 77% of the processes execution time was spent waiting for I/O's to complete on reads from fd[3]. If the file descriptors are unknown, the /usr/proc/bin/pfiles utility can be used to provide more information. (The next version of etruss will show filename information).

The etruss utility can be obtained from the downloads directory.