Home | History | Annotate | Line # | Download | only in Examples 
      1  1.1  christos The following are examples of sh_cpudist.d.
      2  1.1  christos 
      3  1.1  christos This script traces the on-CPU time of Bourne shell functions and
      4  1.1  christos prints a report containing distribution plots per function. Here it
      5  1.1  christos traces the example program, Code/Shell/func_slow.sh.
      6  1.1  christos 
      7  1.1  christos    # sh_cpudist.d
      8  1.1  christos    Tracing... Hit Ctrl-C to end.
      9  1.1  christos    ^C
     10  1.1  christos    
     11  1.1  christos    On-CPU times (us),
     12  1.1  christos    
     13  1.1  christos       func_slow.sh, builtin, echo 
     14  1.1  christos               value  ------------- Distribution ------------- count    
     15  1.1  christos                   8 |                                         0        
     16  1.1  christos                  16 |@@@@@@@@@@@@@                            1        
     17  1.1  christos                  32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@              2        
     18  1.1  christos                  64 |                                         0        
     19  1.1  christos    
     20  1.1  christos       func_slow.sh, builtin, [ 
     21  1.1  christos               value  ------------- Distribution ------------- count    
     22  1.1  christos                   0 |                                         0        
     23  1.1  christos                   1 |                                         1        
     24  1.1  christos                   2 |                                         1        
     25  1.1  christos                   4 |@                                        22       
     26  1.1  christos                   8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   575      
     27  1.1  christos                  16 |                                         2        
     28  1.1  christos                  32 |                                         0        
     29  1.1  christos                  64 |                                         2        
     30  1.1  christos                 128 |                                         0        
     31  1.1  christos    
     32  1.1  christos    Exclusive function on-CPU times (us),
     33  1.1  christos    
     34  1.1  christos       func_slow.sh, func, func_a 
     35  1.1  christos               value  ------------- Distribution ------------- count    
     36  1.1  christos               65536 |                                         0        
     37  1.1  christos              131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     38  1.1  christos              262144 |                                         0        
     39  1.1  christos    
     40  1.1  christos       func_slow.sh, func, func_b 
     41  1.1  christos               value  ------------- Distribution ------------- count    
     42  1.1  christos              262144 |                                         0        
     43  1.1  christos              524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     44  1.1  christos             1048576 |                                         0        
     45  1.1  christos    
     46  1.1  christos       func_slow.sh, func, func_c 
     47  1.1  christos               value  ------------- Distribution ------------- count    
     48  1.1  christos              524288 |                                         0        
     49  1.1  christos             1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     50  1.1  christos             2097152 |                                         0        
     51  1.1  christos    
     52  1.1  christos    Inclusive function on-CPU times (us),
     53  1.1  christos    
     54  1.1  christos       func_slow.sh, func, func_b 
     55  1.1  christos               value  ------------- Distribution ------------- count    
     56  1.1  christos              524288 |                                         0        
     57  1.1  christos             1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     58  1.1  christos             2097152 |                                         0        
     59  1.1  christos    
     60  1.1  christos       func_slow.sh, func, func_c 
     61  1.1  christos               value  ------------- Distribution ------------- count    
     62  1.1  christos              524288 |                                         0        
     63  1.1  christos             1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     64  1.1  christos             2097152 |                                         0        
     65  1.1  christos    
     66  1.1  christos       func_slow.sh, func, func_a 
     67  1.1  christos               value  ------------- Distribution ------------- count    
     68  1.1  christos             1048576 |                                         0        
     69  1.1  christos             2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
     70  1.1  christos             4194304 |                                         0        
     71  1.1  christos 
     72  1.1  christos The on-CPU times should that the "[" builtin (test) usually took between 
     73  1.1  christos 8 and 15 microseconds to execute, and was called over 500 times.
     74  1.1  christos 
     75  1.1  christos The exclusive function on-CPU times show that func_a() spent between
     76  1.1  christos 131 ms and 262 ms on-CPU.
     77  1.1  christos 
     78  1.1  christos The inclusive function on-CPU times show that both func_b() and func_c()
     79  1.1  christos spent between 1.0 and 2.1 seconds on-CPU, and func_a() spent between 2.1
     80  1.1  christos and 4.2 seconds on-CPU. This inclusive time includes the time spent in other
     81  1.1  christos functions called, and since func_a() called func_b() which called func_c(),
     82  1.1  christos these times make sense.
     83  1.1  christos 
     84  1.1  christos These on-CPU times are the time the thread spent running on a CPU, from when
     85  1.1  christos the function began to when it completed. This does not include time 
     86  1.1  christos spent off-CPU time such as sleeping for I/O or waiting for scheduling.
     87  1.1  christos 
     88  1.1  christos On-CPU times are useful for showing who is causing the CPUs to be busy.
     89  1.1  christos See Notes/ALLoncpu_notes.txt for more details. Also see
     90  1.1  christos Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a
     91  1.1  christos detailed explanation of exclusive vs inclusive function time.
     92  1.1  christos 
     93