The following are examples of sh_cputime.d. This script traces the on-CPU time of Bourne shell functions and prints a report. Here it traces the example program, Code/Shell/func_slow.sh. # sh_cputime.d Tracing... Hit Ctrl-C to end. ^C Counts, FILE TYPE NAME COUNT func_slow.sh func func_a 1 func_slow.sh func func_b 1 func_slow.sh func func_c 1 func_slow.sh builtin echo 3 func_slow.sh builtin [ 603 - total - 609 On-CPU times (us), FILE TYPE NAME TOTAL func_slow.sh builtin echo 162 func_slow.sh builtin [ 6279 - total - 6441 Exclusive function on-CPU times (us), FILE TYPE NAME TOTAL func_slow.sh func func_a 269465 func_slow.sh func func_b 670372 func_slow.sh func func_c 1259073 - total - 2198911 Inclusive function on-CPU times (us), FILE TYPE NAME TOTAL func_slow.sh func func_c 1262209 func_slow.sh func func_b 1934839 func_slow.sh func func_a 2205352 In total, three functions were called, one builtin and one command. The exclusive function on-CPU times show that func_a() spent around 268.4 ms on-CPU, func_b() spent 670.3 ms, and func_c() spent 1259 ms. This exclusive times excludes time spent in other functions. The inclusive function on-CPU times show that func_c() spent around 1.3 seconds on-CPU, func_b() spent around 1.9 seconds, and func_a() spent around 2.2 seconds. This inclusive time includes the time spent in other functions called, and since func_a() called func_b() which called func_c(), these times make sense. These on-CPU times are the time the thread spent running on a CPU, from when the function began to when it completed. This does not include time spent off-CPU time such as sleeping for I/O or waiting for scheduling. On-CPU times are useful for showing who is causing the CPUs to be busy. See Notes/ALLoncpu_notes.txt for more details. Also see Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a detailed explanation of exclusive vs inclusive function time. If you study the func_slow.sh program alongside the above output, the numbers should make sense. The following traced the firefox start script. # sh_cputime.d Tracing... Hit Ctrl-C to end. ^C Counts, FILE TYPE NAME COUNT firefox builtin break 1 firefox builtin pwd 1 firefox builtin test 1 firefox cmd run-mozilla.sh 1 run-mozilla.sh builtin break 1 run-mozilla.sh builtin return 1 run-mozilla.sh builtin shift 1 run-mozilla.sh builtin type 1 run-mozilla.sh cmd firefox-bin 1 run-mozilla.sh func moz_run_program 1 run-mozilla.sh func moz_test_binary 1 firefox builtin echo 2 firefox func moz_pis_startstop_scripts 2 firefox builtin cd 3 firefox builtin export 3 run-mozilla.sh builtin export 3 firefox builtin : 6 firefox func moz_spc_verbose_echo 6 firefox builtin [ 18 run-mozilla.sh builtin [ 20 - total - 103 On-CPU times (us), FILE TYPE NAME TOTAL run-mozilla.sh builtin return 0 run-mozilla.sh builtin shift 0 run-mozilla.sh builtin break 1 firefox builtin break 2 run-mozilla.sh builtin export 4 firefox builtin export 7 firefox builtin : 9 firefox builtin test 35 firefox builtin pwd 49 firefox builtin cd 64 run-mozilla.sh builtin [ 176 firefox builtin echo 309 firefox builtin [ 357 run-mozilla.sh builtin type 475 firefox cmd run-mozilla.sh 17090 run-mozilla.sh cmd firefox-bin 1932333 - total - 1950979 Exclusive function on-CPU times (us), FILE TYPE NAME TOTAL run-mozilla.sh func moz_test_binary 21 firefox func moz_spc_verbose_echo 22 run-mozilla.sh func moz_run_program 9098 firefox func moz_pis_startstop_scripts 12960 - total - 22103 Inclusive function on-CPU times (us), FILE TYPE NAME TOTAL firefox func moz_spc_verbose_echo 31 run-mozilla.sh func moz_test_binary 56 run-mozilla.sh func moz_run_program 9243 firefox func moz_pis_startstop_scripts 13133 The output showed that the most CPU time was spent in the firefox-bin command, taking 1.9 seconds of on-CPU time.