rails3 with cache_cache classes = false causes problems with many 2 many associations

[solnic]

I have isolated a problem with rails3 and many 2 many associations in this sample rails3 app: git://github.com/mbj/bugapp
It is NOT reproducible under a non rails3 cache_classes = false environment.

The app is featuring two models:

class Article
  include DataMapper::Resource
  property :id, Serial
  has n, :persons, :through => Resource
end

class Person
  include DataMapper::Resource
  property :id, Serial
  has n, :articles, :through => Resource
end

One Controller:

class ApplicationController < ActionController::Base
  protect_from_forgery

  # routed from GET /a, creates some records needed for demonstration
  # you have to hit it to get this demo working

  def create_person_and_articles
    person = Person.create
    person.articles.create
    person.articles.create
    head :ok
  end

  # routet from GET /b, is basically a noop, (Articles are linked already), but
  # causes problems when classes got reloaded! (so hit at least twice after a fresh start)

  def assing_articles_another_time
    person = Person.first
    person.attributes = { :articles => Article.all }
    person.save
    head :ok
  end
end

Hitting /b after /a results in the following exception where sqlite complains over the already existing join record. DataMapper tries to create the join records, where it should not.

mbj@seon ~/devel/bugapp $ rake db:automigrate
(in /home/mbj/devel/bugapp)
[datamapper] Finished auto_migrate! for :default repository '/home/mbj/devel/bugapp/db/development.sqlite3'
mbj@seon ~/devel/bugapp $ ./script/rails s -p 4003
=> Booting WEBrick
=> Rails 3.0.0.rc application starting in development on http://0.0.0.0:4003
=> Call with -d to detach
=> Ctrl-C to shutdown server
[datamapper] Setting up the "development" environment:
[datamapper] Setting up :default repository: '/home/mbj/devel/bugapp/db/development.sqlite3' on sqlite3
[2010-08-10 23:00:02] INFO  WEBrick 1.3.1
[2010-08-10 23:00:02] INFO  ruby 1.9.2 (2010-07-11) [x86_64-linux]
[2010-08-10 23:00:02] INFO  WEBrick::HTTPServer#start: pid=2919 port=4003

Started GET "/a" for 93.131.158.195 at 2010-08-10 23:00:14 +0200
  Processing by ApplicationController#create_person_and_articles as HTML
  SQL (38.603ms)  INSERT INTO "people" DEFAULT VALUES
  SQL (29.642ms)  INSERT INTO "articles" DEFAULT VALUES
  SQL (0.124ms)  SELECT "article_id", "person_id" FROM "article_people" WHERE ("person_id" = 1 AND "article_id" = 1) ORDER BY "article_id", "person_id" LIMIT 1
  SQL (6.635ms)  INSERT INTO "article_people" ("article_id", "person_id") VALUES (1, 1)
  SQL (11.762ms)  INSERT INTO "articles" DEFAULT VALUES
  SQL (0.101ms)  SELECT "article_id", "person_id" FROM "article_people" WHERE ("person_id" = 1 AND "article_id" = 2) ORDER BY "article_id", "person_id" LIMIT 1
  SQL (7.455ms)  INSERT INTO "article_people" ("article_id", "person_id") VALUES (2, 1)
Completed 200 OK in 150ms


Started GET "/b" for 93.131.158.195 at 2010-08-10 23:00:17 +0200
  Processing by ApplicationController#assing_articles_another_time as HTML
  SQL (0.079ms)  SELECT "id" FROM "people" ORDER BY "id" LIMIT 1
  SQL (0.137ms)  SELECT "articles"."id" FROM "articles" INNER JOIN "article_people" ON "articles"."id" = "article_people"."article_id" INNER JOIN "people" ON "article_people"."person_id" = "people"."id" WHERE "article_people"."person_id" = 1 GROUP BY "articles"."id" ORDER BY "articles"."id"
  SQL (0.034ms)  SELECT "id" FROM "articles" ORDER BY "id"
columns article_id, person_id are not unique (code: 19, sql state: , query: INSERT INTO "article_people" ("article_id", "person_id") VALUES (1, 1), uri: sqlite3:///home/mbj/devel/bugapp/db/development.sqlite3)
Completed   in 13ms

DataObjects::IntegrityError (columns article_id, person_id are not unique):
  app/controllers/application_controller.rb:14:in `assing_articles_another_time'

Setting cache_classes = true, eliminates the problem. Running in rails console also. I'd expect the bug somewhere in the model reload code.

Note about running my example bugapp, you need to use dm-rails from git://github.com/datamapper/dm-rails, see Gemfile. dm-rails-1.0.0 from rubyforge is not yet compatible with rails3.

If you feel this bugreport would fit better in another bugtracker (like rails one under rails.lighthouseapp.com) please let me know I will post this issue there.

ruby -v
ruby 1.9.2dev (2010-07-11 revision 28618) x86_64-linux

---

Created by mbj - 2010-08-10 21:49:08 UTC

Original Lighthouse ticket: http://datamapper.lighthouseapp.com/projects/20609/tickets/1385

[solnic]

Sorry for not getting back so long, is this still an issue?

by Martin Gamsjaeger (snusnu)

[solnic]

The issue ist still reproducible under current rails3, dm-core-1.0.2, and dm-rails-1.0.3

I also updated the github repository with the sample application showing this issue!

Additionally I’d to patch the dm-rails setup code, before the sqlite database was initialized correctly (this mabye is another issue):

diff --git a/lib/dm-rails/setup.rb b/lib/dm-rails/setup.rb
index 8378a8e..0e619be 100644
--- a/lib/dm-rails/setup.rb
+++ b/lib/dm-rails/setup.rb
@@ -16,7 +16,8 @@ module Rails

     def self.setup_with_instrumentation(name, options)
       ::DataMapper.logger.info "[datamapper] Setting up #{name.inspect} repository: ’#{options[’database’]}’ on #{options[’adapter’]}"
-      adapter = ::DataMapper.setup(name, options)
+      uri = "#{options[’adapter’]}://#{options[’database’]}"
+      adapter = ::DataMapper.setup(name, uri)
       if convention = configuration.resource_naming_convention[name]
         adapter.resource_naming_convention = convention
       end

by mbj

[solnic]

I can confirm the exact same problem. cache_classes = true fixes it.

by Arturo

[solnic]

In a similar situation, where I try to invalidate an m:n relationship by setting the dependency via update_attributes, as long as cache_classes is false, it fails with a duplicate key error in the link table. Setting cache_classes to true fixes it.

by Anton Bangratz

[solnic]

My thoughts:

dm-rails does not do real reloading (because you cannot "unload" ruby code), in my opinion it simply tries to load the class/models twice. Deep in the (dm-core?) code there will be data initialized a second time, loosing some information from the first load, causing this problem. Can someone give me a pointer, I’ll try to find it!

I did not spend much time in this, since this is not a problem in production.

Off-Topic:

Would be cool when rails where able to accept requests before loading the models, for each request it can fork itself and load the models in that fork before processing it. In this case it would hide problems, but in other cases the development mode would behave much closer to production.

by mbj

[solnic]

Could you guys test against latest dm-core master please? I’m not entirely certain wether the issue is fixed or not, but mbj’s comment about code being initialized a second time deep inside dm-core made me think about a change I recently pushed to dm-core, that definitely affects reloading behavior.

datamapper/dm-core@2ffa59f

by Martin Gamsjaeger (snusnu)

[solnic]

Hi,

I just tested with latest master, the issue is still reproducible. I also updated the example repo under http://github.com/mbj/bugapp

Still got no luck or enough time to debug into it. Since it is only a non production issue it has no high priority at my workplace.

by mbj

[solnic]

[bulk edit]

by Dan Kubb (dkubb)

[solnic]

Some more details on this (I’m using the Article/Person schema that mbj has in the OP as an example)

Remember:

• The Rails auto-loading behavior is to load models at the start of the request, and blow their classes away once the request finishes
• Implicit join tables don’t get auto-reloaded

Step by Step of what’s going on (as I understand it):

Request #1

• Classes are auto loaded: Article (obj Railtie breaks migrations #1), Person (obj Mass Assignment Security using ActiveModel::MassAssignmentSecurity #2), ArticlePerson (obj Fixed crash with dm session store and devise #3), PersonArticle (obj Have the db:migrate task call either db:migrate:up or db:autoupgrade #4)
• The implicit join tables are instantiated with and hold references onto the model classes (not names)
• ApplicationController#create_person_and_articles creates our initial data set
• Classes are torn down: Article(Railtie breaks migrations #1), Person(Mass Assignment Security using ActiveModel::MassAssignmentSecurity #2)

At this point, the implicit join tables now have ’orphaned’ references to Article(#1) and Person(#2)

Request #2

• Classes are auto loaded: Article(field_naming_convention Overlooked? #5), Person(Fixes a bug in the name... not sure if this breaks something elsewhere! #6). The implicit join tables are already there, so DM just connects the dots
• The join tables are still referring to Article(Railtie breaks migrations #1) and Person(Mass Assignment Security using ActiveModel::MassAssignmentSecurity #2)
• ApplicationController#assing_articles_another_time is called and the save barfs because the association is generating an invalid query. (The condition validators freak out because the target model isn’t the right class. It’s especially confusing for single table inheritance situations)

Couple ideas to fix this

• Make join tables auto-reload aware in dm-rails. If someone defines a DM model outside of the auto-loading environment, but references a model inside of it, they could still encounter this.

• When a class (re)defines an association to an implicit join table; update the association’s parent_model reference to point to the new class instance?

• Make the query validation code aware of this issue? (seems complicated)

  by Ian MacLeod

[solnic]

Note: A workaround to this is to explicitly define all your join tables for now (and avoid the use of :through => Resource)

by Ian MacLeod

[d11wtq]

Does adding DataMapper.finalize to the class reloading code in Rails fix this? I've poked around in that code before, but don't really remember where it is now.

[d11wtq]

FWIW, I reckon Rails could cheat the cache_classes thing by forking before each request rather than trying to reload into the same process. I doesn't reload anything that happens in the initializers anyway.

[solnic]

@d11wtq I'm not sure if this is still a problem. Can somebody confirm that?

ps. the amount of bug reports that are specific to has n :through => Resource makes me think this should be removed from DM and people should be using explicit join models :P