1The following are examples of php_calldist.d. 2 3This script traces the elapsed time of PHP functions and prints a report 4containing distribution plots per subroutine. Here it traces the example program 5Code/Php/func_abc.php. 6 7# php_calldist.d 8Tracing... Hit Ctrl-C to end. 9^C 10 11Exclusive function elapsed times (us), 12 func_abc.php, func, func_a 13 value ------------- Distribution ------------- count 14 128 | 0 15 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 16 512 | 0 17 18 func_abc.php, func, func_b 19 value ------------- Distribution ------------- count 20 128 | 0 21 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 22 512 | 0 23 24 func_abc.php, func, func_c 25 value ------------- Distribution ------------- count 26 128 | 0 27 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 28 512 | 0 29 30 func_abc.php, func, sleep 31 value ------------- Distribution ------------- count 32 262144 | 0 33 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 34 1048576 | 0 35 36 37Inclusive function elapsed times (us), 38 func_abc.php, func, func_c 39 value ------------- Distribution ------------- count 40 262144 | 0 41 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 42 1048576 | 0 43 44 func_abc.php, func, func_b 45 value ------------- Distribution ------------- count 46 524288 | 0 47 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 48 2097152 | 0 49 50 func_abc.php, func, sleep 51 value ------------- Distribution ------------- count 52 262144 | 0 53 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 54 1048576 | 0 55 56 func_abc.php, func, func_a 57 value ------------- Distribution ------------- count 58 1048576 | 0 59 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 60 4194304 | 0 61 62In total, 3 subroutines were called, one each of func_a(), func_b() and 63func_c(), and sleep was called 3 times. You can see this reflected in the 64"count" column on the right. 65 66The exclusive subroutine elapsed times show that each subroutine spent 67between 256 and 512 microseconds. This time excludes the time spent in 68other subroutines. 69 70The inclusive subroutine elapsed times show that func_c() took between 0.5 71seconds and 1 second, func_b() took between 1 second and 2.1 seconds, and 72func_a() took between 2.1 seconds and 4.2 seconds to execute. This time 73includes the time spent in other subroutines called, and since func_a() called 74func_b() which called func_c(), these times make sense. 75 76These elapsed times are the absolute time from when the subroutine began to 77when it completed - which includes off-CPU time due to other system events 78such as I/O, scheduling, interrupts, etc. 79 80Elapsed times are useful for identifying where latencies are. 81See Notes/ALLelapsed_notes.txt for more details. Also see 82Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a 83detailed explanation of exclusive vs inclusive subroutine time. 84 85