BUG: counter cache not working

Hi guys,

I have a problem with counter cache on the rails trunk version. I have
the following test case:

doc = Document.new

assert doc.bookmarks.create()

assert doc.save!

assert doc.reload

assert_equal 1, doc.bookmarks_count

But doc.save! sets the bookmarks_count column on document to 0 (after
it has been raised by bookmarks.create)

the following queries can be found in log:

  1. SELECT * FROM documents WHERE (documents.id = 1)

  2. UPDATE documents SET bookmarks_count = bookmarks_count + 1 WHERE (id
    = 1)

  3. COMMIT

  4. BEGIN

  5. SELECT * FROM bookmarks WHERE (bookmarks.bookmarkable_id = 1 AND
    bookmarks.bookmarkable_type = ‘Document’)

  6. UPDATE documents SET content = NULL, bookmarks_count = 0, name
    = NULL WHERE id = 1

  7. COMMIT

quite frustrating… :S

My models:

– Document.rb:

class Document < ActiveRecord::Base

has_many :bookmarks, :as => :bookmarkable, :dependent => :destroy

end

– Bookmark.rb:

class Bookmark < ActiveRecord::Base

associations

belongs_to :bookmarkable, :polymorphic => true, :counter_cache
=> “bookmarks_count”

end

I have a problem with counter cache on the rails trunk version. I have the
following test case:

doc = Document.new
assert doc.bookmarks.create()
assert doc.save!
assert doc.reload
assert_equal 1, doc.bookmarks_count

But doc.save! sets the bookmarks_count column on document to 0 (after it
has been raised by bookmarks.create)

the following queries can be found in log:

1. SELECT * FROM documents WHERE (documents.id = 1)
2. UPDATE documents SET bookmarks_count = bookmarks_count + 1 WHERE (id =
1)
3. COMMIT
4. BEGIN
5. SELECT * FROM bookmarks WHERE (bookmarks.bookmarkable_id = 1 AND
bookmarks.bookmarkable_type = 'Document')
6. UPDATE documents SET `content` = NULL, `bookmarks_count` = 0, `name` =
NULL WHERE id = 1
7. COMMIT

This log doesn't seem to correspond to the snippet above, there's no
Document.find(1) etc. Are you sure you've pasted the right stuff?

Hi,

Sorry, you are correct, its the wrong log (new log in the bottom of the email) but I have made some progress, after some debugging I made the following test case (named two) where I save the document Object before I create the bookmarks associations what results in duplicate increment sql statements. But when I turn this around (creating bookmarks associations first before saving the document object) everything seems to work fine with the counter_cache triggers.

the following test case where the last assertion fails

def test_case_two
  bookmark = {:title => "mytitle", :description=>"mydescription", :note=>"mynote"}
  # save document before bookmarking
  doc = Document.new
  assert doc.save!
  assert doc.bookmarks.create!(bookmark.merge!({:user_id => users(:user1).id}))
  assert_equal 1, doc.bookmarks.count # fetch directly from database
  assert_equal 0, doc.bookmarks.size # it hasn't retrieved the updated counter yet
  assert doc.reload
  assert_equal 1, doc.bookmarks.size # << THIS FAILS because doc.bookmarks.size return 2
end

the following output can be found in my testing log where you can see the update to both documents (as users) happens twice with + 1 (together 4 updates). There should be only one "UPDATE documents SET bookmarks_count = bookmarks_count + 1 WHERE (id = 22)" statement (and one "UPDATE users ... + 1".

my models again:

-- Document.rb:
class Document < ActiveRecord::Base
has_many :bookmarks, :as => :bookmarkable, :dependent => :destroy
end

-- Bookmark.rb:
class Bookmark < ActiveRecord::Base
# associations
belongs_to :bookmarkable, :polymorphic => true, :counter_cache => "bookmarks_count"
end

The following logs gets generated when I execute the test case (two) above:

e[4;36;1mSQL (0.000448)e[0m e[0;1mBEGINe[0m
e[4;35;1mSQL (0.000877)e[0m e[0mINSERT INTO documents (`created_on`, `name`, `updated_on`, `bookmarks_count`, `content`) VALUES('2006-12-26 22:47:46', NULL, '2006-12-26 22:47:46', 0, NULL)e[0m
e[4;36;1mSQL (0.000982)e[0m e[0;1mCOMMITe[0m
e[4;35;1mUser Load (0.001562)e[0m e[0mSELECT * FROM users WHERE (users.id = 1) e[0m
e[4;36;1mSQL (0.000505)e[0m e[0;1mBEGINe[0m
e[4;35;1mBookmark Load (0.002043)e[0m e[0mSELECT * FROM bookmarks WHERE (bookmarks.user_id = 1 AND bookmarks.bookmarkable_id = 22 AND bookmarks.bookmarkable_type = 'Document') LIMIT 1e[0m
e[4;36;1mBookmark Load (0.001914)e[0m e[0;1mSELECT * FROM bookmarks WHERE (bookmarks.user_id = 1 AND bookmarks.bookmarkable_id = 22 AND bookmarks.bookmarkable_type = 'Document') LIMIT 1e[0m
e[4;35;1mSQL (0.000876)e[0m e[0mINSERT INTO bookmarks (`bookmarkable_type`, `title`, `bookmarkable_id`, `description`, `note`, `user_id`) VALUES('Document', 'mytitle', 22, 'mydescription', 'mynote', 1)e[0m
e[4;36;1mDocument Load (0.001840)e[0m e[0;1mSELECT * FROM documents WHERE (documents.id = 22) e[0m
e[4;35;1mDocument Update (0.000869)e[0m e[0mUPDATE documents SET bookmarks_count = bookmarks_count + 1 WHERE (id = 22) e[0m
e[4;36;1mUser Load (0.001459)e[0m e[0;1mSELECT * FROM users WHERE (users.id = 1) e[0m
e[4;35;1mUser Update (0.001149)e[0m e[0mUPDATE users SET bookmarks_count = bookmarks_count + 1 WHERE (id = 1) e[0m
e[4;36;1mDocument Update (0.000796)e[0m e[0;1mUPDATE documents SET bookmarks_count = bookmarks_count + 1 WHERE (id = 22) e[0m
e[4;35;1mUser Update (0.000718)e[0m e[0mUPDATE users SET bookmarks_count = bookmarks_count + 1 WHERE (id = 1) e[0m
e[4;36;1mDocument Load Including Associations (0.004153)e[0m e[0;1mSELECT documents.`id` AS t0_r0, documents.`name` AS t0_r1, documents.`content` AS t0_r2, documents.`bookmarks_count` AS t0_r3, documents.`created_on` AS t0_r4, documents.`updated_on` AS t0_r5, bookmarks.`id` AS t1_r0, bookmarks.`bookmarkable_id` AS t1_r1, bookmarks.`bookmarkable_type` AS t1_r2, bookmarks.`user_id` AS t1_r3, bookmarks.`title` AS t1_r4, bookmarks.`description` AS t1_r5, bookmarks.`note` AS t1_r6 FROM documents LEFT OUTER JOIN bookmarks ON bookmarks.bookmarkable_id = documents.id AND bookmarks.bookmarkable_type = 'Document'WHERE (documents.id = 22) e[0m
e[4;35;1mTagging Columns (0.002069)e[0m e[0mSHOW FIELDS FROM taggingse[0m
e[4;36;1mTag Load (0.001298)e[0m e[0;1mSELECT tags.* FROM tags INNER JOIN taggings ON tags.id = taggings.tag_id WHERE ((taggings.taggable_type = 'Bookmark') AND (taggings.taggable_id = 29)) e[0m
e[4;35;1mTagging Load (0.002059)e[0m e[0mSELECT * FROM taggings WHERE (taggings.taggable_id = 22 AND taggings.taggable_type = 'Document') e[0m
e[4;36;1mDocument Load Including Associations (0.003034)e[0m e[0;1mSELECT documents.`id` AS t0_r0, documents.`name` AS t0_r1, documents.`content` AS t0_r2, documents.`bookmarks_count` AS t0_r3, documents.`created_on` AS t0_r4, documents.`updated_on` AS t0_r5, bookmarks.`id` AS t1_r0, bookmarks.`bookmarkable_id` AS t1_r1, bookmarks.`bookmarkable_type` AS t1_r2, bookmarks.`user_id` AS t1_r3, bookmarks.`title` AS t1_r4, bookmarks.`description` AS t1_r5, bookmarks.`note` AS t1_r6 FROM documents LEFT OUTER JOIN bookmarks ON bookmarks.bookmarkable_id = documents.id AND bookmarks.bookmarkable_type = 'Document'WHERE (documents.id = 22) e[0m
e[4;35;1mTag Load (0.001362)e[0m e[0mSELECT tags.* FROM tags INNER JOIN taggings ON tags.id = taggings.tag_id WHERE ((taggings.taggable_type = 'Bookmark') AND (taggings.taggable_id = 29)) e[0m
e[4;36;1mTagging Load (0.001654)e[0m e[0;1mSELECT * FROM taggings WHERE (taggings.taggable_id = 22 AND taggings.taggable_type = 'Document') e[0m
e[4;35;1mSQL (0.001052)e[0m e[0mCOMMITe[0m
e[4;36;1mSQL (0.001172)e[0m e[0;1mSELECT count(*) AS count_all FROM bookmarks WHERE (bookmarks.bookmarkable_id = 22 AND bookmarks.bookmarkable_type = 'Document') e[0m
e[4;35;1mDocument Load (0.001758)e[0m e[0mSELECT * FROM documents WHERE (documents.id = 22) e[0,

Hi,

Beside the dual update problem below I am also experiencing the problem that is described in this ticket: http://dev.rubyonrails.org/ticket/5050

The statement below that when I add a bookmark before saving the document the counter_cache appears to be fine is INVALID. Actually when I do a reload! I see that the value of .size is 0 (as is the value of bookmarks_count). This is a really annoying problem but should be easy to fix. The dual trigger of the counter cache after_create (mentioned below) is an other problem.

Abdul

Abdur-Rahman Advany wrote:

Hi,

Looks like loading model's in a plugin is causing the dual updates to counter cache columns (maybe because it triggers the eval 2 times in belongs_to). The problem mentioned in ticket #5050 still isn't fixed, I tried it myself but can't seem to figure out how to solve this. The provided fix wouldn't work as you can specify the counter_cache column (and it doesn't have to end on _count), and you can't just exclude all counter_cache column because increment and decrement use those columns.

Hope someone with a little more experience with active record can create a fix (or provide some tips on how to fix it so I can create a patch).

Abdul

Abdur-Rahman Advany wrote:

Hi,

Looks like loading model's in a plugin is causing the dual updates to
counter cache columns (maybe because it triggers the eval 2 times in
belongs_to). The problem mentioned in ticket #5050 still isn't fixed, I
tried it myself but can't seem to figure out how to solve this. The
provided fix wouldn't work as you can specify the counter_cache column
(and it doesn't have to end on _count), and you can't just exclude all
counter_cache column because increment and decrement use those columns.

Hope someone with a little more experience with active record can create
a fix (or provide some tips on how to fix it so I can create a patch).

Abdul

belongs_to is a method, and if you call it twice on the same model,
it's going to create 2 callbacks to set the counter_cache. Loading a
model in app/models and in a plugin is going to do that.

If it's *only* in the plugin, I'm not sure why it would load it
multiple times. Try this in the model:

def self.belongs_to(*args)
  breakpoint "#{name}.belongs_to(#{args.inspect})"
  super
end

Now, pull up script/console and try to access your model. This should
set a breakpoint for each time belongs_to is called. If you see this
being called twice, use show_call_stack to see where it's being loaded
from.

$ script/console

require 'breakpoint'
Foo # this should load your module

Executing break point "Foo.belongs_to([:bar])" .... blah blah

Rick,

could not get it to work, somehow calling the model with the constant was not triggering it. So I though maybe it already loaded and removed my require 'model_name' from the init.rb in my plugin. That solved the problem, THNX!

Any idea's on the #5050 ticket? I was thinking of creating a before_update method on the model (incrementing the counter) if the association it belong to was not saved yet. Any other idea's I have would require rewriting a lot of code (and a hack like this shouldn't be that ugly).

Abdul

Rick Olson wrote:

Abdur-Rahman Advany wrote:

provided fix wouldn't work as you can specify the counter_cache column
(and it doesn't have to end on _count),

I created a new ticket http://dev.rubyonrails.org/ticket/6807 with a
patch that solves the problem. It may need some tweaks, or there may
be a better way to solve the problem, but the patch works and includes
tests.

Dan

Dan Manges wrote:

I created a new ticket http://dev.rubyonrails.org/ticket/6807

That was the wrong link, here is the correct one:
http://dev.rubyonrails.org/ticket/6896

Dan