systemtap block-io

block-io.stp

#!/usr/bin/stap

global block_size=512
global devices
global cmd_start
global writes_time
global reads_time
global writes_size
global reads_size
global cmd_size
global seeks
global this_sector
global last_sector
 
probe module("scsi_mod").function("scsi_dispatch_cmd")
{
    /* start time for this scsi command */
    cmd_start[$cmd] = gettimeofday_ms() 
 
    /* cmd_size = number of sections * sector size */
    cmd_size[$cmd] = $cmd->request->nr_sectors * $cmd->device->sector_size
}
 
probe module("scsi_mod").function("scsi_done")
{
    /* end time for this scsi command */
    delta = gettimeofday_ms() - cmd_start[$cmd]
 
    /* delete global */
    delete cmd_start[$cmd]
 
    /* should never happen but it does for unknown reasons */
    if (delta > 0)
    {
        /* scsi device (e.g., sdb) */
        dev = kernel_string($cmd->request->rq_disk->disk_name)
 
        /* add dev to list of devices */
        devices[dev]++
 
        /* read */
        if (2 == $cmd->sc_data_direction)
        {
            reads_time[dev] <<< delta
            reads_size[dev] <<< cmd_size[$cmd]
        }
        /* write */
        else
        {
            writes_time[dev] <<< delta
            writes_size[dev] <<< cmd_size[$cmd]
        }
    }
    /* delete global */
    delete cmd_size[$cmd]
}
 
probe ioblock.request
{
    /* device (e.g., sdb) */
    dev = substr(devname,0,3)
 
    /* trim devices to prevent duplicate reporting */
    if (devname != "N/A" && dev != "dm-")
 
    this_sector[devname] = sector
 
    delta = this_sector[devname] - last_sector[devname]
    if (delta < 0)
        delta = delta * -1
 
    seeks[devname] <<< delta
 
    last_sector[devname] = this_sector[devname]
}

probe timer.s($1)
{
    /* print header */
    ansi_clear_screen()
    printf("\n%s %8s %10s %10s %12s %12s %12s %12s %12s %12s %12s %12s %16s %16s %13s\n",
            "device", "ops", "r_ops", "w_ops",
            "r_min(ms)", "r_avg(ms)", "r_max(ms)",
            "w_min(ms)", "w_avg(ms)", "w_max(ms)",
            "r_sum(kb)", "w_sum(kb)", "r_blk_avg(kb)", "w_blk_avg(kb)",
            "seeks(avg)")
 
    foreach ([dev+] in devices)
    {
        /* establish counts for reads and writes */
        read_size_count = @count(reads_size[dev])
        read_time_count = @count(reads_time[dev])
        write_size_count = @count(writes_size[dev])
        write_time_count = @count(writes_time[dev])
 
        /* io count */
        ops = (read_size_count + write_size_count) / $1
        read_ops = read_size_count / $1
        write_ops = write_size_count / $1
 
        /* io service time */
        read_time_min = read_time_count ? @min(reads_time[dev]) : 0
        read_time_avg = read_time_count ? @avg(reads_time[dev]) : 0
        read_time_max = read_time_count ? @max(reads_time[dev]) : 0
        write_time_min = write_time_count ? @min(writes_time[dev]) : 0
        write_time_avg = write_time_count ? @avg(writes_time[dev]) : 0
        write_time_max = write_time_count ? @max(writes_time[dev]) : 0
 
        /* divide by block_size to get size in kb */
        read_size_sum = read_size_count ? @sum(reads_size[dev]) / block_size : 0
        read_size_avg = read_size_count ? @avg(reads_size[dev]) / block_size : 0
        write_size_sum = write_size_count ? @sum(writes_size[dev]) / block_size : 0
        write_size_avg = write_size_count ? @avg(writes_size[dev]) / block_size : 0
 
        /* io seeks */
        seeks_count = @count(seeks[dev])
        seeks_avg = seeks_count ? @avg(seeks[dev]) : 0
 
        /* print stats */
        printf("%s %11d %10d %10d %12d %12d %12d %12d %12d %12d %12d %12d %16d %16d %13d\n",
                dev, ops, read_ops, write_ops,
                read_time_min, read_time_avg, read_time_max,
                write_time_min, write_time_avg, write_time_max,
                read_size_sum, write_size_sum, read_size_avg, write_size_avg, seeks_avg)
    }
 
    /* delete globals */
    delete writes_time
    delete reads_time
    delete writes_size
    delete reads_size
    delete seeks
}