dtruss revision 1.1.1.1
1 #!/bin/sh 2 # 3 # dtruss - print process system call time details. 4 # Written using DTrace (Solaris 10 3/05). 5 # 6 # $Id: dtruss,v 1.1.1.1 2015/09/30 22:01:07 christos Exp $ 7 # 8 # USAGE: dtruss [-acdeflhoLs] [-t syscall] { -p PID | -n name | command } 9 # 10 # -p PID # examine this PID 11 # -n name # examine this process name 12 # -t syscall # examine this syscall only 13 # -a # print all details 14 # -c # print system call counts 15 # -d # print relative timestamps (us) 16 # -e # print elapsed times (us) 17 # -f # follow children as they are forked 18 # -l # force printing of pid/lwpid per line 19 # -o # print on cpu times (us) 20 # -s # print stack backtraces 21 # -L # don't print pid/lwpid per line 22 # -b bufsize # dynamic variable buf size (default is "4m") 23 # eg, 24 # dtruss df -h # run and examine the "df -h" command 25 # dtruss -p 1871 # examine PID 1871 26 # dtruss -n tar # examine all processes called "tar" 27 # dtruss -f test.sh # run test.sh and follow children 28 # 29 # See the man page dtruss(1M) for further details. 30 # 31 # SEE ALSO: procsystime # DTraceToolkit 32 # dapptrace # DTraceToolkit 33 # truss 34 # 35 # COPYRIGHT: Copyright (c) 2005, 2006, 2007 Brendan Gregg. 36 # 37 # CDDL HEADER START 38 # 39 # The contents of this file are subject to the terms of the 40 # Common Development and Distribution License, Version 1.0 only 41 # (the "License"). You may not use this file except in compliance 42 # with the License. 43 # 44 # You can obtain a copy of the license at Docs/cddl1.txt 45 # or http://www.opensolaris.org/os/licensing. 46 # See the License for the specific language governing permissions 47 # and limitations under the License. 48 # 49 # CDDL HEADER END 50 # 51 # TODO: Track signals, more output formatting. 52 # 53 # 29-Apr-2005 Brendan Gregg Created this. 54 # 09-May-2005 " " Fixed evaltime (thanks Adam L.) 55 # 16-May-2005 " " Added -t syscall tracing. 56 # 17-Jun-2005 " " Added -s stack backtraces. 57 # 17-Jun-2005 " " Last update. 58 # 29-Jun-2007 " " Used progenyof() (thanks Aaron Gutman). 59 # 06-Aug-2007 " " Various updates. 60 # 61 62 63 ############################## 64 # --- Process Arguments --- 65 # 66 67 ### Default variables 68 opt_pid=0; opt_name=0; pid=0; pname="."; opt_elapsed=0; opt_cpu=0 69 opt_counts=0; opt_relative=0; opt_printid=0; opt_follow=0; opt_command=0 70 command=""; opt_buf=0; buf="4m"; opt_trace=0; trace="."; opt_stack=0 71 72 ### Process options 73 while getopts ab:cdefhln:op:st:L name 74 do 75 case $name in 76 b) opt_buf=1; buf=$OPTARG ;; 77 p) opt_pid=1; pid=$OPTARG ;; 78 n) opt_name=1; pname=$OPTARG ;; 79 t) opt_trace=1; trace=$OPTARG ;; 80 a) opt_counts=1; opt_relative=1; opt_elapsed=1; opt_follow=1 81 opt_printid=1; opt_cpu=1 ;; 82 c) opt_counts=1 ;; 83 d) opt_relative=1 ;; 84 e) opt_elapsed=1 ;; 85 f) opt_follow=1 ;; 86 l) opt_printid=1 ;; 87 o) opt_cpu=1 ;; 88 L) opt_printid=-1 ;; 89 s) opt_stack=-1 ;; 90 h|?) cat <<-END >&2 91 USAGE: dtruss [-acdefholLs] [-t syscall] { -p PID | -n name | command } 92 93 -p PID # examine this PID 94 -n name # examine this process name 95 -t syscall # examine this syscall only 96 -a # print all details 97 -c # print syscall counts 98 -d # print relative times (us) 99 -e # print elapsed times (us) 100 -f # follow children (-p or cmd only) 101 -l # force printing pid/lwpid 102 -o # print on cpu times 103 -s # print stack backtraces 104 -L # don't print pid/lwpid 105 -b bufsize # dynamic variable buf size 106 eg, 107 dtruss df -h # run and examine "df -h" 108 dtruss -p 1871 # examine PID 1871 109 dtruss -n tar # examine all processes called "tar" 110 dtruss -f test.sh # run test.sh and follow children 111 END 112 exit 1 113 esac 114 done 115 shift `expr $OPTIND - 1` 116 117 ### Option logic 118 if [ $opt_pid -eq 0 -a $opt_name -eq 0 ]; then 119 opt_command=1 120 if [ "$*" = "" ]; then 121 $0 -h 122 exit 123 fi 124 command="$*" # yes, I meant $*! 125 fi 126 if [ $opt_follow -eq 1 -o $opt_name -eq 1 ]; then 127 if [ $opt_printid -ne -1 ]; then 128 opt_printid=1 129 else 130 opt_printid=0 131 fi 132 fi 133 if [ $opt_follow -eq 1 -a $opt_name -eq 1 ]; then 134 echo "ERROR: -f option cannot be used with -n (use -p or cmd instead)." 135 exit 1 136 fi 137 138 ### Option translation 139 if [ "$trace" = "exec" ]; then trace="exece"; fi 140 if [ "$trace" = "time" ]; then trace="gtime"; fi 141 if [ "$trace" = "exit" ]; then trace="rexit"; fi 142 143 144 ################################# 145 # --- Main Program, DTrace --- 146 # 147 148 ### Define D Script 149 dtrace=' 150 #pragma D option quiet 151 #pragma D option switchrate=10 152 153 /* 154 * Command line arguments 155 */ 156 inline int OPT_command = '$opt_command'; 157 inline int OPT_follow = '$opt_follow'; 158 inline int OPT_printid = '$opt_printid'; 159 inline int OPT_relative = '$opt_relative'; 160 inline int OPT_elapsed = '$opt_elapsed'; 161 inline int OPT_cpu = '$opt_cpu'; 162 inline int OPT_counts = '$opt_counts'; 163 inline int OPT_pid = '$opt_pid'; 164 inline int OPT_name = '$opt_name'; 165 inline int OPT_trace = '$opt_trace'; 166 inline int OPT_stack = '$opt_stack'; 167 inline string NAME = "'$pname'"; 168 inline string TRACE = "'$trace'"; 169 170 dtrace:::BEGIN 171 { 172 /* print header */ 173 OPT_printid ? printf("%-9s ", "PID/LWP") : 1; 174 OPT_relative ? printf("%8s ", "RELATIVE") : 1; 175 OPT_elapsed ? printf("%7s ", "ELAPSD") : 1; 176 OPT_cpu ? printf("%6s ", "CPU") : 1; 177 printf("SYSCALL(args) \t\t = return\n"); 178 } 179 180 /* 181 * Save syscall entry info 182 */ 183 syscall:::entry 184 /((OPT_command || OPT_pid) && pid == $target) || 185 (OPT_name && execname == NAME) || 186 (OPT_follow && progenyof($target))/ 187 { 188 /* set start details */ 189 self->start = timestamp; 190 self->vstart = vtimestamp; 191 self->arg0 = arg0; 192 self->arg1 = arg1; 193 self->arg2 = arg2; 194 195 /* count occurances */ 196 OPT_counts == 1 ? @Counts[probefunc] = count() : 1; 197 } 198 199 /* 200 * Follow children 201 */ 202 syscall::fork*:return 203 /(OPT_follow && progenyof($target)) && (!OPT_trace || (TRACE == probefunc))/ 204 { 205 /* print output */ 206 self->code = errno == 0 ? "" : "Err#"; 207 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 208 OPT_relative ? printf("%8d: ", vtimestamp/1000) : 1; 209 OPT_elapsed ? printf("%7d: ", 0) : 1; 210 OPT_cpu ? printf("%6d ", 0) : 1; 211 printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, 212 self->arg0, self->arg1, self->arg2, (int)arg0, self->code, 213 (int)errno); 214 } 215 216 /* 217 * Check for syscall tracing 218 */ 219 syscall:::entry 220 /OPT_trace && probefunc != TRACE/ 221 { 222 /* drop info */ 223 self->start = 0; 224 self->vstart = 0; 225 self->arg0 = 0; 226 self->arg1 = 0; 227 self->arg2 = 0; 228 } 229 230 /* 231 * Print return data 232 */ 233 234 /* 235 * The following code is written in an intentionally repetative way. 236 * The first versions had no code redundancies, but performed badly during 237 * benchmarking. The priority here is speed, not cleverness. I know there 238 * are many obvious shortcuts to this code, I have tried them. This style has 239 * shown in benchmarks to be the fastest (fewest probes fired, fewest actions). 240 */ 241 242 /* print 3 args, return as hex */ 243 syscall::sigprocmask:return 244 /self->start/ 245 { 246 /* calculate elapsed time */ 247 this->elapsed = timestamp - self->start; 248 self->start = 0; 249 this->cpu = vtimestamp - self->vstart; 250 self->vstart = 0; 251 self->code = errno == 0 ? "" : "Err#"; 252 253 /* print optional fields */ 254 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 255 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 256 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 257 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 258 259 /* print main data */ 260 printf("%s(0x%X, 0x%X, 0x%X)\t\t = 0x%X %s%d\n", probefunc, 261 (int)self->arg0, self->arg1, self->arg2, (int)arg0, 262 self->code, (int)errno); 263 OPT_stack ? ustack() : 1; 264 OPT_stack ? trace("\n") : 1; 265 self->arg0 = 0; 266 self->arg1 = 0; 267 self->arg2 = 0; 268 } 269 270 /* print 3 args, arg0 as a string */ 271 syscall::access*:return, 272 syscall::stat*:return, 273 syscall::lstat*:return, 274 syscall::readlink*:return, 275 syscall::open*:return 276 /self->start/ 277 { 278 /* calculate elapsed time */ 279 this->elapsed = timestamp - self->start; 280 self->start = 0; 281 this->cpu = vtimestamp - self->vstart; 282 self->vstart = 0; 283 self->code = errno == 0 ? "" : "Err#"; 284 285 /* print optional fields */ 286 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 287 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 288 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 289 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 290 291 /* print main data */ 292 printf("%s(\"%S\", 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, 293 copyinstr(self->arg0), self->arg1, self->arg2, (int)arg0, 294 self->code, (int)errno); 295 OPT_stack ? ustack() : 1; 296 OPT_stack ? trace("\n") : 1; 297 self->arg0 = 0; 298 self->arg1 = 0; 299 self->arg2 = 0; 300 } 301 302 /* print 3 args, arg1 as a string */ 303 syscall::write:return, 304 syscall::pwrite:return, 305 syscall::*read*:return 306 /self->start/ 307 { 308 /* calculate elapsed time */ 309 this->elapsed = timestamp - self->start; 310 self->start = 0; 311 this->cpu = vtimestamp - self->vstart; 312 self->vstart = 0; 313 self->code = errno == 0 ? "" : "Err#"; 314 315 /* print optional fields */ 316 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 317 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 318 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 319 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 320 321 /* print main data */ 322 printf("%s(0x%X, \"%S\", 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0, 323 stringof(copyin(self->arg1, self->arg2)), self->arg2, (int)arg0, 324 self->code, (int)errno); 325 OPT_stack ? ustack() : 1; 326 OPT_stack ? trace("\n") : 1; 327 self->arg0 = 0; 328 self->arg1 = 0; 329 self->arg2 = 0; 330 } 331 332 /* print 0 arg output */ 333 syscall::*fork*:return 334 /self->start/ 335 { 336 /* calculate elapsed time */ 337 this->elapsed = timestamp - self->start; 338 self->start = 0; 339 this->cpu = vtimestamp - self->vstart; 340 self->vstart = 0; 341 self->code = errno == 0 ? "" : "Err#"; 342 343 /* print optional fields */ 344 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 345 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 346 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 347 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 348 349 /* print main data */ 350 printf("%s()\t\t = %d %s%d\n", probefunc, 351 (int)arg0, self->code, (int)errno); 352 OPT_stack ? ustack() : 1; 353 OPT_stack ? trace("\n") : 1; 354 self->arg0 = 0; 355 self->arg1 = 0; 356 self->arg2 = 0; 357 } 358 359 /* print 1 arg output */ 360 syscall::close:return 361 /self->start/ 362 { 363 /* calculate elapsed time */ 364 this->elapsed = timestamp - self->start; 365 self->start = 0; 366 this->cpu = vtimestamp - self->vstart; 367 self->vstart = 0; 368 self->code = errno == 0 ? "" : "Err#"; 369 370 /* print optional fields */ 371 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 372 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 373 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 374 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 375 376 /* print main data */ 377 printf("%s(0x%X)\t\t = %d %s%d\n", probefunc, self->arg0, 378 (int)arg0, self->code, (int)errno); 379 OPT_stack ? ustack() : 1; 380 OPT_stack ? trace("\n") : 1; 381 self->arg0 = 0; 382 self->arg1 = 0; 383 self->arg2 = 0; 384 } 385 386 /* print 2 arg output */ 387 syscall::utimes:return, 388 syscall::munmap:return 389 /self->start/ 390 { 391 /* calculate elapsed time */ 392 this->elapsed = timestamp - self->start; 393 self->start = 0; 394 this->cpu = vtimestamp - self->vstart; 395 self->vstart = 0; 396 self->code = errno == 0 ? "" : "Err#"; 397 398 /* print optional fields */ 399 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 400 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 401 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 402 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 403 404 /* print main data */ 405 printf("%s(0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0, 406 self->arg1, (int)arg0, self->code, (int)errno); 407 OPT_stack ? ustack() : 1; 408 OPT_stack ? trace("\n") : 1; 409 self->arg0 = 0; 410 self->arg1 = 0; 411 self->arg2 = 0; 412 } 413 414 /* print 3 arg output - default */ 415 syscall:::return 416 /self->start/ 417 { 418 /* calculate elapsed time */ 419 this->elapsed = timestamp - self->start; 420 self->start = 0; 421 this->cpu = vtimestamp - self->vstart; 422 self->vstart = 0; 423 self->code = errno == 0 ? "" : "Err#"; 424 425 /* print optional fields */ 426 OPT_printid ? printf("%6d/%d: ", pid, tid) : 1; 427 OPT_relative ? printf("%8d ", vtimestamp/1000) : 1; 428 OPT_elapsed ? printf("%7d ", this->elapsed/1000) : 1; 429 OPT_cpu ? printf("%6d ", this->cpu/1000) : 1; 430 431 /* print main data */ 432 printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n", probefunc, self->arg0, 433 self->arg1, self->arg2, (int)arg0, self->code, (int)errno); 434 OPT_stack ? ustack() : 1; 435 OPT_stack ? trace("\n") : 1; 436 self->arg0 = 0; 437 self->arg1 = 0; 438 self->arg2 = 0; 439 } 440 441 /* program exited */ 442 proc:::exit 443 /(OPT_command || OPT_pid) && pid == $target/ 444 { 445 exit(0); 446 } 447 448 /* print counts */ 449 dtrace:::END 450 { 451 OPT_counts == 1 ? printf("\n%-32s %16s\n", "CALL", "COUNT") : 1; 452 OPT_counts == 1 ? printa("%-32s %@16d\n", @Counts) : 1; 453 } 454 ' 455 456 ### Run DTrace 457 if [ $opt_command -eq 1 ]; then 458 /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ 459 -c "$command" >&2 460 elif [ $opt_pid -eq 1 ]; then 461 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -p "$pid" >&2 462 else 463 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" >&2 464 fi 465
Indexes created Tue May 05 00:25:04 UTC 2026