how to find the cause of ActiveRecord ROLLBACK

Question

In the logs I'm seeing a ROLLBACK, but no exception is logged. Is there a way to find out what caused the ROLLBACK?

Here's the excerpt of the log:

  Phone Load (0.4ms)  SELECT "phones".* FROM "phones" WHERE "phones"."id" = $1 LIMIT 1  [["id", 980190963]]
   (0.2ms)  BEGIN
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."phone_id" = 980190963 LIMIT 1
   (0.2ms)  ROLLBACK
  Phone Load (0.4ms)  SELECT "phones".* FROM "phones" WHERE "phones"."id" = $1 LIMIT 1  [["id", 980190963]]
  User Load (0.4ms)  SELECT "users".* FROM "users" WHERE "users"."phone_id" = 980190963 LIMIT 1

Answer 1

save record with BANG '!' so it will make a run time error and you get know where does it happens

Answer 2

One way is to manually write information to the log. Try something like this from your controller:

Rails.logger.info(@your_object.errors.inspect) 

That should output the content of all validations that failed.

Answer 3

1) Disable before_create, before_save, before_update and check where it saves the day

2) If rollback was caused by one of those methods, check that those methods return true when you don't plan to rollback.

For example if you set default value for boolean field to avoid nil, you would probably do it this way

def set_defaults_before_create
  self.my_boolean_field ||= false
end

In this example method set_defaults_before_create always returns false and thus rollbacks your transaction. So refactor it to return true

def set_defaults_before_create
  self.my_boolean_field ||= false
  true
end

Answer 4

The 3 methodologies (1 failed) I have come up with are to

1. use an observer on active record on all the relevant save, validate methods

2. to open up active record and put a debugger statement where ROLLBACKs are triggered and then run caller to pinpoint the code that triggered the error.

3. Failed :override the active record methods and pause on exception. If I remember this method does not catch any exception because the save methods are wrapped in a transaction.

Notes: Only enable when the mode is not Rails.env.production?. Tested on Rails 3.2.13, using ruby 1.9.3.

1. Observer: http://guides.rubyonrails.org/v3.2.13/active_record_validations_callbacks.html#observers

   class ActiveRecordObserver < ActiveRecord::Observer

   observe "ActiveRecord::Base"
   
   def after_validation(model)
       debugger if model.errors.messages.any?
       Rails.logger.error "after validation"
   end
   def before_update(model)
       debugger if !model.valid?
       Rails.logger.error "before update"
   end
   def after_update(model)
       debugger if !model.valid?
       Rails.logger.error "after update"
   end
   def before_save(model)
   
       debugger if model.errors.messages.any?
       Rails.logger.error "#{model}"
       Rails.logger.error "before save"
   end
   def after_save(model)
       debugger if model.errors.messages.any?
       Rails.logger.error "after save"
   end
   

   end

NOTE: To use Observers in recent Rails versions (from v.4 up to the most recent v.6), you need to bundle gem 'rails-observers' in Gemfile (best if enclosed inside a :development and :test group), put the class under app/observers/active_record_observer.rb, and register the observer in your current environment config file (e.g. config/environments/development.rb) by placing (or adding to) this line: config.active_record.observers = [:active_record_observer]

2) https://github.com/rails/rails/blob/3-1-stable/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb#L231 cd `bundle show activerecord`

     Put a debugger statement when where the rollback is executed.
    /Users/<user>/.rvm/gems/ruby-1.9.3-<env>/gems/activerecord-3.2.14/lib/active_record/connection_adapters/abstract/database_statements.rb

   196              transaction_open = false
   197              decrement_open_transactions
   198              if open_transactions == 0
   199                rollback_db_transaction
   200                debugger
=> 201                rollback_transaction_records(true)
   202              else
   203                rollback_to_savepoint
   204                debugger
   205                rollback_transaction_records(false)

When the rails server or console hits the breakpoint type in caller to get the backtrace.

3. Override AR in development mode. TODO: only override if !Rails.env.production? Put this in app/config/initializers/active_record_or_any_file_name.rb

   ActiveRecord::Base.class_eval do alias_method :old_save, :save alias_method :old_save!, :save! def save(*args) begin puts "#{self} save" Rails.logger.info "#{self} save" old_save(*args) rescue Exception => e debugger puts e end end def save!(*args) begin Rails.logger.info "#{self} save!" puts "#{self} save!" old_save!(*args) rescue Exception => e debugger puts e end end end

Answer 5

In my case a has_many association was defined with dependent: :restrict_with_error instead of dependent: :destroy. It was defined in a concern so I didn't see it immediately. Anyway, it would be nice if Rails told us what causes a Rollback to happen :-)