1*e137d3e0SchristosThe following are examples of php_cputime.d.
2*e137d3e0Schristos
3*e137d3e0SchristosThis script traces the on-CPU time of PHP functions and prints a report.
4*e137d3e0SchristosHere it traces the example program, Code/Php/func_abc.php.
5*e137d3e0Schristos
6*e137d3e0Schristos# php_cputime.d
7*e137d3e0SchristosTracing... Hit Ctrl-C to end.
8*e137d3e0Schristos^C
9*e137d3e0Schristos
10*e137d3e0SchristosCount,
11*e137d3e0Schristos   FILE                 TYPE       NAME                                COUNT
12*e137d3e0Schristos   func_abc.php         func       func_a                                  1
13*e137d3e0Schristos   func_abc.php         func       func_b                                  1
14*e137d3e0Schristos   func_abc.php         func       func_c                                  1
15*e137d3e0Schristos   func_abc.php         func       sleep                                   3
16*e137d3e0Schristos   -                    total      -                                       6
17*e137d3e0Schristos
18*e137d3e0SchristosExclusive function on-CPU times (us),
19*e137d3e0Schristos   FILE                 TYPE       NAME                                TOTAL
20*e137d3e0Schristos   func_abc.php         func       func_c                                 17
21*e137d3e0Schristos   func_abc.php         func       func_b                                 25
22*e137d3e0Schristos   func_abc.php         func       func_a                                 74
23*e137d3e0Schristos   func_abc.php         func       sleep                                  93
24*e137d3e0Schristos   -                    total      -                                     210
25*e137d3e0Schristos
26*e137d3e0SchristosInclusive function on-CPU times (us),
27*e137d3e0Schristos   FILE                 TYPE       NAME                                TOTAL
28*e137d3e0Schristos   func_abc.php         func       func_c                                 39
29*e137d3e0Schristos   func_abc.php         func       func_b                                 87
30*e137d3e0Schristos   func_abc.php         func       sleep                                  93
31*e137d3e0Schristos   func_abc.php         func       func_a                                210
32*e137d3e0Schristos
33*e137d3e0SchristosIn total, six functions were called; sleep was called three times and there
34*e137d3e0Schristoswas one call each of func_a(), func_b() and func_c().
35*e137d3e0Schristos
36*e137d3e0SchristosThe exclusive subroutine on-CPU times show that func_a() spent around 74
37*e137d3e0Schristosmicroseconds on-CPU, func_b() spent 25 microseconds on-CPU, and func_c() spent
38*e137d3e0Schristos17 microseconds on-CPU. This exclusive times excludes time spent in other
39*e137d3e0Schristossubroutines.
40*e137d3e0Schristos
41*e137d3e0SchristosThe inclusive subroutine on-CPU times show that func_c() spent around 39
42*e137d3e0Schristosmicroseconds on-CPU, func_b() spent around 87 microseconds on-CPU and
43*e137d3e0Schristosfunc_a() spent around 210 microseconds. This inclusive time includes the time
44*e137d3e0Schristosspent in other functions called (including sleep),  and since func_a() called
45*e137d3e0Schristosfunc_b() which called func_c(), these times make perfect sense.
46*e137d3e0Schristos
47*e137d3e0SchristosThese on-CPU times are the time the program spent running on a CPU, from when
48*e137d3e0Schristosthe function began to when it completed. This does not include time
49*e137d3e0Schristosspent off-CPU time such as sleeping for I/O or waiting for scheduling.
50*e137d3e0Schristos
51*e137d3e0SchristosOn-CPU times are useful for showing who is causing the CPUs to be busy.
52*e137d3e0SchristosSee Notes/ALLoncpu_notes.txt for more details. Also see
53*e137d3e0SchristosNotes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a
54*e137d3e0Schristosdetailed explanation of exclusive vs inclusive subroutine time.
55*e137d3e0Schristos
56*e137d3e0SchristosIf you study the func_abc.php program alongside the above output, the numbers
57*e137d3e0Schristosshould make sense.
58*e137d3e0Schristos
59