1 The following demonstrates the dtruss command - a DTrace version of truss. 2 This version is designed to be less intrusive and safer than running truss. 3 4 dtruss has many options. Here is the help for version 0.70, 5 6 USAGE: dtruss [-acdefholL] [-t syscall] { -p PID | -n name | command } 7 8 -p PID # examine this PID 9 -n name # examine this process name 10 -t syscall # examine this syscall only 11 -a # print all details 12 -c # print syscall counts 13 -d # print relative times (us) 14 -e # print elapsed times (us) 15 -f # follow children 16 -l # force printing pid/lwpid 17 -o # print on cpu times 18 -L # don't print pid/lwpid 19 -b bufsize # dynamic variable buf size 20 eg, 21 dtruss df -h # run and examine "df -h" 22 dtruss -p 1871 # examine PID 1871 23 dtruss -n tar # examine all processes called "tar" 24 dtruss -f test.sh # run test.sh and follow children 25 26 27 28 For example, here we dtruss any process with the name "ksh" - the Korn shell, 29 30 # dtruss -n ksh 31 PID/LWP SYSCALL(args) = return 32 27547/1: llseek(0x3F, 0xE4E, 0x0) = 3662 0 33 27547/1: read(0x3F, "\0", 0x400) = 0 0 34 27547/1: llseek(0x3F, 0x0, 0x0) = 3662 0 35 27547/1: write(0x3F, "ls -l\n\0", 0x8) = 8 0 36 27547/1: fdsync(0x3F, 0x10, 0xFEC1D444) = 0 0 37 27547/1: lwp_sigmask(0x3, 0x20000, 0x0) = 0xFFBFFEFF 0 38 27547/1: stat64("/usr/bin/ls\0", 0x8047A00, 0xFEC1D444) = 0 0 39 27547/1: lwp_sigmask(0x3, 0x0, 0x0) = 0xFFBFFEFF 0 40 [...] 41 42 The output for each system call does not yet evaluate as much as truss does. 43 44 45 46 In the following example, syscall elapsed and overhead times are measured. 47 Elapsed times represent the time from syscall start to finish; overhead 48 times measure the time spent on the CPU, 49 50 # dtruss -eon bash 51 PID/LWP ELAPSD CPU SYSCALL(args) = return 52 3911/1: 41 26 write(0x2, "l\0", 0x1) = 1 0 53 3911/1: 1001579 43 read(0x0, "s\0", 0x1) = 1 0 54 3911/1: 38 26 write(0x2, "s\0", 0x1) = 1 0 55 3911/1: 1019129 43 read(0x0, " \001\0", 0x1) = 1 0 56 3911/1: 38 26 write(0x2, " \0", 0x1) = 1 0 57 3911/1: 998533 43 read(0x0, "-\0", 0x1) = 1 0 58 3911/1: 38 26 write(0x2, "-\001\0", 0x1) = 1 0 59 3911/1: 1094323 42 read(0x0, "l\0", 0x1) = 1 0 60 3911/1: 39 27 write(0x2, "l\001\0", 0x1) = 1 0 61 3911/1: 1210496 44 read(0x0, "\r\0", 0x1) = 1 0 62 3911/1: 40 28 write(0x2, "\n\001\0", 0x1) = 1 0 63 3911/1: 9 1 lwp_sigmask(0x3, 0x2, 0x0) = 0xFFBFFEFF 0 64 3911/1: 70 63 ioctl(0x0, 0x540F, 0x80F6D00) = 0 0 65 66 A bash command was in another window, where the "ls -l" command was being 67 typed. The keystrokes can be seen above, along with the long elapsed times 68 (keystroke delays), and short overhead times (as the bash process blocks 69 on the read and leaves the CPU). 70 71 72 73 Now dtruss is put to the test. Here we truss a test program that runs several 74 hundred smaller programs, which in turn generate thousands of system calls. 75 76 First, as a "control" we run the program without a truss or dtruss running, 77 78 # time ./test 79 real 0m38.508s 80 user 0m5.299s 81 sys 0m25.668s 82 83 Now we try truss, 84 85 # time truss ./test 2> /dev/null 86 real 0m41.281s 87 user 0m0.558s 88 sys 0m1.351s 89 90 Now we try dtruss, 91 92 # time dtruss ./test 2> /dev/null 93 real 0m46.226s 94 user 0m6.771s 95 sys 0m31.703s 96 97 In the above test, truss slowed the program from 38 seconds to 41. dtruss 98 slowed the program from 38 seconds to 46, slightly slower that truss... 99 100 Now we try follow mode "-f". The test program does run several hundred 101 smaller programs, so now there are plenty more system calls to track, 102 103 # time truss -f ./test 2> /dev/null 104 real 2m28.317s 105 user 0m0.893s 106 sys 0m3.527s 107 108 Now we try dtruss, 109 110 # time dtruss -f ./test 2> /dev/null 111 real 0m56.179s 112 user 0m10.040s 113 sys 0m38.185s 114 115 Wow, the difference is huge! truss slows the program from 38 to 148 seconds; 116 but dtruss has only slowed the program from 38 to 56 seconds. 117 118 119 120 121
Indexes created Fri Apr 24 00:22:58 UTC 2026