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
save record with BANG '!' so it will make a run time error and you get know where does it happens
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.
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
The 3 methodologies (1 failed) I have come up with are to
-
use an observer on active record on all the relevant save, validate methods
-
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. -
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.
-
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.
-
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