#!/bin/sh
#
# iosnoop - A program to print disk I/O events as they happen, with useful
# details such as UID, PID, filename (if available), command, etc.
# Written using DTrace (Solaris 10 3/05, MacOS X 10.5).
#
# This is measuring events that have made it past system caches, such as
# disk events for local file systems, and network events for remote
# filesystems (such as NFS.)
#
# $Id: iosnoop,v 1.2 2018/10/01 13:28:07 sevan Exp $
#
# USAGE: iosnoop [-a|-A|-DeghiNostv] [-d device] [-f filename]
# [-m mount_point] [-n name] [-p PID]
#
# iosnoop # default output
#
# -a # print all data (mostly)
# -A # dump all data, space delimited
# -D # print time delta, us (elapsed)
# -e # print device name
# -g # print command arguments
# -i # print device instance
# -N # print major and minor numbers
# -o # print disk delta time, us
# -s # print start time, us
# -t # print completion time, us
# -v # print completion time, string
# -d device # instance name to snoop (eg, dad0)
# -f filename # full pathname of file to snoop
# -m mount_point # this FS only (will skip raw events)
# -n name # this process name only
# -p PID # this PID only
# eg,
# iosnoop -v # human readable timestamps
# iosnoop -N # print major and minor numbers
# iosnoop -m / # snoop events on the root filesystem only
#
# FIELDS:
# UID user ID
# PID process ID
# PPID parennt process ID
# COMM command name for the process
# ARGS argument listing for the process
# SIZE size of operation, bytes
# BLOCK disk block for the operation (location)
# STIME timestamp for the disk request, us
# TIME timestamp for the disk completion, us
# DELTA elapsed time from request to completion, us
# DTIME time for disk to complete request, us
# STRTIME timestamp for the disk completion, string
# DEVICE device name
# INS device instance number
# D direction, Read or Write
# MOUNT mount point
# FILE filename (basename) for io operation
#
# NOTE:
# - There are two different delta times reported. -D prints the
# elapsed time from the disk request (strategy) to the disk completion
# (iodone); -o prints the time for the disk to complete that event
# since it's last event (time between iodones), or, the time to the
# strategy if the disk had been idle.
# - When filtering on PID or process name, be aware that poor disk event
# times may be due to events that have been filtered away, for example
# another process that may be seeking the disk heads elsewhere.
#
# SEE ALSO: BigAdmin: DTrace, http://www.sun.com/bigadmin/content/dtrace
# Solaris Dynamic Tracing Guide, http://docs.sun.com
# DTrace Tools, http://www.brendangregg.com/dtrace.html
#
# COPYRIGHT: Copyright (c) 2009 Brendan Gregg.
#
# CDDL HEADER START
#
# The contents of this file are subject to the terms of the
# Common Development and Distribution License, Version 1.0 only
# (the "License"). You may not use this file except in compliance
# with the License.
#
# You can obtain a copy of the license at Docs/cddl1.txt
# or http://www.opensolaris.org/os/licensing.
# See the License for the specific language governing permissions
# and limitations under the License.
#
# CDDL HEADER END
#
# 12-Mar-2004 Brendan Gregg Created this, build 51.
# 23-May-2004 " " Fixed mntpt bug.
# 10-Oct-2004 " " Rewritten to use the io provider, build 63.
# 04-Jan-2005 " " Wrapped in sh to provide options.
# 08-May-2005 " " Rewritten for perfromance.
# 15-Jul-2005 " " Improved DTIME calculation.
# 25-Jul-2005 " " Added -p, -n. Improved code.
# 17-Sep-2005 " " Increased switchrate.
# 15-Sep-2009 " " Removed genunix for both MacOS X and NFS.
#
##############################
# --- Process Arguments ---
#
### default variables
opt_dump=0; opt_device=0; opt_delta=0; opt_devname=0; opt_file=0; opt_args=0;
opt_mount=0; opt_start=0 opt_end=0; opt_endstr=0; opt_ins=0; opt_nums=0
opt_dtime=0; filter=0; device=.; filename=.; mount=.; pname=.; pid=0
opt_name=0; opt_pid=0
### process options
while getopts aAd:Def:ghim:Nn:op:stv name
do
case $name in
a) opt_devname=1; opt_args=1; opt_endstr=1; opt_nums=1 ;;
A) opt_dump=1 ;;
d) opt_device=1; device=$OPTARG ;;
D) opt_delta=1 ;;
e) opt_devname=1 ;;
f) opt_file=1; filename=$OPTARG ;;
g) opt_args=1 ;;
i) opt_ins=1 ;;
N) opt_nums=1 ;;
n) opt_name=1; pname=$OPTARG ;;
o) opt_dtime=1 ;;
p) opt_pid=1; pid=$OPTARG ;;
m) opt_mount=1; mount=$OPTARG ;;
s) opt_start=1 ;;
t) opt_end=1 ;;
v) opt_endstr=1 ;;
h|?) cat <<-END >&2
USAGE: iosnoop [-a|-A|-DeghiNostv] [-d device] [-f filename]
[-m mount_point] [-n name] [-p PID]
iosnoop # default output
-a # print all data (mostly)
-A # dump all data, space delimited
-D # print time delta, us (elapsed)
-e # print device name
-g # print command arguments
-i # print device instance
-N # print major and minor numbers
-o # print disk delta time, us
-s # print start time, us
-t # print completion time, us
-v # print completion time, string
-d device # instance name to snoop
-f filename # snoop this file only
-m mount_point # this FS only
-n name # this process name only
-p PID # this PID only
eg,
iosnoop -v # human readable timestamps
iosnoop -N # print major and minor numbers
iosnoop -m / # snoop events on filesystem / only
END
exit 1
esac
done
### option logic
if [ $opt_dump -eq 1 ]; then
opt_delta=0; opt_devname=0; opt_args=2; opt_start=0;
opt_end=0; opt_endstr=0; opt_nums=0; opt_ins=0; opt_dtime=0
fi
if [ $opt_device -eq 1 -o $opt_file -eq 1 -o $opt_mount -eq 1 -o \
$opt_name -eq 1 -o $opt_pid -eq 1 ]; then
filter=1
fi
#################################
# --- Main Program, DTrace ---
#
/usr/sbin/dtrace -n '
/*
* Command line arguments
*/
inline int OPT_dump = '$opt_dump';
inline int OPT_device = '$opt_device';
inline int OPT_delta = '$opt_delta';
inline int OPT_devname = '$opt_devname';
inline int OPT_file = '$opt_file';
inline int OPT_args = '$opt_args';
inline int OPT_ins = '$opt_ins';
inline int OPT_nums = '$opt_nums';
inline int OPT_dtime = '$opt_dtime';
inline int OPT_mount = '$opt_mount';
inline int OPT_start = '$opt_start';
inline int OPT_pid = '$opt_pid';
inline int OPT_name = '$opt_name';
inline int OPT_end = '$opt_end';
inline int OPT_endstr = '$opt_endstr';
inline int FILTER = '$filter';
inline int PID = '$pid';
inline string DEVICE = "'$device'";
inline string FILENAME = "'$filename'";
inline string MOUNT = "'$mount'";
inline string NAME = "'$pname'";
#pragma D option quiet
#pragma D option switchrate=10hz
/* boost the following if you get "dynamic variable drops" */
#pragma D option dynvarsize=16m
/*
* Print header
*/
dtrace:::BEGIN
{
last_event[""] = 0;
/* print optional headers */
OPT_start ? printf("%-14s ","STIME(us)") : 1;
OPT_end ? printf("%-14s ","TIME(us)") : 1;
OPT_endstr ? printf("%-20s ","STRTIME") : 1;
OPT_devname ? printf("%-7s ","DEVICE") : 1;
OPT_ins ? printf("%-3s ","INS") : 1;
OPT_nums ? printf("%-3s %-3s ","MAJ","MIN") : 1;
OPT_delta ? printf("%-10s ","DELTA(us)") : 1;
OPT_dtime ? printf("%-10s ","DTIME(us)") : 1;
/* print main headers */
OPT_dump ?
printf("%s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s\n",
"TIME", "STIME", "DELTA", "DEVICE", "INS", "MAJ", "MIN", "UID",
"PID", "PPID", "D", "BLOCK", "SIZE", "MOUNT", "FILE", "PATH",
"COMM","ARGS") :
printf("%5s %5s %1s %8s %6s ", "UID", "PID", "D", "BLOCK", "SIZE");
OPT_args == 0 ? printf("%10s %s\n", "COMM", "PATHNAME") : 1;
OPT_args == 1 ? printf("%28s %s\n", "PATHNAME", "ARGS") : 1;
}
/*
* Check event is being traced
*/
io:::start
{
/* default is to trace unless filtering, */
self->ok = FILTER ? 0 : 1;
/* check each filter, */
(OPT_device == 1 && DEVICE == args[1]->dev_statname)? self->ok = 1 : 1;
(OPT_file == 1 && FILENAME == args[2]->fi_pathname) ? self->ok = 1 : 1;
(OPT_mount == 1 && MOUNT == args[2]->fi_mount) ? self->ok = 1 : 1;
(OPT_name == 1 && NAME == execname) ? self->ok = 1 : 1;
(OPT_pid == 1 && PID == pid) ? self->ok = 1 : 1;
}
/*
* Reset last_event for disk idle -> start
* this prevents idle time being counted as disk time.
*/
io:::start
/! pending[args[1]->dev_statname]/
{
/* save last disk event */
last_event[args[1]->dev_statname] = timestamp;
}
/*
* Store entry details
*/
io:::start
/self->ok/
{
/* these are used as a unique disk event key, */
this->dev = args[0]->b_edev;
this->blk = args[0]->b_blkno;
/* save disk event details, */
start_uid[this->dev, this->blk] = uid;
start_pid[this->dev, this->blk] = pid;
start_ppid[this->dev, this->blk] = ppid;
start_args[this->dev, this->blk] = (char *)curpsinfo->pr_psargs;
start_comm[this->dev, this->blk] = execname;
start_time[this->dev, this->blk] = timestamp;
/* increase disk event pending count */
pending[args[1]->dev_statname]++;
self->ok = 0;
}
/*
* Process and Print completion
*/
io:::done
/start_time[args[0]->b_edev, args[0]->b_blkno]/
{
/* decrease disk event pending count */
pending[args[1]->dev_statname]--;
/*
* Process details
*/
/* fetch entry values */
this->dev = args[0]->b_edev;
this->blk = args[0]->b_blkno;
this->suid = start_uid[this->dev, this->blk];
this->spid = start_pid[this->dev, this->blk];
this->sppid = start_ppid[this->dev, this->blk];
self->sargs = (int)start_args[this->dev, this->blk] == 0 ?
"" : start_args[this->dev, this->blk];
self->scomm = start_comm[this->dev, this->blk];
this->stime = start_time[this->dev, this->blk];
this->etime = timestamp; /* endtime */
this->delta = this->etime - this->stime;
this->dtime = last_event[args[1]->dev_statname] == 0 ? 0 :
timestamp - last_event[args[1]->dev_statname];
/* memory cleanup */
start_uid[this->dev, this->blk] = 0;
start_pid[this->dev, this->blk] = 0;
start_ppid[this->dev, this->blk] = 0;
start_args[this->dev, this->blk] = 0;
start_time[this->dev, this->blk] = 0;
start_comm[this->dev, this->blk] = 0;
start_rw[this->dev, this->blk] = 0;
/*
* Print details
*/
/* print optional fields */
OPT_start ? printf("%-14d ", this->stime/1000) : 1;
OPT_end ? printf("%-14d ", this->etime/1000) : 1;
OPT_endstr ? printf("%-20Y ", walltimestamp) : 1;
OPT_devname ? printf("%-7s ", args[1]->dev_statname) : 1;
OPT_ins ? printf("%3d ", args[1]->dev_instance) : 1;
OPT_nums ? printf("%3d %3d ",
args[1]->dev_major, args[1]->dev_minor) : 1;
OPT_delta ? printf("%-10d ", this->delta/1000) : 1;
OPT_dtime ? printf("%-10d ", this->dtime/1000) : 1;
/* print main fields */
OPT_dump ?
printf("%d %d %d %s %d %d %d %d %d %d %s %d %d %s %s %s %s %S\n",
this->etime/1000, this->stime/1000, this->delta/1000,
args[1]->dev_statname, args[1]->dev_instance, args[1]->dev_major,
args[1]->dev_minor, this->suid, this->spid, this->sppid,
args[0]->b_flags & B_READ ? "R" : "W",
args[0]->b_blkno, args[0]->b_bcount, args[2]->fi_mount,
args[2]->fi_name, args[2]->fi_pathname, self->scomm, self->sargs) :
printf("%5d %5d %1s %8d %6d ",
this->suid, this->spid, args[0]->b_flags & B_READ ? "R" : "W",
args[0]->b_blkno, args[0]->b_bcount);
OPT_args == 0 ? printf("%10s %s\n", self->scomm, args[2]->fi_pathname)
: 1;
OPT_args == 1 ? printf("%28s %S\n",
args[2]->fi_pathname, self->sargs) : 1;
/* save last disk event */
last_event[args[1]->dev_statname] = timestamp;
/* cleanup */
self->scomm = 0;
self->sargs = 0;
}
/*
* Prevent pending from underflowing
* this can happen if this program is started during disk events.
*/
io:::done
/pending[args[1]->dev_statname] < 0/
{
pending[args[1]->dev_statname] = 0;
}
'