tmm1 / rblineprof

line-profiler for ruby
MIT License
770 stars 33 forks source link

How are calls being counted? #23

Open ghost opened 11 years ago

ghost commented 11 years ago

I got the following result from 100 iterations of the method and I'm wondering how rblineprof comes up with these counts.

                   | module Aeee
                   |   class Request
                   |     attr_reader :finished, :banana
                   | 
                   |     attr_reader :http_method, :uri, :headers, :body
                   |     attr_reader :http_version
                   | 
                   |     def initialize(http_method, uri, headers = {}, body = '', http_version = 1.1)
                   |       @http_method, @uri = http_method, uri
                   |       @headers, @body = headers, body
                   |       @http_version = http_version
                   | 
     0.6ms (  600) |       @finished, @banana = Promise.new, Promise.new
                   |     end
                   | 
                   |     def self.build(parser)
     0.3ms (  300) |       http_method = parser.http_method.downcase.to_sym
     3.2ms (  200) |       uri = URI('http://' + parser.request_url)
     0.1ms (  100) |       headers = parser.headers
     0.7ms (  500) |       http_version = parser.http_version.join('.').to_f
                   | 
     1.4ms (  400) |       new(http_method, uri.request_uri, headers, '', http_version)
                   |     end
                   |   end
                   | end

In the first three lines of self.build, it seems to count the number of method calls, but from then on I have no idea. Might there be a problem with Fibers? Each of the iterations was running in its own Fiber, with roughly 10 running concurrently - although clearly none should have been interrupted (Promise.new doesn't yield either).

Edit: the actual code is on its way...

tmm1 commented 11 years ago

It's a number of "events", that loosely correlates to number of method calls. It depends on the exact version of ruby and VM optimizations enabled.

ghost commented 11 years ago

The same events as in Kernel#set_trace_func?

ghost commented 11 years ago

Briefly looking at the code it looks like we could increase the counter in profiler_hook instead of stackframe_record, which is called for every event. Once per "stack frame entry", which seems to more closely correlate to method calls.

Giving it a try.

ghost commented 11 years ago

Nevermind that idea, it's effectively the same as how it works now.

ghost commented 11 years ago

I came up with lgierth/rblineprof@6517ddc, it's supposed to skip the frame if its file and line equal the previous frame's file and line. Doesn't work yet, but I'll figure it out - my first C steps!