2

I have a problem with DataMapper (I'm using it with Sinatra)

I have a very basic app with 3 models. Here's the code.

class Level
  include DataMapper::Resource
  property :id, Serial
  property :name, String, :required => true, :unique => true, :lazy => true
  property :description, Text, :lazy => true
  timestamps :at
end

class Player
  include DataMapper::Resource
  property :id, Serial
  property :name, String, :required => true, :lazy => true
  timestamps :at
  belongs_to :game
end

class Game
  include DataMapper::Resource
  property :id, Serial
  has n, :players
  belongs_to :level
  belongs_to :current_player, 'Player', :required => false
end

Here's a basic route:

get '/' do
  DataMapper::logger.debug 'Creating level'
  level = Level.create(:name => "One")

  DataMapper::logger.debug 'Creating game'
  game = Game.create(:level => level)

  DataMapper::logger.debug 'Adding players'
  alice = Player.create(:name => 'Alice', :game => game)
  bob = Player.create(:name => 'Bob', :game => game)

  DataMapper::logger.debug 'Setting game current player'
  game.current_player = alice
  game.save
  'ok'
end

My problem is that when I look at the DataMapper log file, I find it has made many useless queries and I don't understand why!

Here's the log output:

 ~ Creating level
 ~ (0.000062) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.002241) INSERT INTO "levels" ("name", "created_at", "updated_at") VALUES ('One', '2012-01-15T18:15:28+01:00', '2012-01-15T18:15:28+01:00')
 ~ Creating game
 ~ (0.000048) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.001747) INSERT INTO "games" ("level_id") VALUES (1)
 ~ Adding players
 ~ (0.000050) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.003762) INSERT INTO "players" ("name", "created_at", "updated_at", "game_id") VALUES ('Alice', '2012-01-15T18:15:28+01:00', '2012-01-15T18:15:28+01:00', 1)
 ~ (0.000085) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.001820) INSERT INTO "players" ("name", "created_at", "updated_at", "game_id") VALUES ('Bob', '2012-01-15T18:15:28+01:00', '2012-01-15T18:15:28+01:00', 1)
 ~ Setting game current player
 ~ (0.000078) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.001826) UPDATE "games" SET "current_player_id" = 1 WHERE "id" = 1

As you can see, there's a lot of queries for the level model. I really don't understand why DataMapper is doing these.

Thanks a lot in advance for your help.

PS: You may think that it is not a big deal but I actually simplified the model structure before posting here. The actual model is more complex and is full of those useless queries..

Here's a short part of my real datamapper log file: It happens when I save an instance of my game model.

 ~ (0.001640) UPDATE "asd_games" SET "updated_at" = '2012-01-15T17:51:27+01:00', "current_player_id" = 3, "current_action_id" = 3 WHERE "id" = 1
 ~ (0.000079) SELECT "id", "body" FROM "asd_actions" WHERE "id" = 3 ORDER BY "id"
 ~ (0.000083) SELECT "id", "name", "description" FROM "asd_levels" WHERE "id" = 1 ORDER BY "id"
 ~ (0.000057) SELECT "id" FROM "asd_levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.000075) SELECT "id" FROM "asd_levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.000083) SELECT "id" FROM "asd_levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.000082) SELECT "id" FROM "asd_levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.000084) SELECT "id" FROM "asd_levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1

2 Answers 2

0

The extra SELECTS are being made to check the :unique => true constraint on the Level class. This check seems to be being made on every database call.

One way to avoid this would be instead of using create when creating your model objects, which immediately saves the model in the database, use new and then save the whole object graph with a single call to save on a suitable object when they're all ready (see the docs on creating and saving models):

DataMapper::logger.debug 'Creating level'
level = Level.new(:name => "One")

DataMapper::logger.debug 'Creating game'
game = Game.new(:level => level)

DataMapper::logger.debug 'Adding players'
alice = Player.new(:name => 'Alice', :game => game)
bob = Player.new(:name => 'Bob', :game => game)

DataMapper::logger.debug 'Setting game current player'
game.current_player = alice
game.save

produces the output:

 ~ Creating level
 ~ Creating game
 ~ Adding players
 ~ Setting game current player
 ~ (0.000074) SELECT "id" FROM "levels" WHERE "name" = 'One' ORDER BY "id" LIMIT 1
 ~ (0.001062) INSERT INTO "levels" ("name", "created_at", "updated_at") VALUES ('One', '2012-01-15T20:07:16+00:00', '2012-01-15T20:07:16+00:00')
 ~ (0.001460) INSERT INTO "games" ("level_id") VALUES (1)
 ~ (0.001279) INSERT INTO "players" ("name", "created_at", "updated_at", "game_id") VALUES ('Alice', '2012-01-15T20:07:16+00:00', '2012-01-15T20:07:16+00:00', 1)
 ~ (0.001592) UPDATE "games" SET "current_player_id" = 1 WHERE "id" = 1

So the models are not immediately persisted, but are all done together, and the uniqueness check is only done once.

Another possibility would be to set :auto_validation => false on the :name property.

This change produces this output (using create):

 ~ Creating level
 ~ (0.001162) INSERT INTO "levels" ("name", "created_at", "updated_at") VALUES ('One', '2012-01-15T20:13:51+00:00', '2012-01-15T20:13:51+00:00')
 ~ Creating game
 ~ (0.001958) INSERT INTO "games" ("level_id") VALUES (1)
 ~ Adding players
 ~ (0.001194) INSERT INTO "players" ("name", "created_at", "updated_at", "game_id") VALUES ('Alice', '2012-01-15T20:13:51+00:00', '2012-01-15T20:13:51+00:00', 1)
 ~ (0.001304) INSERT INTO "players" ("name", "created_at", "updated_at", "game_id") VALUES ('Bob', '2012-01-15T20:13:51+00:00', '2012-01-15T20:13:51+00:00', 1)
 ~ Setting game current player
 ~ (0.001369) UPDATE "games" SET "current_player_id" = 1 WHERE "id" = 1

So there are still multiple calls to the database, but the check isn't made on each call (in fact it doesn't look like it's being made at all, so this rather defeats the object of using :unique => true in the first place).

1
  • Thanks a lot for your help ! I'll investigate more on the :unique => true ;)
    – Balzard
    Jan 18, 2012 at 16:51
0

I ran into the same issue where I have a User and a Job. The Job belongs_to the user. Snippets:

class User
  include DataMapper::Resource
  property :id,                 Serial,   writer: :protected, key: true
  property :email,              String,   required: true, length: (5..40),
                                          unique: true, format: :email_address
end

class Job
  include DataMapper::Resource
  property :id, Serial, key: true
  property :progress, Integer
  property :updated_at, DateTime
  belongs_to :user
end

Every time I save the job, two queries are run:

~ (0.000421) SELECT `id` FROM `users` WHERE `email` = 'mike@example.com' ORDER BY `id` LIMIT 1
~ (0.001589) UPDATE `jobs` SET `progress` = 19, `updated_at` = '2013-12-19 06:32:43' WHERE `id` = 91

Because I am confident that my update contains no bad data (nothing is tainted by user input), I was able to stop the SELECT from running by using the bang (!) version of save

-    save
+    save!

http://datamapper.org/docs/create_and_destroy.html describes what actually happens when you use the bang method instead of the non-bang method, so you will want to review that and see if it's safe for your use case.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.