Interpreting the second profiling column of Ruby profiler

ruby-talk
1

Hello,

I doubt in interpreting the second profiling column of Ruby profiler.
Here you are a small portion of the profiler’s output:

% cumulative self self total
time seconds seconds calls ms/call ms/call name
12.63 115.42 115.42 268703 0.43 0.63 Array#hash
7.48 183.72 68.31 160340 0.43 0.64 Array#eql?
6.06 239.10 55.38 161270 0.34 1.56 Hash#[]
5.99 293.87 54.77 537406 0.10 0.10 Kernel.hash
4.29 333.06 39.19 14370 2.73 10.98 FST#del_transition

[…]

0.00 905.65 0.00 1 0.00 913743.00 #toplevel
0.00 905.65 0.00 5 0.00 0.00 Module#public
0.00 905.65 0.00 6 0.00 0.00 Hash#clear
0.00 905.65 0.00 1 0.00 460.00 Chains2MINFST#finish
0.00 905.65 0.00 5 0.00 0.00 Hash#new

In “Ruby Developer’s Guide”, it is written:
"… The second column is the cumulative for the methods up to and including
the current one. …"

But why the numbers below in the second column are so big?

With the best regards,
Sergei

2

Olonichev Sergei wrote:

Hello,

I doubt in interpreting the second profiling column of Ruby profiler.
Here you are a small portion of the profiler’s output:

% cumulative self self total
time seconds seconds calls ms/call ms/call name
12.63 115.42 115.42 268703 0.43 0.63 Array#hash
7.48 183.72 68.31 160340 0.43 0.64 Array#eql?
6.06 239.10 55.38 161270 0.34 1.56 Hash#
5.99 293.87 54.77 537406 0.10 0.10 Kernel.hash
4.29 333.06 39.19 14370 2.73 10.98 FST#del_transition

[…]

0.00 905.65 0.00 1 0.00 913743.00 #toplevel
0.00 905.65 0.00 5 0.00 0.00 Module#public
0.00 905.65 0.00 6 0.00 0.00 Hash#clear
0.00 905.65 0.00 1 0.00 460.00 Chains2MINFST#finish
0.00 905.65 0.00 5 0.00 0.00 Hash#new

In “Ruby Developer’s Guide”, it is written:
“… The second column is the cumulative for the methods up to and including
the current one. …”

But why the numbers below in the second column are so big?

It’s cumulative as you read down the column, adding “self seconds” each
time. So:

183.72 = 115.42 + 68.31 (approx.)

and so on.