deadlock_retry icon indicating copy to clipboard operation
deadlock_retry copied to clipboard

deadlock retry fails to save record that raises a deadlock in after hooks

Open mdimas opened this issue 13 years ago • 4 comments

If a deadlock occurs in an after commit hook for a record deadlock_retry will retry the commit but issues an "UPDATE" instead of an "INSERT" statement, resulting in the record never being saved even though calling #save returns true. This is easily demonstrated with the following code:

require 'deadlock_retry'

class MyTest < ActiveRecord::Base

  after_create :deadlock_error
  after_commit :puts_after_commit, :on => :create

  def deadlock_error
    unless @errored
      @errored = true
      raise ActiveRecord::StatementInvalid.new("Deadlock found when trying to get lock")
    end
    return
  end

  def puts_after_commit
    puts "After Commit"
  end
end

my_test = MyTest.new(:name => "Testing")

if my_test.save
  MyTest.find(my_test.id)
end

This will have the following output:

> my_test = MyTest.new(:name => "Testing")
=> #<MyTest id: nil, name: "Testing"> 
> if my_test.save
?>     MyTest.find(my_test.id)
?>   end

After Commit
ActiveRecord::RecordNotFound: Couldn't find MyTest with ID=1
from /Users/dimas/.rvm/gems/ree-1.8.7-2011.03/gems/activerecord-3.0.11/lib/active_record/relation/finder_methods.rb:306:in `find_one'
from /Users/dimas/.rvm/gems/ree-1.8.7-2011.03/gems/activerecord-3.0.11/lib/active_record/relation/finder_methods.rb:291:in `find_with_ids'
from /Users/dimas/.rvm/gems/ree-1.8.7-2011.03/gems/activerecord-3.0.11/lib/active_record/relation/finder_methods.rb:107:in `find'
from /Users/dimas/.rvm/gems/ree-1.8.7-2011.03/gems/activerecord-3.0.11/lib/active_record/base.rb:444:in `__send__'
from /Users/dimas/.rvm/gems/ree-1.8.7-2011.03/gems/activerecord-3.0.11/lib/active_record/base.rb:444:in `find'
from (irb):22

And if you look at the log you'll see:

SQL (0.1ms)  BEGIN
SQL (1.9ms)  describe `my_tests`
AREL (0.2ms)  INSERT INTO `my_tests` (`name`) VALUES ('Testing')
SQL (0.5ms)  ROLLBACK
Deadlock detected on retry 1, restarting transaction
SQL (3.3ms)  BEGIN
AREL (0.3ms)  UPDATE `my_tests` SET `name` = 'Testing' WHERE `my_tests`.`id` = 1
SQL (0.1ms)  COMMIT
MyTest Load (0.2ms)  SELECT `my_tests`.* FROM `my_tests` WHERE `my_tests`.`id` = 1 LIMIT 1

mdimas avatar Feb 04 '12 18:02 mdimas

Is there a fix for this issue?

mdimas avatar Feb 15 '12 22:02 mdimas

arrgh just faced this issue on Prod, after using the gem for couple years! now need to remove the gem, sigh..

artemv avatar Dec 05 '13 23:12 artemv

Btw code example can be simpler:

require 'deadlock_retry'

class MyTest < ActiveRecord::Base
  after_create :deadlock_error

  def deadlock_error
    raise ActiveRecord::StatementInvalid.new("Deadlock found when trying to get lock")
  end
end

my_test = MyTest.new(:name => "Testing")

if my_test.save
  MyTest.find(my_test.id)
end

with same output : ActiveRecord::RecordNotFound: Couldn't find MyTest with ID=1

artemv avatar Dec 05 '13 23:12 artemv

I'm thinking about using this gem, just came across this issue. FWIW I don't see the problem when running either of the above examples in a console. The second, shorter example bails after 3 retries and raises ActiveRecord::StatementInvalid: Deadlock found when trying to get lock. The first example fails once, retries with "Deadlock detected on retry 1, restarting transaction", then finishes on a second iteration. The put is not executed until after successful 2nd iteration:

   (0.1ms)  BEGIN
  SQL (0.2ms)  INSERT INTO `my_tests` (`name`) VALUES ('Testing')
   (0.2ms)  ROLLBACK
Deadlock detected on retry 1, restarting transaction
   (0.1ms)  BEGIN
  SQL (0.1ms)  INSERT INTO `my_tests` (`name`) VALUES ('Testing')
   (0.2ms)  COMMIT
After Commit
  MyTest Load (0.3ms)  SELECT `my_tests`.* FROM `my_tests` WHERE `my_tests`.`id` = 10 LIMIT 1
 => #<MyTest id: 10, name: "Testing">

this running on rails v 3.2.16

readysetawesome avatar Jan 08 '15 23:01 readysetawesome