xref: /netbsd-src/external/cddl/dtracetoolkit/dist/Docs/Examples/php_flowinfo_example.txt (revision c29d51755812ace2e87aeefdb06cb2b4dac7087a)
1*c29d5175SchristosThe following are examples of php_flowinfo.d.
2*c29d5175Schristos
3*c29d5175SchristosThis is a simple script to trace the flow of PHP functions.
4*c29d5175SchristosHere it traces the example program, Code/Php/func_abc.php
5*c29d5175Schristos
6*c29d5175Schristos# php_flowinfo.d
7*c29d5175SchristosC    PID/TID   DELTA(us)              FILE:LINE TYPE     -- FUNC
8*c29d5175Schristos0  18422/1             9      func_abc.php:22   func     -> func_a
9*c29d5175Schristos0  18422/1            35      func_abc.php:18   func       -> sleep
10*c29d5175Schristos0  18422/1       1009146      func_abc.php:18   func       <- sleep
11*c29d5175Schristos0  18422/1            35      func_abc.php:19   func       -> func_b
12*c29d5175Schristos0  18422/1            24      func_abc.php:11   func         -> sleep
13*c29d5175Schristos0  18422/1       1009803      func_abc.php:11   func         <- sleep
14*c29d5175Schristos0  18422/1            34      func_abc.php:12   func         -> func_c
15*c29d5175Schristos0  18422/1            24      func_abc.php:5    func           -> sleep
16*c29d5175Schristos0  18422/1       1009953      func_abc.php:5    func           <- sleep
17*c29d5175Schristos0  18422/1            28      func_abc.php:6    func         <- func_c
18*c29d5175Schristos0  18422/1            11      func_abc.php:13   func       <- func_b
19*c29d5175Schristos0  18422/1            10      func_abc.php:20   func     <- func_a
20*c29d5175Schristos^C
21*c29d5175Schristos
22*c29d5175SchristosThe third column is indented by 2 spaces to show when a new function begins.
23*c29d5175SchristosThis shows which function is calling which - the output above begins by
24*c29d5175Schristosshowing that func_a() began; slept, and returned from sleep; and then called
25*c29d5175Schristosfunc_b().
26*c29d5175Schristos
27*c29d5175SchristosThe DELTA(us) column shows time from that line to the previous line, and
28*c29d5175Schristosso can be a bit tricky to read. For example, the second line of data output
29*c29d5175Schristos(skipping the header) reads as "the time from func_a() beginning to
30*c29d5175Schristoscalling the sleep function beginning was 35 microseconds".
31*c29d5175Schristos
32*c29d5175SchristosThe LINE column shows the line in the file what was being executed. Refer
33*c29d5175Schristosto the source program to see what this line refers to.
34*c29d5175Schristos
35*c29d5175SchristosIf the output looks shuffled, check the CPU "C" column - if it changes,
36*c29d5175Schristosthen the output is probably shuffled. See Notes/ALLsnoop_notes.txt for
37*c29d5175Schristosdetails and suggested workarounds.
38*c29d5175Schristos
39*c29d5175SchristosSee Notes/ALLflow_notes.txt for important notes about reading flow outputs.
40*c29d5175Schristos
41