search

paper-trail-gem / paper_trail

Track changes to your rails models
MIT License
6.78k stars 895 forks source link

Unique database errors #451

Closed EleanorRagone closed 9 years ago

EleanorRagone commented 9 years ago

Hi there -

I'm having intermittent problems that I'm having trouble replicating, but I figured I'd reach out to you guys and see if you're familiar with it.

Long story short, this is the error:

ActiveRecord::RecordNotUnique: PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "versions_pkey"

The conditions:

It's a big problem because this error ends up rolling back my update:

2.1.5 :006 > u.save(validate: false)
   (0.4ms)  BEGIN
  SQL (1.0ms)  UPDATE "public"."users" SET "apartment_roles_mask" = $1, "updated_at" = $2 WHERE "public"."users"."id" = 5  [["apartment_roles_mask", "\"hvremo\"=>\"5\",\"public\"=>\"32\""], ["updated_at
", "2014-12-26 18:54:43.412041"]]
  SQL (33.6ms)  INSERT INTO "versions" ("created_at", "event", "item_id", "item_type", "object") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  [["created_at", "2014-12-26 18:54:43.467064"], ["event", "upd
ate"], ["item_id", 5], ["item_type", "User"], ["object", "---\nid: 5\nfirst_name: Peter\nlast_name: Ragone\nemail: peter@prmtech.com\nusername: '350310'\nold_data: \ncreated_at: 2014-12-26 02:31:32.3762
95000 Z\nupdated_at: 2014-12-26 18:29:09.237037000 Z\nencrypted_password: \"$2a$10$BsdfJlY51q3YRmuKe4MpoONq9hIgS2Lrrh8EQYpG.3IYRpzPtPNtq\"\nreset_password_token: \nreset_password_sent_at: \nremember_cre
ated_at: \nsign_in_count: 3\ncurrent_sign_in_at: 2014-12-26 18:29:09.233149000 Z\nlast_sign_in_at: 2014-12-26 03:50:52.172595000 Z\ncurrent_sign_in_ip: !ruby/object:IPAddr\n  family: 2\n  addr: 21307064
33\n  mask_addr: 4294967295\nlast_sign_in_ip: !ruby/object:IPAddr\n  family: 2\n  addr: 2130706433\n  mask_addr: 4294967295\nconfirmation_token: \nconfirmed_at: 2014-12-26 02:40:15.863417000 Z\nconfirma
tion_sent_at: 2014-12-26 02:39:54.487143000 Z\nunconfirmed_email: \nfailed_attempts: 0\nunlock_token: \nlocked_at: \napartment_roles_mask:\n  hvremo: '5'\n  public: '0'\nflags:\n  new_remo_als_user: 'fa
lse'\n  after_signup_complete: 'true'\n  next_after_signup_step: 'false'\n  email_confirmation_instructions_sent: 'true'\ndefault_region_id: \n"]]
PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "versions_pkey"
DETAIL:  Key (id)=(1) already exists.
: INSERT INTO "versions" ("created_at", "event", "item_id", "item_type", "object") VALUES ($1, $2, $3, $4, $5) RETURNING "id"
   (0.5ms)  ROLLBACK
ActiveRecord::RecordNotUnique: PG::UniqueViolation: ERROR:  duplicate key value violates unique constraint "versions_pkey"
DETAIL:  Key (id)=(1) already exists.
: INSERT INTO "versions" ("created_at", "event", "item_id", "item_type", "object") VALUES ($1, $2, $3, $4, $5) RETURNING "id"
        from /Users/pragone/.rvm/gems/ruby-2.1.5@remoonline/gems/activerecord-4.1.8/lib/active_record/connection_adapters/postgresql_adapter.rb:834:in `get_last_result'
        from /Users/pragone/.rvm/gems/ruby-2.1.5@remoonline/gems/activerecord-4.1.8/lib/active_record/connection_adapters/postgresql_adapter.rb:834:in `block in exec_cache'
        from /Users/pragone/.rvm/gems/ruby-2.1.5@remoonline/gems/activerecord-4.1.8/lib/active_record/connection_adapters/abstract_adapter.rb:373:in `block in log'
        from /Users/pragone/.rvm/gems/ruby-2.1.5@remoonline/gems/activesupport-4.1.8/lib/active_support/notifications/instrumenter.rb:20:in `instrument'

I re-issue the save command, and everything works fine.

Are you familiar with this condition happening? Can you give me any more insight? I'm happy to try and replicate this more and identify it, but, like I said, it seems to be an intermittent problem.

Edit: Looking at this some more, it seems to be issuing a double-insert into versions; I'm not sure why, when there's clearly only a single update to the users table.

batter commented 9 years ago

I am not familiar with the error unfortunately. What is the 'versions_pkey' constraint they are referring to? Or is that PG's way of referring to a primary key for the versions table? I don't think the versions table would have a primary key by default if you used the base setup from the generator.. just an index. So maybe it's an index duplicate insert, but it shouldn't be a unique index by default so I'm not sure why that would occur.

batter commented 9 years ago

Closing for now, but feel free to follow up if you encounter these issues again.

tombroomfield commented 9 years ago

Hi, I am also getting this error when I save a previous version in order to rollback.

Thanks, Tom.

batter commented 9 years ago

What version of PaperTrail are you using?

rvfx commented 9 years ago

I get a similar error. paper_trail (4.0.0.beta2) tries to save my entry while the old one still exists, when I call PaperTrail::Version.find(params[:id]).reify.save!:

INSERT INTO "reservations" ("id", "created_at", "guest_id", "updated_at") VALUES ($1, $2, $3, $4) RETURNING "id" ["id", 15], ["created_at", "2015-03-06 16:54:04.016854"], ["guest_id", 6], ["updated_at", "2015-03-09 10:57:10.457005"]]

PG::UniqueViolation: ERROR: duplicate key value violates unique constraint "reservations_pkey" DETAIL: Key (id)=(15) already exists.

batter commented 9 years ago

Looks like these are issues of your database table sequence falling out of sync or something. This StackOverflow post might give you some help on how to reset the sequence on your table.

Although I do find it a bit strange that it's attempting to do an insert instead of an update on this row, so maybe that's what's going wrong here. When I try this on my local w/ SQLite I get an update statement:

2.0.0-p247 :004 > PaperTrail::Version.find(2).reify.save!
  PaperTrail::Version Load (0.2ms)  SELECT  "versions".* FROM "versions"  WHERE "versions"."id" = ? LIMIT 1  [["id", 2]]
  Widget Load (0.1ms)  SELECT  "widgets".* FROM "widgets"  WHERE "widgets"."id" = ? LIMIT 1  [["id", 1]]
   (0.0ms)  SAVEPOINT active_record_1
  SQL (0.0ms)  UPDATE "widgets" SET "name" = ?, "updated_at" = ? WHERE "widgets"."id" = 1  [["name", "foobar"], ["updated_at", "2015-03-09 16:03:21.239462"]]
  SQL (0.1ms)  INSERT INTO "versions" ("created_at", "event", "item_id", "item_type", "object", "object_changes", "transaction_id") VALUES (?, ?, ?, ?, ?, ?, ?)  [["created_at", "2015-03-09 16:03:21.239462"], ["event", "update"], ["item_id", 1], ["item_type", "Widget"], ["object", "---\nid: 1\nname: bar\na_text: \nan_integer: \na_float: \na_decimal: \na_datetime: \na_time: \na_date: \na_boolean: \nsacrificial_column: \ntype: \ncreated_at: 2015-03-09 16:03:06.105316000 Z\nupdated_at: 2015-03-09 16:03:15.704597000 Z\n"], ["object_changes", "---\nname:\n- bar\n- foobar\nupdated_at:\n- 2015-03-09 16:03:15.704597000 Z\n- 2015-03-09 16:03:21.239462000 Z\n"], ["transaction_id", 1]]
   (0.0ms)  RELEASE SAVEPOINT active_record_1
 => true

So perhaps it's a Postgres / ActiveRecord error. Does this happen for you w/ PaperTrail 3.x and also what version of ActiveRecord are you using?

rvfx commented 9 years ago

I get the same error with version 3.0.7 (ActiveRecord 4.2.0), but I have an idea why PaperTrail tries to insert the row. The entry I want to reset is excluded by a default_scope. ActiveRecord might think the entry was deleted and has to be inserted...

Update: I don't get an error when I remove the default_scope.

rvfx commented 9 years ago

I looked more closely at the gem's code: version_concern.rb:8 uses a standard belongs_to association: belongs_to :item, :polymorphic => true

Thereby any default_scope which is defined in the item's model will be applied. I think it would be an improvement if PaperTrail would use an unscoped query. Otherwise any item "hidden" by default_scope will cause an error.

batter commented 9 years ago

@rvfx - can you try using the :dup => true option arg to the reify method? like so: PaperTrail::Version.find(params[:id]).reify(dup: true).save!

rvfx commented 9 years ago

No changes with :dup => true. :(

batter commented 9 years ago

Ok what is your suggested adjustment that you think would fix the issue? Drop this approach and do something more along the lines of this?

inheritance_column_name = item_type.constantize.inheritance_column
class_name = attrs[inheritance_column_name].blank? ? item_type : attrs[inheritance_column_name]
klass = class_name.constantize
model = klass.unscoped.find_by_id(item_id) || klass.new

Any chance you can provide a failing test case via a PR or something?

rvfx commented 9 years ago

The unscoped version works great! PR coming up...

batter commented 9 years ago

@rvfx - Did you ever find time to implement this code into something that could be made into a PR? I'm trying to tie of loose ends for 4.x before an official release and I think this would be a good addition, but I'm unsure of exactly what should change since I don't have test cases to duplicate this issue..

rvfx commented 9 years ago

The code you suggested works fine. Sorry, I haven't found time to make a commit.

mockdeep commented 3 years ago

For what it's worth, I was seeing this issue with a custom subclass in development mode. Rails 6.0.3.6, PaperTrail 12.0.0. I had this class:

class SubjectVersion < PaperTrail::Version
  self.table_name = :subject_versions
end

When I would reset the database with our seeds, there would be 16 records in the subjects_versions table, but for some reason Postgres would have the next id as 2. I instead switched it to include VersionConcern, and things seem to work better at first glance. The next id is 17 and the page that was throwing the error allows me to continue:

class SubjectVersion < ApplicationRecord
  include PaperTrail::VersionConcern
end