The following are examples of sh_cpudist.d. This script traces the on-CPU time of Bourne shell functions and prints a report containing distribution plots per function. Here it traces the example program, Code/Shell/func_slow.sh. # sh_cpudist.d Tracing... Hit Ctrl-C to end. ^C On-CPU times (us), func_slow.sh, builtin, echo value ------------- Distribution ------------- count 8 | 0 16 |@@@@@@@@@@@@@ 1 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 64 | 0 func_slow.sh, builtin, [ value ------------- Distribution ------------- count 0 | 0 1 | 1 2 | 1 4 |@ 22 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 575 16 | 2 32 | 0 64 | 2 128 | 0 Exclusive function on-CPU times (us), func_slow.sh, func, func_a value ------------- Distribution ------------- count 65536 | 0 131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 262144 | 0 func_slow.sh, func, func_b value ------------- Distribution ------------- count 262144 | 0 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 1048576 | 0 func_slow.sh, func, func_c value ------------- Distribution ------------- count 524288 | 0 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 2097152 | 0 Inclusive function on-CPU times (us), func_slow.sh, func, func_b value ------------- Distribution ------------- count 524288 | 0 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 2097152 | 0 func_slow.sh, func, func_c value ------------- Distribution ------------- count 524288 | 0 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 2097152 | 0 func_slow.sh, func, func_a value ------------- Distribution ------------- count 1048576 | 0 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 4194304 | 0 The on-CPU times should that the "[" builtin (test) usually took between 8 and 15 microseconds to execute, and was called over 500 times. The exclusive function on-CPU times show that func_a() spent between 131 ms and 262 ms on-CPU. The inclusive function on-CPU times show that both func_b() and func_c() spent between 1.0 and 2.1 seconds on-CPU, and func_a() spent between 2.1 and 4.2 seconds on-CPU. 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. |