Home | History | Annotate | Line # | Download | only in Bin
      1 #!/usr/bin/sh
      2 #
      3 # iosnoop - A program to print disk I/O events as they happen, with useful
      4 #           details such as UID, PID, filename, command, etc. 
      5 #           Written using DTrace (Solaris 10 3/05).
      6 #
      7 # This is measuring disk events that have made it past system caches.
      8 #
      9 # $Id: iosnoop,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $
     10 #
     11 # USAGE: 	iosnoop [-a|-A|-DeghiNostv] [-d device] [-f filename] 
     12 #			[-m mount_point] [-n name] [-p PID]
     13 #
     14 #		iosnoop		# default output
     15 #
     16 #		-a		# print all data (mostly)
     17 #		-A		# dump all data, space delimited
     18 #		-D		# print time delta, us (elapsed)
     19 #		-e		# print device name
     20 #		-g		# print command arguments
     21 #		-i		# print device instance
     22 #		-N		# print major and minor numbers
     23 #		-o		# print disk delta time, us 
     24 #		-s		# print start time, us
     25 #		-t 		# print completion time, us
     26 #		-v		# print completion time, string
     27 #		-d device	# instance name to snoop (eg, dad0)
     28 #		-f filename	# full pathname of file to snoop
     29 #		-m mount_point	# this FS only (will skip raw events)
     30 #		-n name		# this process name only
     31 #		-p PID		# this PID only
     32 #  eg,
     33 #		iosnoop -v	# human readable timestamps
     34 #		iosnoop -N	# print major and minor numbers
     35 #		iosnoop -m /	# snoop events on the root filesystem only
     36 # 	
     37 # FIELDS:
     38 #		UID		user ID
     39 #		PID		process ID
     40 #		PPID		parennt process ID
     41 #		COMM		command name for the process
     42 #		ARGS		argument listing for the process
     43 #		SIZE		size of operation, bytes
     44 #		BLOCK		disk block for the operation (location)
     45 #		STIME	 	timestamp for the disk request, us
     46 #		TIME		timestamp for the disk completion, us
     47 #		DELTA		elapsed time from request to completion, us
     48 #		DTIME		time for disk to complete request, us
     49 #		STRTIME		timestamp for the disk completion, string
     50 #		DEVICE  	device name
     51 #		INS     	device instance number
     52 #		D		direction, Read or Write
     53 #		MOUNT		mount point
     54 #		FILE		filename (basename) for io operation
     55 # 
     56 # NOTE:
     57 # - There are two different delta times reported. -D prints the
     58 #   elapsed time from the disk request (strategy) to the disk completion
     59 #   (iodone); -o prints the time for the disk to complete that event 
     60 #   since it's last event (time between iodones), or, the time to the 
     61 #   strategy if the disk had been idle. 
     62 # - When filtering on PID or process name, be aware that poor disk event
     63 #   times may be due to events that have been filtered away, for example
     64 #   another process that may be seeking the disk heads elsewhere.
     65 #
     66 # SEE ALSO: BigAdmin: DTrace, http://www.sun.com/bigadmin/content/dtrace
     67 #	    Solaris Dynamic Tracing Guide, http://docs.sun.com
     68 #	    DTrace Tools, http://www.brendangregg.com/dtrace.html
     69 #
     70 # COPYRIGHT: Copyright (c) 2005 Brendan Gregg.
     71 #
     72 # CDDL HEADER START
     73 #
     74 #  The contents of this file are subject to the terms of the
     75 #  Common Development and Distribution License, Version 1.0 only
     76 #  (the "License").  You may not use this file except in compliance
     77 #  with the License.
     78 #
     79 #  You can obtain a copy of the license at Docs/cddl1.txt
     80 #  or http://www.opensolaris.org/os/licensing.
     81 #  See the License for the specific language governing permissions
     82 #  and limitations under the License.
     83 #
     84 # CDDL HEADER END
     85 #
     86 # Author: Brendan Gregg  [Sydney, Australia]
     87 #
     88 # 12-Mar-2004	Brendan Gregg	Created this, build 51.
     89 # 23-May-2004	   "	  "	Fixed mntpt bug.
     90 # 10-Oct-2004	   "      "	Rewritten to use the io provider, build 63.
     91 # 04-Jan-2005	   "	  "	Wrapped in sh to provide options.
     92 # 08-May-2005	   "      "	Rewritten for perfromance.
     93 # 15-Jul-2005	   "      "	Improved DTIME calculation.
     94 # 25-Jul-2005	   "      "	Added -p, -n. Improved code.
     95 # 17-Sep-2005	   "      "	Increased switchrate.
     96 # 17-Sep-2005	   "      "	Last update.
     97 #
     98 
     99 
    100 ##############################
    101 # --- Process Arguments ---
    102 #
    103 
    104 ### default variables
    105 opt_dump=0; opt_device=0; opt_delta=0; opt_devname=0; opt_file=0; opt_args=0; 
    106 opt_mount=0; opt_start=0 opt_end=0; opt_endstr=0; opt_ins=0; opt_nums=0
    107 opt_dtime=0; filter=0; device=.; filename=.; mount=.; pname=.; pid=0
    108 opt_name=0; opt_pid=0
    109 
    110 ### process options
    111 while getopts aAd:Def:ghim:Nn:op:stv name
    112 do
    113 	case $name in
    114 	a)	opt_devname=1; opt_args=1; opt_endstr=1; opt_nums=1 ;;
    115 	A)	opt_dump=1 ;;
    116 	d)	opt_device=1; device=$OPTARG ;;
    117 	D)	opt_delta=1 ;;
    118 	e)	opt_devname=1 ;;
    119 	f)	opt_file=1; filename=$OPTARG ;;
    120 	g)	opt_args=1 ;;
    121 	i)	opt_ins=1 ;;
    122 	N)	opt_nums=1 ;;
    123 	n)	opt_name=1; pname=$OPTARG ;;
    124 	o)	opt_dtime=1 ;;
    125 	p)	opt_pid=1; pid=$OPTARG ;;
    126 	m)	opt_mount=1; mount=$OPTARG ;;
    127 	s)	opt_start=1 ;;
    128 	t)	opt_end=1 ;;
    129 	v)	opt_endstr=1 ;;
    130 	h|?)	cat <<-END >&2
    131 		USAGE: iosnoop [-a|-A|-DeghiNostv] [-d device] [-f filename]
    132 		               [-m mount_point] [-n name] [-p PID]
    133 		       iosnoop          # default output
    134 		                -a      # print all data (mostly)
    135 		                -A      # dump all data, space delimited
    136 		                -D      # print time delta, us (elapsed)
    137 		                -e      # print device name
    138 		                -g      # print command arguments
    139 		                -i      # print device instance
    140 		                -N      # print major and minor numbers
    141 		                -o      # print disk delta time, us
    142 		                -s      # print start time, us
    143 		                -t      # print completion time, us
    144 		                -v      # print completion time, string
    145 		                -d device       # instance name to snoop 
    146 		                -f filename     # snoop this file only
    147 		                -m mount_point  # this FS only 
    148 		                -n name         # this process name only 
    149 		                -p PID          # this PID only 
    150 		   eg,
    151 		        iosnoop -v      # human readable timestamps
    152 		        iosnoop -N      # print major and minor numbers
    153 		        iosnoop -m /    # snoop events on filesystem / only
    154 		END
    155 		exit 1
    156 	esac
    157 done
    158 
    159 ### option logic
    160 if [ $opt_dump -eq 1 ]; then
    161 	opt_delta=0; opt_devname=0; opt_args=2; opt_start=0; 
    162 	opt_end=0; opt_endstr=0; opt_nums=0; opt_ins=0; opt_dtime=0
    163 fi
    164 if [ $opt_device -eq 1 -o $opt_file -eq 1 -o $opt_mount -eq 1 -o \
    165     $opt_name -eq 1 -o $opt_pid -eq 1 ]; then
    166 	filter=1
    167 fi
    168 
    169 
    170 #################################
    171 # --- Main Program, DTrace ---
    172 #
    173 /usr/sbin/dtrace -n '
    174  /*
    175   * Command line arguments
    176   */
    177  inline int OPT_dump 	= '$opt_dump';
    178  inline int OPT_device 	= '$opt_device';
    179  inline int OPT_delta 	= '$opt_delta';
    180  inline int OPT_devname = '$opt_devname';
    181  inline int OPT_file 	= '$opt_file';
    182  inline int OPT_args 	= '$opt_args';
    183  inline int OPT_ins  	= '$opt_ins';
    184  inline int OPT_nums  	= '$opt_nums';
    185  inline int OPT_dtime 	= '$opt_dtime';
    186  inline int OPT_mount 	= '$opt_mount';
    187  inline int OPT_start 	= '$opt_start';
    188  inline int OPT_pid 	= '$opt_pid';
    189  inline int OPT_name 	= '$opt_name';
    190  inline int OPT_end 	= '$opt_end';
    191  inline int OPT_endstr 	= '$opt_endstr';
    192  inline int FILTER 	= '$filter';
    193  inline int PID 	= '$pid';
    194  inline string DEVICE 	= "'$device'";
    195  inline string FILENAME = "'$filename'";
    196  inline string MOUNT 	= "'$mount'";
    197  inline string NAME 	= "'$pname'";
    198  
    199  #pragma D option quiet
    200  #pragma D option switchrate=10hz
    201 
    202  /*
    203   * Print header
    204   */
    205  dtrace:::BEGIN 
    206  {
    207 	last_event[""] = 0;
    208 
    209 	/* print optional headers */
    210  	OPT_start   ? printf("%-14s ","STIME")   : 1;
    211  	OPT_end     ? printf("%-14s ","TIME")    : 1;
    212  	OPT_endstr  ? printf("%-20s ","STRTIME") : 1;
    213  	OPT_devname ? printf("%-7s ","DEVICE")   : 1;
    214  	OPT_ins     ? printf("%-3s ","INS")      : 1;
    215  	OPT_nums    ? printf("%-3s %-3s ","MAJ","MIN") : 1;
    216  	OPT_delta   ? printf("%-10s ","DELTA")   : 1;
    217  	OPT_dtime   ? printf("%-10s ","DTIME")   : 1;
    218 
    219 	/* print main headers */
    220 	OPT_dump ? 
    221 	    printf("%s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s %s\n",
    222  	    "TIME", "STIME", "DELTA", "DEVICE", "INS", "MAJ", "MIN", "UID",
    223 	    "PID", "PPID", "D", "BLOCK", "SIZE", "MOUNT", "FILE", "PATH",
    224 	    "COMM","ARGS") :
    225  	    printf("%5s %5s %1s %8s %6s ", "UID", "PID", "D", "BLOCK", "SIZE");
    226 	OPT_args == 0 ? printf("%10s %s\n", "COMM", "PATHNAME") : 1;
    227  	OPT_args == 1 ? printf("%28s %s\n", "PATHNAME", "ARGS") : 1;
    228  }
    229 
    230  /*
    231   * Check event is being traced
    232   */
    233  io:genunix::start
    234  { 
    235 	/* default is to trace unless filtering, */
    236 	self->ok = FILTER ? 0 : 1;
    237 
    238 	/* check each filter, */
    239 	(OPT_device == 1 && DEVICE == args[1]->dev_statname)? self->ok = 1 : 1;
    240 	(OPT_file == 1 && FILENAME == args[2]->fi_pathname) ? self->ok = 1 : 1;
    241 	(OPT_mount == 1 && MOUNT == args[2]->fi_mount) ? self->ok = 1 : 1;
    242 	(OPT_name == 1 && NAME == execname) ? self->ok = 1 : 1;
    243 	(OPT_pid == 1 && PID == pid) ? self->ok = 1 : 1;
    244  }
    245 
    246  /*
    247   * Reset last_event for disk idle -> start
    248   * this prevents idle time being counted as disk time.
    249   */
    250  io:genunix::start
    251  /! pending[args[1]->dev_statname]/
    252  {
    253 	/* save last disk event */
    254 	last_event[args[1]->dev_statname] = timestamp;
    255  }
    256 
    257  /*
    258   * Store entry details
    259   */
    260  io:genunix::start
    261  /self->ok/
    262  {
    263 	/* these are used as a unique disk event key, */
    264  	this->dev = args[0]->b_edev;
    265  	this->blk = args[0]->b_blkno;
    266 
    267 	/* save disk event details, */
    268  	start_uid[this->dev, this->blk] = uid;
    269  	start_pid[this->dev, this->blk] = pid;
    270  	start_ppid[this->dev, this->blk] = ppid;
    271  	start_args[this->dev, this->blk] = (char *)curpsinfo->pr_psargs;
    272  	start_comm[this->dev, this->blk] = execname;
    273  	start_time[this->dev, this->blk] = timestamp;
    274 
    275 	/* increase disk event pending count */
    276 	pending[args[1]->dev_statname]++;
    277 
    278 	self->ok = 0;
    279  }
    280 
    281  /*
    282   * Process and Print completion
    283   */
    284  io:genunix::done
    285  /start_time[args[0]->b_edev, args[0]->b_blkno]/
    286  {
    287 	/* decrease disk event pending count */
    288 	pending[args[1]->dev_statname]--;
    289 
    290 	/*
    291 	 * Process details
    292 	 */
    293 
    294  	/* fetch entry values */
    295  	this->dev = args[0]->b_edev;
    296  	this->blk = args[0]->b_blkno;
    297  	this->suid = start_uid[this->dev, this->blk];
    298  	this->spid = start_pid[this->dev, this->blk];
    299  	this->sppid = start_ppid[this->dev, this->blk];
    300  	self->sargs = (int)start_args[this->dev, this->blk] == 0 ? 
    301  	    "" : start_args[this->dev, this->blk];
    302  	self->scomm = start_comm[this->dev, this->blk];
    303  	this->stime = start_time[this->dev, this->blk];
    304 	this->etime = timestamp; /* endtime */
    305 	this->delta = this->etime - this->stime;
    306 	this->dtime = last_event[args[1]->dev_statname] == 0 ? 0 :
    307 	    timestamp - last_event[args[1]->dev_statname];
    308 
    309  	/* memory cleanup */
    310  	start_uid[this->dev, this->blk]  = 0;
    311  	start_pid[this->dev, this->blk]  = 0;
    312  	start_ppid[this->dev, this->blk] = 0;
    313  	start_args[this->dev, this->blk] = 0;
    314  	start_time[this->dev, this->blk] = 0;
    315  	start_comm[this->dev, this->blk] = 0;
    316  	start_rw[this->dev, this->blk]   = 0;
    317 
    318 	/*
    319 	 * Print details
    320 	 */
    321 
    322 	/* print optional fields */
    323  	OPT_start   ? printf("%-14d ", this->stime/1000) : 1;
    324  	OPT_end     ? printf("%-14d ", this->etime/1000) : 1;
    325  	OPT_endstr  ? printf("%-20Y ", walltimestamp) : 1;
    326  	OPT_devname ? printf("%-7s ", args[1]->dev_statname) : 1;
    327  	OPT_ins     ? printf("%3d ", args[1]->dev_instance) : 1;
    328  	OPT_nums    ? printf("%3d %3d ",
    329 	    args[1]->dev_major, args[1]->dev_minor) : 1;
    330  	OPT_delta   ? printf("%-10d ", this->delta/1000) : 1;
    331  	OPT_dtime   ? printf("%-10d ", this->dtime/1000) : 1;
    332 
    333 	/* print main fields */
    334 	OPT_dump ? 
    335  	    printf("%d %d %d %s %d %d %d %d %d %d %s %d %d %s %s %s %s %S\n",
    336  	    this->etime/1000, this->stime/1000, this->delta/1000,
    337  	    args[1]->dev_statname, args[1]->dev_instance, args[1]->dev_major,
    338 	    args[1]->dev_minor, this->suid, this->spid, this->sppid, 
    339 	    args[0]->b_flags & B_READ ? "R" : "W", 
    340 	    args[0]->b_blkno, args[0]->b_bcount, args[2]->fi_mount,
    341 	    args[2]->fi_name, args[2]->fi_pathname, self->scomm, self->sargs) :
    342  	    printf("%5d %5d %1s %8d %6d ",
    343  	    this->suid, this->spid, args[0]->b_flags & B_READ ? "R" : "W",
    344 	    args[0]->b_blkno, args[0]->b_bcount);
    345 	OPT_args == 0 ? printf("%10s %s\n", self->scomm, args[2]->fi_pathname)
    346 	    : 1;
    347  	OPT_args == 1 ? printf("%28s %S\n",
    348 	    args[2]->fi_pathname, self->sargs) : 1;
    349 
    350 	/* save last disk event */
    351 	last_event[args[1]->dev_statname] = timestamp;
    352 
    353 	/* cleanup */
    354 	self->scomm = 0;
    355 	self->sargs = 0;
    356  }
    357 
    358  /*
    359   * Prevent pending from underflowing
    360   * this can happen if this program is started during disk events.
    361   */
    362  io:genunix::done
    363  /pending[args[1]->dev_statname] < 0/
    364  {
    365 	pending[args[1]->dev_statname] = 0;
    366  }
    367 '
    368