Skip to content

Instantly share code, notes, and snippets.

@patbl

patbl/gist:40acf3d438303b9e979c

Created January 23, 2016 05:32
Show Gist options
  • Save patbl/40acf3d438303b9e979c to your computer and use it in GitHub Desktop.
Save patbl/40acf3d438303b9e979c to your computer and use it in GitHub Desktop.
Download ZIP
merge! profile
Raw
gistfile1.txt
require 'ruby-prof'
MODES = [
RubyProf::WALL_TIME,
RubyProf::PROCESS_TIME,
RubyProf::CPU_TIME,
RubyProf::ALLOCATIONS,
RubyProf::MEMORY,
RubyProf::GC_TIME,
RubyProf::GC_RUNS,
]
MODES.each do |mode|
RubyProf.measure_mode = mode
result = RubyProf.profile do
h = {}
10_000_000.times do
h[:a] = 1
h[:b] = 2
end
end
# print a graph profile to text
printer = RubyProf::GraphPrinter.new(result)
printer.print(STDOUT, {})
result = RubyProf.profile do
h = {}
10_000_000.times do
h.merge!(a: 1, b: 2)
end
end
# print a graph profile to text
printer = RubyProf::GraphPrinter.new(result)
printer.print(STDOUT, {})
end
=begin
~/c 2.3.0 ➜ ruby merge_prof.rb
Measure Mode: wall_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 3.257678985595703
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 3.258 0.000 0.000 3.258 1 Global#[No method]
3.258 3.258 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
3.258 3.258 0.000 0.000 1/1 Global#[No method]
100.00% 100.00% 3.258 3.258 0.000 0.000 1 Integer#times
* indicates recursively called methods
Measure Mode: wall_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 9.427637100219727
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 9.428 0.000 0.000 9.428 1 Global#[No method]
9.428 7.231 0.000 2.197 1/1 Integer#times
--------------------------------------------------------------------------------
9.428 7.231 0.000 2.197 1/1 Global#[No method]
100.00% 76.70% 9.428 7.231 0.000 2.197 1 Integer#times
2.197 2.197 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
2.197 2.197 0.000 0.00010000000/10000000 Integer#times
23.30% 23.30% 2.197 2.197 0.000 0.000 10000000 Hash#merge!
* indicates recursively called methods
Measure Mode: process_time_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 10.420684999999999
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 10.421 0.000 0.000 10.421 1 Global#[No method]
10.421 10.421 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
10.421 10.421 0.000 0.000 1/1 Global#[No method]
100.00% 100.00% 10.421 10.421 0.000 0.000 1 Integer#times
* indicates recursively called methods
Measure Mode: process_time_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 20.447099
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 20.447 0.000 0.000 20.447 1 Global#[No method]
20.447 14.804 0.000 5.643 1/1 Integer#times
--------------------------------------------------------------------------------
20.447 14.804 0.000 5.643 1/1 Global#[No method]
100.00% 72.40% 20.447 14.804 0.000 5.643 1 Integer#times
5.643 5.643 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
5.643 5.643 0.000 0.00010000000/10000000 Integer#times
27.60% 27.60% 5.643 5.643 0.000 0.000 10000000 Hash#merge!
* indicates recursively called methods
Measure Mode: cpu_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 10.255427999999995
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 10.255 0.000 0.000 10.255 1 Global#[No method]
10.255 10.255 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
10.255 10.255 0.000 0.000 1/1 Global#[No method]
100.00% 100.00% 10.255 10.255 0.000 0.000 1 Integer#times
* indicates recursively called methods
Measure Mode: cpu_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 20.016907000000003
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00% 20.017 0.000 0.000 20.017 1 Global#[No method]
20.017 14.456 0.000 5.561 1/1 Integer#times
--------------------------------------------------------------------------------
20.017 14.456 0.000 5.561 1/1 Global#[No method]
100.00% 72.22% 20.017 14.456 0.000 5.561 1 Integer#times
5.561 5.561 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
5.561 5.561 0.000 0.00010000000/10000000 Integer#times
27.78% 27.78% 5.561 5.561 0.000 0.000 10000000 Hash#merge!
* indicates recursively called methods
Measure Mode: allocations
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 1.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 100.00% 1.000 1.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Integer#times
* indicates recursively called methods
Measure Mode: allocations
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 10000001.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
100.00% 0.00%10000001.000 1.000 0.00010000000.000 1 Global#[No method]
10000000.00010000000.000 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
10000000.00010000000.000 0.000 0.000 1/1 Global#[No method]
100.00% 100.00%10000000.00010000000.000 0.000 0.000 1 Integer#times
0.000 0.000 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.00010000000/10000000 Integer#times
0.00% 0.00% 0.000 0.000 0.000 0.000 10000000 Hash#merge!
* indicates recursively called methods
Measure Mode: memory
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 0.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
NaN% NaN% 0.000 0.000 0.000 0.000 1 Integer#times
--------------------------------------------------------------------------------
NaN% NaN% 0.000 0.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
* indicates recursively called methods
Measure Mode: memory
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 0.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.00010000000/10000000 Integer#times
NaN% NaN% 0.000 0.000 0.000 0.000 10000000 Hash#merge!
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
NaN% NaN% 0.000 0.000 0.000 0.000 1 Integer#times
0.000 0.000 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
NaN% NaN% 0.000 0.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
* indicates recursively called methods
Measure Mode: gc_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 0.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
NaN% NaN% 0.000 0.000 0.000 0.000 1 Integer#times
--------------------------------------------------------------------------------
NaN% NaN% 0.000 0.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
* indicates recursively called methods
Measure Mode: gc_time
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 0.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.00010000000/10000000 Integer#times
NaN% NaN% 0.000 0.000 0.000 0.000 10000000 Hash#merge!
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
NaN% NaN% 0.000 0.000 0.000 0.000 1 Integer#times
0.000 0.000 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
NaN% NaN% 0.000 0.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
* indicates recursively called methods
Measure Mode: gc_runs
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 0.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Global#[No method]
NaN% NaN% 0.000 0.000 0.000 0.000 1 Integer#times
--------------------------------------------------------------------------------
NaN% NaN% 0.000 0.000 0.000 0.000 1 Global#[No method]
0.000 0.000 0.000 0.000 1/1 Integer#times
* indicates recursively called methods
Measure Mode: gc_runs
Thread ID: 70120995289640
Fiber ID: 70121003442800
Total Time: 278.0
Sort by: total_time
%total %self total self wait child calls name
--------------------------------------------------------------------------------
278.000 278.000 0.000 0.000 1/1 Global#[No method]
100.00% 100.00% 278.000 278.000 0.000 0.000 1 Integer#times
0.000 0.000 0.000 0.00010000000/10000000 Hash#merge!
--------------------------------------------------------------------------------
100.00% 0.00% 278.000 0.000 0.000 278.000 1 Global#[No method]
278.000 278.000 0.000 0.000 1/1 Integer#times
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.00010000000/10000000 Integer#times
0.00% 0.00% 0.000 0.000 0.000 0.000 10000000 Hash#merge!
* indicates recursively called methods
=end
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment