23 Dec 2013
Cpu vs idle time is one of the first things I look at when benchmarking rails requests.
Cpu time consists of number crunching, template rendering, method invocation and any other time spent executing instructions on the CPU. Idle time is everything else- generally this is time spent waiting on disk or network I/O, and can be highly variable depending on disk activity, remote server load, network conditions, etc.
In the past I’ve used ruby-prof’s RubyProf::Measure::ProcessTime.measure
to measure cpu time, but with Ruby 2.1 we have a clock_gettime(3)
wrapper built-in!
def time
real = Time.now
cpu = Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID)
yield
cpu = Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID) - cpu
real = Time.now - real
{ real: real, cpu: cpu, idle: real-cpu }
end
>> time{ sleep 1 } # all idle time
=> {:real=>1.000452, :cpu=>0.00041599999999997195, :idle=>1.000036}
>> time{ 10000.times{2**65536} } # all cpu time
=> {:real=>0.21192, :cpu=>0.211714, :idle=>0.00020599999999998397}
>> time{ open('http://google.com').read } # mixed, mostly idle
=> {:real=>0.342832, :cpu=>0.05224400000000001, :idle=>0.290588}
The method also takes an optional second argument unit
, which can be :millisecond
, :microsecond
, :nanosecond
, or a :float_
variant thereof. See the documentation for more details.
23 Dec 2013
In Ruby 2.1, "str".freeze
is optimized by the compiler to return a single shared frozen strings on every invocation. An alternative "str"f
syntax was implemented initially, but later reverted.
Although the external scope of this feature is limited, internally it is used extensively to de-duplicate strings in the VM. Previously, every def method_missing()
, the symbol :method_missing
and any literal "method_missing"
strings in the code-base would all create their own String objects. With Ruby 2.1, only one string is created and shared. Since many strings are commonly re-used in any given code base, this easily adds up. In fact, large applications can expect up to 30% fewer long-lived strings on their heaps in 2.1.
For 2.2, there are plans to expose this feature via a new String#f
. There’s also a proposal for a magic immutable: string
comment to make frozen strings default for a given file.
22 Dec 2013
For years, MRI cleared the entire VM’s method cache whenever a new method was defined. In fact, method defintions were only one of a dozen ways to clear the method cache. Earlier this year, @jamesgolick decided to improve things with a patchset for 1.9 implementing hierarchical invalidation. @charliesome subsequently ported and committed the patchset to trunk. Starting with Ruby 2.1, altering a class will only invalidate the caches for that class and its subclasses.
To provide visibility, we’ve exposed some basic stats about the method cache via a new RubyVM.stat()
method. For instance, an application can measure “global invalidations per request” by comparing RubyVM.stat(:global_method_state)
before and after every request. See simeonwillbanks/busted for some convenience methods around these new stats.
To track down where (global and non-global) invalidations are happening, Ruby 2.1 ships with a new probe: ruby::method-cache-clear
. This can easily be used via dtrace or systemtap to find the source of method cache invalidations in your application.
$ cat ruby_mcache.stp
probe process("/usr/bin/ruby").mark("method__cache__clear") {
printf("%s(%d) %s %s:%d cleared `%s'\n", execname(), pid(), $$name, kernel_sring($arg2), $arg3, kernel_string($arg1))
}
$ sudo stap ruby_mcache.stp
ruby(25410) method__cache__clear lib/ruby/2.1.0/ostruct.rb:169 cleared `OpenStruct'
ruby(25410) method__cache__clear lib/ruby/2.1.0/ostruct.rb:170 cleared `OpenStruct'
Work on improving ruby’s method cache is continuing on ruby-core. Early numbers show up to 5-10% improvements are possible with a larger and more resilient cache. We hope to land some improvements to ruby-trunk (for 2.2), and maybe backport them into a future 2.1 patchlevel release.