mirror of
https://github.com/Stichting-MINIX-Research-Foundation/netbsd.git
synced 2025-09-10 23:56:52 -04:00
167 lines
8.2 KiB
Plaintext
167 lines
8.2 KiB
Plaintext
The following are examples of tcl_calldist.d.
|
|
|
|
This script traces the elapsed time of Tcl procedures and commands and
|
|
prints a report containing distribution plots per function. Here it traces the
|
|
example program, Code/Tcl/func_abc.tcl
|
|
|
|
# tcl_calldist.d
|
|
Tracing... Hit Ctrl-C to end.
|
|
^C
|
|
|
|
Top 10 exclusive elapsed times (us),
|
|
PID=16033, cmd, namespace
|
|
value ------------- Distribution ------------- count
|
|
1 | 0
|
|
2 |@@@@@@@@@@@@@ 1
|
|
4 |@@@@@@@@@@@@@ 1
|
|
8 | 0
|
|
16 | 0
|
|
32 | 0
|
|
64 | 0
|
|
128 |@@@@@@@@@@@@@ 1
|
|
256 | 0
|
|
|
|
PID=16033, cmd, puts
|
|
value ------------- Distribution ------------- count
|
|
16 | 0
|
|
32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2
|
|
64 | 0
|
|
128 |@@@@@@@@@@@@@ 1
|
|
256 | 0
|
|
|
|
PID=16033, cmd, tclInit
|
|
value ------------- Distribution ------------- count
|
|
128 | 0
|
|
256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
512 | 0
|
|
|
|
PID=16033, proc, func_a
|
|
value ------------- Distribution ------------- count
|
|
128 | 0
|
|
256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
512 | 0
|
|
|
|
PID=16033, proc, func_b
|
|
value ------------- Distribution ------------- count
|
|
128 | 0
|
|
256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
512 | 0
|
|
|
|
PID=16033, proc, func_c
|
|
value ------------- Distribution ------------- count
|
|
128 | 0
|
|
256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
512 | 0
|
|
|
|
PID=16033, cmd, file
|
|
value ------------- Distribution ------------- count
|
|
2 | 0
|
|
4 |@@@@@@@@@@@@@ 4
|
|
8 |@@@@@@@ 2
|
|
16 |@@@@@@@ 2
|
|
32 |@@@ 1
|
|
64 |@@@@@@@@@@ 3
|
|
128 | 0
|
|
|
|
PID=16033, cmd, source
|
|
value ------------- Distribution ------------- count
|
|
256 | 0
|
|
512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
1024 | 0
|
|
|
|
PID=16033, cmd, if
|
|
value ------------- Distribution ------------- count
|
|
8 | 0
|
|
16 |@@@@@@@@@@@@@@@@@@@@ 4
|
|
32 |@@@@@@@@@@@@@@@ 3
|
|
64 | 0
|
|
128 | 0
|
|
256 | 0
|
|
512 |@@@@@ 1
|
|
1024 | 0
|
|
|
|
PID=16033, cmd, after
|
|
value ------------- Distribution ------------- count
|
|
262144 | 0
|
|
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3
|
|
1048576 | 0
|
|
|
|
|
|
Top 10 inclusive elapsed times (us),
|
|
PID=16033, cmd, uplevel
|
|
value ------------- Distribution ------------- count
|
|
512 | 0
|
|
1024 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
2048 | 0
|
|
|
|
PID=16033, cmd, tclInit
|
|
value ------------- Distribution ------------- count
|
|
1024 | 0
|
|
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
4096 | 0
|
|
|
|
PID=16033, proc, tclInit
|
|
value ------------- Distribution ------------- count
|
|
1024 | 0
|
|
2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
4096 | 0
|
|
|
|
PID=16033, cmd, func_c
|
|
value ------------- Distribution ------------- count
|
|
262144 | 0
|
|
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
1048576 | 0
|
|
|
|
PID=16033, proc, func_c
|
|
value ------------- Distribution ------------- count
|
|
262144 | 0
|
|
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
1048576 | 0
|
|
|
|
PID=16033, cmd, func_b
|
|
value ------------- Distribution ------------- count
|
|
524288 | 0
|
|
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
2097152 | 0
|
|
|
|
PID=16033, proc, func_b
|
|
value ------------- Distribution ------------- count
|
|
524288 | 0
|
|
1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
2097152 | 0
|
|
|
|
PID=16033, cmd, after
|
|
value ------------- Distribution ------------- count
|
|
262144 | 0
|
|
524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3
|
|
1048576 | 0
|
|
|
|
PID=16033, cmd, func_a
|
|
value ------------- Distribution ------------- count
|
|
1048576 | 0
|
|
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
4194304 | 0
|
|
|
|
PID=16033, proc, func_a
|
|
value ------------- Distribution ------------- count
|
|
1048576 | 0
|
|
2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
|
|
4194304 | 0
|
|
|
|
The exclusive function elapsed times show that each func_a took between 256
|
|
and 511 microseconds. This time excludes the time spent in any other functions.
|
|
|
|
The inclusive elapsed times section shows that each func_a spent
|
|
took between 2.1 and 4.2 seconds. This time also includes the time spent in
|
|
any other commands or procedures called by func_a.
|
|
|
|
These elapsed times are the absolute time from when the function began to
|
|
when it completed - which includes off-CPU time due to other system events
|
|
such as I/O, scheduling, interrupts, etc.
|
|
|
|
Elapsed times are useful for identifying where latencies are.
|
|
See Notes/ALLelapsed_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.
|
|
|