Home | History | Annotate | Line # | Download | only in Examples 
      1 The following are examples of rb_flowtime.d.
      2 
      3 This is a simple script to trace the flow of Ruby methods.
      4 Here it traces the example program, Code/Ruby/func_abc.rb
      5 
      6 # rb_flowtime.d
      7   C TIME(us)         FILE             DELTA(us) -- CLASS::METHOD
      8   0 3066547402640    func_abc.rb              2 -> Module::method_added
      9   0 3066547402662    func_abc.rb             22 <- Module::method_added
     10   0 3066547402683    func_abc.rb             20 -> Module::method_added
     11   0 3066547402693    func_abc.rb              9 <- Module::method_added
     12   0 3066547402707    func_abc.rb             14 -> Module::method_added
     13   0 3066547402716    func_abc.rb              9 <- Module::method_added
     14   0 3066547402729    func_abc.rb             12 -> Object::func_a
     15   0 3066547402740    func_abc.rb             10   -> Object::print
     16   0 3066547402759    func_abc.rb             18     -> IO::write
     17   0 3066547402860    func_abc.rb            101     <- IO::write
     18   0 3066547402871    func_abc.rb             10   <- Object::print
     19   0 3066547402881    func_abc.rb             10   -> Object::sleep
     20   0 3066548410630    func_abc.rb        1007749   <- Object::sleep
     21   0 3066548410660    func_abc.rb             30   -> Object::func_b
     22   0 3066548410679    func_abc.rb             18     -> Object::print
     23   0 3066548410689    func_abc.rb             10       -> IO::write
     24   0 3066548410730    func_abc.rb             40       <- IO::write
     25   0 3066548410740    func_abc.rb              9     <- Object::print
     26   0 3066548410749    func_abc.rb              9     -> Object::sleep
     27   0 3066549420724    func_abc.rb        1009974     <- Object::sleep
     28   0 3066549420755    func_abc.rb             30     -> Object::func_c
     29   0 3066549420773    func_abc.rb             18       -> Object::print
     30   0 3066549420783    func_abc.rb             10         -> IO::write
     31   0 3066549420825    func_abc.rb             41         <- IO::write
     32   0 3066549420835    func_abc.rb              9       <- Object::print
     33   0 3066549420844    func_abc.rb              9       -> Object::sleep
     34   0 3066550430611    func_abc.rb        1009766       <- Object::sleep
     35   0 3066550430635    func_abc.rb             24     <- Object::func_c
     36   0 3066550430645    func_abc.rb             10   <- Object::func_b
     37   0 3066550430655    func_abc.rb              9 <- Object::func_a
     38 ^C
     39 
     40 The fifth column is indented by 2 spaces to show when a new method begins.
     41 This shows which method is calling which.
     42 
     43 The TIME(us) column shows time since boot.
     44 
     45 The DELTA(us) column shows time from that line to the previous line, and
     46 so can be a bit tricky to read. For example, the seventh line of data output
     47 (skipping the header) reads as "the time from func_a beginning to
     48 calling the print method was 10 microseconds".
     49 
     50 The FILE column shows file that was being executed.
     51 
     52 If the output looks shuffled, check the CPU "C" and "TIME" columns, and
     53 post sort based on TIME if necessary.
     54 
     55 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.
     56 
     57