GC.disable
An important difference to note is the how time is reported by various measurement methods. Wall clock time is the actual time passed in terms of human perception whereas CPU time is the time spent processing the work. CPU time doesn't include any delays waiting on resources to free up such as thread interrupts or garbage collection.
To keep things simple, we'll create a Ruby Proc and just repeatedly call that Proc for each of the measurement methods below.
work_proc = Proc.new {
big = []
1000.times do
big << rand(36**16).to_s(36)
end
x = big.sort
x.first
}To give an idea of what this array will look like, this will print out the first five elements:
puts big[0..4]
=> ["nuwc05c4xuz1ua2l", "rpwgr1tpbmnnrp2q", "okco1ablpme8mguo", "hut9e5f2umzj2f5j", "ppqu554al4zcdwtm"]
start = Time.now
work_proc.call
finish = Time.now
# Result
total_time = finish - start
puts total_timeThis will output a number (in seconds) similar to the following:
0.025681
require 'benchmark'
puts Benchmark.measure { work_proc.call }http://www.ruby-doc.org/stdlib-1.9.3/libdoc/benchmark/rdoc/Benchmark.html
Linking to the older 1.9.3 Benchmark documentation because it has a good discussion about realtime in the comments section. Here's the 2.1.0 version if you need it.
gem install ruby-prof
require 'ruby-prof'
result = RubyProf.profile do
work_proc.call
end
# Print a graph profile to text
printer = RubyProf::GraphPrinter.new(result)
printer.print(STDOUT, {})This will output something along the lines of the following:
Thread ID: 70238909684700
Fiber ID: 70238917178180
Total Time: 0.007679000000000102
Sort by: total_time
%total %self total self wait child calls Name
--------------------------------------------------------------------------------
100.00% 0.31% 0.008 0.000 0.000 0.008 1 <Object::Object>#__pry__
0.008 0.000 0.000 0.008 1/1 Proc#call
--------------------------------------------------------------------------------
0.008 0.000 0.000 0.008 1/1 <Object::Object>#__pry__
99.69% 0.16% 0.008 0.000 0.000 0.008 1 Proc#call
0.007 0.003 0.000 0.005 1/1 Integer#times
0.000 0.000 0.000 0.000 1/1 Array#sort
0.000 0.000 0.000 0.000 1/1 Array#first
--------------------------------------------------------------------------------
0.007 0.003 0.000 0.005 1/1 Proc#call
96.02% 34.00% 0.007 0.003 0.000 0.005 1 Integer#times
0.002 0.002 0.000 0.001 1000/1000 Kernel#rand
0.001 0.001 0.000 0.000 1000/1000 Bignum#to_s
0.001 0.001 0.000 0.000 1000/1000 Fixnum#**
--------------------------------------------------------------------------------
0.002 0.002 0.000 0.001 1000/1000 Integer#times
31.98% 23.96% 0.002 0.002 0.000 0.001 1000 Kernel#rand
0.001 0.001 0.000 0.000 1000/1000 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
0.001 0.001 0.000 0.000 1000/1000 Integer#times
17.27% 17.27% 0.001 0.001 0.000 0.000 1000 Bignum#to_s
--------------------------------------------------------------------------------
0.001 0.001 0.000 0.000 1000/1000 Integer#times
12.76% 12.76% 0.001 0.001 0.000 0.000 1000 Fixnum#**
--------------------------------------------------------------------------------
0.001 0.001 0.000 0.000 1000/1000 Kernel#rand
8.02% 8.02% 0.001 0.001 0.000 0.000 1000 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Proc#call
3.46% 3.46% 0.000 0.000 0.000 0.000 1 Array#sort
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Proc#call
0.05% 0.05% 0.000 0.000 0.000 0.000 1 Array#first
* indicates recursively called methods
- https://github.com/change/method_profiler
- https://github.com/lpasqualis/rubyperf
- https://github.com/sandro/bench_press
- https://github.com/geemus/tach
- https://bitbucket.org/amanking/benchmarkable/wiki/Home
- https://github.com/MiniProfiler/rack-mini-profiler
- https://github.com/MattStopa/DevPanel
- http://guides.rubyonrails.org/v3.2.13/performance_testing.html
- https://github.com/rails/rails-perftest
- http://rubylearning.com/blog/2011/08/14/performance-testing-rails-applications-how-to/
- https://www.ruby-forum.com/topic/179748
- http://www.schneems.com/post/21027306312/performance-testing-rails-with-blitzio/
- http://www.sinatrarb.com/testing.html
- https://github.com/francescoagati/async_sinatra_test_thin_rainbows
- http://recipes.sinatrarb.com/p/testing/minitest
- https://github.com/jruby/jruby/wiki/Profiling-jruby#profiling-specific-code-in-an-application
- http://railscasts.com/episodes/376-jruby-basics
- https://github.com/jruby/jruby/wiki/Profiling-jruby
- https://github.com/jruby/jruby/wiki/Profiling-Object-Allocations
- http://blog.headius.com/2013/01/constant-and-global-optimization-in.html
- https://github.com/jruby/jruby/wiki/PerformanceTuning