1#!/bin/sh 2# #!/usr/bin/sh 3# 4# dtruss - print process system call time details. 5# Written using DTrace (Solaris 10 3/05). 6# 7# 17-Jun-2005, ver 0.80 (check for newer versions) 8# 9# USAGE: dtruss [-acdeflhoLs] [-t syscall] { -p PID | -n name | command } 10# 11# -p PID # examine this PID 12# -n name # examine this process name 13# -t syscall # examine this syscall only 14# -a # print all details 15# -c # print system call counts 16# -d # print relative timestamps (us) 17# -e # print elapsed times (us) 18# -f # follow children as they are forked 19# -l # force printing of pid/lwpid per line 20# -o # print on cpu times (us) 21# -s # print stack backtraces 22# -L # don't print pid/lwpid per line 23# -b bufsize # dynamic variable buf size (default is "4m") 24# eg, 25# dtruss df -h # run and examine the "df -h" command 26# dtruss -p 1871 # examine PID 1871 27# dtruss -n tar # examine all processes called "tar" 28# dtruss -f test.sh # run test.sh and follow children 29# 30# The elapsed times are interesting, to help identify syscalls that take 31# some time to complete (during which the process may have context 32# switched off the CPU). 33# 34# SEE ALSO: procsystime # DTraceToolkit 35# dapptrace # DTraceToolkit 36# truss 37# 38# COPYRIGHT: Copyright (c) 2005 Brendan Gregg. 39# 40# CDDL HEADER START 41# 42# The contents of this file are subject to the terms of the 43# Common Development and Distribution License, Version 1.0 only 44# (the "License"). You may not use this file except in compliance 45# with the License. 46# 47# You can obtain a copy of the license at Docs/cddl1.txt 48# or http://www.opensolaris.org/os/licensing. 49# See the License for the specific language governing permissions 50# and limitations under the License. 51# 52# CDDL HEADER END 53# 54# Author: Brendan Gregg [Sydney, Australia] 55# 56# TODO: Track signals, more output formatting. 57# 58# 29-Apr-2005 Brendan Gregg Created this. 59# 09-May-2005 " " Fixed evaltime (thanks Adam L.) 60# 16-May-2005 " " Added -t syscall tracing. 61# 17-Jun-2005 " " Added -s stack backtraces. 62# 63 64 65############################## 66# --- Process Arguments --- 67# 68 69### Default variables 70opt_pid=0; opt_name=0; pid=0; pname="." 71opt_elapsed=0; opt_cpu=0; opt_counts=0; 72opt_relative=0; opt_printid=0; opt_follow=0 73opt_command=0; command=""; opt_buf=0; buf="4m" 74opt_trace=0; trace="."; opt_stack=0; 75 76### Process options 77while getopts ab:cdefhln:op:st:L name 78do 79 case $name in 80 b) opt_buf=1; buf=$OPTARG ;; 81 p) opt_pid=1; pid=$OPTARG ;; 82 n) opt_name=1; pname=$OPTARG ;; 83 t) opt_trace=1; trace=$OPTARG ;; 84 a) opt_counts=1; opt_relative=1; opt_elapsed=1; opt_follow=1 85 opt_printid=1; opt_cpu=1 ;; 86 c) opt_counts=1 ;; 87 d) opt_relative=1 ;; 88 e) opt_elapsed=1 ;; 89 f) opt_follow=1 ;; 90 l) opt_printid=1 ;; 91 o) opt_cpu=1 ;; 92 L) opt_printid=-1 ;; 93 s) opt_stack=-1 ;; 94 h|?) cat <<-END >&2 95 USAGE: dtruss [-acdefholLs] [-t syscall] { -p PID | -n name | command } 96 97 -p PID # examine this PID 98 -n name # examine this process name 99 -t syscall # examine this syscall only 100 -a # print all details 101 -c # print syscall counts 102 -d # print relative times (us) 103 -e # print elapsed times (us) 104 -f # follow children 105 -l # force printing pid/lwpid 106 -o # print on cpu times 107 -s # print stack backtraces 108 -L # don't print pid/lwpid 109 -b bufsize # dynamic variable buf size 110 eg, 111 dtruss df -h # run and examine "df -h" 112 dtruss -p 1871 # examine PID 1871 113 dtruss -n tar # examine all processes called "tar" 114 dtruss -f test.sh # run test.sh and follow children 115 END 116 exit 1 117 esac 118done 119shift `expr $OPTIND - 1` 120 121### Option logic 122if [ $opt_pid -eq 0 -a $opt_name -eq 0 ]; then 123 opt_command=1 124 if [ "$*" = "" ]; then 125 $0 -h 126 exit 127 fi 128 command="$*" # yes, I meant $*! 129fi 130if [ $opt_follow -eq 1 -o $opt_name -eq 1 ]; then 131 if [ $opt_printid -ne -1 ]; then 132 opt_printid=1 133 else 134 opt_printid=0 135 fi 136fi 137 138### Option translation 139## if [ "$trace" = "exec" ]; then trace="exece"; fi 140if [ "$trace" = "exec" ]; then trace="execve"; fi 141 142 143################################# 144# --- Main Program, DTrace --- 145# 146 147### Define D Script 148dtrace=' 149 #pragma D option quiet 150 151 /* 152 * Command line arguments 153 */ 154 inline int OPT_command = '$opt_command'; 155 inline int OPT_follow = '$opt_follow'; 156 inline int OPT_printid = '$opt_printid'; 157 inline int OPT_relative = '$opt_relative'; 158 inline int OPT_elapsed = '$opt_elapsed'; 159 inline int OPT_cpu = '$opt_cpu'; 160 inline int OPT_counts = '$opt_counts'; 161 inline int OPT_pid = '$opt_pid'; 162 inline int OPT_name = '$opt_name'; 163 inline int OPT_trace = '$opt_trace'; 164 inline int OPT_stack = '$opt_stack'; 165 inline int PID = '$pid'; 166 inline string NAME = "'$pname'"; 167 inline string TRACE = "'$trace'"; 168 169 dtrace:::BEGIN 170 { 171 /* print header */ 172 /* OPT_printid ? printf("%-8s ","PID/LWP") : 1; */ 173 OPT_printid ? printf("\t%-8s ","PID/THRD") : 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 /* globals */ 180 trackedpid[pid] = 0; 181 self->child = 0; 182 this->type = 0; 183 } 184 185 /* 186 * Save syscall entry info 187 */ 188 189 /* MacOS X: notice first appearance of child from fork. Its parent 190 fires syscall::*fork:return in the ususal way (see below) */ 191 syscall:::entry 192 /OPT_follow && trackedpid[ppid] == -1 && 0 == self->child/ 193 { 194 /* set as child */ 195 self->child = 1; 196 197 /* print output */ 198 self->code = errno == 0 ? "" : "Err#"; 199 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 200 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 201 OPT_relative ? printf("%8d: ",vtimestamp/1000) : 1; 202 OPT_elapsed ? printf("%7d: ",0) : 1; 203 OPT_cpu ? printf("%6d ",0) : 1; 204 printf("%s()\t\t = %d %s%d\n","fork", 205 0,self->code,(int)errno); 206 } 207 208 /* MacOS X: notice first appearance of child and parent from vfork */ 209 syscall:::entry 210 /OPT_follow && trackedpid[ppid] > 0 && 0 == self->child/ 211 { 212 /* set as child */ 213 this->vforking_tid = trackedpid[ppid]; 214 self->child = (this->vforking_tid == tid) ? 0 : 1; 215 216 /* print output */ 217 self->code = errno == 0 ? "" : "Err#"; 218 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 219 OPT_printid ? printf("%5d/0x%x: ",(this->vforking_tid == tid) ? ppid : pid,tid) : 1; 220 OPT_relative ? printf("%8d: ",vtimestamp/1000) : 1; 221 OPT_elapsed ? printf("%7d: ",0) : 1; 222 OPT_cpu ? printf("%6d ",0) : 1; 223 printf("%s()\t\t = %d %s%d\n","vfork", 224 (this->vforking_tid == tid) ? pid : 0,self->code,(int)errno); 225 } 226 227 syscall:::entry 228 /(OPT_command && pid == $target) || 229 (OPT_pid && pid == PID) || 230 (OPT_name && NAME == strstr(NAME, execname)) || 231 (OPT_name && execname == strstr(execname, NAME)) || 232 (self->child)/ 233 { 234 /* set start details */ 235 self->start = timestamp; 236 self->vstart = vtimestamp; 237 self->arg0 = arg0; 238 self->arg1 = arg1; 239 self->arg2 = arg2; 240 241 /* count occurances */ 242 OPT_counts == 1 ? @Counts[probefunc] = count() : 1; 243 } 244 245/* 5 and 6 arguments */ 246 syscall::select:entry, 247 syscall::mmap:entry, 248 syscall::pwrite:entry, 249 syscall::pread:entry 250 /(OPT_command && pid == $target) || 251 (OPT_pid && pid == PID) || 252 (OPT_name && NAME == strstr(NAME, execname)) || 253 (OPT_name && execname == strstr(execname, NAME)) || 254 (self->child)/ 255 { 256 self->arg3 = arg3; 257 self->arg4 = arg4; 258 self->arg5 = arg5; 259 } 260 261 /* 262 * Follow children 263 */ 264 syscall::fork:entry 265 /OPT_follow && self->start/ 266 { 267 /* track this parent process */ 268 trackedpid[pid] = -1; 269 } 270 271 syscall::vfork:entry 272 /OPT_follow && self->start/ 273 { 274 /* track this parent process */ 275 trackedpid[pid] = tid; 276 } 277 278 /* syscall::rexit:entry */ 279 syscall::exit:entry 280 { 281 /* forget child */ 282 self->child = 0; 283 trackedpid[pid] = 0; 284 } 285 286 /* 287 * Check for syscall tracing 288 */ 289 syscall:::entry 290 /OPT_trace && probefunc != TRACE/ 291 { 292 /* drop info */ 293 self->start = 0; 294 self->vstart = 0; 295 self->arg0 = 0; 296 self->arg1 = 0; 297 self->arg2 = 0; 298 self->arg3 = 0; 299 self->arg4 = 0; 300 self->arg5 = 0; 301 } 302 303 /* 304 * Print return data 305 */ 306 307 /* 308 * NOTE: 309 * The following code is written in an intentionally repetetive way. 310 * The first versions had no code redundancies, but performed badly during 311 * benchmarking. The priority here is speed, not cleverness. I know there 312 * are many obvious shortcuts to this code, Ive tried them. This style has 313 * shown in benchmarks to be the fastest (fewest probes, fewest actions). 314 */ 315 316 /* print 3 args, return as hex */ 317 syscall::sigprocmask:return 318 /self->start/ 319 { 320 /* calculate elapsed time */ 321 this->elapsed = timestamp - self->start; 322 self->start = 0; 323 this->cpu = vtimestamp - self->vstart; 324 self->vstart = 0; 325 self->code = errno == 0 ? "" : "Err#"; 326 327 /* print optional fields */ 328 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 329 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 330 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 331 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 332 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 333 334 /* print main data */ 335 printf("%s(0x%X, 0x%X, 0x%X)\t\t = 0x%X %s%d\n",probefunc, 336 (int)self->arg0,self->arg1,self->arg2,(int)arg0, 337 self->code,(int)errno); 338 OPT_stack ? ustack() : 1; 339 OPT_stack ? trace("\n") : 1; 340 self->arg0 = 0; 341 self->arg1 = 0; 342 self->arg2 = 0; 343 } 344 345 /* print 3 args, arg0 as a string */ 346 syscall::execve:return, 347 syscall::stat:return, 348 syscall::stat64:return, 349 syscall::lstat:return, 350 syscall::lstat64:return, 351 syscall::access:return, 352 syscall::mkdir:return, 353 syscall::chdir:return, 354 syscall::chroot:return, 355 syscall::getattrlist:return, /* XXX 5 arguments */ 356 syscall::chown:return, 357 syscall::lchown:return, 358 syscall::chflags:return, 359 syscall::readlink:return, 360 syscall::utimes:return, 361 syscall::pathconf:return, 362 syscall::truncate:return, 363 syscall::getxattr:return, 364 syscall::setxattr:return, 365 syscall::removexattr:return, 366 syscall::unlink:return, 367 syscall::open:return, 368 syscall::open_nocancel:return 369 /self->start/ 370 { 371 /* calculate elapsed time */ 372 this->elapsed = timestamp - self->start; 373 self->start = 0; 374 this->cpu = vtimestamp - self->vstart; 375 self->vstart = 0; 376 self->code = errno == 0 ? "" : "Err#"; 377 378 /* print optional fields */ 379 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 380 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 381 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 382 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 383 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 384 385 /* print main data */ 386 printf("%s(\"%S\", 0x%X, 0x%X)\t\t = %d %s%d\n",probefunc, 387 copyinstr(self->arg0),self->arg1,self->arg2,(int)arg0, 388 self->code,(int)errno); 389 OPT_stack ? ustack() : 1; 390 OPT_stack ? trace("\n") : 1; 391 self->arg0 = 0; 392 self->arg1 = 0; 393 self->arg2 = 0; 394 } 395 396 /* print 3 args, arg1 as a string */ 397 syscall::write:return, 398 syscall::write_nocancel:return, 399 syscall::read:return, 400 syscall::read_nocancel:return 401 /self->start/ 402 { 403 /* calculate elapsed time */ 404 this->elapsed = timestamp - self->start; 405 self->start = 0; 406 this->cpu = vtimestamp - self->vstart; 407 self->vstart = 0; 408 self->code = errno == 0 ? "" : "Err#"; 409 410 /* print optional fields */ 411 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 412 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 413 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 414 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 415 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 416 417 /* print main data */ 418 printf("%s(0x%X, \"%S\", 0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 419 arg0 == -1 ? "" : stringof(copyin(self->arg1,arg0)),self->arg2,(int)arg0, 420 self->code,(int)errno); 421 OPT_stack ? ustack() : 1; 422 OPT_stack ? trace("\n") : 1; 423 self->arg0 = 0; 424 self->arg1 = 0; 425 self->arg2 = 0; 426 } 427 428 /* print 2 args, arg0 and arg1 as strings */ 429 syscall::rename:return, 430 syscall::symlink:return, 431 syscall::link:return 432 /self->start/ 433 { 434 /* calculate elapsed time */ 435 this->elapsed = timestamp - self->start; 436 self->start = 0; 437 this->cpu = vtimestamp - self->vstart; 438 self->vstart = 0; 439 self->code = errno == 0 ? "" : "Err#"; 440 441 /* print optional fields */ 442 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 443 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 444 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 445 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 446 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 447 448 /* print main data */ 449 printf("%s(\"%S\", \"%S\")\t\t = %d %s%d\n",probefunc, 450 copyinstr(self->arg0), copyinstr(self->arg1), 451 (int)arg0,self->code,(int)errno); 452 OPT_stack ? ustack() : 1; 453 OPT_stack ? trace("\n") : 1; 454 self->arg0 = 0; 455 self->arg1 = 0; 456 self->arg2 = 0; 457 } 458 459 /* print 0 arg output */ 460 syscall::*fork:return 461 /self->start/ 462 { 463 /* calculate elapsed time */ 464 this->elapsed = timestamp - self->start; 465 self->start = 0; 466 this->cpu = vtimestamp - self->vstart; 467 self->vstart = 0; 468 self->code = errno == 0 ? "" : "Err#"; 469 470 /* print optional fields */ 471 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 472 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 473 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 474 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 475 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 476 477 /* print main data */ 478 printf("%s()\t\t = %d %s%d\n",probefunc, 479 (int)arg0,self->code,(int)errno); 480 OPT_stack ? ustack() : 1; 481 OPT_stack ? trace("\n") : 1; 482 self->arg0 = 0; 483 self->arg1 = 0; 484 self->arg2 = 0; 485 } 486 487 /* print 1 arg output */ 488 syscall::close:return, 489 syscall::close_nocancel:return 490 /self->start/ 491 { 492 /* calculate elapsed time */ 493 this->elapsed = timestamp - self->start; 494 self->start = 0; 495 this->cpu = vtimestamp - self->vstart; 496 self->vstart = 0; 497 self->code = errno == 0 ? "" : "Err#"; 498 499 /* print optional fields */ 500 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 501 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 502 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 503 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 504 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 505 506 /* print main data */ 507 printf("%s(0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 508 (int)arg0,self->code,(int)errno); 509 OPT_stack ? ustack() : 1; 510 OPT_stack ? trace("\n") : 1; 511 self->arg0 = 0; 512 self->arg1 = 0; 513 self->arg2 = 0; 514 } 515 516 /* print 2 arg output */ 517 syscall::utimes:return, 518 syscall::munmap:return 519 /self->start/ 520 { 521 /* calculate elapsed time */ 522 this->elapsed = timestamp - self->start; 523 self->start = 0; 524 this->cpu = vtimestamp - self->vstart; 525 self->vstart = 0; 526 self->code = errno == 0 ? "" : "Err#"; 527 528 /* print optional fields */ 529 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 530 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 531 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 532 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 533 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 534 535 /* print main data */ 536 printf("%s(0x%X, 0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 537 self->arg1,(int)arg0,self->code,(int)errno); 538 OPT_stack ? ustack() : 1; 539 OPT_stack ? trace("\n") : 1; 540 self->arg0 = 0; 541 self->arg1 = 0; 542 self->arg2 = 0; 543 } 544 545 /* print pread/pwrite with 4 arguments */ 546 syscall::pread*:return, 547 syscall::pwrite*:return 548 /self->start/ 549 { 550 /* calculate elapsed time */ 551 this->elapsed = timestamp - self->start; 552 self->start = 0; 553 this->cpu = vtimestamp - self->vstart; 554 self->vstart = 0; 555 self->code = errno == 0 ? "" : "Err#"; 556 557 /* print optional fields */ 558 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 559 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 560 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 561 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 562 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 563 564 /* print main data */ 565 printf("%s(0x%X, \"%S\", 0x%X, 0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 566 stringof(copyin(self->arg1,self->arg2)),self->arg2,self->arg3,(int)arg0,self->code,(int)errno); 567 OPT_stack ? ustack() : 1; 568 OPT_stack ? trace("\n") : 1; 569 self->arg0 = 0; 570 self->arg1 = 0; 571 self->arg2 = 0; 572 self->arg3 = 0; 573 } 574 575 /* print select with 5 arguments */ 576 syscall::select:return 577 /self->start/ 578 { 579 /* calculate elapsed time */ 580 this->elapsed = timestamp - self->start; 581 self->start = 0; 582 this->cpu = vtimestamp - self->vstart; 583 self->vstart = 0; 584 self->code = errno == 0 ? "" : "Err#"; 585 586 /* print optional fields */ 587 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 588 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 589 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 590 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 591 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 592 593 /* print main data */ 594 printf("%s(0x%X, 0x%X, 0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 595 self->arg1,self->arg2,self->arg3,self->arg4,(int)arg0,self->code,(int)errno); 596 OPT_stack ? ustack() : 1; 597 OPT_stack ? trace("\n") : 1; 598 self->arg0 = 0; 599 self->arg1 = 0; 600 self->arg2 = 0; 601 self->arg3 = 0; 602 self->arg4 = 0; 603 } 604 605 /* mmap has 6 arguments */ 606 syscall::mmap:return 607 /self->start/ 608 { 609 /* calculate elapsed time */ 610 this->elapsed = timestamp - self->start; 611 self->start = 0; 612 this->cpu = vtimestamp - self->vstart; 613 self->vstart = 0; 614 self->code = errno == 0 ? "" : "Err#"; 615 616 /* print optional fields */ 617 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 618 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 619 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 620 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 621 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 622 623 /* print main data */ 624 printf("%s(0x%X, 0x%X, 0x%X, 0x%X, 0x%X, 0x%X)\t\t = 0x%X %s%d\n",probefunc,self->arg0, 625 self->arg1,self->arg2,self->arg3,self->arg4,self->arg5, arg0,self->code,(int)errno); 626 OPT_stack ? ustack() : 1; 627 OPT_stack ? trace("\n") : 1; 628 self->arg0 = 0; 629 self->arg1 = 0; 630 self->arg2 = 0; 631 self->arg3 = 0; 632 self->arg4 = 0; 633 self->arg5 = 0; 634 } 635 636 /* print 3 arg output - default */ 637 syscall:::return 638 /self->start/ 639 { 640 /* calculate elapsed time */ 641 this->elapsed = timestamp - self->start; 642 self->start = 0; 643 this->cpu = vtimestamp - self->vstart; 644 self->vstart = 0; 645 self->code = errno == 0 ? "" : "Err#"; 646 647 /* print optional fields */ 648 /* OPT_printid ? printf("%5d/%d: ",pid,tid) : 1; */ 649 OPT_printid ? printf("%5d/0x%x: ",pid,tid) : 1; 650 OPT_relative ? printf("%8d ",vtimestamp/1000) : 1; 651 OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1; 652 OPT_cpu ? printf("%6d ",this->cpu/1000) : 1; 653 654 /* print main data */ 655 printf("%s(0x%X, 0x%X, 0x%X)\t\t = %d %s%d\n",probefunc,self->arg0, 656 self->arg1,self->arg2,(int)arg0,self->code,(int)errno); 657 OPT_stack ? ustack() : 1; 658 OPT_stack ? trace("\n") : 1; 659 self->arg0 = 0; 660 self->arg1 = 0; 661 self->arg2 = 0; 662 } 663 664 /* print counts */ 665 dtrace:::END 666 { 667 OPT_counts == 1 ? printf("\n%-32s %16s\n","CALL","COUNT") : 1; 668 OPT_counts == 1 ? printa("%-32s %@16d\n",@Counts) : 1; 669 } 670' 671 672### Run DTrace 673#if [ $opt_command -eq 1 ]; then 674# /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ 675# -c "$command" >&2 676#else 677# /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" >&2 678#fi 679 680### Run DTrace (Mac OS X) 681# Redirect the output to /dev/stderr so that it doesn't mingle with 682# data going to the target's stdout 683if [ $opt_command -eq 1 ]; then 684 /usr/sbin/dtrace -x dynvarsize=$buf -x evaltime=exec -n "$dtrace" \ 685 -c "$command" -o /dev/stderr 686else 687 /usr/sbin/dtrace -x dynvarsize=$buf -n "$dtrace" -o /dev/stderr 688fi 689