cddl/contrib/dtracetoolkit/Examples/sh_flow_example.txt

   1 The following are examples of sh_flow.d.
   2
   3 This is a simple script to trace the flow of Bourne shell functions,
   4 builtins and external commands. Here it traces the example program,
   5 Code/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
  23 As each function is entered, the third column is indented by 2 spaces. This
  24 shows which function is calling who - the output abovebegins by showing that
  25 func_a() began, and then called func_b().
  26
  27 If the output looks shuffled, check the CPU "C" and "TIME" columns, and
  28 post sort based on TIME if necessary.
  29
  30 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
  31
  32
  33
  34 The 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
 121 This shows the flow, incluing the handover between the "firefox" script
 122 and the "run-mozilla.sh" script.
 123
 124 There is a point in the output where flow appears to reverse (at time
 125 3060321709953, with the entry "> type"). This is due to another instance
 126 of the run-mozilla.sh script running, which is indistinguishable from
 127 the other lines in the output. To confirm this for yourself, add a PID
 128 column to the flow script (or use sh_flowinfo.d).
 129