1 The following are examples of rb_flowtime.d.
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
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
40 The fifth column is indented by 2 spaces to show when a new method begins.
41 This shows which method is calling which.
43 The TIME(us) column shows time since boot.
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".
50 The FILE column shows file that was being executed.
52 If the output looks shuffled, check the CPU "C" and "TIME" columns, and
53 post sort based on TIME if necessary.
55 See Notes/ALLflow_notes.txt for important notes about reading flow outputs.