xref: /netbsd-src/external/cddl/dtracetoolkit/dist/Docs/Examples/sh_flow_example.txt (revision c29d51755812ace2e87aeefdb06cb2b4dac7087a)
1The following are examples of sh_flow.d.
2
3This is a simple script to trace the flow of Bourne shell functions,
4builtins and external commands. Here it traces the example program,
5Code/Shell/func_abc.sh.
6
7   # sh_flow.d
8     C TIME(us)         FILE             -- NAME
9     0 3060274370505    func_abc.sh      -> func_a
10     0 3060274370529    func_abc.sh        > echo
11     0 3060274372742    func_abc.sh        | sleep
12     0 3060275381634    func_abc.sh        -> func_b
13     0 3060275381660    func_abc.sh          > echo
14     0 3060275383852    func_abc.sh          | sleep
15     0 3060276391653    func_abc.sh          -> func_c
16     0 3060276391679    func_abc.sh            > echo
17     0 3060276393671    func_abc.sh            | sleep
18     0 3060277401753    func_abc.sh          <- func_c
19     0 3060277401767    func_abc.sh        <- func_b
20     0 3060277401775    func_abc.sh      <- func_a
21   ^C
22
23As each function is entered, the third column is indented by 2 spaces. This
24shows which function is calling who - the output abovebegins by showing that
25func_a() began, and then called func_b().
26
27If the output looks shuffled, check the CPU "C" and "TIME" columns, and
28post sort based on TIME if necessary.
29
30See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
31
32
33
34The following traces the firefox startup script.
35
36# sh_flow.d
37  C TIME(us)         FILE             -- NAME
38  0 3060321598138    firefox          > test
39  0 3060321603730    firefox          > [
40  0 3060321603796    firefox          > cd
41  0 3060321603878    firefox          > [
42  0 3060321603900    firefox          > [
43  0 3060321604099    firefox          > [
44  0 3060321609050    firefox          > echo
45  0 3060321620601    firefox          > echo
46  0 3060321626369    firefox          > [
47  0 3060321626432    firefox          > export
48  0 3060321626459    firefox          -> moz_pis_startstop_scripts
49  0 3060321626519    firefox            > export
50  0 3060321626966    firefox            > [
51  0 3060321627031    firefox            > .
52  0 3060321628446    firefox            -> moz_spc_verbose_echo
53  0 3060321628458    firefox              > :
54  0 3060321628467    firefox            <- moz_spc_verbose_echo
55  0 3060321636461    firefox            > [
56  0 3060321636738    firefox            -> moz_spc_verbose_echo
57  0 3060321636751    firefox              > :
58  0 3060321636760    firefox            <- moz_spc_verbose_echo
59  0 3060321636778    firefox            > [
60  0 3060321636793    firefox            > [
61  0 3060321636817    firefox            > [
62  0 3060321637126    firefox            -> moz_spc_verbose_echo
63  0 3060321637136    firefox              > :
64  0 3060321637143    firefox            <- moz_spc_verbose_echo
65  0 3060321666922    firefox            -> moz_spc_verbose_echo
66  0 3060321666952    firefox              > :
67  0 3060321666964    firefox            <- moz_spc_verbose_echo
68  0 3060321674929    firefox          > [
69  0 3060321680246    firefox            > [
70  0 3060321680312    firefox            -> moz_spc_verbose_echo
71  0 3060321680323    firefox              > :
72  0 3060321680331    firefox            <- moz_spc_verbose_echo
73  0 3060321680356    firefox            -> moz_spc_verbose_echo
74  0 3060321680363    firefox              > :
75  0 3060321680370    firefox            <- moz_spc_verbose_echo
76  0 3060321680396    firefox            > [
77  0 3060321680428    firefox          <- moz_pis_startstop_scripts
78  0 3060321680525    firefox          > [
79  0 3060321680580    firefox          > [
80  0 3060321685358    firefox          | /usr/lib/firefox/run-mozilla.sh
81  0 3060321700731    run-mozilla.sh   > [
82  0 3060321700950    run-mozilla.sh   > break
83  0 3060321703259    run-mozilla.sh   > [
84  0 3060321703292    run-mozilla.sh   > shift
85  0 3060321703382    run-mozilla.sh   > [
86  0 3060321703421    run-mozilla.sh   > [
87  0 3060321703493    run-mozilla.sh   > [
88  0 3060321703642    run-mozilla.sh   > [
89  0 3060321703669    run-mozilla.sh   > export
90  0 3060321703706    run-mozilla.sh   > [
91  0 3060321703725    run-mozilla.sh   > [
92  0 3060321703857    run-mozilla.sh   > [
93  0 3060321703880    run-mozilla.sh   > export
94  0 3060321703925    run-mozilla.sh   > export
95  0 3060321703954    run-mozilla.sh   > [
96  0 3060321703982    run-mozilla.sh   -> moz_run_program
97  0 3060321704013    run-mozilla.sh     > [
98  0 3060321704049    run-mozilla.sh     -> moz_test_binary
99  0 3060321704065    run-mozilla.sh       > [
100  0 3060321704097    run-mozilla.sh       > [
101  0 3060321704127    run-mozilla.sh       > return
102  0 3060321704137    run-mozilla.sh     <- moz_test_binary
103  0 3060321704151    run-mozilla.sh     > [
104  0 3060321709953    run-mozilla.sh   > type
105  0 3060321724260    run-mozilla.sh     > [
106  0 3060321724559    run-mozilla.sh     > [
107  0 3060321724574    run-mozilla.sh     > [
108  0 3060321727396    run-mozilla.sh     | /usr/lib/firefox/firefox-bin
109  0 3060325513871    run-mozilla.sh     > [
110  0 3060325513898    run-mozilla.sh     > [
111  0 3060325513929    run-mozilla.sh     > [
112  0 3060325513940    run-mozilla.sh   <- moz_run_program
113  0 3060325513967    run-mozilla.sh   > exit
114  0 3060325515113    firefox          -> moz_pis_startstop_scripts
115  0 3060325515189    firefox            > export
116  0 3060325515431    firefox            > [
117  0 3060325515466    firefox            > [
118  0 3060325515487    firefox          <- moz_pis_startstop_scripts
119  0 3060325515503    firefox          > exit
120
121This shows the flow, incluing the handover between the "firefox" script
122and the "run-mozilla.sh" script.
123
124There is a point in the output where flow appears to reverse (at time
1253060321709953, with the entry "> type"). This is due to another instance
126of the run-mozilla.sh script running, which is indistinguishable from
127the other lines in the output. To confirm this for yourself, add a PID
128column to the flow script (or use sh_flowinfo.d).
129
130