Training courses

Kernel and Embedded Linux

Bootlin training courses

Embedded Linux, kernel,
Yocto Project, Buildroot, real-time,
graphics, boot time, debugging...

Bootlin logo

Elixir Cross Referencer

Open Menu /external/cddl/dtracetoolkit/dist/Examples/rb_cputime_example.txt 
 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
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.