2

I am timing some code and I would like to tell how much of the time taken is due to reading the data in from disk. I don't believe the result that time gives me. For example, I have a 1.3GB file and if I run wc I get 

time wc largefile.file 
  50000000  150000000 1316665179 largefile.file

real    0m26.835s
user    0m18.363s
sys     0m0.495s

It can't possibly have taken < 0.5 seconds to read in the file from my old hard drive.

Is there a reliable way to tell how much of the time was due to I/O?

Further details for why I don't see how to interpret time. If I do 

time cat largefile.file > /dev/null

real    0m24.230s
user    0m0.060s
sys     0m1.473s

then it is tempting to say that about 22.5 seconds are spent on I/O. But the wc figure from above implies that it is 8 seconds. These two figures are not consistent.

Simd
  • 927
  • 6
  • 14
  • 28
  • 1
    Better redo the 2 measurements while rebooting before each one. If the file is even partially in memory then the measurement is false. – harrymc May 16 '14 at 13:21
  • @harrymc I just did `sync && sudo bash -c 'echo 3 > /proc/sys/vm/drop_caches'` first and get the same result. It's not a caching effect as the overall time is the same. – Simd May 16 '14 at 13:29
  • sync doesn't clear the memory cache - it just ensures that blocks marked as dirty are written to the disk. – harrymc May 16 '14 at 16:44
  • @harrymc OK but if you don't do the sync the timing is about 0 seconds. – Simd May 17 '14 at 18:01
  • Because Linux uses the memory cache very effectively, one must be very careful in measuring. – harrymc May 17 '14 at 21:00

1 Answers1

2

sys means cpu time spent in-kernel, but you want io-wait time.

Googling turned up another stack exchange answer pointing at "per-process iowait from /proc/$pid/stat". (And maybe need to run the programmer under a debugger and set a breakpoint on exit() / _exit(), so you can read out the iowait before the process goes away ?).

Often I just calculate it by subtracting the cpu time (user+sys) from the realtime. That assumes the process doesn't wait for things you don't count as "IO".

sourcejedi
  • 3,212
  • 2
  • 22
  • 33
  • Thank you. I added some to the question to show where my confusion lies. Subtracting the cpu time (user+sys) from the realtime doesn't give consistent answers. – Simd May 13 '14 at 08:26
  • Good point. I can say why it doesn't: IO can happen "in the background" while the process is still using cpu. That time is counted as cpu time not io-wait. Hopefully most programmers understand background writes (see fsync), aka write-back. Background reads happen because of [read-ahead](https://lwn.net/Articles/155510/). Maybe we can get what we want by running the task on an idle system (hah) and looking at the read/write milliseconds fields in `vmstat -d`. – sourcejedi May 20 '14 at 19:11