Rails core - Jul 2013 - Reported timing aren't thread-safe, are they?

I was taking a look at the implementation for reporting the time spent 
on each part of an action processing.

Rails, by default will report timing for the view and db (ActiveRecord).

Both use class attributes for storing the timing (or accumulating them 
in the case of AR), which are shared among all threads.

This is fine if you''re deploying using the fork approach, like done by 
Passenger or Unicorn (my current case), but once you decide to use a 
multi-threaded deployment strategy, like using Puma or Warbler on JRuby, 
those reported numbers are no longer reliable, specially under high load.

Maybe implementing them using thread locals (Thread.current[:foo]) would 
be more friendly to such environments.

It isn''t a perfect solution as it won''t report correct timings
(whatever
the correct definition would be) for some action like:

def some_action
     render json: Hash[[:sections, :fields].zip [
         Thread.start {Section.all.to_a},
         Thread.start {Field.all.to_a},
     ].map &:value]
end

But in that case, I don''t even know how this should be reported
ideally.
For instance, suppose Section.all.to_a takes 50ms from DB while 
Field.all.to_a takes 70ms.

How would you explain an output like this?

Action completed in 80ms (view: 5ms, db: 120ms)

So, except for such cases, using thread locals would yield to more 
reliable results in the production logs for a quick inspect.

Is the overhead of using Thread.current so high when compared to 
"self.runtime"?

Cheers,
Rodrigo.

-- 
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Core" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to rubyonrails-core+unsubscribe@googlegroups.com.
To post to this group, send email to rubyonrails-core@googlegroups.com.
Visit this group at http://groups.google.com/group/rubyonrails-core.
For more options, visit https://groups.google.com/groups/opt_out.