diff options
Diffstat (limited to 'Examples/rb_cputime_example.txt')
| -rw-r--r-- | Examples/rb_cputime_example.txt | 81 |
1 files changed, 81 insertions, 0 deletions
diff --git a/Examples/rb_cputime_example.txt b/Examples/rb_cputime_example.txt new file mode 100644 index 000000000000..edfa5aa75da2 --- /dev/null +++ b/Examples/rb_cputime_example.txt @@ -0,0 +1,81 @@ +The following are examples of rb_cputime.d. + +This script traces the on-CPU time of Ruby functions and prints a report. +Here it traces the example program, Code/Ruby/func_slow.rb + +# rb_cputime.d +Tracing... Hit Ctrl-C to end. +^C + +Count, + FILE TYPE NAME COUNT + . obj-new NoMemoryError 1 + . obj-new SystemStackError 1 + . obj-new ThreadGroup 1 + . obj-new fatal 1 + func_slow.rb func Object::func_a 1 + func_slow.rb func Object::func_b 1 + func_slow.rb func Object::func_c 1 + . obj-new Object 3 + func_slow.rb func IO::write 3 + func_slow.rb func Module::method_added 3 + func_slow.rb func Object::print 3 + func_slow.rb func Fixnum::< 600003 + func_slow.rb func Fixnum::+ 1200000 + - total - 1800015 + +Elapsed times (us), + FILE TYPE NAME TOTAL + . obj-new SystemStackError 2 + . obj-new NoMemoryError 2 + . obj-new fatal 11 + . obj-new ThreadGroup 12 + . obj-new Object 19 + +Exclusive function on-CPU times (us), + FILE TYPE NAME TOTAL + func_slow.rb func Module::method_added 4 + func_slow.rb func Object::print 57 + func_slow.rb func IO::write 180 + func_slow.rb func Object::func_a 405946 + func_slow.rb func Fixnum::< 691125 + func_slow.rb func Object::func_b 809970 + func_slow.rb func Object::func_c 1225235 + func_slow.rb func Fixnum::+ 1285200 + - total - 4417721 + +Inclusive function on-CPU times (us), + FILE TYPE NAME TOTAL + func_slow.rb func Module::method_added 4 + func_slow.rb func IO::write 180 + func_slow.rb func Object::print 238 + func_slow.rb func Fixnum::< 691125 + func_slow.rb func Fixnum::+ 1285200 + func_slow.rb func Object::func_c 2212572 + func_slow.rb func Object::func_b 3683688 + func_slow.rb func Object::func_a 4417717 + +You can see the results are printed in four sections. + +The first section reports how many times each subroutine was called, and it's +type. + +The second section reports on the on-CPU time of anything that was not of type +"func", in this case the only elements reported here are of type obj-new. + +The exclusive function on-CPU times shows, amongst other results, that func_a +spent around 0.4 seconds on-CPU. This time excludes time spent in other +subroutines. + +The inclusive function on-CPU times show that func_a spent around 4.4 +seconds on-CPU. This includes the time spent in other subroutines called. + +These on-CPU times are the time the thread spent running on a CPU, from when +the subroutine began to when it completed. This does not include time +spent off-CPU time such as sleeping for I/O or waiting for scheduling. + +On-CPU times are useful for showing who is causing the CPUs to be busy. +See Notes/ALLoncpu_notes.txt for more details. Also see +Notes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a +detailed explanation of exclusive vs inclusive subroutine time. + |