Skip to content

Instantly share code, notes, and snippets.

@jmstacey

jmstacey/gist:3890814

Created October 15, 2012 04:23
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save jmstacey/3890814 to your computer and use it in GitHub Desktop.
Save jmstacey/3890814 to your computer and use it in GitHub Desktop.
Download ZIP
Rubinius Profiler Graph
Raw
gistfile1.txt
Jon-Staceys-iMac:Desktop jon$ time rubinius/bin/rbx -X19 -Xprofile -Xprofiler.graph ./run.rb
500000
===== Thread 1 =====
Total running time: 16.516832237000003s
index % time self children called name
----------------------------------------------------------
[1] 99.8 0.00 16.48 1 Rubinius::Loader#script [1]
0.00 16.48 1 Rubinius::CodeLoader.load_script [2]
-------------------------------------------------------
0.00 16.48 1 Rubinius::Loader#script [1]
[2] 99.8 0.00 16.48 1 Rubinius::CodeLoader.load_script [2]
0.00 16.48 1 Rubinius::CodeLoader#load_script [3]
-------------------------------------------------------
0.00 16.48 1 Rubinius::CodeLoader.load_script [2]
[3] 99.8 0.00 16.48 1 Rubinius::CodeLoader#load_script [3]
0.00 16.48 1 Rubinius.run_script [4]
-------------------------------------------------------
0.00 16.48 1 Rubinius::CodeLoader#load_script [3]
[4] 99.8 0.00 16.48 1 Rubinius.run_script [4]
0.00 16.48 1 script:/Users/jon/Desktop/run.rb [5]
-------------------------------------------------------
0.00 16.48 1 Rubinius.run_script [4]
[5] 99.8 0.00 16.48 1 script:/Users/jon/Desktop/run.rb [5]
0.42 16.05 1 IO#readlines [6]
-------------------------------------------------------
0.00 16.48 1 script:/Users/jon/Desktop/run.rb [5]
[6] 99.8 0.42 16.05 1 IO#readlines [6]
0.42 15.31 500001 IO#gets [7]
0.21 0.06 500000 Array#<< [28]
0.06 0.00 1 GC.collect_mature [38]
-------------------------------------------------------
0.42 16.05 1 IO#readlines [6]
[7] 95.2 0.42 15.31 500001 IO#gets [7]
1.41 13.90 500001 IO#each [8]
-------------------------------------------------------
0.42 15.31 500001 IO#gets [7]
[8] 92.7 1.41 13.90 500001 IO#each [8]
0.65 11.06 500001 IO::EachReader#each [9]
0.06 1.39 500001 Class#allocate [18]
0.44 0.05 500001 IO#ensure_open_and_readable [22]
0.16 0.00 500001 IO::EachReader#initialize [29]
0.04 0.00 500001 IO::InternalBuffer#exhausted? [43]
0.03 0.00 500001 Module#===
0.02 0.00 500001 Proc.__from_block__
-------------------------------------------------------
1.41 13.90 500001 IO#each [8]
[9] 70.9 0.65 11.06 500001 IO::EachReader#each [9]
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
0.05 0.00 500001 String#empty? [42]
0.02 0.00 500001 Proc.__from_block__
-------------------------------------------------------
0.65 11.06 500001 IO::EachReader#each [9]
[10] 66.6 1.80 9.19 500001 IO::EachReader#read_to_separator [10]
1.34 2.61 507814 String#<< [11]
0.41 2.50 507814 IO::InternalBuffer#fill_from [12]
0.37 1.46 507814 IO::InternalBuffer#shift [15]
0.25 0.03 507813 IO::InternalBuffer#find [26]
0.08 0.00 500000 IO#increment_lineno [35]
0.08 0.00 500000 IO::gets<496> {} [36]
0.03 0.00 507814 IO::InternalBuffer#exhausted?
0.03 0.00 500000 Kernel#taint
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[11] 23.9 1.34 2.61 507814 String#<< [11]
0.38 1.73 507814 String#modify! [14]
0.28 0.00 1015628 String#encoding [27]
0.10 0.00 507814 String#append [31]
0.08 0.00 1015628 Kernel#kind_of? [37]
0.02 0.00 507814 Rubinius::Type.infect
0.02 0.00 507814 Kernel#==
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[12] 17.6 0.41 2.50 507814 IO::InternalBuffer#fill_from [12]
1.57 0.93 507814 Rubinius.synchronize [13]
-------------------------------------------------------
0.41 2.50 507814 IO::InternalBuffer#fill_from [12]
[13] 15.1 1.57 0.93 507814 Rubinius.synchronize [13]
0.59 0.17 507814 IO::InternalBuffer::fill_from<64> {} [20]
0.08 0.00 507814 Rubinius.lock [33]
0.08 0.00 507814 Rubinius.unlock [34]
-------------------------------------------------------
1.34 2.61 507814 String#<< [11]
[14] 12.8 0.38 1.73 507814 String#modify! [14]
0.85 0.87 500001 Rubinius::ByteArray#dup [16]
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[15] 11.1 0.37 1.46 507814 IO::InternalBuffer#shift [15]
0.61 0.85 507814 Rubinius.synchronize [17]
-------------------------------------------------------
0.38 1.73 507814 String#modify! [14]
[16] 10.5 0.85 0.87 500001 Rubinius::ByteArray#dup [16]
0.39 0.08 500001 Rubinius::ByteArray.new [23]
0.33 0.04 500001 Kernel#initialize_copy [24]
0.02 0.00 500001 Kernel#__class__
0.02 0.00 500001 Rubinius::ByteArray#size
-------------------------------------------------------
0.37 1.46 507814 IO::InternalBuffer#shift [15]
[17] 8.8 0.61 0.85 507814 Rubinius.synchronize [17]
0.57 0.15 507814 IO::InternalBuffer::shift<153> {} [21]
0.08 0.00 507814 Rubinius.lock [32]
0.05 0.00 507814 Rubinius.unlock [41]
-------------------------------------------------------
1.41 13.90 500001 IO#each [8]
[18] 8.8 0.06 1.39 500001 Class#allocate [18]
1.09 0.00 202 GC.collect_young [19]
0.30 0.00 6 GC.collect_mature [25]
-------------------------------------------------------
0.06 1.39 500001 Class#allocate [18]
[19] 6.6 1.09 0.00 202 GC.collect_young [19]
-------------------------------------------------------
1.57 0.93 507814 Rubinius.synchronize [13]
[20] 4.6 0.59 0.17 507814 IO::InternalBuffer::fill_from<64> {} [20]
0.06 0.00 507814 IO::InternalBuffer#empty_to [39]
0.04 0.00 8791 IO::InternalBuffer#fill [45]
0.04 0.00 507814 IO::InternalBuffer#empty?
0.04 0.00 507814 IO::InternalBuffer#size
0.00 0.00 8791 IO::InternalBuffer#reset!
-------------------------------------------------------
0.61 0.85 507814 Rubinius.synchronize [17]
[21] 4.3 0.57 0.15 507814 IO::InternalBuffer::shift<153> {} [21]
0.12 0.00 507814 String.from_bytearray [30]
0.03 0.00 507814 IO::InternalBuffer#size
-------------------------------------------------------
1.41 13.90 500001 IO#each [8]
[22] 2.9 0.44 0.05 500001 IO#ensure_open_and_readable [22]
0.03 0.00 500001 IO#ensure_open
0.02 0.00 500001 Fixnum#&
-------------------------------------------------------
0.85 0.87 500001 Rubinius::ByteArray#dup [16]
[23] 2.8 0.39 0.08 500001 Rubinius::ByteArray.new [23]
0.04 0.00 500001 Rubinius::ByteArray.allocate_sized [44]
0.04 0.00 500001 BasicObject#initialize
-------------------------------------------------------
0.85 0.87 500001 Rubinius::ByteArray#dup [16]
[24] 2.2 0.33 0.04 500001 Kernel#initialize_copy [24]
0.02 0.00 500001 Kernel#instance_of?
0.02 0.00 500001 Kernel#__class__
-------------------------------------------------------
0.06 1.39 500001 Class#allocate [18]
[25] 1.8 0.30 0.00 6 GC.collect_mature [25]
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[26] 1.7 0.25 0.03 507813 IO::InternalBuffer#find [26]
0.03 0.00 507813 Rubinius::ByteArray#locate
-------------------------------------------------------
1.34 2.61 507814 String#<< [11]
[27] 1.7 0.28 0.00 1015628 String#encoding [27]
-------------------------------------------------------
0.42 16.05 1 IO#readlines [6]
[28] 1.6 0.21 0.06 500000 Array#<< [28]
0.06 0.00 500000 Array#set_index [40]
-------------------------------------------------------
1.41 13.90 500001 IO#each [8]
[29] 1.0 0.16 0.00 500001 IO::EachReader#initialize [29]
-------------------------------------------------------
0.57 0.15 507814 IO::InternalBuffer::shift<153> {} [21]
[30] 0.7 0.12 0.00 507814 String.from_bytearray [30]
-------------------------------------------------------
1.34 2.61 507814 String#<< [11]
[31] 0.6 0.10 0.00 507814 String#append [31]
-------------------------------------------------------
0.61 0.85 507814 Rubinius.synchronize [17]
[32] 0.5 0.08 0.00 507814 Rubinius.lock [32]
-------------------------------------------------------
1.57 0.93 507814 Rubinius.synchronize [13]
[33] 0.5 0.08 0.00 507814 Rubinius.lock [33]
-------------------------------------------------------
1.57 0.93 507814 Rubinius.synchronize [13]
[34] 0.5 0.08 0.00 507814 Rubinius.unlock [34]
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[35] 0.5 0.08 0.00 500000 IO#increment_lineno [35]
-------------------------------------------------------
1.80 9.19 500001 IO::EachReader#read_to_separator [10]
[36] 0.5 0.08 0.00 500000 IO::gets<496> {} [36]
-------------------------------------------------------
1.34 2.61 507814 String#<< [11]
[37] 0.5 0.08 0.00 1015628 Kernel#kind_of? [37]
-------------------------------------------------------
0.42 16.05 1 IO#readlines [6]
[38] 0.4 0.06 0.00 1 GC.collect_mature [38]
-------------------------------------------------------
0.59 0.17 507814 IO::InternalBuffer::fill_from<64> {} [20]
[39] 0.3 0.06 0.00 507814 IO::InternalBuffer#empty_to [39]
-------------------------------------------------------
0.21 0.06 500000 Array#<< [28]
[40] 0.3 0.06 0.00 500000 Array#set_index [40]
-------------------------------------------------------
0.61 0.85 507814 Rubinius.synchronize [17]
[41] 0.3 0.05 0.00 507814 Rubinius.unlock [41]
-------------------------------------------------------
0.65 11.06 500001 IO::EachReader#each [9]
[42] 0.3 0.05 0.00 500001 String#empty? [42]
-------------------------------------------------------
1.41 13.90 500001 IO#each [8]
[43] 0.3 0.04 0.00 500001 IO::InternalBuffer#exhausted? [43]
-------------------------------------------------------
0.39 0.08 500001 Rubinius::ByteArray.new [23]
[44] 0.3 0.04 0.00 500001 Rubinius::ByteArray.allocate_sized [44]
-------------------------------------------------------
0.59 0.17 507814 IO::InternalBuffer::fill_from<64> {} [20]
[45] 0.2 0.04 0.00 8791 IO::InternalBuffer#fill [45]
-------------------------------------------------------
76 methods omitted
121 methods called a total of 0 times
real 0m17.630s
user 0m17.778s
sys 0m0.157s
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment