1*c29d5175SchristosThe following are examples of php_cpudist.d. 2*c29d5175Schristos 3*c29d5175SchristosThis script traces the on-CPU time of PHP functions and prints a report 4*c29d5175Schristoscontaining distribution plots per subroutine. Here it traces the example 5*c29d5175Schristosprogram Code/Php/func_abc.php. 6*c29d5175Schristos 7*c29d5175Schristos# php_cpudist.d 8*c29d5175SchristosTracing... Hit Ctrl-C to end. 9*c29d5175Schristos^C 10*c29d5175Schristos 11*c29d5175SchristosExclusive function on-CPU times (us), 12*c29d5175Schristos func_abc.php, func, func_a 13*c29d5175Schristos value ------------- Distribution ------------- count 14*c29d5175Schristos 8 | 0 15*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 16*c29d5175Schristos 32 | 0 17*c29d5175Schristos 18*c29d5175Schristos func_abc.php, func, func_b 19*c29d5175Schristos value ------------- Distribution ------------- count 20*c29d5175Schristos 8 | 0 21*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 22*c29d5175Schristos 32 | 0 23*c29d5175Schristos 24*c29d5175Schristos func_abc.php, func, func_c 25*c29d5175Schristos value ------------- Distribution ------------- count 26*c29d5175Schristos 8 | 0 27*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 28*c29d5175Schristos 32 | 0 29*c29d5175Schristos 30*c29d5175Schristos func_abc.php, func, sleep 31*c29d5175Schristos value ------------- Distribution ------------- count 32*c29d5175Schristos 8 | 0 33*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 34*c29d5175Schristos 32 | 0 35*c29d5175Schristos 36*c29d5175Schristos 37*c29d5175SchristosInclusive function on-CPU times (us), 38*c29d5175Schristos func_abc.php, func, func_c 39*c29d5175Schristos value ------------- Distribution ------------- count 40*c29d5175Schristos 16 | 0 41*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 42*c29d5175Schristos 64 | 0 43*c29d5175Schristos 44*c29d5175Schristos func_abc.php, func, sleep 45*c29d5175Schristos value ------------- Distribution ------------- count 46*c29d5175Schristos 8 | 0 47*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 48*c29d5175Schristos 32 | 0 49*c29d5175Schristos 50*c29d5175Schristos func_abc.php, func, func_b 51*c29d5175Schristos value ------------- Distribution ------------- count 52*c29d5175Schristos 32 | 0 53*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 54*c29d5175Schristos 128 | 0 55*c29d5175Schristos 56*c29d5175Schristos func_abc.php, func, func_a 57*c29d5175Schristos value ------------- Distribution ------------- count 58*c29d5175Schristos 64 | 0 59*c29d5175Schristos 128 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 60*c29d5175Schristos 256 | 0 61*c29d5175Schristos 62*c29d5175SchristosIn total, 3 subroutines were called, one each of func_a(), func_b() and 63*c29d5175Schristosfunc_c(), and sleep was called 3 times. You can see this reflected in the 64*c29d5175Schristos"count" column on the right. 65*c29d5175Schristos 66*c29d5175SchristosThe exclusive subroutine elapsed times show that each subroutine spent 67*c29d5175Schristosbetween 16 and 31 microseconds on CPU. This time excludes the time spent in 68*c29d5175Schristosother subroutines. 69*c29d5175Schristos 70*c29d5175SchristosThe inclusive subroutine elapsed times show that func_c() took between 32 71*c29d5175Schristosmicroseconds and 63 microseconds on CPU; sleep ran three times and each time 72*c29d5175Schristostook between 16 and 31 microseconds on CPU; func_b() took between 64 and 127 73*c29d5175Schristosmicroseconds on CPU; and func_a() took between 128 and 255 microseconds on 74*c29d5175SchristosCPU. This time includes the time spent in other subroutines called, and since 75*c29d5175Schristosfunc_a() called func_b() which called func_c(), these times make sense. 76*c29d5175Schristos 77*c29d5175SchristosThese elapsed times are the on CPU time from when the subroutine began to 78*c29d5175Schristoswhen it completed. 79*c29d5175Schristos 80*c29d5175SchristosOn-CPU times are useful for showing who is causing the CPUs to be busy. 81*c29d5175SchristosSee Notes/ALLelapsed_notes.txt for more details. Also see 82*c29d5175SchristosNotes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a 83*c29d5175Schristosdetailed explanation of exclusive vs inclusive subroutine time. 84*c29d5175Schristos 85