The following are examples of tcl_cpudist.d.
This script traces the on-CPU time of Tcl commands and procedures and
prints a report containing distribution plots per subroutine. Here it
traces the example program, Code/Tcl/func_slow.tcl.
Tracing... Hit Ctrl-C to end.
^C
Top 10 exclusive on-CPU times (us),
PID=16043, cmd, info
value ------------- Distribution ------------- count
0 | 0
1 |@@@@ 1
2 |@@@@@@@@@@@@@@@ 4
4 |@@@@ 1
8 |@@@@ 1
16 |@@@@@@@@@@@ 3
32 |@@@@ 1
64 | 0
PID=16043, cmd, namespace
value ------------- Distribution ------------- count
0 | 0
1 |@@@@@@@@@@@@@ 1
2 |@@@@@@@@@@@@@ 1
4 | 0
8 | 0
16 | 0
32 | 0
64 | 0
128 |@@@@@@@@@@@@@ 1
256 | 0
PID=16043, cmd, puts
value ------------- Distribution ------------- count
16 | 0
32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2
64 | 0
128 |@@@@@@@@@@@@@ 1
256 | 0
PID=16043, cmd, if
value ------------- Distribution ------------- count
4 | 0
8 |@@@@@@@@@@ 2
16 |@@@@@@@@@@@@@@@@@@@@ 4
32 |@@@@@ 1
64 | 0
128 |@@@@@ 1
256 | 0
PID=16043, cmd, tclInit
value ------------- Distribution ------------- count
128 | 0
256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
512 | 0
PID=16043, cmd, file
value ------------- Distribution ------------- count
2 | 0
4 |@@@@@@@@@@@@@ 4
8 |@@@@@@@@@@@@@ 4
16 | 0
32 |@@@ 1
64 |@@@@@@@@@@ 3
128 | 0
PID=16043, cmd, source
value ------------- Distribution ------------- count
256 | 0
512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
1024 | 0
PID=16043, proc, func_a
value ------------- Distribution ------------- count
262144 | 0
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
1048576 | 0
PID=16043, proc, func_b
value ------------- Distribution ------------- count
524288 | 0
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2097152 | 0
PID=16043, proc, func_c
value ------------- Distribution ------------- count
524288 | 0
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2097152 | 0
Top 10 inclusive on-CPU times (us),
PID=16043, cmd, source
value ------------- Distribution ------------- count
512 | 0
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2048 | 0
PID=16043, cmd, uplevel
value ------------- Distribution ------------- count
512 | 0
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2048 | 0
PID=16043, proc, tclInit
value ------------- Distribution ------------- count
512 | 0
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2048 | 0
PID=16043, cmd, tclInit
value ------------- Distribution ------------- count
1024 | 0
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
4096 | 0
PID=16043, cmd, func_c
value ------------- Distribution ------------- count
524288 | 0
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2097152 | 0
PID=16043, proc, func_c
value ------------- Distribution ------------- count
524288 | 0
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
2097152 | 0
PID=16043, cmd, func_a
value ------------- Distribution ------------- count
1048576 | 0
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
4194304 | 0
PID=16043, cmd, func_b
value ------------- Distribution ------------- count
1048576 | 0
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
4194304 | 0
PID=16043, proc, func_a
value ------------- Distribution ------------- count
1048576 | 0
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
4194304 | 0
PID=16043, proc, func_b
value ------------- Distribution ------------- count
1048576 | 0
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
4194304 | 0
These on-CPU times are the time the thread spent running on a CPU, from when
the subroutine 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
detailed explanation of exclusive vs inclusive subroutine time.