procsystime revision 235456
1#!/bin/sh 2# 3# procsystime - print process system call time details. 4# Written using DTrace (Solaris 10 3/05). 5# 6# $Id: procsystime 4 2007-08-01 11:01:38Z brendan $ 7# 8# USAGE: procsystime [-acehoT] [ -p PID | -n name | command ] 9# 10# -p PID # examine this PID 11# -n name # examine this process name 12# -a # print all details 13# -c # print syscall counts 14# -e # print elapsed times 15# -o # print CPU times 16# -T # print totals 17# eg, 18# procsystime -p 1871 # examine PID 1871 19# procsystime -n tar # examine processes called "tar" 20# procsystime -aTn bash # print all details for bash shells 21# procsystime df -h # run and examine "df -h" 22# 23# The elapsed times are interesting, to help identify syscalls that take 24# some time to complete (during which the process may have slept). CPU time 25# helps us identify syscalls that are consuming CPU cycles to run. 26# 27# FIELDS: 28# SYSCALL System call name 29# TIME (ns) Total time, nanoseconds 30# COUNT Number of occurrences 31# 32# COPYRIGHT: Copyright (c) 2005 Brendan Gregg. 33# 34# CDDL HEADER START 35# 36# The contents of this file are subject to the terms of the 37# Common Development and Distribution License, Version 1.0 only 38# (the "License"). You may not use this file except in compliance 39# with the License. 40# 41# You can obtain a copy of the license at Docs/cddl1.txt 42# or http://www.opensolaris.org/os/licensing. 43# See the License for the specific language governing permissions 44# and limitations under the License. 45# 46# CDDL HEADER END 47# 48# Author: Brendan Gregg [Sydney, Australia] 49# 50# 27-Apr-2005 Brendan Gregg Created this. 51# 08-Jun-2005 " " Added command option. 52# 22-Sep-2005 " " Allowed systemwide tracing. 53# 22-Sep-2005 " " Last update. 54# 55 56 57############################## 58# --- Process Arguments --- 59# 60 61### Default variables 62opt_filter=0; opt_pid=0; opt_name=0; pid=0; pname="."; 63opt_elapsed=0; opt_cpu=0; opt_counts=0; opt_totals=0 64opt_command=0; command=""; 65 66### Process options 67while getopts acehn:op:T name 68do 69 case $name in 70 p) opt_filter=1; opt_pid=1; pid=$OPTARG ;; 71 n) opt_filter=1; opt_name=1; pname=$OPTARG ;; 72 a) opt_totals=1; opt_elapsed=1; opt_cpu=1; opt_counts=1 ;; 73 e) opt_elapsed=1 ;; 74 c) opt_counts=1 ;; 75 o) opt_cpu=1 ;; 76 T) opt_totals=1 ;; 77 h|?) cat <<-END >&2 78 USAGE: procsystime [-aceho] [ -p PID | -n name | command ] 79 -p PID # examine this PID 80 -n name # examine this process name 81 -a # print all details 82 -e # print elapsed times 83 -c # print syscall counts 84 -o # print CPU times 85 -T # print totals 86 eg, 87 procsystime -p 1871 # examine PID 1871 88 procsystime -n tar # examine processes called "tar" 89 procsystime -aTn bash # print all details for bash 90 procsystime df -h # run and examine "df -h" 91 END 92 exit 1 93 esac 94done 95shift `expr $OPTIND - 1` 96 97### Option logic 98if [ $opt_pid -eq 0 -a $opt_name -eq 0 -a "$*" != "" ]; then 99 opt_filter=1 100 opt_command=1 101 command="$*" 102fi 103if [ $opt_elapsed -eq 0 -a $opt_cpu -eq 0 -a $opt_counts -eq 0 ]; then 104 opt_elapsed=1; 105fi 106 107 108################################# 109# --- Main Program, DTrace --- 110# 111dtrace=' 112 #pragma D option quiet 113 114 /* 115 * Command line arguments 116 */ 117 inline int OPT_elapsed = '$opt_elapsed'; 118 inline int OPT_cpu = '$opt_cpu'; 119 inline int OPT_counts = '$opt_counts'; 120 inline int OPT_filter = '$opt_filter'; 121 inline int OPT_pid = '$opt_pid'; 122 inline int OPT_name = '$opt_name'; 123 inline int OPT_totals = '$opt_totals'; 124 inline int OPT_command = '$opt_command'; 125 inline int PID = '$pid'; 126 inline string NAME = "'$pname'"; 127 inline string COMMAND = "'$command'"; 128 129 dtrace:::BEGIN 130 { 131 self->start = 0; 132 self->vstart = 0; 133 } 134 dtrace:::BEGIN 135 /! OPT_command/ 136 { 137 printf("Tracing... Hit Ctrl-C to end...\n"); 138 } 139 140 /* 141 * Set start timestamp and counts 142 */ 143 syscall:::entry 144 /(! OPT_filter) || 145 (OPT_pid && pid == PID) || 146 (OPT_name && execname == NAME) || 147 (OPT_command && pid == $target)/ 148 { 149 self->ok = 1; 150 } 151 syscall:::entry 152 /self->ok/ 153 { 154 OPT_counts ? @Counts[probefunc] = count() : 1; 155 (OPT_counts && OPT_totals) ? @Counts["TOTAL:"] = count() : 1; 156 OPT_elapsed ? self->start = timestamp : 1; 157 OPT_cpu ? self->vstart = vtimestamp : 1; 158 self->ok = 0; 159 } 160 161 /* 162 * Calculate time deltas 163 */ 164 syscall:::return 165 /self->start/ 166 { 167 this->elapsed = timestamp - self->start; 168 @Elapsed[probefunc] = sum(this->elapsed); 169 OPT_totals ? @Elapsed["TOTAL:"] = sum(this->elapsed) : 1; 170 self->start = 0; 171 } 172 syscall:::return 173 /self->vstart/ 174 { 175 this->cpu = vtimestamp - self->vstart; 176 @CPU[probefunc] = sum(this->cpu); 177 OPT_totals ? @CPU["TOTAL:"] = sum(this->cpu) : 1; 178 self->vstart = 0; 179 } 180 181 /* 182 * Elapsed time report 183 */ 184 dtrace:::END 185 /OPT_elapsed/ 186 { 187 printf("\nElapsed Times for "); 188 OPT_pid ? printf("PID %d,\n\n",PID) : 1; 189 OPT_name ? printf("processes %s,\n\n",NAME) : 1; 190 OPT_command ? printf("command %s,\n\n",COMMAND) : 1; 191 (! OPT_filter) ? printf("all processes,\n\n") : 1; 192 printf("%16s %18s\n","SYSCALL","TIME (ns)"); 193 printa("%16s %@18d\n",@Elapsed); 194 } 195 196 /* 197 * CPU time report 198 */ 199 dtrace:::END 200 /OPT_cpu/ 201 { 202 printf("\nCPU Times for "); 203 OPT_pid ? printf("PID %d,\n\n",PID) : 1; 204 OPT_name ? printf("processes %s,\n\n",NAME) : 1; 205 OPT_command ? printf("command %s,\n\n",COMMAND) : 1; 206 (! OPT_filter) ? printf("all processes,\n\n") : 1; 207 printf("%16s %18s\n","SYSCALL","TIME (ns)"); 208 printa("%16s %@18d\n",@CPU); 209 } 210 211 /* 212 * Syscall count report 213 */ 214 dtrace:::END 215 /OPT_counts/ 216 { 217 printf("\nSyscall Counts for "); 218 OPT_pid ? printf("PID %d,\n\n",PID) : 1; 219 OPT_name ? printf("processes %s,\n\n",NAME) : 1; 220 OPT_command ? printf("command %s,\n\n",COMMAND) : 1; 221 (! OPT_filter) ? printf("all processes,\n\n") : 1; 222 printf("%16s %18s\n","SYSCALL","COUNT"); 223 OPT_counts ? printa("%16s %@18d\n",@Counts) : 1; 224 } 225' 226 227### Run DTrace 228if [ $opt_command -eq 1 ]; then 229 /usr/sbin/dtrace -n "$dtrace" -x evaltime=exec -c "$command" >&2 230else 231 /usr/sbin/dtrace -n "$dtrace" >&2 232fi 233 234