This section describes how to track the amount of time each block I/O requests spends waiting for completion. This is useful in determining whether there are too many outstanding block I/O operations at any given time.

#! /usr/bin/env stap

global req_time%[25000], etimes

probe ioblock.request
{
  req_time[$bio] = gettimeofday_us()
}

probe ioblock.end
{
  t = gettimeofday_us()
  s =  req_time[$bio]
  delete req_time[$bio]
  if (s) {
    etimes[devname, bio_rw_str(rw)] <<< t - s
  }
}

/* for time being delete things that get merged with others */
probe kernel.{trace("block_bio_frontmerge"),
              trace("block_bio_backmerge")}
{
  delete req_time[$bio]
}

probe timer.s(10), end {
  ansi_clear_screen()
  printf("%10s %3s %10s %10s %10s\n",
         "device", "rw", "total (us)", "count", "avg (us)")
  foreach ([dev,rw] in etimes - limit 20) {
    printf("%10s %3s %10d %10d %10d\n", dev, rw,
           @sum(etimes[dev,rw]), @count(etimes[dev,rw]), @avg(etimes[dev,rw]))
  }
  delete etimes
}

ioblktime.stp computes the average waiting time for block I/O per device, and prints a list every 10 seconds. As always, you can revise this refresh rate by editing the specified value in probe timer.s(10), end {.

In some cases, there can be too many outstanding block I/O operations, at which point the script can exceed the default number of MAXMAPENTRIES. MAXMAPENTRIES is the maximum number of rows in an array if the array size is not specified explicitly when declared. If the script exceeds the default MAXMAPENTRIES value of 2048, run the script again with the stap option -DMAXMAPENTRIES=10000.

    device  rw total (us)      count   avg (us)
       sda   W       9659          6       1609
      dm-0   W      20278          6       3379
      dm-0   R      20524          5       4104
       sda   R      19277          5       3855

Example 5.12, “ioblktime.stp Sample Output” displays the device name, operations performed (rw), total wait time of all operations (total(us)), number of operations (count), and average wait time for all those operations (avg (us)). The times tallied by the script are in microseconds.