Calling ActiveRecord attributes creates additional load

[max-reznichenko]

This might have already been reported or even improved -- sorry, if it has already been.

While working on a rails project, we found additional load when ActiveRecord objects' attributes are called. In our code base, it was .sort_by, but an example below shows that the same happens when .map is called.

begin
  require 'bundler/inline'
rescue LoadError => e
  $stderr.puts 'Bundler version 1.10 or later is required. Please update your Bundler'
  raise e
end

gemfile(true) do
  source 'https://rubygems.org'
  # Activate the gem you are reporting the issue against.
  gem 'activerecord', '4.2.0'
  gem 'sqlite3'
end

require 'active_record'
require 'logger'

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: 'sqlite3', database: ':memory:')
ActiveRecord::Base.logger = nil # Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true  do |t|
    15.times do |iteration|
      t.string "string_column_#{iteration}"
    end

    t.timestamps
  end
end
class Post < ActiveRecord::Base; end
PostObject = Struct.new(:created_at)

16_000.times { Post.create! }; ar_objects = Post.all.to_a
struct_objects = []; 16_000.times { struct_objects << PostObject.new(created_at: DateTime.now) }

puts "== Testing AR maps =="
Benchmark.benchmark do |x|
  x.report("Run #1. AR objects. Map `created_at'") { ar_objects.map(&:created_at) }
end

Benchmark.benchmark do |x|
  x.report("Run #2. AR objects. Map `created_at'") { ar_objects.map(&:created_at) }
end

ar_objects = Post.all.to_a; :done

Benchmark.benchmark do |x|
  x.report("Run #3. AR objects reloaded. Map `created_at'") { ar_objects.map(&:created_at) }
end

Benchmark.benchmark do |x|
  x.report("Run #4. AR objects reloaded. Map `created_at'") { ar_objects.map(&:created_at) }
end

puts "== Testing Struct maps =="
Benchmark.benchmark do |x|
  x.report("Run #1. Struct objects. Map `created_at'") { struct_objects.map(&:created_at) }
end

Benchmark.benchmark do |x|
  x.report("Run #2. Struct objects. Map `created_at'") { struct_objects.map(&:created_at) }
end

Benchmark.benchmark do |x|
  x.report("Run #3. Struct objects reloaded. Map `created_at'") { struct_objects.map(&:created_at) }
end

Benchmark.benchmark do |x|
  x.report("Run #4. Struct objects reloaded. Map `created_at'") { struct_objects.map(&:created_at) }
end

Output:

== Testing AR maps ==
Run #1. AR objects. Map `created_at'  0.210000   0.010000   0.220000 (  0.221489)
Run #2. AR objects. Map `created_at'  0.010000   0.000000   0.010000 (  0.016131)
Run #3. AR objects reloaded. Map `created_at'  0.190000   0.010000   0.200000 (  0.195684)
Run #4. AR objects reloaded. Map `created_at'  0.020000   0.000000   0.020000 (  0.017788)
== Testing Struct maps ==
Run #1. Struct objects. Map `created_at'  0.000000   0.000000   0.000000 (  0.001329)
Run #2. Struct objects. Map `created_at'  0.000000   0.000000   0.000000 (  0.001290)
Run #3. Struct objects reloaded. Map `created_at'  0.000000   0.000000   0.000000 (  0.001441)
Run #4. Struct objects reloaded. Map `created_at'  0.000000   0.000000   0.000000 (  0.001178)

Does ActiveRecord add anything on the fly and then keeps it in memory?

Rails Version: "4.2.3"
Ruby Version: "ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-linux]"

[pixeltrix]

@SER1AL this is to be expected - the Struct implementation you have isn't really doing anything other than an optimised ivar lookup whereas the Active Record object is looking up the attribute name in a hash and then converting the timestamp to the application's timezone. This conversion is cached which is why you see the difference between Run #1 & Run #2.

So a difference between Structs and Active Record instance attribute accessing is to be expected. It is possible that there's been a performance regression between versions in which case you should check rubybench.com to check where that occurred.