- Prev
- SystemTap Beginners Guide
- Next

### ⁠5.2.7. Periodically Print I/O Block Time

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.
ioblktime.stp

    #! /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`.
⁠

Example 5.12. ioblktime.stp Sample Output

        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.

- Prev5.2.6. Monitoring Changes to File Attributes
- Up
- Home
- Next5.3. Profiling