rails debugging: #count with #uniq and #joins

3-2-stable

irb(main):001:0> require 'active_record'

                                         :database => ':memory:' )

# Create a database schema to reproduce the bug
ActiveRecord::Schema.define do
  create_table :users

  create_table :dogs do |t|
    t.integer :user_id
  end
end

# Create a set of models to reproduce the bug
class User < ActiveRecord::Base
  has_many :dogs
end

class Dog < ActiveRecord::Base
  belongs_to :user
end

# Create some test data
user = User.create!
2.times do user.dogs.create! end

# Inconsistent behavior:
puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
puts User.joins(:dogs).uniq.all.count #  prints "1"

puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
puts User.joins(:dogs).uniq.to_a.count #  prints "1"

puts "`User.joins(:dogs).uniq.count` evaluates to:"
puts User.joins(:dogs).uniq.count       # prints "2", why?
=> true
irb(main):002:0> require 'logger'
=> true
irb(main):003:0> 
irb(main):004:0* puts "Active Record #{ ActiveRecord::VERSION::STRING }"
Active Record 3.2.12
=> nil
irb(main):005:0> 
irb(main):006:0* # ActiveRecord::Base.logger = Logger.new(STDOUT)
irb(main):007:0* 
irb(main):008:0* # Connect to an in-memory sqlite3 database
irb(main):009:0* ActiveRecord::Base.establish_connection( :adapter  => 'sqlite3',
irb(main):010:1*                                          :database => ':memory:' )
=> #<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007ff7c3ad7c18 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007ff7c3ad7bc8>, @spec=#<ActiveRecord::Base::ConnectionSpecification:0x007ff7c3aa26d0 @config={:adapter=>"sqlite3", :database=>":memory:"}, @adapter_method="sqlite3_connection">, @reserved_connections={}, @queue=#<MonitorMixin::ConditionVariable:0x007ff7c3ad7b00 @monitor=#<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007ff7c3ad7c18 ...>, @cond=#<ConditionVariable:0x007ff7c3ad7a60 @waiters=[], @waiters_mutex=#<Mutex:0x007ff7c3ad79c0>>>, @timeout=5, @size=5, @connections=[], @automatic_reconnect=true>
irb(main):011:0> 
irb(main):012:0* # Create a database schema to reproduce the bug
irb(main):013:0* ActiveRecord::Schema.define do
irb(main):014:1*   create_table :users
irb(main):015:1> 
irb(main):016:1*   create_table :dogs do |t|
irb(main):017:2*     t.integer :user_id
irb(main):018:2>   end
irb(main):019:1> end
-- create_table(:users)
   -> 0.0064s
-- create_table(:dogs)
   -> 0.0004s
=> nil
irb(main):020:0> 
irb(main):021:0* # Create a set of models to reproduce the bug
irb(main):022:0* class User < ActiveRecord::Base
irb(main):023:1>   has_many :dogs
irb(main):024:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007ff7c6e35768 @macro=:has_many, @name=:dogs, @options={:extend=>[]}, @active_record=User(id: integer), @plural_name="dogs", @collection=true>
irb(main):025:0> 
irb(main):026:0* class Dog < ActiveRecord::Base
irb(main):027:1>   belongs_to :user
irb(main):028:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007ff7c3bf2710 @macro=:belongs_to, @name=:user, @options={}, @active_record=Dog(id: integer, user_id: integer), @plural_name="users", @collection=false>
irb(main):029:0> 
irb(main):030:0* # Create some test data
irb(main):031:0* user = User.create!
=> #<User id: 1>
irb(main):032:0> 2.times do user.dogs.create! end
=> 2
irb(main):033:0> 
irb(main):034:0* # Inconsistent behavior:
irb(main):035:0* puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
`User.joins(:dogs).uniq.all.count` evaluates to:
=> nil
irb(main):036:0> puts User.joins(:dogs).uniq.all.count #  prints "1"
1
=> nil
irb(main):037:0> 
irb(main):038:0* puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
`User.joins(:dogs).uniq.to_a.count` evaluates to:
=> nil
irb(main):039:0> puts User.joins(:dogs).uniq.to_a.count #  prints "1"
1
=> nil
irb(main):040:0> 
irb(main):041:0* puts "`User.joins(:dogs).uniq.count` evaluates to:"
`User.joins(:dogs).uniq.count` evaluates to:
=> nil
irb(main):042:0> puts User.joins(:dogs).uniq.count       # prints "2", why?
1
=> nil
irb(main):043:0> 

master

irb(main):001:0> require 'active_record'

                                         :database => ':memory:' )

# Create a database schema to reproduce the bug
ActiveRecord::Schema.define do
  create_table :users

  create_table :dogs do |t|
    t.integer :user_id
  end
end

# Create a set of models to reproduce the bug
class User < ActiveRecord::Base
  has_many :dogs
end

class Dog < ActiveRecord::Base
  belongs_to :user
end

# Create some test data
user = User.create!
2.times do user.dogs.create! end

# Inconsistent behavior:
puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
puts User.joins(:dogs).uniq.all.count #  prints "1"

puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
puts User.joins(:dogs).uniq.to_a.count #  prints "1"

puts "`User.joins(:dogs).uniq.count` evaluates to:"
puts User.joins(:dogs).uniq.count       # prints "2", why?
=> true
irb(main):002:0> require 'logger'
=> false
irb(main):003:0> 
irb(main):004:0* puts "Active Record #{ ActiveRecord::VERSION::STRING }"
Active Record 4.0.0.beta1
=> nil
irb(main):005:0> 
irb(main):006:0* # ActiveRecord::Base.logger = Logger.new(STDOUT)
irb(main):007:0* 
irb(main):008:0* # Connect to an in-memory sqlite3 database
irb(main):009:0* ActiveRecord::Base.establish_connection( :adapter  => 'sqlite3',
irb(main):010:1*                                          :database => ':memory:' )
=> #<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007fea9c06c6e0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007fea9c06c320>, @spec=#<ActiveRecord::ConnectionAdapters::ConnectionSpecification:0x007fea9df15ec0 @config={:adapter=>"sqlite3", :database=>":memory:"}, @adapter_method="sqlite3_connection">, @checkout_timeout=5, @dead_connection_timeout=5, @reaper=#<ActiveRecord::ConnectionAdapters::ConnectionPool::Reaper:0x007fea9c06c1b8 @pool=#<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007fea9c06c6e0 ...>, @frequency=nil>, @size=5, @reserved_connections=#<ThreadSafe::Cache:0x007fea9c06bf38 @backend={}, @default_proc=nil>, @connections=[], @automatic_reconnect=true, @available=#<ActiveRecord::ConnectionAdapters::ConnectionPool::Queue:0x007fea9c06b948 @lock=#<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007fea9c06c6e0 ...>, @cond=#<MonitorMixin::ConditionVariable:0x007fea9c06b8f8 @monitor=#<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007fea9c06c6e0 ...>, @cond=#<ConditionVariable:0x007fea9c06b8d0 @waiters=[], @waiters_mutex=#<Mutex:0x007fea9c06b740>>>, @num_waiting=0, @queue=[]>>
irb(main):011:0> 
irb(main):012:0* # Create a database schema to reproduce the bug
irb(main):013:0* ActiveRecord::Schema.define do
irb(main):014:1*   create_table :users
irb(main):015:1> 
irb(main):016:1*   create_table :dogs do |t|
irb(main):017:2*     t.integer :user_id
irb(main):018:2>   end
irb(main):019:1> end
-- create_table(:users)
   -> 0.0064s
-- create_table(:dogs)
   -> 0.0003s
=> nil
irb(main):020:0> 
irb(main):021:0* # Create a set of models to reproduce the bug
irb(main):022:0* class User < ActiveRecord::Base
irb(main):023:1>   has_many :dogs
irb(main):024:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007fea9bbf79e8 @macro=:has_many, @name=:dogs, @scope=nil, @options={}, @active_record=User(id: integer), @plural_name="dogs", @collection=true>
irb(main):025:0> 
irb(main):026:0* class Dog < ActiveRecord::Base
irb(main):027:1>   belongs_to :user
irb(main):028:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007fea9c0be828 @macro=:belongs_to, @name=:user, @scope=nil, @options={}, @active_record=Dog(id: integer, user_id: integer), @plural_name="users", @collection=false>
irb(main):029:0> 
irb(main):030:0* # Create some test data
irb(main):031:0* user = User.create!
=> #<User id: 1>
irb(main):032:0> 2.times do user.dogs.create! end
=> 2
irb(main):033:0> 
irb(main):034:0* # Inconsistent behavior:
irb(main):035:0* puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
`User.joins(:dogs).uniq.all.count` evaluates to:
=> nil
irb(main):036:0> puts User.joins(:dogs).uniq.all.count #  prints "1"
DEPRECATION WARNING: Relation#all is deprecated. If you want to eager-load a relation, you can call #load (e.g. `Post.where(published: true).load`). If you want to get an array of records from a relation, you can call #to_a (e.g. `Post.where(published: true).to_a`). (called from irb_binding at (irb):36)
1
=> nil
irb(main):037:0> 
irb(main):038:0* puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
`User.joins(:dogs).uniq.to_a.count` evaluates to:
=> nil
irb(main):039:0> puts User.joins(:dogs).uniq.to_a.count #  prints "1"
1
=> nil
irb(main):040:0> 
irb(main):041:0* puts "`User.joins(:dogs).uniq.count` evaluates to:"
`User.joins(:dogs).uniq.count` evaluates to:
=> nil
irb(main):042:0> puts User.joins(:dogs).uniq.count       # prints "2", why?
1
=> nil

v3.2.12

irb(main):001:0> require 'active_record'

                                         :database => ':memory:' )

# Create a database schema to reproduce the bug
ActiveRecord::Schema.define do
  create_table :users

  create_table :dogs do |t|
    t.integer :user_id
  end
end

# Create a set of models to reproduce the bug
class User < ActiveRecord::Base
  has_many :dogs
end

class Dog < ActiveRecord::Base
  belongs_to :user
end

# Create some test data
user = User.create!
2.times do user.dogs.create! end

# Inconsistent behavior:
puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
puts User.joins(:dogs).uniq.all.count #  prints "1"

puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
puts User.joins(:dogs).uniq.to_a.count #  prints "1"

puts "`User.joins(:dogs).uniq.count` evaluates to:"
puts User.joins(:dogs).uniq.count       # prints "2", why?
=> true
irb(main):002:0> require 'logger'
=> true
irb(main):003:0> 
irb(main):004:0* puts "Active Record #{ ActiveRecord::VERSION::STRING }"
Active Record 3.2.12
=> nil
irb(main):005:0> 
irb(main):006:0* # ActiveRecord::Base.logger = Logger.new(STDOUT)
irb(main):007:0* 
irb(main):008:0* # Connect to an in-memory sqlite3 database
irb(main):009:0* ActiveRecord::Base.establish_connection( :adapter  => 'sqlite3',
irb(main):010:1*                                          :database => ':memory:' )
=> #<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007f847d1aff50 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f847d1afe10>, @spec=#<ActiveRecord::Base::ConnectionSpecification:0x007f847d0ea7f0 @config={:adapter=>"sqlite3", :database=>":memory:"}, @adapter_method="sqlite3_connection">, @reserved_connections={}, @queue=#<MonitorMixin::ConditionVariable:0x007f847d1b7d40 @monitor=#<ActiveRecord::ConnectionAdapters::ConnectionPool:0x007f847d1aff50 ...>, @cond=#<ConditionVariable:0x007f847d1b7c00 @waiters=[], @waiters_mutex=#<Mutex:0x007f847d1b7890>>>, @timeout=5, @size=5, @connections=[], @automatic_reconnect=true>
irb(main):011:0> 
irb(main):012:0* # Create a database schema to reproduce the bug
irb(main):013:0* ActiveRecord::Schema.define do
irb(main):014:1*   create_table :users
irb(main):015:1> 
irb(main):016:1*   create_table :dogs do |t|
irb(main):017:2*     t.integer :user_id
irb(main):018:2>   end
irb(main):019:1> end
-- create_table(:users)
   -> 0.0061s
-- create_table(:dogs)
   -> 0.0004s
=> nil
irb(main):020:0> 
irb(main):021:0* # Create a set of models to reproduce the bug
irb(main):022:0* class User < ActiveRecord::Base
irb(main):023:1>   has_many :dogs
irb(main):024:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007f847e9010f0 @macro=:has_many, @name=:dogs, @options={:extend=>[]}, @active_record=User(id: integer), @plural_name="dogs", @collection=true>
irb(main):025:0> 
irb(main):026:0* class Dog < ActiveRecord::Base
irb(main):027:1>   belongs_to :user
irb(main):028:1> end
=> #<ActiveRecord::Reflection::AssociationReflection:0x007f847d4429e8 @macro=:belongs_to, @name=:user, @options={}, @active_record=Dog(id: integer, user_id: integer), @plural_name="users", @collection=false>
irb(main):029:0> 
irb(main):030:0* # Create some test data
irb(main):031:0* user = User.create!
=> #<User id: 1>
irb(main):032:0> 2.times do user.dogs.create! end
=> 2
irb(main):033:0> 
irb(main):034:0* # Inconsistent behavior:
irb(main):035:0* puts "`User.joins(:dogs).uniq.all.count` evaluates to:"
`User.joins(:dogs).uniq.all.count` evaluates to:
=> nil
irb(main):036:0> puts User.joins(:dogs).uniq.all.count #  prints "1"
1
=> nil
irb(main):037:0> 
irb(main):038:0* puts "`User.joins(:dogs).uniq.to_a.count` evaluates to:"
`User.joins(:dogs).uniq.to_a.count` evaluates to:
=> nil
irb(main):039:0> puts User.joins(:dogs).uniq.to_a.count #  prints "1"
1
=> nil
irb(main):040:0> 
irb(main):041:0* puts "`User.joins(:dogs).uniq.count` evaluates to:"
`User.joins(:dogs).uniq.count` evaluates to:
=> nil
irb(main):042:0> puts User.joins(:dogs).uniq.count       # prints "2", why?
2
=> nil
irb(main):043:0>