Home | History | Annotate | Line # | Download | only in Examples
      1 Following are examples of running tcl_cputime.d.
      2 
      3 Here it runs while we execute Code/Tcl/func_slow.tcl
      4 
      5 # tcl_cputime.d
      6 Tracing... Hit Ctrl-C to end.
      7 ^C
      8 
      9 Top 10 counts,
     10       PID TYPE       NAME                                                COUNT
     11     16038 cmd        set                                                     2
     12     16038 cmd        namespace                                               3
     13     16038 cmd        puts                                                    3
     14     16038 cmd        lappend                                                 4
     15     16038 cmd        lsearch                                                 4
     16     16038 cmd        if                                                      8
     17     16038 cmd        info                                                   11
     18     16038 cmd        file                                                   12
     19     16038 cmd        proc                                                   12
     20         0 total      -                                                      82
     21 
     22 Top 10 exclusive on-CPU times (us),
     23       PID TYPE       NAME                                                TOTAL
     24     16038 cmd        namespace                                             130
     25     16038 cmd        puts                                                  232
     26     16038 cmd        if                                                    310
     27     16038 cmd        tclInit                                               315
     28     16038 cmd        file                                                  411
     29     16038 cmd        source                                                760
     30     16038 proc       func_a                                             535521
     31     16038 proc       func_b                                            1071082
     32     16038 proc       func_c                                            1619323
     33         0 total      -                                                 3228670
     34 
     35 Top 10 inclusive on-CPU times (us),
     36       PID TYPE       NAME                                                TOTAL
     37     16038 cmd        source                                               1359
     38     16038 cmd        uplevel                                              1367
     39     16038 proc       tclInit                                              1865
     40     16038 cmd        tclInit                                              2180
     41     16038 proc       func_c                                            1619360
     42     16038 cmd        func_c                                            1619404
     43     16038 proc       func_b                                            2690525
     44     16038 cmd        func_b                                            2690568
     45     16038 proc       func_a                                            3226247
     46     16038 cmd        func_a                                            3226275
     47 
     48 We can see that the output is in three sections.  The first section represents
     49 the ten most commonly executed commands while the script is tracing.
     50 
     51 The exclusive function on-CPU times show that func_a spent around 0.5 seconds
     52 on-CPU, func_b spent about 1.0 seconds, and func_c, 1.6 seconds. This excludes
     53 time spent in other procedures or commands.
     54 
     55 The inclusive function on-CPU times show the time spent by these procedures in
     56 total, including the time spent in other functions called, and since func_a
     57 called func_b which called func_c, these times make sense.
     58 
     59 These on-CPU times are the time the thread spent running on a CPU, from when
     60 the function began to when it completed. This does not include time
     61 spent off-CPU time such as sleeping for I/O or waiting for scheduling.
     62 
     63 On-CPU times are useful for showing who is causing the CPUs to be busy.
     64 See Notes/ALLoncpu_notes.txt for more details. Also see
     65 Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a
     66 detailed explanation of exclusive vs inclusive function time.
     67 
     68