cddl/contrib/dtracetoolkit/Examples/php_syscolors_example.txt

   1 The following are examples of php_syscolors.d.
   2
   3 This is a simple script to trace the flow of PHP functions and system
   4 calls made, and renders the output in color ("colour") using terminal
   5 escape sequences (which you can tweak by modifying the script).
   6
   7 Here it traces the example program, Code/Php/func_abc.php.
   8
   9 WARNING: This output is full of terminal escape sequences, so if you are
  10 trying to view this through an editor or web browser - it may look awful.
  11 Try viewing this using "more" (although, depending on your terminal, it
  12 still may look awful).
  13
  14 # php_syscolors.d
  15 C    PID/TID   DELTA(us)              FILE:LINE TYPE     -- NAME
  16 \e[2;35m0  18426/1             8      func_abc.php:22   func     -> func_a\e[0m
  17 \e[2;35m0  18426/1            41      func_abc.php:18   func       -> sleep\e[0m
  18 \e[2;32m0  18426/1            15                 ":-    syscall      -> nanosleep\e[0m
  19 \e[2;32m0  18426/1       1008700                 ":-    syscall      <- nanosleep\e[0m
  20 \e[2;35m0  18426/1            30      func_abc.php:18   func       <- sleep\e[0m
  21 \e[2;35m0  18426/1            42      func_abc.php:19   func       -> func_b\e[0m
  22 \e[2;35m0  18426/1            28      func_abc.php:11   func         -> sleep\e[0m
  23 \e[2;32m0  18426/1            14                 ":-    syscall        -> nanosleep\e[0m
  24 \e[2;32m0  18426/1       1010083                 ":-    syscall        <- nanosleep\e[0m
  25 \e[2;35m0  18426/1            29      func_abc.php:11   func         <- sleep\e[0m
  26 \e[2;35m0  18426/1            43      func_abc.php:12   func         -> func_c\e[0m
  27 \e[2;35m0  18426/1            28      func_abc.php:5    func           -> sleep\e[0m
  28 \e[2;32m0  18426/1            14                 ":-    syscall          -> nanosleep\e[0m
  29 \e[2;32m0  18426/1       1009794                 ":-    syscall          <- nanosleep\e[0m
  30 \e[2;35m0  18426/1            28      func_abc.php:5    func           <- sleep\e[0m
  31 \e[2;35m0  18426/1            34      func_abc.php:6    func         <- func_c\e[0m
  32 \e[2;35m0  18426/1            18      func_abc.php:13   func       <- func_b\e[0m
  33 \e[2;35m0  18426/1            17      func_abc.php:20   func     <- func_a\e[0m
  34 \e[2;32m0  18426/1            21                 ":-    syscall  -> fchdir\e[0m
  35 \e[2;32m0  18426/1            19                 ":-    syscall  <- fchdir\e[0m
  36 \e[2;32m0  18426/1             9                 ":-    syscall  -> close\e[0m
  37 \e[2;32m0  18426/1            13                 ":-    syscall  <- close\e[0m
  38 \e[2;32m0  18426/1            35                 ":-    syscall  -> semsys\e[0m
  39 \e[2;32m0  18426/1            12                 ":-    syscall  <- semsys\e[0m
  40 \e[2;32m0  18426/1             7                 ":-    syscall  -> semsys\e[0m
  41 \e[2;32m0  18426/1             7                 ":-    syscall  <- semsys\e[0m
  42 \e[2;32m0  18426/1            66                 ":-    syscall  -> setitimer\e[0m
  43 \e[2;32m0  18426/1             8                 ":-    syscall  <- setitimer\e[0m
  44 \e[2;32m0  18426/1            39                 ":-    syscall  -> read\e[0m
  45 \e[2;32m0  18426/1            14                 ":-    syscall  <- read\e[0m
  46 \e[2;32m0  18426/1            11                 ":-    syscall  -> writev\e[0m
  47 \e[2;32m0  18426/1            22                 ":-    syscall  <- writev\e[0m
  48 \e[2;32m0  18426/1            23                 ":-    syscall  -> write\e[0m
  49 \e[2;32m0  18426/1           110                 ":-    syscall  <- write\e[0m
  50 \e[2;32m0  18426/1            61                 ":-    syscall  -> pollsys\e[0m
  51
  52 In this excerpt:
  53 \e[2;35m0  18426/1            43      func_abc.php:12   func         -> func_c\e[0m
  54 \e[2;35m0  18426/1            28      func_abc.php:5    func           -> sleep\e[0m
  55 \e[2;32m0  18426/1            14                 ":-    syscall          -> nanosleep\e[0m
  56 \e[2;32m0  18426/1       1009794                 ":-    syscall          <- nanosleep\e[0m
  57 \e[2;35m0  18426/1            28      func_abc.php:5    func           <- sleep\e[0m
  58 \e[2;35m0  18426/1            34      func_abc.php:6    func         <- func_c\e[0m
  59
  60 we can see that we are at Line 12 of the program which invokes func_c.  func_c
  61 then invokes sleep, which uses the syscall nanosleep.  Approximately one
  62 second later nanosleep returns, then sleep finishes, then func_c finishes.
  63