Skip to content

Instantly share code, notes, and snippets.

@ernie
Created August 22, 2011 18:40
Show Gist options
  • Save ernie/1163139 to your computer and use it in GitHub Desktop.
Save ernie/1163139 to your computer and use it in GitHub Desktop.
AR serialization memory usage
====================
3.0.10
====================
user system total real
============================================================
RSS : 37592k (37592k)
Objects : 182328 (182328)
============================================================
all 0.650000 0.010000 0.660000 ( 0.682556)
============================================================
RSS : 38616k (1024k)
Objects : 182328 (0)
============================================================
Thread ID: 70275010088600
Total Time: 40598.373046875
%total %self total self wait child calls Name
--------------------------------------------------------------------------------
100.00% 0.01% 40598.37 2.14 0.00 40596.23 1 Global#[No method]
40596.23 0.98 0.00 40595.25 1/1 Benchmark::Report#item
--------------------------------------------------------------------------------
40596.23 0.98 0.00 40595.25 1/1 Global#[No method]
99.99% 0.00% 40596.23 0.98 0.00 40595.25 1 Benchmark::Report#item
40583.87 0.98 0.00 40582.89 1/1 Benchmark#measure
8.84 0.98 0.00 7.86 1/1 Benchmark::Tms#format
1.69 0.84 0.00 0.84 2/2 Kernel#print
0.84 0.84 0.00 0.00 1/1 String#ljust
--------------------------------------------------------------------------------
40583.87 0.98 0.00 40582.89 1/1 Benchmark::Report#item
99.96% 0.00% 40583.87 0.98 0.00 40582.89 1 Benchmark#measure
40565.00 0.84 0.00 40564.16 1/11 Integer#times
5.06 0.84 0.00 4.22 2/2 Time#to_f
3.72 0.84 0.00 2.88 2/22 <Class::Time>#now
3.64 0.98 0.00 2.66 2/2 <Module::Benchmark>#times
2.09 0.52 0.00 1.58 1/51 Class#new
0.84 0.84 0.00 0.00 2/2 Struct::Tms#utime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#cutime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#cstime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#stime
--------------------------------------------------------------------------------
0.00 6.45 0.00 0.00 10/11 SQLite3::Statement#get_metadata
40565.00 0.84 0.00 40564.16 1/11 Benchmark#measure
99.92% 0.02% 40565.00 7.30 0.00 40564.16 11 Integer#times
40564.16 1.00 0.00 40563.16 10/10 <Class::ActiveRecord::Base>#all
0.84 0.84 0.00 0.00 70/70 SQLite3::Statement#column_name
0.84 0.84 0.00 0.00 70/70 SQLite3::Statement#column_decltype
--------------------------------------------------------------------------------
40564.16 1.00 0.00 40563.16 10/10 Integer#times
99.92% 0.00% 40564.16 1.00 0.00 40563.16 10 <Class::ActiveRecord::Base>#all
40534.03 1.04 0.00 40533.00 10/10 ActiveRecord::FinderMethods#all
29.13 1.01 0.00 28.12 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
--------------------------------------------------------------------------------
40534.03 1.04 0.00 40533.00 10/10 <Class::ActiveRecord::Base>#all
99.84% 0.00% 40534.03 1.04 0.00 40533.00 10 ActiveRecord::FinderMethods#all
40531.31 1.01 0.00 40530.30 10/10 ActiveRecord::Relation#to_a
1.69 0.84 0.00 0.84 10/50 Enumerable#any?
--------------------------------------------------------------------------------
40531.31 1.01 0.00 40530.30 10/10 ActiveRecord::FinderMethods#all
99.83% 0.00% 40531.31 1.01 0.00 40530.30 10 ActiveRecord::Relation#to_a
40434.73 1.00 0.00 40433.73 10/10 <Class::ActiveRecord::Base>#find_by_sql
52.52 1.01 0.00 51.51 10/10 Arel::TreeManager#to_sql
39.66 1.03 0.00 38.62 10/10 ActiveRecord::QueryMethods#arel
2.04 1.01 0.00 1.03 20/20 ActiveRecord::Relation#eager_loading?
0.84 0.84 0.00 0.00 10/10 NilClass#nil?
0.52 0.52 0.00 0.00 10/10110 Array#each
--------------------------------------------------------------------------------
40434.73 1.00 0.00 40433.73 10/10 ActiveRecord::Relation#to_a
99.60% 0.00% 40434.73 1.00 0.00 40433.73 10 <Class::ActiveRecord::Base>#find_by_sql
35251.23 1.07 0.00 35250.16 10/10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
5167.05 0.84 0.00 5166.21 10/10 Array#collect!
8.75 1.09 0.00 7.65 10/10 <Class::ActiveRecord::Base>#connection
5.17 1.00 0.00 4.18 10/10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
1.02 1.02 0.00 0.00 10/10 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#table_name
0.52 0.52 0.00 0.00 10/42 Module#name
--------------------------------------------------------------------------------
35251.23 1.07 0.00 35250.16 10/10 <Class::ActiveRecord::Base>#find_by_sql
86.83% 0.00% 35251.23 1.07 0.00 35250.16 10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
35250.16 1.08 0.00 35249.07 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
--------------------------------------------------------------------------------
35250.16 1.08 0.00 35249.07 10/10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
86.83% 0.00% 35250.16 1.08 0.00 35249.07 10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
35249.07 1.06 0.00 35248.02 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
--------------------------------------------------------------------------------
35249.07 1.06 0.00 35248.02 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
86.82% 0.00% 35249.07 1.06 0.00 35248.02 10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
25869.78 1.06 0.00 25868.73 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#execute
9378.23 156.77 0.00 9221.47 10/40 Array#map
--------------------------------------------------------------------------------
25869.78 1.06 0.00 25868.73 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
63.72% 0.00% 25869.78 1.06 0.00 25868.73 10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#execute
25868.73 6.53 0.00 25862.20 10/10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
--------------------------------------------------------------------------------
25868.73 6.53 0.00 25862.20 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#execute
63.72% 0.02% 25868.73 6.53 0.00 25862.20 10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
25861.68 1.67 0.00 25860.01 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.52 0.52 0.00 0.00 10/40 Kernel#object_id
--------------------------------------------------------------------------------
25861.68 1.67 0.00 25860.01 10/10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
63.70% 0.00% 25861.68 1.67 0.00 25860.01 10 ActiveSupport::Notifications::Instrumenter#instrument
25846.55 1.01 0.00 25845.54 10/10 SQLite3::Database#execute
7.96 1.03 0.00 6.93 10/10 ActiveSupport::Notifications::Fanout#publish
5.50 0.52 0.00 4.98 20/22 <Class::Time>#now
--------------------------------------------------------------------------------
25846.55 1.01 0.00 25845.54 10/10 ActiveSupport::Notifications::Instrumenter#instrument
63.66% 0.00% 25846.55 1.01 0.00 25845.54 10 SQLite3::Database#execute
25843.34 1.01 0.00 25842.33 10/10 SQLite3::Database#prepare
0.84 0.84 0.00 0.00 10/10 Kernel#nil?
0.84 0.84 0.00 0.00 10/10 Module#const_defined?
0.52 0.52 0.00 0.00 10/90 Array#empty?
--------------------------------------------------------------------------------
25843.34 1.01 0.00 25842.33 10/10 SQLite3::Database#execute
63.66% 0.00% 25843.34 1.01 0.00 25842.33 10 SQLite3::Database#prepare
25815.16 0.84 0.00 25814.31 10/10 Enumerable#map
11.85 1.01 0.00 10.84 10/10 SQLite3::Statement#columns
7.53 1.01 0.00 6.52 10/10 SQLite3::Statement#bind_params
6.11 0.52 0.00 5.59 10/51 Class#new
0.84 0.84 0.00 0.00 20/40020 Kernel#block_given?
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#close
--------------------------------------------------------------------------------
25815.16 0.84 0.00 25814.31 10/10 SQLite3::Database#prepare
63.59% 0.00% 25815.16 0.84 0.00 25814.31 10 Enumerable#map
25814.31 1.01 0.00 25813.30 10/10 SQLite3::Statement#each
--------------------------------------------------------------------------------
25814.31 1.01 0.00 25813.30 10/10 Enumerable#map
63.58% 0.00% 25814.31 1.01 0.00 25813.30 10 SQLite3::Statement#each
25813.30 3.81 0.00 25809.49 10/10 Kernel#loop
--------------------------------------------------------------------------------
25813.30 3.81 0.00 25809.49 10/10 SQLite3::Statement#each
63.58% 0.01% 25813.30 3.81 0.00 25809.49 10 Kernel#loop
23130.09 1.01 0.00 23129.08 10000/10000 SQLite3::Database#ordered_map_for
2678.56 2677.72 0.00 0.84 10010/10010 SQLite3::Statement#step
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Statement#done?
--------------------------------------------------------------------------------
23130.09 1.01 0.00 23129.08 10000/10000 Kernel#loop
56.97% 0.00% 23130.09 1.01 0.00 23129.08 10000 SQLite3::Database#ordered_map_for
9219.59 9219.59 0.00 0.00 10000/10000 <Class::Hash>#[]
6564.38 0.84 0.00 6563.53 10000/10000 Enumerable#each_with_index
6250.52 6250.52 0.00 0.00 10000/10010 Array#flatten
1094.59 1094.59 0.00 0.00 10000/10000 Array#zip
--------------------------------------------------------------------------------
2.58 1.55 0.00 1.03 2/140002 Proc#yield
6563.02 6563.02 0.00 0.00 70000/140002 Array#each
9219.27 9219.27 0.00 0.00 70000/140002 Hash#each
38.88% 38.88% 15784.86 15783.83 0.00 1.03 140002 Hash#[]=
1.03 1.03 0.00 0.00 2/42 Kernel#hash
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
3.38 0.84 0.00 2.53 10/40 Arel::SelectManager#project
21.13 0.52 0.00 20.62 10/40 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
9378.23 156.77 0.00 9221.47 10/40 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
23.16% 0.39% 9402.74 158.64 0.00 9244.62 40 Array#map
9221.47 0.52 0.00 9220.95 10000/10010 Hash#each
20.62 2.11 0.00 18.51 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
1.69 0.84 0.00 0.84 10/10 Array#include?
0.84 0.84 0.00 0.00 10/40 Kernel#class
0.00 0.52 0.00 0.00 10/30 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10010 ActiveRecord::QueryMethods#collapse_wheres
9221.47 0.52 0.00 9220.95 10000/10010 Array#map
22.72% 0.00% 9222.31 1.36 0.00 9220.95 10010 Hash#each
9219.27 9219.27 0.00 0.00 70000/140002 Hash#[]=
0.84 0.84 0.00 0.00 70000/70000 String#sub
0.84 0.84 0.00 0.00 140000/140000 Kernel#is_a?
--------------------------------------------------------------------------------
9219.59 9219.59 0.00 0.00 10000/10000 SQLite3::Database#ordered_map_for
22.71% 22.71% 9219.59 9219.59 0.00 0.00 10000 <Class::Hash>#[]
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/10110 ActiveRecord::Relation#to_a
0.52 0.52 0.00 0.00 10/10110 Enumerable#grep
0.52 0.52 0.00 0.00 10/10110 Enumerable#group_by
0.52 0.52 0.00 0.00 10/10110 ActiveRecord::QueryMethods#collapse_wheres
0.52 0.52 0.00 0.00 10/10110 SQLite3::Statement#bind_params
1.36 1.36 0.00 0.00 50/10110 Enumerable#any?
5.90 1.14 0.00 4.76 10/10110 ActiveSupport::Notifications::Fanout#publish
6563.53 0.52 0.00 6563.02 10000/10110 Enumerable#each_with_index
16.19% 0.01% 6573.37 5.59 0.00 6567.77 10110 Array#each
6563.02 6563.02 0.00 0.00 70000/140002 Hash#[]=
4.76 1.66 0.00 3.10 10/10 ActiveSupport::Notifications::Fanout::Subscriber#publish
--------------------------------------------------------------------------------
6564.38 0.84 0.00 6563.53 10000/10000 SQLite3::Database#ordered_map_for
16.17% 0.00% 6564.38 0.84 0.00 6563.53 10000 Enumerable#each_with_index
6563.53 0.52 0.00 6563.02 10000/10110 Array#each
--------------------------------------------------------------------------------
6.00 6.00 0.00 0.00 10/10010 SQLite3::Statement#bind_params
6250.52 6250.52 0.00 0.00 10000/10010 SQLite3::Database#ordered_map_for
15.41% 15.41% 6256.52 6256.52 0.00 0.00 10010 Array#flatten
--------------------------------------------------------------------------------
5167.05 0.84 0.00 5166.21 10/10 <Class::ActiveRecord::Base>#find_by_sql
12.73% 0.00% 5167.05 0.84 0.00 5166.21 10 Array#collect!
5166.21 3594.75 0.00 1571.46 10000/10000 <Class::ActiveRecord::Base>#instantiate
--------------------------------------------------------------------------------
5166.21 3594.75 0.00 1571.46 10000/10000 Array#collect!
12.73% 8.85% 5166.21 3594.75 0.00 1571.46 10000 <Class::ActiveRecord::Base>#instantiate
1566.55 1563.50 0.00 3.05 10000/10000 ActiveRecord::Base#init_with
2.03 1.00 0.00 1.04 10000/10000 <Class::ActiveRecord::Base>#find_sti_class
1.36 0.84 0.00 0.52 10000/10000 Class#allocate
1.00 1.00 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#inheritance_column
0.52 0.52 0.00 0.00 10000/10012 Hash#default
--------------------------------------------------------------------------------
2678.56 2677.72 0.00 0.84 10010/10010 Kernel#loop
6.60% 6.60% 2678.56 2677.72 0.00 0.84 10010 SQLite3::Statement#step
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Database#encoding
--------------------------------------------------------------------------------
1566.55 1563.50 0.00 3.05 10000/10000 <Class::ActiveRecord::Base>#instantiate
3.86% 3.85% 1566.55 1563.50 0.00 3.05 10000 ActiveRecord::Base#init_with
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#_run_initialize_callbacks
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#_run_find_callbacks
--------------------------------------------------------------------------------
1094.59 1094.59 0.00 0.00 10000/10000 SQLite3::Database#ordered_map_for
2.70% 2.70% 1094.59 1094.59 0.00 0.00 10000 Array#zip
--------------------------------------------------------------------------------
52.52 1.01 0.00 51.51 10/10 ActiveRecord::Relation#to_a
0.13% 0.00% 52.52 1.01 0.00 51.51 10 Arel::TreeManager#to_sql
51.51 1.01 0.00 50.50 10/10 Arel::Visitors::ToSql#accept
--------------------------------------------------------------------------------
51.51 1.01 0.00 50.50 10/10 Arel::TreeManager#to_sql
0.13% 0.00% 51.51 1.01 0.00 50.50 10 Arel::Visitors::ToSql#accept
45.44 1.08 0.00 44.37 10/10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
3.01 1.09 0.00 1.92 10/10 <Class::ActiveRecord::Base>#connection_pool
2.04 1.01 0.00 1.03 10/10 Arel::Visitors::ToSql#last_column=
--------------------------------------------------------------------------------
45.44 1.08 0.00 44.37 10/10 Arel::Visitors::ToSql#accept
0.11% 0.00% 45.44 1.08 0.00 44.37 10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
39.31 1.01 0.00 38.29 10/10 Arel::Visitors::Visitor#accept
2.62 1.08 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
2.44 1.08 0.00 1.36 10/30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
--------------------------------------------------------------------------------
39.66 1.03 0.00 38.62 10/10 ActiveRecord::Relation#to_a
0.10% 0.00% 39.66 1.03 0.00 38.62 10 ActiveRecord::QueryMethods#arel
38.62 1.03 0.00 37.59 10/10 ActiveRecord::QueryMethods#build_arel
--------------------------------------------------------------------------------
39.31 1.01 0.00 38.29 10/10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
0.10% 0.00% 39.31 1.01 0.00 38.29 10 Arel::Visitors::Visitor#accept
38.29 1.01 0.00 37.28 10/30 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
38.62 1.03 0.00 37.59 10/10 ActiveRecord::QueryMethods#arel
0.10% 0.00% 38.62 1.03 0.00 37.59 10 ActiveRecord::QueryMethods#build_arel
25.84 1.03 0.00 24.81 10/10 ActiveRecord::QueryMethods#build_select
5.63 1.03 0.00 4.59 10/10 ActiveRecord::QueryMethods#collapse_wheres
4.44 4.44 0.00 0.00 10/20 Array#-
0.84 0.84 0.00 0.00 20/20 Array#uniq
0.84 0.84 0.00 0.00 40/90 Array#empty?
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/30 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.00 0.52 0.00 0.00 10/30 Array#map
38.29 1.01 0.00 37.28 10/30 Arel::Visitors::Visitor#accept
0.09% 0.01% 38.29 2.04 0.00 37.28 30 Arel::Visitors::Visitor#visit
31.31 1.01 0.00 30.29 10/10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
8.47 1.36 0.00 7.12 2/10012 Hash#default
2.02 1.01 0.00 1.01 10/10 Arel::Visitors::ToSql#visit_Arel_Table
1.55 1.55 0.00 0.00 30/40 Kernel#class
1.55 1.55 0.00 0.00 30/42 Kernel#hash
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#visit_Fixnum
--------------------------------------------------------------------------------
31.31 1.01 0.00 30.29 10/10 Arel::Visitors::Visitor#visit
0.08% 0.00% 31.31 1.01 0.00 30.29 10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
30.29 1.79 0.00 28.50 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
--------------------------------------------------------------------------------
30.29 1.79 0.00 28.50 10/10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
0.07% 0.00% 30.29 1.79 0.00 28.50 10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
21.13 0.52 0.00 20.62 10/40 Array#map
5.55 5.55 0.00 0.00 20/40 Array#join
1.30 1.30 0.00 0.00 10/20 Array#compact
0.52 0.52 0.00 0.00 10/90 Array#empty?
--------------------------------------------------------------------------------
29.13 1.01 0.00 28.12 10/10 <Class::ActiveRecord::Base>#all
0.07% 0.00% 29.13 1.01 0.00 28.12 10 ActiveRecord::NamedScope::ClassMethods#scoped
16.55 1.00 0.00 15.55 10/10 <Class::ActiveRecord::Base>#current_scoped_methods
8.73 4.28 0.00 4.45 10/10 Kernel#clone
2.84 1.00 0.00 1.84 10/10 <Class::ActiveRecord::Base>#relation
--------------------------------------------------------------------------------
25.84 1.03 0.00 24.81 10/10 ActiveRecord::QueryMethods#build_arel
0.06% 0.00% 25.84 1.03 0.00 24.81 10 ActiveRecord::QueryMethods#build_select
20.76 0.99 0.00 19.77 10/10 Arel::Table#project
2.53 0.84 0.00 1.69 10/51 Class#new
1.00 1.00 0.00 0.00 10/10 <Class::ActiveRecord::Base>#quoted_table_name
0.52 0.52 0.00 0.00 10/90 Array#empty?
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/51 Class#new
0.00 0.52 0.00 0.00 10/51 Arel::SelectManager#initialize
2.09 0.52 0.00 1.58 1/51 Benchmark#measure
2.53 0.84 0.00 1.69 10/51 ActiveRecord::QueryMethods#build_select
6.11 0.52 0.00 5.59 10/51 SQLite3::Database#prepare
13.55 0.52 0.00 13.03 10/51 Arel::Table#from
0.06% 0.01% 24.28 3.42 0.00 21.89 51 Class#new
12.52 1.63 0.00 10.88 10/10 Arel::SelectManager#initialize
4.44 4.44 0.00 0.00 10/10 SQLite3::Statement#initialize
2.06 2.06 0.00 0.00 31/10041 <Class::BasicObject>#allocate
1.81 1.81 0.00 0.00 10/10 Arel::Nodes::SelectStatement#initialize
1.80 1.80 0.00 0.00 10/10 Arel::Nodes::SelectCore#initialize
1.16 1.16 0.00 0.00 10/10 <Class::SQLite3::Statement>#allocate
1.06 1.06 0.00 0.00 1/1 Benchmark::Tms#initialize
0.84 0.84 0.00 0.00 10/11 <Class::String>#allocate
0.84 0.84 0.00 0.00 10/10 String#initialize
0.00 0.52 0.00 0.00 10/51 Class#new
--------------------------------------------------------------------------------
20.76 0.99 0.00 19.77 10/10 ActiveRecord::QueryMethods#build_select
0.05% 0.00% 20.76 0.99 0.00 19.77 10 Arel::Table#project
14.54 0.99 0.00 13.55 10/10 Arel::Table#from
5.23 1.01 0.00 4.22 10/10 Arel::SelectManager#project
--------------------------------------------------------------------------------
20.62 2.11 0.00 18.51 10/10 Array#map
0.05% 0.01% 20.62 2.11 0.00 18.51 10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
5.88 5.88 0.00 0.00 20/40 Array#join
1.94 1.94 0.00 0.00 10/20 Array#compact
0.52 0.52 0.00 0.00 20/90 Array#empty?
0.00 0.52 0.00 0.00 10/30 Arel::Visitors::Visitor#visit
0.00 0.52 0.00 0.00 10/40 Array#map
--------------------------------------------------------------------------------
16.55 1.00 0.00 15.55 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.04% 0.00% 16.55 1.00 0.00 15.55 10 <Class::ActiveRecord::Base>#current_scoped_methods
14.71 1.00 0.00 13.71 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.84 0.84 0.00 0.00 10/20 Array#last
--------------------------------------------------------------------------------
14.71 1.00 0.00 13.71 10/10 <Class::ActiveRecord::Base>#current_scoped_methods
0.04% 0.00% 14.71 1.00 0.00 13.71 10 <Class::ActiveRecord::Base>#scoped_methods
3.38 0.84 0.00 2.53 10/11 Kernel#dup
3.20 1.07 0.00 2.13 10/10 <Class::ActiveRecord::Base>#default_scoping
2.91 1.04 0.00 1.88 10/10 Object#presence
0.84 0.84 0.00 0.00 10/20 Thread#[]=
0.84 0.84 0.00 0.00 10/10 Thread#[]
0.84 0.84 0.00 0.00 20/60 <Class::Thread>#current
0.84 0.84 0.00 0.00 10/10 String#intern
0.84 0.84 0.00 0.00 10/10 Module#to_s
--------------------------------------------------------------------------------
14.54 0.99 0.00 13.55 10/10 Arel::Table#project
0.04% 0.00% 14.54 0.99 0.00 13.55 10 Arel::Table#from
13.55 0.52 0.00 13.03 10/51 Class#new
--------------------------------------------------------------------------------
12.52 1.63 0.00 10.88 10/10 Class#new
0.03% 0.00% 12.52 1.63 0.00 10.88 10 Arel::SelectManager#initialize
2.85 1.01 0.00 1.84 10/10 Arel::TreeManager#initialize
1.85 1.01 0.00 0.84 10/10 Arel::SelectManager#from
0.52 0.52 0.00 0.00 10/20 Array#last
0.00 0.52 0.00 0.00 10/51 Class#new
--------------------------------------------------------------------------------
11.85 1.01 0.00 10.84 10/10 SQLite3::Database#prepare
0.03% 0.00% 11.85 1.01 0.00 10.84 10 SQLite3::Statement#columns
10.84 1.01 0.00 9.83 10/10 SQLite3::Statement#get_metadata
--------------------------------------------------------------------------------
5.55 5.55 0.00 0.00 20/40 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
5.88 5.88 0.00 0.00 20/40 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.03% 0.03% 11.44 11.44 0.00 0.00 40 Array#join
--------------------------------------------------------------------------------
10.84 1.01 0.00 9.83 10/10 SQLite3::Statement#columns
0.03% 0.00% 10.84 1.01 0.00 9.83 10 SQLite3::Statement#get_metadata
0.84 0.84 0.00 0.00 20/20 Kernel#freeze
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#column_count
0.00 6.45 0.00 0.00 10/11 Integer#times
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10012 <Class::ActiveRecord::Base>#instantiate
0.52 0.52 0.00 0.00 10/10012 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
8.47 1.36 0.00 7.12 2/10012 Arel::Visitors::Visitor#visit
0.02% 0.01% 9.51 2.39 0.00 7.12 10012 Hash#default
7.12 1.46 0.00 5.66 2/2 Proc#yield
--------------------------------------------------------------------------------
3.72 0.84 0.00 2.88 2/22 Benchmark#measure
5.50 0.52 0.00 4.98 20/22 ActiveSupport::Notifications::Instrumenter#instrument
0.02% 0.00% 9.22 1.36 0.00 7.86 22 <Class::Time>#now
5.14 5.14 0.00 0.00 22/22 <Class::Time>#allocate
2.72 1.36 0.00 1.36 22/22 Time#initialize
--------------------------------------------------------------------------------
8.84 0.98 0.00 7.86 1/1 Benchmark::Report#item
0.02% 0.00% 8.84 0.98 0.00 7.86 1 Benchmark::Tms#format
4.38 2.47 0.00 1.90 7/7 String#gsub!
2.39 0.52 0.00 1.88 1/11 Kernel#dup
1.10 1.10 0.00 0.00 1/1 <Module::Kernel>#format
--------------------------------------------------------------------------------
8.75 1.09 0.00 7.65 10/10 <Class::ActiveRecord::Base>#find_by_sql
0.02% 0.00% 8.75 1.09 0.00 7.65 10 <Class::ActiveRecord::Base>#connection
7.65 1.09 0.00 6.56 10/10 <Class::ActiveRecord::Base>#retrieve_connection
--------------------------------------------------------------------------------
8.73 4.28 0.00 4.45 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.02% 0.01% 8.73 4.28 0.00 4.45 10 Kernel#clone
3.61 0.84 0.00 2.76 10/10 Kernel#initialize_clone
0.84 0.84 0.00 0.00 10/10041 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
7.96 1.03 0.00 6.93 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.02% 0.00% 7.96 1.03 0.00 6.93 10 ActiveSupport::Notifications::Fanout#publish
5.90 1.14 0.00 4.76 10/10110 Array#each
1.03 1.03 0.00 0.00 10/10 ActiveSupport::Notifications::Fanout#listeners_for
--------------------------------------------------------------------------------
7.65 1.09 0.00 6.56 10/10 <Class::ActiveRecord::Base>#connection
0.02% 0.00% 7.65 1.09 0.00 6.56 10 <Class::ActiveRecord::Base>#retrieve_connection
6.56 1.08 0.00 5.48 10/10 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
--------------------------------------------------------------------------------
7.53 1.01 0.00 6.52 10/10 SQLite3::Database#prepare
0.02% 0.00% 7.53 1.01 0.00 6.52 10 SQLite3::Statement#bind_params
6.00 6.00 0.00 0.00 10/10010 Array#flatten
0.52 0.52 0.00 0.00 10/10110 Array#each
--------------------------------------------------------------------------------
7.12 1.46 0.00 5.66 2/2 Hash#default
0.02% 0.00% 7.12 1.46 0.00 5.66 2 Proc#yield
2.58 1.55 0.00 1.03 2/140002 Hash#[]=
2.05 2.05 0.00 0.00 2/2 String#gsub
1.03 1.03 0.00 0.00 2/42 Module#name
--------------------------------------------------------------------------------
6.56 1.08 0.00 5.48 10/10 <Class::ActiveRecord::Base>#retrieve_connection
0.02% 0.00% 6.56 1.08 0.00 5.48 10 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
3.42 0.52 0.00 2.91 10/30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
2.06 0.52 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
--------------------------------------------------------------------------------
2.39 0.52 0.00 1.88 1/11 Benchmark::Tms#format
3.38 0.84 0.00 2.53 10/11 <Class::ActiveRecord::Base>#scoped_methods
0.01% 0.00% 5.77 1.36 0.00 4.41 11 Kernel#dup
3.05 1.36 0.00 1.69 11/11 Kernel#initialize_dup
0.84 0.84 0.00 0.00 10/10 <Class::Array>#allocate
0.52 0.52 0.00 0.00 1/11 <Class::String>#allocate
--------------------------------------------------------------------------------
5.63 1.03 0.00 4.59 10/10 ActiveRecord::QueryMethods#build_arel
0.01% 0.00% 5.63 1.03 0.00 4.59 10 ActiveRecord::QueryMethods#collapse_wheres
1.36 0.84 0.00 0.52 10/10 Enumerable#grep
1.36 0.84 0.00 0.52 10/10 Enumerable#group_by
0.84 0.84 0.00 0.00 10/10010 Hash#each
0.52 0.52 0.00 0.00 10/20 Array#-
0.52 0.52 0.00 0.00 10/10110 Array#each
--------------------------------------------------------------------------------
2.44 1.08 0.00 1.36 10/30 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
3.09 1.03 0.00 2.06 20/30 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
0.01% 0.01% 5.53 2.11 0.00 3.42 30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
1.88 1.88 0.00 0.00 30/40 Kernel#object_id
1.55 1.55 0.00 0.00 30/60 <Class::Thread>#current
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
1.92 1.08 0.00 0.84 10/30 <Class::ActiveRecord::Base>#connection_pool
3.42 0.52 0.00 2.91 10/30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
0.01% 0.01% 5.34 2.11 0.00 3.75 30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
1.88 1.88 0.00 0.00 30/42 Module#name
0.84 0.84 0.00 0.00 10/10 Class#superclass
0.52 0.52 0.00 0.00 10/10012 Hash#default
0.00 0.52 0.00 0.00 10/30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
--------------------------------------------------------------------------------
5.23 1.01 0.00 4.22 10/10 Arel::Table#project
0.01% 0.00% 5.23 1.01 0.00 4.22 10 Arel::SelectManager#project
3.38 0.84 0.00 2.53 10/40 Array#map
0.84 0.84 0.00 0.00 10/10 Array#concat
--------------------------------------------------------------------------------
5.17 1.00 0.00 4.18 10/10 <Class::ActiveRecord::Base>#find_by_sql
0.01% 0.00% 5.17 1.00 0.00 4.18 10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
3.66 1.04 0.00 2.62 10/10 String#blank?
0.52 0.52 0.00 0.00 20/30 Module#===
--------------------------------------------------------------------------------
5.14 5.14 0.00 0.00 22/22 <Class::Time>#now
0.01% 0.01% 5.14 5.14 0.00 0.00 22 <Class::Time>#allocate
--------------------------------------------------------------------------------
5.06 0.84 0.00 4.22 2/2 Benchmark#measure
0.01% 0.00% 5.06 0.84 0.00 4.22 2 Time#to_f
4.22 0.84 0.00 3.38 2/2 Numeric#quo
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 ActiveRecord::QueryMethods#collapse_wheres
4.44 4.44 0.00 0.00 10/20 ActiveRecord::QueryMethods#build_arel
0.01% 0.01% 4.95 4.95 0.00 0.00 20 Array#-
--------------------------------------------------------------------------------
4.76 1.66 0.00 3.10 10/10 Array#each
0.01% 0.00% 4.76 1.66 0.00 3.10 10 ActiveSupport::Notifications::Fanout::Subscriber#publish
3.10 1.02 0.00 2.08 10/10 ActiveSupport::LogSubscriber#call
--------------------------------------------------------------------------------
2.06 0.52 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
2.62 1.08 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
0.01% 0.00% 4.69 1.59 0.00 3.09 20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
3.09 1.03 0.00 2.06 20/30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
--------------------------------------------------------------------------------
4.44 4.44 0.00 0.00 10/10 Class#new
0.01% 0.01% 4.44 4.44 0.00 0.00 10 SQLite3::Statement#initialize
--------------------------------------------------------------------------------
4.38 2.47 0.00 1.90 7/7 Benchmark::Tms#format
0.01% 0.01% 4.38 2.47 0.00 1.90 7 String#gsub!
1.90 1.90 0.00 0.00 4/4 String#%
--------------------------------------------------------------------------------
4.22 0.84 0.00 3.38 2/2 Time#to_f
0.01% 0.00% 4.22 0.84 0.00 3.38 2 Numeric#quo
3.38 0.84 0.00 2.53 2/2 Rational#/
--------------------------------------------------------------------------------
3.66 1.04 0.00 2.62 10/10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
0.01% 0.00% 3.66 1.04 0.00 2.62 10 String#blank?
2.62 0.84 0.00 1.78 10/10 Kernel#!~
--------------------------------------------------------------------------------
3.64 0.98 0.00 2.66 2/2 Benchmark#measure
0.01% 0.00% 3.64 0.98 0.00 2.66 2 <Module::Benchmark>#times
2.66 0.84 0.00 1.81 2/2 <Module::Process>#times
--------------------------------------------------------------------------------
3.61 0.84 0.00 2.76 10/10 Kernel#clone
0.01% 0.00% 3.61 0.84 0.00 2.76 10 Kernel#initialize_clone
2.76 1.01 0.00 1.76 10/10 ActiveRecord::Relation#initialize_copy
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10041 Class#allocate
0.84 0.84 0.00 0.00 10/10041 Kernel#clone
2.06 2.06 0.00 0.00 31/10041 Class#new
0.01% 0.01% 3.42 3.42 0.00 0.00 10041 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/42 <Class::ActiveRecord::Base>#find_by_sql
1.03 1.03 0.00 0.00 2/42 Proc#yield
1.88 1.88 0.00 0.00 30/42 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
0.01% 0.01% 3.42 3.42 0.00 0.00 42 Module#name
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/42 <Module::Arel::Visitors>#visitor_for
1.03 1.03 0.00 0.00 2/42 Hash#[]=
1.55 1.55 0.00 0.00 30/42 Arel::Visitors::Visitor#visit
0.01% 0.01% 3.42 3.42 0.00 0.00 42 Kernel#hash
--------------------------------------------------------------------------------
3.38 0.84 0.00 2.53 2/2 Numeric#quo
0.01% 0.00% 3.38 0.84 0.00 2.53 2 Rational#/
1.69 0.84 0.00 0.84 2/2 Rational#to_f
0.84 0.84 0.00 0.00 2/2 Float#/
--------------------------------------------------------------------------------
1.30 1.30 0.00 0.00 10/20 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
1.94 1.94 0.00 0.00 10/20 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.01% 0.01% 3.23 3.23 0.00 0.00 20 Array#compact
--------------------------------------------------------------------------------
3.20 1.07 0.00 2.13 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.01% 0.00% 3.20 1.07 0.00 2.13 10 <Class::ActiveRecord::Base>#default_scoping
2.13 1.07 0.00 1.07 10/10 Class#read_inheritable_attribute
--------------------------------------------------------------------------------
3.10 1.02 0.00 2.08 10/10 ActiveSupport::Notifications::Fanout::Subscriber#publish
0.01% 0.00% 3.10 1.02 0.00 2.08 10 ActiveSupport::LogSubscriber#call
2.08 1.02 0.00 1.06 10/10 ActiveRecord::LogSubscriber#logger
--------------------------------------------------------------------------------
3.05 1.36 0.00 1.69 11/11 Kernel#dup
0.01% 0.00% 3.05 1.36 0.00 1.69 11 Kernel#initialize_dup
0.84 0.84 0.00 0.00 1/1 String#initialize_copy
0.84 0.84 0.00 0.00 10/10 Array#initialize_copy
--------------------------------------------------------------------------------
3.01 1.09 0.00 1.92 10/10 Arel::Visitors::ToSql#accept
0.01% 0.00% 3.01 1.09 0.00 1.92 10 <Class::ActiveRecord::Base>#connection_pool
1.92 1.08 0.00 0.84 10/30 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
--------------------------------------------------------------------------------
2.91 1.04 0.00 1.88 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.01% 0.00% 2.91 1.04 0.00 1.88 10 Object#presence
1.88 1.04 0.00 0.84 10/10 Object#present?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/60 Arel::Visitors::ToSql#last_column=
0.84 0.84 0.00 0.00 20/60 <Class::ActiveRecord::Base>#scoped_methods
1.55 1.55 0.00 0.00 30/60 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
0.01% 0.01% 2.91 2.91 0.00 0.00 60 <Class::Thread>#current
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/90 SQLite3::Database#execute
0.52 0.52 0.00 0.00 10/90 ActiveRecord::QueryMethods#build_select
0.52 0.52 0.00 0.00 10/90 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
0.52 0.52 0.00 0.00 20/90 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.84 0.84 0.00 0.00 40/90 ActiveRecord::QueryMethods#build_arel
0.01% 0.01% 2.91 2.91 0.00 0.00 90 Array#empty?
--------------------------------------------------------------------------------
2.85 1.01 0.00 1.84 10/10 Arel::SelectManager#initialize
0.01% 0.00% 2.85 1.01 0.00 1.84 10 Arel::TreeManager#initialize
1.84 1.00 0.00 0.84 10/10 <Module::Arel::Visitors>#visitor_for
--------------------------------------------------------------------------------
2.84 1.00 0.00 1.84 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.01% 0.00% 2.84 1.00 0.00 1.84 10 <Class::ActiveRecord::Base>#relation
1.84 1.00 0.00 0.84 10/10 <Class::ActiveRecord::Base>#finder_needs_type_condition?
--------------------------------------------------------------------------------
2.76 1.01 0.00 1.76 10/10 Kernel#initialize_clone
0.01% 0.00% 2.76 1.01 0.00 1.76 10 ActiveRecord::Relation#initialize_copy
1.76 1.76 0.00 0.00 10/10 ActiveRecord::Relation#reset
--------------------------------------------------------------------------------
2.72 1.36 0.00 1.36 22/22 <Class::Time>#now
0.01% 0.00% 2.72 1.36 0.00 1.36 22 Time#initialize
1.36 1.36 0.00 0.00 22/22 Fixnum#+
--------------------------------------------------------------------------------
1.03 0.52 0.00 0.52 40/50 ActiveRecord::Relation#eager_loading?
1.69 0.84 0.00 0.84 10/50 ActiveRecord::FinderMethods#all
0.01% 0.00% 2.72 1.36 0.00 1.36 50 Enumerable#any?
1.36 1.36 0.00 0.00 50/10110 Array#each
--------------------------------------------------------------------------------
2.66 0.84 0.00 1.81 2/2 <Module::Benchmark>#times
0.01% 0.00% 2.66 0.84 0.00 1.81 2 <Module::Process>#times
0.97 0.97 0.00 0.00 2/2 <Class::Struct::Tms>#allocate
0.84 0.84 0.00 0.00 2/2 Struct#initialize
--------------------------------------------------------------------------------
2.62 0.84 0.00 1.78 10/10 String#blank?
0.01% 0.00% 2.62 0.84 0.00 1.78 10 Kernel#!~
1.78 1.78 0.00 0.00 10/10 String#=~
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/40 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
1.88 1.88 0.00 0.00 30/40 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
0.01% 0.01% 2.39 2.39 0.00 0.00 40 Kernel#object_id
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/40 Array#map
1.55 1.55 0.00 0.00 30/40 Arel::Visitors::Visitor#visit
0.01% 0.01% 2.39 2.39 0.00 0.00 40 Kernel#class
--------------------------------------------------------------------------------
2.13 1.07 0.00 1.07 10/10 <Class::ActiveRecord::Base>#default_scoping
0.01% 0.00% 2.13 1.07 0.00 1.07 10 Class#read_inheritable_attribute
1.07 1.07 0.00 0.00 10/10 Class#inheritable_attributes
--------------------------------------------------------------------------------
2.08 1.02 0.00 1.06 10/10 ActiveSupport::LogSubscriber#call
0.01% 0.00% 2.08 1.02 0.00 1.06 10 ActiveRecord::LogSubscriber#logger
1.06 1.06 0.00 0.00 10/10 <Class::ActiveRecord::Base>#logger
--------------------------------------------------------------------------------
2.05 2.05 0.00 0.00 2/2 Proc#yield
0.01% 0.01% 2.05 2.05 0.00 0.00 2 String#gsub
--------------------------------------------------------------------------------
2.04 1.01 0.00 1.03 10/10 Arel::Visitors::ToSql#accept
0.01% 0.00% 2.04 1.01 0.00 1.03 10 Arel::Visitors::ToSql#last_column=
0.52 0.52 0.00 0.00 10/20 Thread#[]=
0.52 0.52 0.00 0.00 10/60 <Class::Thread>#current
--------------------------------------------------------------------------------
2.04 1.01 0.00 1.03 20/20 ActiveRecord::Relation#to_a
0.01% 0.00% 2.04 1.01 0.00 1.03 20 ActiveRecord::Relation#eager_loading?
1.03 0.52 0.00 0.52 40/50 Enumerable#any?
--------------------------------------------------------------------------------
2.03 1.00 0.00 1.04 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.01% 0.00% 2.03 1.00 0.00 1.04 10000 <Class::ActiveRecord::Base>#find_sti_class
1.04 1.04 0.00 0.00 10000/10000 NilClass#blank?
--------------------------------------------------------------------------------
2.02 1.01 0.00 1.01 10/10 Arel::Visitors::Visitor#visit
0.00% 0.00% 2.02 1.01 0.00 1.01 10 Arel::Visitors::ToSql#visit_Arel_Table
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#quote_table_name
--------------------------------------------------------------------------------
1.90 1.90 0.00 0.00 4/4 String#gsub!
0.00% 0.00% 1.90 1.90 0.00 0.00 4 String#%
--------------------------------------------------------------------------------
1.88 1.04 0.00 0.84 10/10 Object#presence
0.00% 0.00% 1.88 1.04 0.00 0.84 10 Object#present?
0.84 0.84 0.00 0.00 10/10 Array#blank?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20000/40020 ActiveRecord::Base#_run_initialize_callbacks
0.52 0.52 0.00 0.00 20000/40020 ActiveRecord::Base#_run_find_callbacks
0.84 0.84 0.00 0.00 20/40020 SQLite3::Database#prepare
0.00% 0.00% 1.88 1.88 0.00 0.00 40020 Kernel#block_given?
--------------------------------------------------------------------------------
1.85 1.01 0.00 0.84 10/10 Arel::SelectManager#initialize
0.00% 0.00% 1.85 1.01 0.00 0.84 10 Arel::SelectManager#from
0.84 0.84 0.00 0.00 10/30 Module#===
--------------------------------------------------------------------------------
1.84 1.00 0.00 0.84 10/10 <Class::ActiveRecord::Base>#relation
0.00% 0.00% 1.84 1.00 0.00 0.84 10 <Class::ActiveRecord::Base>#finder_needs_type_condition?
0.84 0.84 0.00 0.00 10/10 Symbol#==
--------------------------------------------------------------------------------
1.84 1.00 0.00 0.84 10/10 Arel::TreeManager#initialize
0.00% 0.00% 1.84 1.00 0.00 0.84 10 <Module::Arel::Visitors>#visitor_for
0.84 0.84 0.00 0.00 10/42 Kernel#hash
--------------------------------------------------------------------------------
1.81 1.81 0.00 0.00 10/10 Class#new
0.00% 0.00% 1.81 1.81 0.00 0.00 10 Arel::Nodes::SelectStatement#initialize
--------------------------------------------------------------------------------
1.80 1.80 0.00 0.00 10/10 Class#new
0.00% 0.00% 1.80 1.80 0.00 0.00 10 Arel::Nodes::SelectCore#initialize
--------------------------------------------------------------------------------
1.78 1.78 0.00 0.00 10/10 Kernel#!~
0.00% 0.00% 1.78 1.78 0.00 0.00 10 String#=~
--------------------------------------------------------------------------------
1.76 1.76 0.00 0.00 10/10 ActiveRecord::Relation#initialize_copy
0.00% 0.00% 1.76 1.76 0.00 0.00 10 ActiveRecord::Relation#reset
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 2/2 Benchmark::Report#item
0.00% 0.00% 1.69 0.84 0.00 0.84 2 Kernel#print
0.84 0.84 0.00 0.00 2/2 IO#write
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 2/2 Rational#/
0.00% 0.00% 1.69 0.84 0.00 0.84 2 Rational#to_f
0.84 0.84 0.00 0.00 2/2 Fixnum#fdiv
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 10/10 Array#map
0.00% 0.00% 1.69 0.84 0.00 0.84 10 Array#include?
0.84 0.84 0.00 0.00 20/20 Module#==
--------------------------------------------------------------------------------
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#init_with
0.00% 0.00% 1.53 1.01 0.00 0.52 10000 ActiveRecord::Base#_run_find_callbacks
0.52 0.52 0.00 0.00 20000/40020 Kernel#block_given?
--------------------------------------------------------------------------------
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#init_with
0.00% 0.00% 1.53 1.01 0.00 0.52 10000 ActiveRecord::Base#_run_initialize_callbacks
0.52 0.52 0.00 0.00 20000/40020 Kernel#block_given?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 1/11 Kernel#dup
0.84 0.84 0.00 0.00 10/11 Class#new
0.00% 0.00% 1.36 1.36 0.00 0.00 11 <Class::String>#allocate
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 22/22 Time#initialize
0.00% 0.00% 1.36 1.36 0.00 0.00 22 Fixnum#+
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 Arel::SelectManager#initialize
0.84 0.84 0.00 0.00 10/20 <Class::ActiveRecord::Base>#current_scoped_methods
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Array#last
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 Arel::Visitors::ToSql#last_column=
0.84 0.84 0.00 0.00 10/20 <Class::ActiveRecord::Base>#scoped_methods
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Thread#[]=
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20/30 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
0.84 0.84 0.00 0.00 10/30 Arel::SelectManager#from
0.00% 0.00% 1.36 1.36 0.00 0.00 30 Module#===
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.00% 0.00% 1.36 0.84 0.00 0.52 10000 Class#allocate
0.52 0.52 0.00 0.00 10000/10041 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 10/10 ActiveRecord::QueryMethods#collapse_wheres
0.00% 0.00% 1.36 0.84 0.00 0.52 10 Enumerable#grep
0.52 0.52 0.00 0.00 10/10110 Array#each
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 10/10 ActiveRecord::QueryMethods#collapse_wheres
0.00% 0.00% 1.36 0.84 0.00 0.52 10 Enumerable#group_by
0.52 0.52 0.00 0.00 10/10110 Array#each
--------------------------------------------------------------------------------
1.16 1.16 0.00 0.00 10/10 Class#new
0.00% 0.00% 1.16 1.16 0.00 0.00 10 <Class::SQLite3::Statement>#allocate
--------------------------------------------------------------------------------
1.10 1.10 0.00 0.00 1/1 Benchmark::Tms#format
0.00% 0.00% 1.10 1.10 0.00 0.00 1 <Module::Kernel>#format
--------------------------------------------------------------------------------
1.07 1.07 0.00 0.00 10/10 Class#read_inheritable_attribute
0.00% 0.00% 1.07 1.07 0.00 0.00 10 Class#inheritable_attributes
--------------------------------------------------------------------------------
1.06 1.06 0.00 0.00 1/1 Class#new
0.00% 0.00% 1.06 1.06 0.00 0.00 1 Benchmark::Tms#initialize
--------------------------------------------------------------------------------
1.06 1.06 0.00 0.00 10/10 ActiveRecord::LogSubscriber#logger
0.00% 0.00% 1.06 1.06 0.00 0.00 10 <Class::ActiveRecord::Base>#logger
--------------------------------------------------------------------------------
1.04 1.04 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#find_sti_class
0.00% 0.00% 1.04 1.04 0.00 0.00 10000 NilClass#blank?
--------------------------------------------------------------------------------
1.03 1.03 0.00 0.00 10/10 ActiveSupport::Notifications::Fanout#publish
0.00% 0.00% 1.03 1.03 0.00 0.00 10 ActiveSupport::Notifications::Fanout#listeners_for
--------------------------------------------------------------------------------
1.02 1.02 0.00 0.00 10/10 <Class::ActiveRecord::Base>#find_by_sql
0.00% 0.00% 1.02 1.02 0.00 0.00 10 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#table_name
--------------------------------------------------------------------------------
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#visit_Arel_Table
0.00% 0.00% 1.01 1.01 0.00 0.00 10 Arel::Visitors::ToSql#quote_table_name
--------------------------------------------------------------------------------
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::Visitor#visit
0.00% 0.00% 1.01 1.01 0.00 0.00 10 Arel::Visitors::ToSql#visit_Fixnum
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.00% 0.00% 1.00 1.00 0.00 0.00 10000 <Class::ActiveRecord::Base>#inheritance_column
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10/10 ActiveRecord::QueryMethods#build_select
0.00% 0.00% 1.00 1.00 0.00 0.00 10 <Class::ActiveRecord::Base>#quoted_table_name
--------------------------------------------------------------------------------
0.97 0.97 0.00 0.00 2/2 <Module::Process>#times
0.00% 0.00% 0.97 0.97 0.00 0.00 2 <Class::Struct::Tms>#allocate
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 1/1 Benchmark::Report#item
0.00% 0.00% 0.84 0.84 0.00 0.00 1 String#ljust
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Kernel#print
0.00% 0.00% 0.84 0.84 0.00 0.00 2 IO#write
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#cstime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#cutime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#stime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#utime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 1/1 Kernel#initialize_dup
0.00% 0.00% 0.84 0.84 0.00 0.00 1 String#initialize_copy
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 <Module::Process>#times
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct#initialize
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Rational#/
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Float#/
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Rational#to_f
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Fixnum#fdiv
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 ActiveRecord::Relation#to_a
0.00% 0.00% 0.84 0.84 0.00 0.00 10 NilClass#nil?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Module#to_s
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.00% 0.00% 0.84 0.84 0.00 0.00 10 String#intern
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::ActiveRecord::Base>#finder_needs_type_condition?
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Symbol#==
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::ActiveRecord::Base>#scoped_methods
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Thread#[]
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Kernel#dup
0.00% 0.00% 0.84 0.84 0.00 0.00 10 <Class::Array>#allocate
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 ActiveRecord::QueryMethods#build_arel
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Array#uniq
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Object#present?
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Array#blank?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Kernel#initialize_dup
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Array#initialize_copy
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Class#new
0.00% 0.00% 0.84 0.84 0.00 0.00 10 String#initialize
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Arel::SelectManager#project
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Array#concat
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Class#superclass
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 140000/140000 Hash#each
0.00% 0.00% 0.84 0.84 0.00 0.00 140000 Kernel#is_a?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 70000/70000 Hash#each
0.00% 0.00% 0.84 0.84 0.00 0.00 70000 String#sub
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 Array#include?
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Module#==
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 SQLite3::Database#execute
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Kernel#nil?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 SQLite3::Database#execute
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Module#const_defined?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 SQLite3::Database#prepare
0.00% 0.00% 0.84 0.84 0.00 0.00 10 SQLite3::Statement#close
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 SQLite3::Statement#get_metadata
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Kernel#freeze
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#get_metadata
0.00% 0.00% 0.84 0.84 0.00 0.00 10 SQLite3::Statement#column_count
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 70/70 Integer#times
0.00% 0.00% 0.84 0.84 0.00 0.00 70 SQLite3::Statement#column_decltype
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 70/70 Integer#times
0.00% 0.00% 0.84 0.84 0.00 0.00 70 SQLite3::Statement#column_name
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10010/10010 Kernel#loop
0.00% 0.00% 0.84 0.84 0.00 0.00 10010 SQLite3::Statement#done?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Statement#step
0.00% 0.00% 0.84 0.84 0.00 0.00 10010 SQLite3::Database#encoding
#!/usr/bin/env ruby
require 'benchmark'
require 'active_record'
require 'ruby-prof'
puts "#{'=' * 20}\n#{ActiveRecord::VERSION::STRING}\n#{'=' * 20}\n"
class Person < ActiveRecord::Base
serialize :extra_info
end
def display_mem_stats
@prev_rss = @current_rss || 0
@current_rss = `ps -o rss= -p #{$$}`.to_i
@prev_obj_count = @current_obj_count || 0
@current_obj_count = ObjectSpace.count_objects[:TOTAL]
puts "=" * 60
puts "RSS : #{@current_rss}k (#{@current_rss - @prev_rss}k)"
puts "Objects : #{@current_obj_count} (#{@current_obj_count - @prev_obj_count})"
puts "=" * 60
end
def setup_database
ActiveRecord::Base.establish_connection(
:adapter => 'sqlite3',
:database => ':memory:',
)
ActiveRecord::Base.silence do
ActiveRecord::Migration.verbose = false
ActiveRecord::Schema.define do
create_table :people, :force => true do |t|
t.string :first_name
t.string :last_name
t.integer :age
t.text :extra_info
t.timestamps
end
end
end
1.upto(1000) do |num|
Person.create :first_name => "Person", :last_name => "Number#{num}", :age => num % 99, :extra_info => {:some_key => 'some_value'}
end
end
setup_database
Benchmark.bm(5) do |x|
display_mem_stats
RubyProf.measure_mode = RubyProf::MEMORY
RubyProf.start
x.report("all") do
10.times do
Person.all
end
end
result = RubyProf.stop
printer = RubyProf::GraphPrinter.new(result)
printer.print
display_mem_stats
end
====================
3.2.0.beta
====================
user system total real
============================================================
RSS : 38504k (38504k)
Objects : 182333 (182333)
============================================================
all 1.120000 0.100000 1.220000 ( 1.215856)
============================================================
RSS : 148956k (110452k)
Objects : 182333 (0)
============================================================
Thread ID: 70213953605260
Total Time: 34161.345703125
%total %self total self wait child calls Name
--------------------------------------------------------------------------------
100.00% 0.01% 34161.35 2.14 0.00 34159.20 1 Global#[No method]
34159.20 0.98 0.00 34158.22 1/1 Benchmark::Report#item
--------------------------------------------------------------------------------
34159.20 0.98 0.00 34158.22 1/1 Global#[No method]
99.99% 0.00% 34159.20 0.98 0.00 34158.22 1 Benchmark::Report#item
34146.18 0.98 0.00 34145.20 1/1 Benchmark#measure
9.51 0.98 0.00 8.53 1/1 Benchmark::Tms#format
1.69 0.84 0.00 0.84 2/2 Kernel#print
0.84 0.84 0.00 0.00 1/1 String#ljust
--------------------------------------------------------------------------------
34146.18 0.98 0.00 34145.20 1/1 Benchmark::Report#item
99.96% 0.00% 34146.18 0.98 0.00 34145.20 1 Benchmark#measure
34127.31 0.84 0.00 34126.47 1/11 Integer#times
5.06 0.84 0.00 4.22 2/2 Time#to_f
3.72 0.84 0.00 2.88 2/22 <Class::Time>#now
3.64 0.98 0.00 2.66 2/2 <Module::Benchmark>#times
2.09 0.52 0.00 1.58 1/90071 Class#new
0.84 0.84 0.00 0.00 2/2 Struct::Tms#utime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#cutime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#cstime
0.84 0.84 0.00 0.00 2/2 Struct::Tms#stime
--------------------------------------------------------------------------------
0.00 6.45 0.00 0.00 10/11 SQLite3::Statement#get_metadata
34127.31 0.84 0.00 34126.47 1/11 Benchmark#measure
99.90% 0.02% 34127.31 7.30 0.00 34126.47 11 Integer#times
34126.47 1.00 0.00 34125.47 10/10 <Class::ActiveRecord::Base>#all
0.84 0.84 0.00 0.00 70/70 SQLite3::Statement#column_name
0.84 0.84 0.00 0.00 70/70 SQLite3::Statement#column_decltype
--------------------------------------------------------------------------------
34126.47 1.00 0.00 34125.47 10/10 Integer#times
99.90% 0.00% 34126.47 1.00 0.00 34125.47 10 <Class::ActiveRecord::Base>#all
34108.42 1.04 0.00 34107.38 10/10 ActiveRecord::FinderMethods#all
17.05 1.01 0.00 16.04 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
--------------------------------------------------------------------------------
34108.42 1.04 0.00 34107.38 10/10 <Class::ActiveRecord::Base>#all
99.85% 0.00% 34108.42 1.04 0.00 34107.38 10 ActiveRecord::FinderMethods#all
34105.70 1.01 0.00 34104.69 10/10 ActiveRecord::Relation#to_a
1.69 0.84 0.00 0.84 10/70 Enumerable#any?
--------------------------------------------------------------------------------
34105.70 1.01 0.00 34104.69 10/10 ActiveRecord::FinderMethods#all
99.84% 0.00% 34105.70 1.01 0.00 34104.69 10 ActiveRecord::Relation#to_a
34034.69 1.00 0.00 34033.69 10/10 <Class::ActiveRecord::Base>#find_by_sql
47.73 1.03 0.00 46.70 10/10 ActiveRecord::QueryMethods#arel
11.37 1.03 0.00 10.35 10/10 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
6.66 1.01 0.00 5.65 10/20 ActiveRecord::Relation#with_default_scope
2.04 1.01 0.00 1.03 20/20 ActiveRecord::Relation#eager_loading?
0.84 0.84 0.00 0.00 20/20 NilClass#nil?
0.84 0.84 0.00 0.00 10/10 BasicObject#equal?
0.52 0.52 0.00 0.00 10/10120 Array#each
--------------------------------------------------------------------------------
34034.69 1.00 0.00 34033.69 10/10 ActiveRecord::Relation#to_a
99.63% 0.00% 34034.69 1.00 0.00 34033.69 10 <Class::ActiveRecord::Base>#find_by_sql
20725.98 0.84 0.00 20725.14 10/10 Array#collect!
13292.57 1.07 0.00 13291.50 10/10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
9.87 1.09 0.00 8.78 10/10 <Class::ActiveRecord::Base>#connection
4.24 1.00 0.00 3.24 10/10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
0.52 0.52 0.00 0.00 10/20 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#table_name
0.52 0.52 0.00 0.00 10/53 Module#name
--------------------------------------------------------------------------------
20725.98 0.84 0.00 20725.14 10/10 <Class::ActiveRecord::Base>#find_by_sql
60.67% 0.00% 20725.98 0.84 0.00 20725.14 10 Array#collect!
20725.14 3594.75 0.00 17130.39 10000/10000 <Class::ActiveRecord::Base>#instantiate
--------------------------------------------------------------------------------
20725.14 3594.75 0.00 17130.39 10000/10000 Array#collect!
60.67% 10.52% 20725.14 3594.75 0.00 17130.39 10000 <Class::ActiveRecord::Base>#instantiate
17122.39 2032.25 0.00 15090.15 10000/10000 ActiveRecord::Base#init_with
2.04 1.01 0.00 1.03 10000/10000 <Module::ActiveRecord::IdentityMap>#enabled
2.03 1.00 0.00 1.04 10000/10000 <Class::ActiveRecord::Base>#find_sti_class
1.36 0.84 0.00 0.52 10000/10000 Class#allocate
1.05 1.05 0.00 0.00 20000/20000 ActiveRecord::AttributeMethods::PrimaryKey::ClassMethods#primary_key
1.00 1.00 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#inheritance_column
0.52 0.52 0.00 0.00 10000/40044 Hash#default
--------------------------------------------------------------------------------
17122.39 2032.25 0.00 15090.15 10000/10000 <Class::ActiveRecord::Base>#instantiate
50.12% 5.95% 17122.39 2032.25 0.00 15090.15 10000 ActiveRecord::Base#init_with
14128.21 1.00 0.00 14127.21 10000/10000 ActiveRecord::Base#set_serialized_attributes
961.94 958.04 0.00 3.90 20000/20000 ActiveSupport::Callbacks#run_callbacks
--------------------------------------------------------------------------------
14128.21 1.00 0.00 14127.21 10000/10000 ActiveRecord::Base#init_with
41.36% 0.00% 14128.21 1.00 0.00 14127.21 10000 ActiveRecord::Base#set_serialized_attributes
14126.69 0.84 0.00 14125.85 10000/10000 Hash#each
0.52 0.52 0.00 0.00 10000/10050 Kernel#class
--------------------------------------------------------------------------------
14126.69 0.84 0.00 14125.85 10000/10000 ActiveRecord::Base#set_serialized_attributes
41.35% 0.00% 14126.69 0.84 0.00 14125.85 10000 Hash#each
14124.82 938.78 0.00 13186.04 10000/10000 ActiveRecord::Coders::YAMLColumn#load
0.52 0.52 0.00 0.00 10000/30004 Hash#[]=
0.52 0.52 0.00 0.00 10000/30010 Hash#key?
--------------------------------------------------------------------------------
14124.82 938.78 0.00 13186.04 10000/10000 Hash#each
41.35% 2.75% 14124.82 938.78 0.00 13186.04 10000 ActiveRecord::Coders::YAMLColumn#load
13185.20 0.97 0.00 13184.22 10000/10000 <Module::Psych>#load
0.84 0.84 0.00 0.00 20000/20000 Kernel#is_a?
--------------------------------------------------------------------------------
13292.57 1.07 0.00 13291.50 10/10 <Class::ActiveRecord::Base>#find_by_sql
38.91% 0.00% 13292.57 1.07 0.00 13291.50 10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
13291.50 1.08 0.00 13290.42 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
--------------------------------------------------------------------------------
13291.50 1.08 0.00 13290.42 10/10 ActiveRecord::ConnectionAdapters::QueryCache#select_all
38.91% 0.00% 13291.50 1.08 0.00 13290.42 10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
13211.30 1.06 0.00 13210.25 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
79.12 1.08 0.00 78.03 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#to_sql
--------------------------------------------------------------------------------
13211.30 1.06 0.00 13210.25 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
38.67% 0.00% 13211.30 1.06 0.00 13210.25 10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
10476.96 0.52 0.00 10476.44 10/20 Enumerable#to_a
2733.29 1.06 0.00 2732.23 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#exec_query
--------------------------------------------------------------------------------
13185.20 0.97 0.00 13184.22 10000/10000 ActiveRecord::Coders::YAMLColumn#load
38.60% 0.00% 13185.20 0.97 0.00 13184.22 10000 <Module::Psych>#load
10024.33 1.00 0.00 10023.33 10000/10000 Psych::Nodes::Node#to_ruby
3159.89 0.97 0.00 3158.92 10000/10000 <Module::Psych>#parse
--------------------------------------------------------------------------------
2685.07 0.84 0.00 2684.23 10/20 ActiveSupport::Notifications::Instrumenter#instrument
10476.96 0.52 0.00 10476.44 10/20 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
38.53% 0.00% 13162.03 1.36 0.00 13160.67 20 Enumerable#to_a
10476.44 1.00 0.00 10475.44 10/10 ActiveRecord::Result#each
2684.23 1.01 0.00 2683.22 10/10 SQLite3::Statement#each
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/50 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.00 0.52 0.00 0.00 10/50 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
3.38 0.84 0.00 2.53 10/50 Arel::SelectManager#project
49.96 0.52 0.00 49.45 10/50 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
10470.95 156.77 0.00 10314.19 10/50 ActiveRecord::Result#hash_rows
30.81% 0.47% 10524.29 159.16 0.00 10366.17 50 Array#map
9219.59 9219.59 0.00 0.00 10000/10000 <Class::Hash>#[]
1094.59 1094.59 0.00 0.00 10000/10000 Array#zip
49.45 2.26 0.00 47.19 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
1.69 0.84 0.00 0.84 10/10 Array#include?
0.84 0.84 0.00 0.00 10/10050 Kernel#class
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
10476.44 1.00 0.00 10475.44 10/10 Enumerable#to_a
30.67% 0.00% 10476.44 1.00 0.00 10475.44 10 ActiveRecord::Result#each
10471.96 1.00 0.00 10470.95 10/10 ActiveRecord::Result#hash_rows
3.48 3.48 0.00 0.00 10/10120 Array#each
--------------------------------------------------------------------------------
10471.96 1.00 0.00 10470.95 10/10 ActiveRecord::Result#each
30.65% 0.00% 10471.96 1.00 0.00 10470.95 10 ActiveRecord::Result#hash_rows
10470.95 156.77 0.00 10314.19 10/50 Array#map
--------------------------------------------------------------------------------
10024.33 1.00 0.00 10023.33 10000/10000 <Module::Psych>#load
29.34% 0.00% 10024.33 1.00 0.00 10023.33 10000 Psych::Nodes::Node#to_ruby
10018.41 1.01 0.00 10017.40 10000/30000 Psych::Visitors::ToRuby#accept
4.92 0.52 0.00 4.40 10000/90071 Class#new
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/10120 ActiveRecord::Relation#to_a
0.52 0.52 0.00 0.00 10/10120 Enumerable#grep
0.52 0.52 0.00 0.00 10/10120 ActiveRecord::QueryMethods#collapse_wheres
2.39 2.39 0.00 0.00 70/10120 Enumerable#any?
3.48 3.48 0.00 0.00 10/10120 ActiveRecord::Result#each
5.90 1.14 0.00 4.76 10/10120 ActiveSupport::Notifications::Fanout#publish
10010.79 0.52 0.00 10010.28 10000/10120 Enumerable#each_slice
29.34% 0.03% 10024.12 9.08 0.00 10015.04 10120 Array#each
3594.27 3594.27 0.00 0.00 10000/30004 Hash#[]=
4.76 1.66 0.00 3.10 10/10 ActiveSupport::Notifications::Fanout::Subscriber#publish
0.52 0.52 0.00 0.00 10000/10010 Symbol#==
0.00 0.52 0.00 0.00 20000/30000 Psych::Visitors::ToRuby#accept
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 20000/30000 Array#each
10018.41 1.01 0.00 10017.40 10000/30000 Psych::Nodes::Node#to_ruby
29.33% 0.00% 10018.41 1.52 0.00 10017.40 30000 Psych::Visitors::ToRuby#accept
10016.89 1.52 0.00 10015.88 30000/30000 Psych::Visitors::Visitor#accept
1.36 1.36 0.00 0.00 30000/30000 Hash#empty?
--------------------------------------------------------------------------------
10016.89 1.52 0.00 10015.88 30000/30000 Psych::Visitors::ToRuby#accept
29.32% 0.00% 10016.89 1.52 0.00 10015.88 30000 Psych::Visitors::Visitor#accept
10015.37 1.01 0.00 10014.36 10000/10000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
6413.11 1.01 0.00 6412.10 20000/20000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Scalar
1.03 1.03 0.00 0.00 40000/40061 Module#===
--------------------------------------------------------------------------------
10015.37 1.01 0.00 10014.36 10000/10000 Psych::Visitors::Visitor#accept
29.32% 0.00% 10015.37 1.01 0.00 10014.36 10000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
10011.64 0.84 0.00 10010.79 10000/10000 Enumerable#each_slice
1.36 0.84 0.00 0.52 70000/70000 String#===
0.84 0.84 0.00 0.00 30000/110000 Regexp#===
0.52 0.52 0.00 0.00 10000/40044 Hash#default
--------------------------------------------------------------------------------
10011.64 0.84 0.00 10010.79 10000/10000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
29.31% 0.00% 10011.64 0.84 0.00 10010.79 10000 Enumerable#each_slice
10010.79 0.52 0.00 10010.28 10000/10120 Array#each
--------------------------------------------------------------------------------
9219.59 9219.59 0.00 0.00 10000/10000 Array#map
26.99% 26.99% 9219.59 9219.59 0.00 0.00 10000 <Class::Hash>#[]
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/30004 Hash#each
0.61 0.61 0.00 0.00 1/30004 Arel::Visitors::ToSql#quote_column_name
3.70 2.16 0.00 1.55 3/30004 Proc#yield
3594.27 3594.27 0.00 0.00 10000/30004 Array#each
3594.27 3594.27 0.00 0.00 10000/30004 Psych::ScalarScanner#tokenize
21.06% 21.05% 7193.36 7191.81 0.00 1.55 30004 Hash#[]=
1.55 1.55 0.00 0.00 3/43 Kernel#hash
--------------------------------------------------------------------------------
6413.11 1.01 0.00 6412.10 20000/20000 Psych::Visitors::Visitor#accept
18.77% 0.00% 6413.11 1.01 0.00 6412.10 20000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Scalar
6411.58 1.00 0.00 6410.58 20000/20000 Psych::ScalarScanner#tokenize
0.52 0.52 0.00 0.00 20000/40044 Hash#default
--------------------------------------------------------------------------------
6411.58 1.00 0.00 6410.58 20000/20000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Scalar
18.77% 0.00% 6411.58 1.00 0.00 6410.58 20000 Psych::ScalarScanner#tokenize
3594.27 3594.27 0.00 0.00 10000/30004 Hash#[]=
1875.77 1875.77 0.00 0.00 80000/110000 Regexp#===
938.34 938.34 0.00 0.00 10000/10000 String#sub
0.84 0.84 0.00 0.00 10000/10000 String#to_sym
0.84 0.84 0.00 0.00 20000/20000 String#empty?
0.52 0.52 0.00 0.00 20000/30010 Hash#key?
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/90071 Arel::Nodes::SelectCore#initialize
0.00 0.52 0.00 0.00 10/90071 Arel::SelectManager#initialize
0.00 0.52 0.00 0.00 10/90071 Class#new
0.00 0.52 0.00 0.00 10000/90071 Psych::Visitors::ToRuby#initialize
2.03 0.52 0.00 1.52 10/90071 ActiveSupport::Notifications::Instrumenter#instrument
2.09 0.52 0.00 1.58 1/90071 Benchmark#measure
2.20 0.52 0.00 1.69 10/90071 <Module::Arel>#sql
3.02 0.52 0.00 2.50 20000/90071 <Module::Psych>#parser
3.03 0.52 0.00 2.51 10000/90071 Psych::TreeBuilder#start_stream
4.92 0.52 0.00 4.40 10000/90071 Psych::Nodes::Node#to_ruby
6.11 0.52 0.00 5.59 10/90071 SQLite3::Database#prepare
14.78 0.84 0.00 13.93 10/90071 Arel::Table#from
783.80 0.52 0.00 783.28 10000/90071 Psych::TreeBuilder#start_mapping
783.80 0.52 0.00 783.29 10000/90071 Psych::TreeBuilder#start_document
1564.53 0.52 0.00 1564.02 20000/90071 Psych::TreeBuilder#scalar
9.28% 0.02% 3170.31 8.06 0.00 3164.31 90071 Class#new
1563.50 1563.50 0.00 0.00 20000/20000 Psych::Nodes::Scalar#initialize
782.77 782.25 0.00 0.52 10000/10000 Psych::Nodes::Document#initialize
782.77 782.25 0.00 0.52 10000/10000 Psych::Nodes::Mapping#initialize
13.42 1.01 0.00 12.41 10/10 Arel::SelectManager#initialize
6.70 6.70 0.00 0.00 90051/100061 <Class::BasicObject>#allocate
4.84 1.79 0.00 3.05 10/10 Arel::Nodes::SelectCore#initialize
4.44 4.44 0.00 0.00 10/10 SQLite3::Statement#initialize
3.89 1.01 0.00 2.88 10000/10000 Psych::Visitors::ToRuby#initialize
2.02 1.01 0.00 1.00 10/10 Arel::Nodes::JoinSource#initialize
2.00 1.00 0.00 1.00 10000/10000 Psych::Nodes::Stream#initialize
1.80 1.80 0.00 0.00 10/10 Arel::Nodes::SelectStatement#initialize
1.16 1.16 0.00 0.00 10/10 <Class::SQLite3::Statement>#allocate
1.06 1.06 0.00 0.00 1/1 Benchmark::Tms#initialize
1.00 1.00 0.00 0.00 10000/10000 Psych::ScalarScanner#initialize
1.00 1.00 0.00 0.00 10/10 ActiveRecord::Result#initialize
1.00 1.00 0.00 0.00 10000/10000 Psych::TreeBuilder#initialize
0.99 0.99 0.00 0.00 10000/10000 Psych::Parser#initialize
0.84 0.84 0.00 0.00 10/11 <Class::String>#allocate
0.84 0.84 0.00 0.00 10/10 String#initialize
0.00 0.52 0.00 0.00 10/90071 Class#new
--------------------------------------------------------------------------------
3159.89 0.97 0.00 3158.92 10000/10000 <Module::Psych>#load
9.25% 0.00% 3159.89 0.97 0.00 3158.92 10000 <Module::Psych>#parse
3157.56 0.97 0.00 3156.59 10000/10000 <Module::Psych>#parse_stream
0.84 0.84 0.00 0.00 20000/20000 Array#first
0.52 0.52 0.00 0.00 10000/10110 Array#empty?
--------------------------------------------------------------------------------
3157.56 0.97 0.00 3156.59 10000/10000 <Module::Psych>#parse
9.24% 0.00% 3157.56 0.97 0.00 3156.59 10000 <Module::Psych>#parse_stream
3152.59 0.84 0.00 3151.75 10000/10000 Psych::Parser#parse
3.99 0.97 0.00 3.02 10000/10000 <Module::Psych>#parser
--------------------------------------------------------------------------------
3152.59 0.84 0.00 3151.75 10000/10000 <Module::Psych>#parse_stream
9.23% 0.00% 3152.59 0.84 0.00 3151.75 10000 Psych::Parser#parse
1565.53 1.00 0.00 1564.53 20000/20000 Psych::TreeBuilder#scalar
785.83 1.00 0.00 784.83 10000/10000 Psych::TreeBuilder#start_document
785.69 0.86 0.00 784.83 10000/10000 Psych::TreeBuilder#start_mapping
5.87 1.00 0.00 4.87 10000/10000 Psych::TreeBuilder#start_stream
3.22 0.86 0.00 2.36 10000/10000 Psych::TreeBuilder#end_mapping
2.55 1.00 0.00 1.55 10000/10000 Psych::TreeBuilder#end_stream
2.55 1.00 0.00 1.55 10000/10000 Psych::TreeBuilder#end_document
0.52 0.52 0.00 0.00 10000/80010 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
2733.29 1.06 0.00 2732.23 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#select
8.00% 0.00% 2733.29 1.06 0.00 2732.23 10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#exec_query
2732.23 7.47 0.00 2724.77 10/10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
--------------------------------------------------------------------------------
2732.23 7.47 0.00 2724.77 10/10 ActiveRecord::ConnectionAdapters::SQLiteAdapter#exec_query
8.00% 0.02% 2732.23 7.47 0.00 2724.77 10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
2724.25 1.67 0.00 2722.58 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.52 0.52 0.00 0.00 10/40 Kernel#object_id
--------------------------------------------------------------------------------
2724.25 1.67 0.00 2722.58 10/10 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
7.97% 0.00% 2724.25 1.67 0.00 2722.58 10 ActiveSupport::Notifications::Instrumenter#instrument
2685.07 0.84 0.00 2684.23 10/20 Enumerable#to_a
11.85 1.01 0.00 10.84 10/10 SQLite3::Statement#columns
7.96 1.03 0.00 6.93 10/10 ActiveSupport::Notifications::Fanout#publish
7.96 1.01 0.00 6.95 10/10 SQLite3::Database#prepare
5.50 0.52 0.00 4.98 20/22 <Class::Time>#now
2.03 0.52 0.00 1.52 10/90071 Class#new
0.84 0.84 0.00 0.00 10/10 Array#to_a
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#close
0.52 0.52 0.00 0.00 10/10110 Array#empty?
--------------------------------------------------------------------------------
2684.23 1.01 0.00 2683.22 10/10 Enumerable#to_a
7.86% 0.00% 2684.23 1.01 0.00 2683.22 10 SQLite3::Statement#each
2683.22 3.81 0.00 2679.41 10/10 Kernel#loop
--------------------------------------------------------------------------------
2683.22 3.81 0.00 2679.41 10/10 SQLite3::Statement#each
7.85% 0.01% 2683.22 3.81 0.00 2679.41 10 Kernel#loop
2678.56 2677.72 0.00 0.84 10010/10010 SQLite3::Statement#step
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Statement#done?
--------------------------------------------------------------------------------
2678.56 2677.72 0.00 0.84 10010/10010 Kernel#loop
7.84% 7.84% 2678.56 2677.72 0.00 0.84 10010 SQLite3::Statement#step
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Database#encoding
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 30000/110000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
1875.77 1875.77 0.00 0.00 80000/110000 Psych::ScalarScanner#tokenize
5.49% 5.49% 1876.61 1876.61 0.00 0.00 110000 Regexp#===
--------------------------------------------------------------------------------
1565.53 1.00 0.00 1564.53 20000/20000 Psych::Parser#parse
4.58% 0.00% 1565.53 1.00 0.00 1564.53 20000 Psych::TreeBuilder#scalar
1564.53 0.52 0.00 1564.02 20000/90071 Class#new
--------------------------------------------------------------------------------
1563.50 1563.50 0.00 0.00 20000/20000 Class#new
4.58% 4.58% 1563.50 1563.50 0.00 0.00 20000 Psych::Nodes::Scalar#initialize
--------------------------------------------------------------------------------
1094.59 1094.59 0.00 0.00 10000/10000 Array#map
3.20% 3.20% 1094.59 1094.59 0.00 0.00 10000 Array#zip
--------------------------------------------------------------------------------
961.94 958.04 0.00 3.90 20000/20000 ActiveRecord::Base#init_with
2.82% 2.80% 961.94 958.04 0.00 3.90 20000 ActiveSupport::Callbacks#run_callbacks
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#_run_initialize_callbacks
1.53 1.01 0.00 0.52 10000/10000 ActiveRecord::Base#_run_find_callbacks
0.84 0.84 0.00 0.00 20000/20000 Symbol#to_s
--------------------------------------------------------------------------------
938.34 938.34 0.00 0.00 10000/10000 Psych::ScalarScanner#tokenize
2.75% 2.75% 938.34 938.34 0.00 0.00 10000 String#sub
--------------------------------------------------------------------------------
785.83 1.00 0.00 784.83 10000/10000 Psych::Parser#parse
2.30% 0.00% 785.83 1.00 0.00 784.83 10000 Psych::TreeBuilder#start_document
783.80 0.52 0.00 783.29 10000/90071 Class#new
1.03 0.52 0.00 0.52 10000/30000 Psych::TreeBuilder#push
--------------------------------------------------------------------------------
785.69 0.86 0.00 784.83 10000/10000 Psych::Parser#parse
2.30% 0.00% 785.69 0.86 0.00 784.83 10000 Psych::TreeBuilder#start_mapping
783.80 0.52 0.00 783.28 10000/90071 Class#new
1.03 0.52 0.00 0.52 10000/30000 Psych::TreeBuilder#push
--------------------------------------------------------------------------------
782.77 782.25 0.00 0.52 10000/10000 Class#new
2.29% 2.29% 782.77 782.25 0.00 0.52 10000 Psych::Nodes::Document#initialize
0.52 0.52 0.00 0.00 10000/30000 Psych::Nodes::Node#initialize
--------------------------------------------------------------------------------
782.77 782.25 0.00 0.52 10000/10000 Class#new
2.29% 2.29% 782.77 782.25 0.00 0.52 10000 Psych::Nodes::Mapping#initialize
0.52 0.52 0.00 0.00 10000/30000 Psych::Nodes::Node#initialize
--------------------------------------------------------------------------------
79.12 1.08 0.00 78.03 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#select_all
0.23% 0.00% 79.12 1.08 0.00 78.03 10 ActiveRecord::ConnectionAdapters::DatabaseStatements#to_sql
77.52 1.01 0.00 76.51 10/10 Arel::Visitors::ToSql#accept
0.52 0.52 0.00 0.00 10/20 Kernel#respond_to?
--------------------------------------------------------------------------------
77.52 1.01 0.00 76.51 10/10 ActiveRecord::ConnectionAdapters::DatabaseStatements#to_sql
0.23% 0.00% 77.52 1.01 0.00 76.51 10 Arel::Visitors::ToSql#accept
74.14 1.08 0.00 73.06 10/10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
2.37 1.01 0.00 1.36 10/20 Arel::Visitors::ToSql#last_column=
--------------------------------------------------------------------------------
74.14 1.08 0.00 73.06 10/10 Arel::Visitors::ToSql#accept
0.22% 0.00% 74.14 1.08 0.00 73.06 10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
69.45 1.01 0.00 68.44 10/10 Arel::Visitors::Visitor#accept
2.06 0.52 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
1.55 0.52 0.00 1.03 10/30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
--------------------------------------------------------------------------------
69.45 1.01 0.00 68.44 10/10 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
0.20% 0.00% 69.45 1.01 0.00 68.44 10 Arel::Visitors::Visitor#accept
68.44 1.01 0.00 67.43 10/40 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
0.00 0.52 0.00 0.00 10/40 Array#map
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
68.44 1.01 0.00 67.43 10/40 Arel::Visitors::Visitor#accept
0.20% 0.01% 68.44 2.56 0.00 67.43 40 Arel::Visitors::Visitor#visit
60.44 1.01 0.00 59.43 10/10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
16.60 1.01 0.00 15.59 10/10 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
11.87 1.55 0.00 10.32 3/40044 Hash#default
9.51 1.01 0.00 8.50 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
2.56 2.56 0.00 0.00 40/40 Arel::Visitors::Visitor#dispatch
2.39 2.39 0.00 0.00 40/43 Kernel#hash
2.06 2.06 0.00 0.00 40/10050 Kernel#class
2.04 1.01 0.00 1.03 10/10 Arel::Visitors::ToSql#visit_Arel_Table
--------------------------------------------------------------------------------
60.44 1.01 0.00 59.43 10/10 Arel::Visitors::Visitor#visit
0.18% 0.00% 60.44 1.01 0.00 59.43 10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
59.43 1.95 0.00 57.49 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
--------------------------------------------------------------------------------
59.43 1.95 0.00 57.49 10/10 Arel::Visitors::SQLite#visit_Arel_Nodes_SelectStatement
0.17% 0.01% 59.43 1.95 0.00 57.49 10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
49.96 0.52 0.00 49.45 10/50 Array#map
5.55 5.55 0.00 0.00 20/60 Array#join
1.45 1.45 0.00 0.00 10/30 Array#compact
0.52 0.52 0.00 0.00 10/10110 Array#empty?
--------------------------------------------------------------------------------
49.45 2.26 0.00 47.19 10/10 Array#map
0.14% 0.01% 49.45 2.26 0.00 47.19 10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
5.88 5.88 0.00 0.00 20/60 Array#join
1.77 1.77 0.00 0.00 10/30 Array#compact
1.01 1.01 0.00 0.00 10/10 Arel::Nodes::JoinSource#empty?
0.52 0.52 0.00 0.00 30/10110 Array#empty?
0.00 0.52 0.00 0.00 10/50 Array#map
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
47.73 1.03 0.00 46.70 10/10 ActiveRecord::Relation#to_a
0.14% 0.00% 47.73 1.03 0.00 46.70 10 ActiveRecord::QueryMethods#arel
41.99 1.03 0.00 40.96 10/10 ActiveRecord::QueryMethods#build_arel
4.70 0.52 0.00 4.19 10/20 ActiveRecord::Relation#with_default_scope
--------------------------------------------------------------------------------
41.99 1.03 0.00 40.96 10/10 ActiveRecord::QueryMethods#arel
0.12% 0.00% 41.99 1.03 0.00 40.96 10 ActiveRecord::QueryMethods#build_arel
15.77 0.99 0.00 14.78 10/10 Arel::Table#from
15.13 1.03 0.00 14.09 10/10 ActiveRecord::QueryMethods#build_select
4.44 4.44 0.00 0.00 10/20 Array#-
3.94 1.03 0.00 2.91 10/10 ActiveRecord::QueryMethods#collapse_wheres
0.84 0.84 0.00 0.00 40/10110 Array#empty?
0.84 0.84 0.00 0.00 20/20 Array#uniq
--------------------------------------------------------------------------------
17.05 1.01 0.00 16.04 10/10 <Class::ActiveRecord::Base>#all
0.05% 0.00% 17.05 1.01 0.00 16.04 10 ActiveRecord::NamedScope::ClassMethods#scoped
9.67 5.22 0.00 4.45 10/10 Kernel#clone
3.53 1.00 0.00 2.53 10/10 <Class::ActiveRecord::Base>#current_scope
2.84 1.00 0.00 1.84 10/10 <Class::ActiveRecord::Base>#relation
--------------------------------------------------------------------------------
16.60 1.01 0.00 15.59 10/10 Arel::Visitors::Visitor#visit
0.05% 0.00% 16.60 1.01 0.00 15.59 10 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
8.00 1.01 0.00 6.99 10/10 Arel::Visitors::ToSql#column_for
3.49 1.01 0.00 2.48 10/10 Arel::Visitors::ToSql#quote_column_name
1.55 0.52 0.00 1.03 10/20 Arel::Visitors::ToSql#last_column=
1.53 1.01 0.00 0.52 10/20 Arel::Visitors::ToSql#quote_table_name
0.52 0.52 0.00 0.00 20/30 #<Class:0x007fb7ebd32688>#relation
0.52 0.52 0.00 0.00 10/20 #<Class:0x007fb7ebd32688>#name
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20000/40044 Psych::Visitors::ToRuby#visit_Psych_Nodes_Scalar
0.52 0.52 0.00 0.00 10/40044 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
0.52 0.52 0.00 0.00 10000/40044 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
0.52 0.52 0.00 0.00 10/40044 Arel::Visitors::ToSql#column_for
0.52 0.52 0.00 0.00 10000/40044 <Class::ActiveRecord::Base>#instantiate
0.52 0.52 0.00 0.00 1/40044 Arel::Visitors::ToSql#quote_column_name
1.36 1.36 0.00 0.00 20/40044 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
11.87 1.55 0.00 10.32 3/40044 Arel::Visitors::Visitor#visit
0.05% 0.02% 16.32 6.00 0.00 10.32 40044 Hash#default
10.32 2.16 0.00 8.16 3/3 Proc#yield
--------------------------------------------------------------------------------
15.77 0.99 0.00 14.78 10/10 ActiveRecord::QueryMethods#build_arel
0.05% 0.00% 15.77 0.99 0.00 14.78 10 Arel::Table#from
14.78 0.84 0.00 13.93 10/90071 Class#new
--------------------------------------------------------------------------------
15.13 1.03 0.00 14.09 10/10 ActiveRecord::QueryMethods#build_arel
0.04% 0.00% 15.13 1.03 0.00 14.09 10 ActiveRecord::QueryMethods#build_select
5.23 1.01 0.00 4.22 10/10 Arel::SelectManager#project
4.16 0.98 0.00 3.18 10/10 <Module::Arel>#star
3.19 0.99 0.00 2.20 10/10 Arel::Table#[]
1.00 1.00 0.00 0.00 10/10 <Class::ActiveRecord::Base>#arel_table
0.52 0.52 0.00 0.00 10/10110 Array#empty?
--------------------------------------------------------------------------------
3.04 3.04 0.00 0.00 20/60 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
5.55 5.55 0.00 0.00 20/60 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
5.88 5.88 0.00 0.00 20/60 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.04% 0.04% 14.47 14.47 0.00 0.00 60 Array#join
--------------------------------------------------------------------------------
13.42 1.01 0.00 12.41 10/10 Class#new
0.04% 0.00% 13.42 1.01 0.00 12.41 10 Arel::SelectManager#initialize
1.85 1.01 0.00 0.84 10/10 Arel::SelectManager#from
1.00 1.00 0.00 0.00 10/10 Arel::TreeManager#initialize
0.84 0.84 0.00 0.00 10/30010 Array#last
0.00 0.52 0.00 0.00 10/90071 Class#new
--------------------------------------------------------------------------------
11.85 1.01 0.00 10.84 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.03% 0.00% 11.85 1.01 0.00 10.84 10 SQLite3::Statement#columns
10.84 1.01 0.00 9.83 10/10 SQLite3::Statement#get_metadata
--------------------------------------------------------------------------------
11.37 1.03 0.00 10.35 10/10 ActiveRecord::Relation#to_a
0.03% 0.00% 11.37 1.03 0.00 10.35 10 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
7.75 1.00 0.00 6.75 10/10 <Class::ActiveRecord::Base>#columns_hash
1.06 1.06 0.00 0.00 10/10 <Class::ActiveRecord::Base>#lock_optimistically
1.02 1.02 0.00 0.00 10/10 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#locking_column
0.52 0.52 0.00 0.00 10/40044 Hash#default
--------------------------------------------------------------------------------
4.70 0.52 0.00 4.19 10/20 ActiveRecord::QueryMethods#arel
6.66 1.01 0.00 5.65 10/20 ActiveRecord::Relation#to_a
0.03% 0.00% 11.36 1.52 0.00 9.84 20 ActiveRecord::Relation#with_default_scope
9.84 1.51 0.00 8.33 20/20 <Class::ActiveRecord::Base>#build_default_scope
--------------------------------------------------------------------------------
10.84 1.01 0.00 9.83 10/10 SQLite3::Statement#columns
0.03% 0.00% 10.84 1.01 0.00 9.83 10 SQLite3::Statement#get_metadata
0.84 0.84 0.00 0.00 20/20 Kernel#freeze
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#column_count
0.00 6.45 0.00 0.00 10/11 Integer#times
--------------------------------------------------------------------------------
10.32 2.16 0.00 8.16 3/3 Hash#default
0.03% 0.01% 10.32 2.16 0.00 8.16 3 Proc#yield
3.70 2.16 0.00 1.55 3/30004 Hash#[]=
2.91 2.91 0.00 0.00 3/3 String#gsub
1.55 1.55 0.00 0.00 3/53 Module#name
--------------------------------------------------------------------------------
9.87 1.09 0.00 8.78 10/10 <Class::ActiveRecord::Base>#find_by_sql
0.03% 0.00% 9.87 1.09 0.00 8.78 10 <Class::ActiveRecord::Base>#connection
8.78 1.09 0.00 7.68 10/10 <Class::ActiveRecord::Base>#retrieve_connection
--------------------------------------------------------------------------------
9.84 1.51 0.00 8.33 20/20 ActiveRecord::Relation#with_default_scope
0.03% 0.00% 9.84 1.51 0.00 8.33 20 <Class::ActiveRecord::Base>#build_default_scope
3.55 3.55 0.00 0.00 20/20 Kernel#method
2.06 1.03 0.00 1.03 20/70 Enumerable#any?
1.36 1.36 0.00 0.00 20/20 Method#owner
1.36 1.36 0.00 0.00 20/20 Kernel#singleton_class
--------------------------------------------------------------------------------
9.67 5.22 0.00 4.45 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.03% 0.02% 9.67 5.22 0.00 4.45 10 Kernel#clone
3.61 0.84 0.00 2.76 10/10 Kernel#initialize_clone
0.84 0.84 0.00 0.00 10/100061 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
9.51 0.98 0.00 8.53 1/1 Benchmark::Report#item
0.03% 0.00% 9.51 0.98 0.00 8.53 1 Benchmark::Tms#format
4.38 2.47 0.00 1.91 7/7 String#gsub!
3.05 0.84 0.00 2.20 1/1 Kernel#dup
1.10 1.10 0.00 0.00 1/1 <Module::Kernel>#format
--------------------------------------------------------------------------------
9.51 1.01 0.00 8.50 10/10 Arel::Visitors::Visitor#visit
0.03% 0.00% 9.51 1.01 0.00 8.50 10 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
3.04 3.04 0.00 0.00 20/60 Array#join
0.84 0.84 0.00 0.00 10/30 Array#compact
0.00 0.52 0.00 0.00 10/50 Array#map
0.00 0.52 0.00 0.00 10/40 Arel::Visitors::Visitor#visit
--------------------------------------------------------------------------------
3.72 0.84 0.00 2.88 2/22 Benchmark#measure
5.50 0.52 0.00 4.98 20/22 ActiveSupport::Notifications::Instrumenter#instrument
0.03% 0.00% 9.22 1.36 0.00 7.86 22 <Class::Time>#now
5.14 5.14 0.00 0.00 22/22 <Class::Time>#allocate
2.72 1.36 0.00 1.36 22/22 Time#initialize
--------------------------------------------------------------------------------
8.78 1.09 0.00 7.68 10/10 <Class::ActiveRecord::Base>#connection
0.03% 0.00% 8.78 1.09 0.00 7.68 10 <Class::ActiveRecord::Base>#retrieve_connection
7.68 1.08 0.00 6.61 10/10 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/100061 Class#allocate
0.84 0.84 0.00 0.00 10/100061 Kernel#clone
6.70 6.70 0.00 0.00 90051/100061 Class#new
0.02% 0.02% 8.06 8.06 0.00 0.00 100061 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
8.00 1.01 0.00 6.99 10/10 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
0.02% 0.00% 8.00 1.01 0.00 6.99 10 Arel::Visitors::ToSql#column_for
2.93 1.01 0.00 1.92 10/10 Arel::Visitors::ToSql#table_exists?
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#column_cache
0.84 0.84 0.00 0.00 10/20 #<Class:0x007fb7ebd32688>#name
0.84 0.84 0.00 0.00 10/30 #<Class:0x007fb7ebd32688>#relation
0.84 0.84 0.00 0.00 10/10 String#to_s
0.52 0.52 0.00 0.00 10/40044 Hash#default
--------------------------------------------------------------------------------
7.96 1.03 0.00 6.93 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.02% 0.00% 7.96 1.03 0.00 6.93 10 ActiveSupport::Notifications::Fanout#publish
5.90 1.14 0.00 4.76 10/10120 Array#each
1.03 1.03 0.00 0.00 10/10 ActiveSupport::Notifications::Fanout#listeners_for
--------------------------------------------------------------------------------
7.96 1.01 0.00 6.95 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.02% 0.00% 7.96 1.01 0.00 6.95 10 SQLite3::Database#prepare
6.11 0.52 0.00 5.59 10/90071 Class#new
0.84 0.84 0.00 0.00 10/40010 Kernel#block_given?
--------------------------------------------------------------------------------
7.75 1.00 0.00 6.75 10/10 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
0.02% 0.00% 7.75 1.00 0.00 6.75 10 <Class::ActiveRecord::Base>#columns_hash
5.73 1.09 0.00 4.64 10/10 <Class::ActiveRecord::Base>#connection_pool
1.02 1.02 0.00 0.00 10/20 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#table_name
--------------------------------------------------------------------------------
0.00 1.03 0.00 0.00 20/40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
3.09 0.52 0.00 2.58 10/40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
4.64 1.08 0.00 3.56 10/40 <Class::ActiveRecord::Base>#connection_pool
0.02% 0.01% 7.73 2.62 0.00 6.14 40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
2.39 2.39 0.00 0.00 40/53 Module#name
1.36 1.36 0.00 0.00 20/20 Class#superclass
1.36 1.36 0.00 0.00 20/40044 Hash#default
0.00 1.03 0.00 0.00 20/40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
--------------------------------------------------------------------------------
7.68 1.08 0.00 6.61 10/10 <Class::ActiveRecord::Base>#retrieve_connection
0.02% 0.00% 7.68 1.08 0.00 6.61 10 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
3.51 1.08 0.00 2.44 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
3.09 0.52 0.00 2.58 10/40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
--------------------------------------------------------------------------------
5.87 1.00 0.00 4.87 10000/10000 Psych::Parser#parse
0.02% 0.00% 5.87 1.00 0.00 4.87 10000 Psych::TreeBuilder#start_stream
3.03 0.52 0.00 2.51 10000/90071 Class#new
1.84 1.00 0.00 0.84 10000/30000 Psych::TreeBuilder#push
--------------------------------------------------------------------------------
5.73 1.09 0.00 4.64 10/10 <Class::ActiveRecord::Base>#columns_hash
0.02% 0.00% 5.73 1.09 0.00 4.64 10 <Class::ActiveRecord::Base>#connection_pool
4.64 1.08 0.00 3.56 10/40 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
--------------------------------------------------------------------------------
2.06 0.52 0.00 1.55 10/20 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
3.51 1.08 0.00 2.44 10/20 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection
0.02% 0.00% 5.57 1.59 0.00 3.98 20 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
3.98 1.59 0.00 2.39 20/30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
--------------------------------------------------------------------------------
1.55 0.52 0.00 1.03 10/30 ActiveRecord::ConnectionAdapters::ConnectionPool#with_connection
3.98 1.59 0.00 2.39 20/30 ActiveRecord::ConnectionAdapters::ConnectionPool#connection
0.02% 0.01% 5.53 2.11 0.00 3.42 30 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
1.88 1.88 0.00 0.00 30/40 Kernel#object_id
1.55 1.55 0.00 0.00 30/10060 <Class::Thread>#current
--------------------------------------------------------------------------------
1.55 0.52 0.00 1.03 10000/30000 Psych::TreeBuilder#end_stream
1.55 0.52 0.00 1.03 10000/30000 Psych::TreeBuilder#end_document
2.36 1.00 0.00 1.36 10000/30000 Psych::TreeBuilder#end_mapping
0.02% 0.01% 5.45 2.03 0.00 3.42 30000 Psych::TreeBuilder#pop
1.88 1.88 0.00 0.00 30000/30000 Array#pop
1.55 1.55 0.00 0.00 30000/30010 Array#last
--------------------------------------------------------------------------------
5.23 1.01 0.00 4.22 10/10 ActiveRecord::QueryMethods#build_select
0.02% 0.00% 5.23 1.01 0.00 4.22 10 Arel::SelectManager#project
3.38 0.84 0.00 2.53 10/50 Array#map
0.84 0.84 0.00 0.00 10/10 Array#concat
--------------------------------------------------------------------------------
5.14 5.14 0.00 0.00 22/22 <Class::Time>#now
0.02% 0.02% 5.14 5.14 0.00 0.00 22 <Class::Time>#allocate
--------------------------------------------------------------------------------
5.06 0.84 0.00 4.22 2/2 Benchmark#measure
0.01% 0.00% 5.06 0.84 0.00 4.22 2 Time#to_f
4.22 0.84 0.00 3.38 2/2 Numeric#quo
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 ActiveRecord::QueryMethods#collapse_wheres
4.44 4.44 0.00 0.00 10/20 ActiveRecord::QueryMethods#build_arel
0.01% 0.01% 4.95 4.95 0.00 0.00 20 Array#-
--------------------------------------------------------------------------------
4.84 1.79 0.00 3.05 10/10 Class#new
0.01% 0.01% 4.84 1.79 0.00 3.05 10 Arel::Nodes::SelectCore#initialize
0.00 0.52 0.00 0.00 10/90071 Class#new
--------------------------------------------------------------------------------
1.03 0.52 0.00 0.52 40/70 ActiveRecord::Relation#eager_loading?
1.69 0.84 0.00 0.84 10/70 ActiveRecord::FinderMethods#all
2.06 1.03 0.00 1.03 20/70 <Class::ActiveRecord::Base>#build_default_scope
0.01% 0.01% 4.78 2.39 0.00 2.39 70 Enumerable#any?
2.39 2.39 0.00 0.00 70/10120 Array#each
--------------------------------------------------------------------------------
4.76 1.66 0.00 3.10 10/10 Array#each
0.01% 0.00% 4.76 1.66 0.00 3.10 10 ActiveSupport::Notifications::Fanout::Subscriber#publish
3.10 1.02 0.00 2.08 10/10 ActiveSupport::LogSubscriber#call
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/53 <Class::ActiveRecord::Base>#find_by_sql
1.55 1.55 0.00 0.00 3/53 Proc#yield
2.39 2.39 0.00 0.00 40/53 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
0.01% 0.01% 4.45 4.45 0.00 0.00 53 Module#name
--------------------------------------------------------------------------------
4.44 4.44 0.00 0.00 10/10 Class#new
0.01% 0.01% 4.44 4.44 0.00 0.00 10 SQLite3::Statement#initialize
--------------------------------------------------------------------------------
4.38 2.47 0.00 1.91 7/7 Benchmark::Tms#format
0.01% 0.01% 4.38 2.47 0.00 1.91 7 String#gsub!
1.91 1.91 0.00 0.00 4/4 String#%
--------------------------------------------------------------------------------
4.24 1.00 0.00 3.24 10/10 <Class::ActiveRecord::Base>#find_by_sql
0.01% 0.00% 4.24 1.00 0.00 3.24 10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
2.72 1.04 0.00 1.69 10/10 Object#blank?
0.52 0.52 0.00 0.00 20/40061 Module#===
--------------------------------------------------------------------------------
4.22 0.84 0.00 3.38 2/2 Time#to_f
0.01% 0.00% 4.22 0.84 0.00 3.38 2 Numeric#quo
3.38 0.84 0.00 2.53 2/2 Rational#/
--------------------------------------------------------------------------------
4.16 0.98 0.00 3.18 10/10 ActiveRecord::QueryMethods#build_select
0.01% 0.00% 4.16 0.98 0.00 3.18 10 <Module::Arel>#star
3.18 0.98 0.00 2.20 10/10 <Module::Arel>#sql
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/30 Arel::Visitors::ToSql#visit_Arel_Nodes_JoinSource
1.45 1.45 0.00 0.00 10/30 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
1.77 1.77 0.00 0.00 10/30 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.01% 0.01% 4.06 4.06 0.00 0.00 30 Array#compact
--------------------------------------------------------------------------------
3.99 0.97 0.00 3.02 10000/10000 <Module::Psych>#parse_stream
0.01% 0.00% 3.99 0.97 0.00 3.02 10000 <Module::Psych>#parser
3.02 0.52 0.00 2.50 20000/90071 Class#new
--------------------------------------------------------------------------------
3.94 1.03 0.00 2.91 10/10 ActiveRecord::QueryMethods#build_arel
0.01% 0.00% 3.94 1.03 0.00 2.91 10 ActiveRecord::QueryMethods#collapse_wheres
1.36 0.84 0.00 0.52 10/10 Enumerable#grep
0.52 0.52 0.00 0.00 10/20 Array#-
0.52 0.52 0.00 0.00 10/10110 Array#empty?
0.52 0.52 0.00 0.00 10/10120 Array#each
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10060 <Module::ActiveRecord::IdentityMap>#enabled
0.84 0.84 0.00 0.00 10/10060 <Class::ActiveRecord::Base>#current_scope
1.03 1.03 0.00 0.00 20/10060 Arel::Visitors::ToSql#last_column=
1.55 1.55 0.00 0.00 30/10060 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
0.01% 0.01% 3.94 3.94 0.00 0.00 10060 <Class::Thread>#current
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10110 <Module::Psych>#parse
0.52 0.52 0.00 0.00 10/10110 ActiveRecord::QueryMethods#collapse_wheres
0.52 0.52 0.00 0.00 10/10110 ActiveRecord::QueryMethods#build_select
0.52 0.52 0.00 0.00 10/10110 ActiveSupport::Notifications::Instrumenter#instrument
0.52 0.52 0.00 0.00 10/10110 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectStatement
0.52 0.52 0.00 0.00 30/10110 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.84 0.84 0.00 0.00 40/10110 ActiveRecord::QueryMethods#build_arel
0.01% 0.01% 3.94 3.94 0.00 0.00 10110 Array#empty?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 1/40061 Arel::Visitors::ToSql#quote_column_name
0.52 0.52 0.00 0.00 20/40061 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
0.84 0.84 0.00 0.00 20/40061 Arel::SelectManager#from
1.03 1.03 0.00 0.00 20/40061 Arel::Visitors::ToSql#quote_table_name
1.03 1.03 0.00 0.00 40000/40061 Psych::Visitors::Visitor#accept
0.01% 0.01% 3.94 3.94 0.00 0.00 40061 Module#===
--------------------------------------------------------------------------------
1.55 1.55 0.00 0.00 3/43 Hash#[]=
2.39 2.39 0.00 0.00 40/43 Arel::Visitors::Visitor#visit
0.01% 0.01% 3.94 3.94 0.00 0.00 43 Kernel#hash
--------------------------------------------------------------------------------
1.55 0.52 0.00 1.03 10/20 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
2.37 1.01 0.00 1.36 10/20 Arel::Visitors::ToSql#accept
0.01% 0.00% 3.92 1.53 0.00 2.39 20 Arel::Visitors::ToSql#last_column=
1.36 1.36 0.00 0.00 20/20 Thread#[]=
1.03 1.03 0.00 0.00 20/10060 <Class::Thread>#current
--------------------------------------------------------------------------------
1.03 0.52 0.00 0.52 10000/30000 Psych::TreeBuilder#start_mapping
1.03 0.52 0.00 0.52 10000/30000 Psych::TreeBuilder#start_document
1.84 1.00 0.00 0.84 10000/30000 Psych::TreeBuilder#start_stream
0.01% 0.01% 3.91 2.03 0.00 1.88 30000 Psych::TreeBuilder#push
1.88 1.88 0.00 0.00 30000/30000 Array#push
--------------------------------------------------------------------------------
3.89 1.01 0.00 2.88 10000/10000 Class#new
0.01% 0.00% 3.89 1.01 0.00 2.88 10000 Psych::Visitors::ToRuby#initialize
0.84 0.84 0.00 0.00 10000/10000 BasicObject#initialize
0.00 0.52 0.00 0.00 10000/90071 Class#new
--------------------------------------------------------------------------------
3.64 0.98 0.00 2.66 2/2 Benchmark#measure
0.01% 0.00% 3.64 0.98 0.00 2.66 2 <Module::Benchmark>#times
2.66 0.84 0.00 1.81 2/2 <Module::Process>#times
--------------------------------------------------------------------------------
3.61 0.84 0.00 2.76 10/10 Kernel#clone
0.01% 0.00% 3.61 0.84 0.00 2.76 10 Kernel#initialize_clone
2.76 1.01 0.00 1.76 10/10 ActiveRecord::Relation#initialize_copy
--------------------------------------------------------------------------------
3.55 3.55 0.00 0.00 20/20 <Class::ActiveRecord::Base>#build_default_scope
0.01% 0.01% 3.55 3.55 0.00 0.00 20 Kernel#method
--------------------------------------------------------------------------------
3.53 1.00 0.00 2.53 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.01% 0.00% 3.53 1.00 0.00 2.53 10 <Class::ActiveRecord::Base>#current_scope
0.84 0.84 0.00 0.00 10/10010 Thread#[]
0.84 0.84 0.00 0.00 10/10 Module#to_s
0.84 0.84 0.00 0.00 10/10060 <Class::Thread>#current
--------------------------------------------------------------------------------
3.49 1.01 0.00 2.48 10/10 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
0.01% 0.00% 3.49 1.01 0.00 2.48 10 Arel::Visitors::ToSql#quote_column_name
0.84 0.84 0.00 0.00 9/9 String#eql?
0.61 0.61 0.00 0.00 1/30004 Hash#[]=
0.52 0.52 0.00 0.00 1/40061 Module#===
0.52 0.52 0.00 0.00 1/40044 Hash#default
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10050 ActiveRecord::Base#set_serialized_attributes
0.84 0.84 0.00 0.00 10/10050 Array#map
2.06 2.06 0.00 0.00 40/10050 Arel::Visitors::Visitor#visit
0.01% 0.01% 3.42 3.42 0.00 0.00 10050 Kernel#class
--------------------------------------------------------------------------------
3.38 0.84 0.00 2.53 2/2 Numeric#quo
0.01% 0.00% 3.38 0.84 0.00 2.53 2 Rational#/
1.69 0.84 0.00 0.84 2/2 Rational#to_f
0.84 0.84 0.00 0.00 2/2 Float#/
--------------------------------------------------------------------------------
3.22 0.86 0.00 2.36 10000/10000 Psych::Parser#parse
0.01% 0.00% 3.22 0.86 0.00 2.36 10000 Psych::TreeBuilder#end_mapping
2.36 1.00 0.00 1.36 10000/30000 Psych::TreeBuilder#pop
--------------------------------------------------------------------------------
3.19 0.99 0.00 2.20 10/10 ActiveRecord::QueryMethods#build_select
0.01% 0.00% 3.19 0.99 0.00 2.20 10 Arel::Table#[]
2.20 0.84 0.00 1.36 10/10 <Class::#<Class:0x007fb7ebd32688>>#new
--------------------------------------------------------------------------------
3.18 0.98 0.00 2.20 10/10 <Module::Arel>#star
0.01% 0.00% 3.18 0.98 0.00 2.20 10 <Module::Arel>#sql
2.20 0.52 0.00 1.69 10/90071 Class#new
--------------------------------------------------------------------------------
3.10 1.02 0.00 2.08 10/10 ActiveSupport::Notifications::Fanout::Subscriber#publish
0.01% 0.00% 3.10 1.02 0.00 2.08 10 ActiveSupport::LogSubscriber#call
2.08 1.02 0.00 1.06 10/10 ActiveRecord::LogSubscriber#logger
--------------------------------------------------------------------------------
3.05 0.84 0.00 2.20 1/1 Benchmark::Tms#format
0.01% 0.00% 3.05 0.84 0.00 2.20 1 Kernel#dup
1.69 0.84 0.00 0.84 1/1 Kernel#initialize_dup
0.52 0.52 0.00 0.00 1/11 <Class::String>#allocate
--------------------------------------------------------------------------------
2.93 1.01 0.00 1.92 10/10 Arel::Visitors::ToSql#column_for
0.01% 0.00% 2.93 1.01 0.00 1.92 10 Arel::Visitors::ToSql#table_exists?
1.92 1.08 0.00 0.84 10/10 ActiveRecord::ConnectionAdapters::ConnectionPool#table_exists?
--------------------------------------------------------------------------------
2.91 2.91 0.00 0.00 3/3 Proc#yield
0.01% 0.01% 2.91 2.91 0.00 0.00 3 String#gsub
--------------------------------------------------------------------------------
2.84 1.00 0.00 1.84 10/10 ActiveRecord::NamedScope::ClassMethods#scoped
0.01% 0.00% 2.84 1.00 0.00 1.84 10 <Class::ActiveRecord::Base>#relation
1.84 1.00 0.00 0.84 10/10 <Class::ActiveRecord::Base>#finder_needs_type_condition?
--------------------------------------------------------------------------------
2.76 1.01 0.00 1.76 10/10 Kernel#initialize_clone
0.01% 0.00% 2.76 1.01 0.00 1.76 10 ActiveRecord::Relation#initialize_copy
1.76 1.76 0.00 0.00 10/10 ActiveRecord::Relation#reset
--------------------------------------------------------------------------------
2.72 1.04 0.00 1.69 10/10 <Class::ActiveRecord::Base>#sanitize_sql_for_conditions
0.01% 0.00% 2.72 1.04 0.00 1.69 10 Object#blank?
1.69 0.84 0.00 0.84 10/20 Kernel#respond_to?
--------------------------------------------------------------------------------
2.72 1.36 0.00 1.36 22/22 <Class::Time>#now
0.01% 0.00% 2.72 1.36 0.00 1.36 22 Time#initialize
1.36 1.36 0.00 0.00 22/22 Fixnum#+
--------------------------------------------------------------------------------
2.66 0.84 0.00 1.81 2/2 <Module::Benchmark>#times
0.01% 0.00% 2.66 0.84 0.00 1.81 2 <Module::Process>#times
0.97 0.97 0.00 0.00 2/2 <Class::Struct::Tms>#allocate
0.84 0.84 0.00 0.00 2/12 Struct#initialize
--------------------------------------------------------------------------------
2.56 2.56 0.00 0.00 40/40 Arel::Visitors::Visitor#visit
0.01% 0.01% 2.56 2.56 0.00 0.00 40 Arel::Visitors::Visitor#dispatch
--------------------------------------------------------------------------------
1.03 0.52 0.00 0.52 10/20 Arel::Visitors::ToSql#visit_Arel_Table
1.53 1.01 0.00 0.52 10/20 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
0.01% 0.00% 2.56 1.53 0.00 1.03 20 Arel::Visitors::ToSql#quote_table_name
1.03 1.03 0.00 0.00 20/40061 Module#===
--------------------------------------------------------------------------------
2.55 1.00 0.00 1.55 10000/10000 Psych::Parser#parse
0.01% 0.00% 2.55 1.00 0.00 1.55 10000 Psych::TreeBuilder#end_document
1.55 0.52 0.00 1.03 10000/30000 Psych::TreeBuilder#pop
--------------------------------------------------------------------------------
2.55 1.00 0.00 1.55 10000/10000 Psych::Parser#parse
0.01% 0.00% 2.55 1.00 0.00 1.55 10000 Psych::TreeBuilder#end_stream
1.55 0.52 0.00 1.03 10000/30000 Psych::TreeBuilder#pop
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/30010 Arel::SelectManager#initialize
1.55 1.55 0.00 0.00 30000/30010 Psych::TreeBuilder#pop
0.01% 0.01% 2.39 2.39 0.00 0.00 30010 Array#last
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/40 ActiveRecord::ConnectionAdapters::AbstractAdapter#log
1.88 1.88 0.00 0.00 30/40 ActiveRecord::ConnectionAdapters::ConnectionPool#current_connection_id
0.01% 0.01% 2.39 2.39 0.00 0.00 40 Kernel#object_id
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 ActiveRecord::ConnectionAdapters::DatabaseStatements#to_sql
1.69 0.84 0.00 0.84 10/20 Object#blank?
0.01% 0.00% 2.20 1.36 0.00 0.84 20 Kernel#respond_to?
0.84 0.84 0.00 0.00 10/80010 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
2.20 0.84 0.00 1.36 10/10 Arel::Table#[]
0.01% 0.00% 2.20 0.84 0.00 1.36 10 <Class::#<Class:0x007fb7ebd32688>>#new
0.84 0.84 0.00 0.00 10/10 <Class::#<Class:0x007fb7ebd32688>>#allocate
0.52 0.52 0.00 0.00 10/12 Struct#initialize
--------------------------------------------------------------------------------
2.08 1.02 0.00 1.06 10/10 ActiveSupport::LogSubscriber#call
0.01% 0.00% 2.08 1.02 0.00 1.06 10 ActiveRecord::LogSubscriber#logger
1.06 1.06 0.00 0.00 10/10 <Class::ActiveRecord::Base>#logger
--------------------------------------------------------------------------------
2.04 1.01 0.00 1.03 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.01% 0.00% 2.04 1.01 0.00 1.03 10000 <Module::ActiveRecord::IdentityMap>#enabled
0.52 0.52 0.00 0.00 10000/10010 Thread#[]
0.52 0.52 0.00 0.00 10000/10060 <Class::Thread>#current
--------------------------------------------------------------------------------
2.04 1.01 0.00 1.03 10/10 Arel::Visitors::Visitor#visit
0.01% 0.00% 2.04 1.01 0.00 1.03 10 Arel::Visitors::ToSql#visit_Arel_Table
1.03 0.52 0.00 0.52 10/20 Arel::Visitors::ToSql#quote_table_name
--------------------------------------------------------------------------------
2.04 1.01 0.00 1.03 20/20 ActiveRecord::Relation#to_a
0.01% 0.00% 2.04 1.01 0.00 1.03 20 ActiveRecord::Relation#eager_loading?
1.03 0.52 0.00 0.52 40/70 Enumerable#any?
--------------------------------------------------------------------------------
2.03 1.00 0.00 1.04 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.01% 0.00% 2.03 1.00 0.00 1.04 10000 <Class::ActiveRecord::Base>#find_sti_class
1.04 1.04 0.00 0.00 10000/10000 NilClass#blank?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/30000 Psych::Nodes::Mapping#initialize
0.52 0.52 0.00 0.00 10000/30000 Psych::Nodes::Document#initialize
1.00 1.00 0.00 0.00 10000/30000 Psych::Nodes::Stream#initialize
0.01% 0.01% 2.03 2.03 0.00 0.00 30000 Psych::Nodes::Node#initialize
--------------------------------------------------------------------------------
2.02 1.01 0.00 1.00 10/10 Class#new
0.01% 0.00% 2.02 1.01 0.00 1.00 10 Arel::Nodes::JoinSource#initialize
1.00 1.00 0.00 0.00 10/10 Arel::Nodes::Binary#initialize
--------------------------------------------------------------------------------
2.00 1.00 0.00 1.00 10000/10000 Class#new
0.01% 0.00% 2.00 1.00 0.00 1.00 10000 Psych::Nodes::Stream#initialize
1.00 1.00 0.00 0.00 10000/30000 Psych::Nodes::Node#initialize
--------------------------------------------------------------------------------
1.92 1.08 0.00 0.84 10/10 Arel::Visitors::ToSql#table_exists?
0.01% 0.00% 1.92 1.08 0.00 0.84 10 ActiveRecord::ConnectionAdapters::ConnectionPool#table_exists?
0.84 0.84 0.00 0.00 10/30010 Hash#key?
--------------------------------------------------------------------------------
1.91 1.91 0.00 0.00 4/4 String#gsub!
0.01% 0.01% 1.91 1.91 0.00 0.00 4 String#%
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 70000/80010 String#===
0.52 0.52 0.00 0.00 10000/80010 Psych::Parser#parse
0.84 0.84 0.00 0.00 10/80010 Kernel#respond_to?
0.01% 0.01% 1.88 1.88 0.00 0.00 80010 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20000/30010 Psych::ScalarScanner#tokenize
0.52 0.52 0.00 0.00 10000/30010 Hash#each
0.84 0.84 0.00 0.00 10/30010 ActiveRecord::ConnectionAdapters::ConnectionPool#table_exists?
0.01% 0.01% 1.88 1.88 0.00 0.00 30010 Hash#key?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20000/40010 ActiveRecord::Base#_run_initialize_callbacks
0.52 0.52 0.00 0.00 20000/40010 ActiveRecord::Base#_run_find_callbacks
0.84 0.84 0.00 0.00 10/40010 SQLite3::Database#prepare
0.01% 0.01% 1.88 1.88 0.00 0.00 40010 Kernel#block_given?
--------------------------------------------------------------------------------
1.88 1.88 0.00 0.00 30000/30000 Psych::TreeBuilder#pop
0.01% 0.01% 1.88 1.88 0.00 0.00 30000 Array#pop
--------------------------------------------------------------------------------
1.88 1.88 0.00 0.00 30000/30000 Psych::TreeBuilder#push
0.01% 0.01% 1.88 1.88 0.00 0.00 30000 Array#push
--------------------------------------------------------------------------------
1.85 1.01 0.00 0.84 10/10 Arel::SelectManager#initialize
0.01% 0.00% 1.85 1.01 0.00 0.84 10 Arel::SelectManager#from
0.84 0.84 0.00 0.00 20/40061 Module#===
--------------------------------------------------------------------------------
1.84 1.00 0.00 0.84 10/10 <Class::ActiveRecord::Base>#relation
0.01% 0.00% 1.84 1.00 0.00 0.84 10 <Class::ActiveRecord::Base>#finder_needs_type_condition?
0.84 0.84 0.00 0.00 10/10010 Symbol#==
--------------------------------------------------------------------------------
1.80 1.80 0.00 0.00 10/10 Class#new
0.01% 0.01% 1.80 1.80 0.00 0.00 10 Arel::Nodes::SelectStatement#initialize
--------------------------------------------------------------------------------
1.76 1.76 0.00 0.00 10/10 ActiveRecord::Relation#initialize_copy
0.01% 0.01% 1.76 1.76 0.00 0.00 10 ActiveRecord::Relation#reset
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 2/2 Benchmark::Report#item
0.00% 0.00% 1.69 0.84 0.00 0.84 2 Kernel#print
0.84 0.84 0.00 0.00 2/2 IO#write
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 1/1 Kernel#dup
0.00% 0.00% 1.69 0.84 0.00 0.84 1 Kernel#initialize_dup
0.84 0.84 0.00 0.00 1/1 String#initialize_copy
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 2/2 Rational#/
0.00% 0.00% 1.69 0.84 0.00 0.84 2 Rational#to_f
0.84 0.84 0.00 0.00 2/2 Fixnum#fdiv
--------------------------------------------------------------------------------
1.69 0.84 0.00 0.84 10/10 Array#map
0.00% 0.00% 1.69 0.84 0.00 0.84 10 Array#include?
0.84 0.84 0.00 0.00 20/20 Module#==
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 <Class::ActiveRecord::Base>#find_by_sql
1.02 1.02 0.00 0.00 10/20 <Class::ActiveRecord::Base>#columns_hash
0.00% 0.00% 1.54 1.54 0.00 0.00 20 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#table_name
--------------------------------------------------------------------------------
1.53 1.01 0.00 0.52 10000/10000 ActiveSupport::Callbacks#run_callbacks
0.00% 0.00% 1.53 1.01 0.00 0.52 10000 ActiveRecord::Base#_run_find_callbacks
0.52 0.52 0.00 0.00 20000/40010 Kernel#block_given?
--------------------------------------------------------------------------------
1.53 1.01 0.00 0.52 10000/10000 ActiveSupport::Callbacks#run_callbacks
0.00% 0.00% 1.53 1.01 0.00 0.52 10000 ActiveRecord::Base#_run_initialize_callbacks
0.52 0.52 0.00 0.00 20000/40010 Kernel#block_given?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 1/11 Kernel#dup
0.84 0.84 0.00 0.00 10/11 Class#new
0.00% 0.00% 1.36 1.36 0.00 0.00 11 <Class::String>#allocate
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 22/22 Time#initialize
0.00% 0.00% 1.36 1.36 0.00 0.00 22 Fixnum#+
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/12 <Class::#<Class:0x007fb7ebd32688>>#new
0.84 0.84 0.00 0.00 2/12 <Module::Process>#times
0.00% 0.00% 1.36 1.36 0.00 0.00 12 Struct#initialize
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10010 <Module::ActiveRecord::IdentityMap>#enabled
0.84 0.84 0.00 0.00 10/10010 <Class::ActiveRecord::Base>#current_scope
0.00% 0.00% 1.36 1.36 0.00 0.00 10010 Thread#[]
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10000/10010 Array#each
0.84 0.84 0.00 0.00 10/10010 <Class::ActiveRecord::Base>#finder_needs_type_condition?
0.00% 0.00% 1.36 1.36 0.00 0.00 10010 Symbol#==
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 20/20 <Class::ActiveRecord::Base>#build_default_scope
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Kernel#singleton_class
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 20/20 <Class::ActiveRecord::Base>#build_default_scope
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Method#owner
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.00% 0.00% 1.36 0.84 0.00 0.52 10000 Class#allocate
0.52 0.52 0.00 0.00 10000/100061 <Class::BasicObject>#allocate
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 10/10 ActiveRecord::QueryMethods#collapse_wheres
0.00% 0.00% 1.36 0.84 0.00 0.52 10 Enumerable#grep
0.52 0.52 0.00 0.00 10/10120 Array#each
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 20/20 ActiveRecord::ConnectionAdapters::ConnectionHandler#retrieve_connection_pool
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Class#superclass
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 20/20 Arel::Visitors::ToSql#last_column=
0.00% 0.00% 1.36 1.36 0.00 0.00 20 Thread#[]=
--------------------------------------------------------------------------------
1.36 1.36 0.00 0.00 30000/30000 Psych::Visitors::ToRuby#accept
0.00% 0.00% 1.36 1.36 0.00 0.00 30000 Hash#empty?
--------------------------------------------------------------------------------
1.36 0.84 0.00 0.52 70000/70000 Psych::Visitors::ToRuby#visit_Psych_Nodes_Mapping
0.00% 0.00% 1.36 0.84 0.00 0.52 70000 String#===
0.52 0.52 0.00 0.00 70000/80010 Kernel#respond_to_missing?
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 10/20 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
0.84 0.84 0.00 0.00 10/20 Arel::Visitors::ToSql#column_for
0.00% 0.00% 1.36 1.36 0.00 0.00 20 #<Class:0x007fb7ebd32688>#name
--------------------------------------------------------------------------------
0.52 0.52 0.00 0.00 20/30 Arel::Visitors::ToSql#visit_Arel_Attributes_Attribute
0.84 0.84 0.00 0.00 10/30 Arel::Visitors::ToSql#column_for
0.00% 0.00% 1.36 1.36 0.00 0.00 30 #<Class:0x007fb7ebd32688>#relation
--------------------------------------------------------------------------------
1.16 1.16 0.00 0.00 10/10 Class#new
0.00% 0.00% 1.16 1.16 0.00 0.00 10 <Class::SQLite3::Statement>#allocate
--------------------------------------------------------------------------------
1.10 1.10 0.00 0.00 1/1 Benchmark::Tms#format
0.00% 0.00% 1.10 1.10 0.00 0.00 1 <Module::Kernel>#format
--------------------------------------------------------------------------------
1.06 1.06 0.00 0.00 1/1 Class#new
0.00% 0.00% 1.06 1.06 0.00 0.00 1 Benchmark::Tms#initialize
--------------------------------------------------------------------------------
1.06 1.06 0.00 0.00 10/10 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
0.00% 0.00% 1.06 1.06 0.00 0.00 10 <Class::ActiveRecord::Base>#lock_optimistically
--------------------------------------------------------------------------------
1.06 1.06 0.00 0.00 10/10 ActiveRecord::LogSubscriber#logger
0.00% 0.00% 1.06 1.06 0.00 0.00 10 <Class::ActiveRecord::Base>#logger
--------------------------------------------------------------------------------
1.05 1.05 0.00 0.00 20000/20000 <Class::ActiveRecord::Base>#instantiate
0.00% 0.00% 1.05 1.05 0.00 0.00 20000 ActiveRecord::AttributeMethods::PrimaryKey::ClassMethods#primary_key
--------------------------------------------------------------------------------
1.04 1.04 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#find_sti_class
0.00% 0.00% 1.04 1.04 0.00 0.00 10000 NilClass#blank?
--------------------------------------------------------------------------------
1.03 1.03 0.00 0.00 10/10 ActiveSupport::Notifications::Fanout#publish
0.00% 0.00% 1.03 1.03 0.00 0.00 10 ActiveSupport::Notifications::Fanout#listeners_for
--------------------------------------------------------------------------------
1.02 1.02 0.00 0.00 10/10 ActiveRecord::Locking::Optimistic::ClassMethods#locking_enabled?
0.00% 0.00% 1.02 1.02 0.00 0.00 10 <Class::Person(id: integer, first_name: string, last_name: string, age: integer, extra_info: text, created_at: datetime, updated_at: datetime)>#locking_column
--------------------------------------------------------------------------------
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#visit_Arel_Nodes_SelectCore
0.00% 0.00% 1.01 1.01 0.00 0.00 10 Arel::Nodes::JoinSource#empty?
--------------------------------------------------------------------------------
1.01 1.01 0.00 0.00 10/10 Arel::Visitors::ToSql#column_for
0.00% 0.00% 1.01 1.01 0.00 0.00 10 Arel::Visitors::ToSql#column_cache
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10/10 Arel::SelectManager#initialize
0.00% 0.00% 1.00 1.00 0.00 0.00 10 Arel::TreeManager#initialize
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10/10 Arel::Nodes::JoinSource#initialize
0.00% 0.00% 1.00 1.00 0.00 0.00 10 Arel::Nodes::Binary#initialize
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10000/10000 Class#new
0.00% 0.00% 1.00 1.00 0.00 0.00 10000 Psych::ScalarScanner#initialize
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10/10 Class#new
0.00% 0.00% 1.00 1.00 0.00 0.00 10 ActiveRecord::Result#initialize
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10000/10000 Class#new
0.00% 0.00% 1.00 1.00 0.00 0.00 10000 Psych::TreeBuilder#initialize
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10/10 ActiveRecord::QueryMethods#build_select
0.00% 0.00% 1.00 1.00 0.00 0.00 10 <Class::ActiveRecord::Base>#arel_table
--------------------------------------------------------------------------------
1.00 1.00 0.00 0.00 10000/10000 <Class::ActiveRecord::Base>#instantiate
0.00% 0.00% 1.00 1.00 0.00 0.00 10000 <Class::ActiveRecord::Base>#inheritance_column
--------------------------------------------------------------------------------
0.99 0.99 0.00 0.00 10000/10000 Class#new
0.00% 0.00% 0.99 0.99 0.00 0.00 10000 Psych::Parser#initialize
--------------------------------------------------------------------------------
0.97 0.97 0.00 0.00 2/2 <Module::Process>#times
0.00% 0.00% 0.97 0.97 0.00 0.00 2 <Class::Struct::Tms>#allocate
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 1/1 Benchmark::Report#item
0.00% 0.00% 0.84 0.84 0.00 0.00 1 String#ljust
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Kernel#print
0.00% 0.00% 0.84 0.84 0.00 0.00 2 IO#write
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#cstime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#cutime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#stime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Benchmark#measure
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Struct::Tms#utime
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 1/1 Kernel#initialize_dup
0.00% 0.00% 0.84 0.84 0.00 0.00 1 String#initialize_copy
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Rational#/
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Float#/
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 ActiveRecord::Relation#to_a
0.00% 0.00% 0.84 0.84 0.00 0.00 10 BasicObject#equal?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 2/2 Rational#to_f
0.00% 0.00% 0.84 0.84 0.00 0.00 2 Fixnum#fdiv
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::ActiveRecord::Base>#current_scope
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Module#to_s
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 ActiveRecord::Relation#to_a
0.00% 0.00% 0.84 0.84 0.00 0.00 20 NilClass#nil?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 ActiveRecord::QueryMethods#build_arel
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Array#uniq
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Arel::SelectManager#project
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Array#concat
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 <Class::#<Class:0x007fb7ebd32688>>#new
0.00% 0.00% 0.84 0.84 0.00 0.00 10 <Class::#<Class:0x007fb7ebd32688>>#allocate
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20000/20000 ActiveSupport::Callbacks#run_callbacks
0.00% 0.00% 0.84 0.84 0.00 0.00 20000 Symbol#to_s
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 Array#include?
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Module#==
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Class#new
0.00% 0.00% 0.84 0.84 0.00 0.00 10 String#initialize
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.00% 0.00% 0.84 0.84 0.00 0.00 10 Array#to_a
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20000/20000 ActiveRecord::Coders::YAMLColumn#load
0.00% 0.00% 0.84 0.84 0.00 0.00 20000 Kernel#is_a?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 ActiveSupport::Notifications::Instrumenter#instrument
0.00% 0.00% 0.84 0.84 0.00 0.00 10 SQLite3::Statement#close
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20000/20000 <Module::Psych>#parse
0.00% 0.00% 0.84 0.84 0.00 0.00 20000 Array#first
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20/20 SQLite3::Statement#get_metadata
0.00% 0.00% 0.84 0.84 0.00 0.00 20 Kernel#freeze
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 SQLite3::Statement#get_metadata
0.00% 0.00% 0.84 0.84 0.00 0.00 10 SQLite3::Statement#column_count
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 70/70 Integer#times
0.00% 0.00% 0.84 0.84 0.00 0.00 70 SQLite3::Statement#column_decltype
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 70/70 Integer#times
0.00% 0.00% 0.84 0.84 0.00 0.00 70 SQLite3::Statement#column_name
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10010/10010 Kernel#loop
0.00% 0.00% 0.84 0.84 0.00 0.00 10010 SQLite3::Statement#done?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10000/10000 Psych::Visitors::ToRuby#initialize
0.00% 0.00% 0.84 0.84 0.00 0.00 10000 BasicObject#initialize
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10010/10010 SQLite3::Statement#step
0.00% 0.00% 0.84 0.84 0.00 0.00 10010 SQLite3::Database#encoding
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 9/9 Arel::Visitors::ToSql#quote_column_name
0.00% 0.00% 0.84 0.84 0.00 0.00 9 String#eql?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10/10 Arel::Visitors::ToSql#column_for
0.00% 0.00% 0.84 0.84 0.00 0.00 10 String#to_s
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 20000/20000 Psych::ScalarScanner#tokenize
0.00% 0.00% 0.84 0.84 0.00 0.00 20000 String#empty?
--------------------------------------------------------------------------------
0.84 0.84 0.00 0.00 10000/10000 Psych::ScalarScanner#tokenize
0.00% 0.00% 0.84 0.84 0.00 0.00 10000 String#to_sym
@ernie
Copy link
Author

ernie commented Aug 22, 2011

So, I realize this is a contrived example, but it seems like find_each would (with its default batch size) encounter similar memory increases. I'm assuming it's partially the fact that we deserialize serialized attributes on instantiation instead of lazily, but I'm also wondering if I'm not running into something specific to the version of Psych in 1.9.2-p290? The difference between ruby-prof's output and the observed RSS increase is what has me wondering.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment