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:
# ./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
# ./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.