Before making use of DTrace functionality, the DTrace device must exist. To load the device, issue the following command:
# kldload dtraceall
DTrace support should now be available. To view all probes the administrator may now execute the following command:
# dtrace -l | more
All output is passed to the more utility as it will quickly overflow the screen buffer. At this point, DTrace should be considered working. It is now time to review the toolkit.
The toolkit is a collection of ready-made scripts to run with DTrace to collect system information. There are scripts to check open files, memory, CPU usage and a lot more. Extract the scripts with the following command:
# gunzip -c DTraceToolkit* | tar xvf -
Change into that directory with the cd and change the execution permissions on all files, designated as those files with lower case names, to 755.
All of these scripts will need modifications to their contents. The ones which refer to /usr/bin/ksh need that changed to /usr/local/bin/ksh, the others which use /usr/bin/sh need to be altered to use /bin/sh, and finally the ones which use /usr/bin/perl will need altered to use /usr/local/bin/perl.
Important: At this point it is prudent to remind the reader that DTrace support in FreeBSD is incomplete and experimental. Many of these scripts will not work as they are either too Solaris™-specific or use probes which are unsupported at this time.
At the time of this writing only two of the scripts of the DTrace Toolkit are fully supported in FreeBSD: the hotkernel and procsystime scripts. These are the two we will explore in the following parts of this section.
The hotkernel is designed to identify which function is using the most kernel time. Run normally, it will produce output similar to the following:
# cd /usr/share/dtrace/toolkit # ./hotkernel Sampling... Hit Ctrl-C to end.
The system administrator must use the Ctrl+C key combination to stop the process. Upon termination, the script will display a list of kernel functions and timing information, sorting the output in increasing order of time:
kernel`_thread_lock_flags 2 0.0% 0xc1097063 2 0.0% kernel`sched_userret 2 0.0% kernel`kern_select 2 0.0% kernel`generic_copyin 3 0.0% kernel`_mtx_assert 3 0.0% kernel`vm_fault 3 0.0% kernel`sopoll_generic 3 0.0% kernel`fixup_filename 4 0.0% kernel`_isitmyx 4 0.0% kernel`find_instance 4 0.0% kernel`_mtx_unlock_flags 5 0.0% kernel`syscall 5 0.0% kernel`DELAY 5 0.0% 0xc108a253 6 0.0% kernel`witness_lock 7 0.0% kernel`read_aux_data_no_wait 7 0.0% kernel`Xint0x80_syscall 7 0.0% kernel`witness_checkorder 7 0.0% kernel`sse2_pagezero 8 0.0% kernel`strncmp 9 0.0% kernel`spinlock_exit 10 0.0% kernel`_mtx_lock_flags 11 0.0% kernel`witness_unlock 15 0.0% kernel`sched_idletd 137 0.3% 0xc10981a5 42139 99.3%
This script will also work with kernel modules. To use this feature, run the script
with the -m flag:
# ./hotkernel -m Sampling... Hit Ctrl-C to end. ^C MODULE COUNT PCNT 0xc107882e 1 0.0% 0xc10e6aa4 1 0.0% 0xc1076983 1 0.0% 0xc109708a 1 0.0% 0xc1075a5d 1 0.0% 0xc1077325 1 0.0% 0xc108a245 1 0.0% 0xc107730d 1 0.0% 0xc1097063 2 0.0% 0xc108a253 73 0.0% kernel 874 0.4% 0xc10981a5 213781 99.6%
The procsystime script captures and prints the system call time usage for a given PID or process name. In the following example, a new instance of /bin/csh was spawned. The procsystime was executed and remained waiting while a few commands were typed on the other incarnation of csh. These are the results of this test:
# ./procsystime -n csh
Tracing... Hit Ctrl-C to end...
^C
Elapsed Times for processes csh,
SYSCALL TIME (ns)
getpid 6131
sigreturn 8121
close 19127
fcntl 19959
dup 26955
setpgid 28070
stat 31899
setitimer 40938
wait4 62717
sigaction 67372
sigprocmask 119091
gettimeofday 183710
write 263242
execve 492547
ioctl 770073
vfork 3258923
sigsuspend 6985124
read 3988049784
As shown, the read() system call seems to use the most
time in nanoseconds with the getpid() system call used the
least amount of time.