m33lky
m33lky

Reputation: 7285

how to find the cause of ActiveRecord ROLLBACK

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

Upvotes: 70

Views: 35001

Answers (5)

davidtingsu
davidtingsu

Reputation: 1180

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. Put a debugger statement when where the rollback is executed. https://github.com/rails/rails/blob/3-1-stable/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb#L231

    Run cd bundle show activerecord to locate the gem folder.

    # /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 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
    

Upvotes: 10

Goulven
Goulven

Reputation: 889

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 :-)

Upvotes: 0

Nitin Jain
Nitin Jain

Reputation: 3083

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

Upvotes: 115

Sergiy Seletskyy
Sergiy Seletskyy

Reputation: 17180

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

Upvotes: 25

DanneManne
DanneManne

Reputation: 21180

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.

Upvotes: 52

Related Questions