Tuesday, November 13, 2012

Rails - Trace and solve rake db migration error

    We were doing a simple db migration in which a new column, say 'valuation_date', is added to an existing model 'Record'.  In the migration, the valuation_date column is added.  Then a code segment is executed to assign value to it.  Like this:

  def self.up
    add_column :records, :valuation_date, :date

    Record.find_each do |record|
      record.valuation_date = ...
      record.save
    end
  end


    The deployment (rake db:migrate) works fine on development environment.  However, when doing cap deploy:migrations, it returns error:

==  AddValutionDateToRecords: migrating ===================================
-- add_column(:records, :valuation_date, :date)
   -> 0.0014s
rake aborted!
An error has occurred, this and all later migrations canceled:

undefined method `column' for nil:NilClass

Tasks: TOP => db:migrate
(See full trace by running task with --trace)



    Turns out this only happens when running the migration under rails' staging environment.  Then tried execute the db migration and trace the issue.
$ bundle exec rake RAILS_ENV=staging db:migrate --trace

undefined method `relation' for nil:NilClass
/Users/laileo/.rvm/gems/ree-1.8.7-2011.03@merlot/gems/arel-2.0.10/lib/arel/crud.rb:12:in `update'
/Users/laileo/.rvm/gems/ree-1.8.7-2011.03@merlot/gems/activerecord-3.0.11/lib/active_record/persistence.rb:266:in `update'
/Users/laileo/.rvm/gems/ree-1.8.7-2011.03@merlot/gems/activerecord-3.0.11/lib/active_record/locking/optimistic.rb:77:in `update'
/Users/laileo/.rvm/gems/ree-1.8.7-2011.03@merlot/gems/activerecord-3.0.11/lib/active_record/attribute_methods/dirty.rb:68:in `update'
/Users/laileo/.rvm/gems/ree-1.8.7-2011.03@merlot/gems/activerecord-3.0.11/lib/active_record/timestamp.rb:60:in `update'
...

    To look deeper, set a "debugger" breakpoint before record.save.  Then another 2 breakpoints on crud.rb:12 .../active_record/base.rb:1718.  It was found that record.class.arel_table['valuation_date'] is nil that caused the failure.

Investigation #1
    Check if the Arel using different version in different environments.  In debug mode, $ p Arel::VERSION show they are the same.

Investigation #2
    Compare the difference between dev and staging:
$ rake about
$ rake RAILS_ENV=staging about

    The results show that ActionDispatch::Static middleware is not include in staging.  Tried to comment out the config.serve_static_asserts = false in config/environments/production.rb.  Then the middleware ActionDispatch::Static is added.  But it doesn't help.

Investigation #3
    Change the settings on config/environments/production.rb to those in config/environments/development.rb one by one to locate what makes the difference.  Luckily, the first one hits.  It is the config.cache_classes=true on staging environment that leaded to the error.  The model column was cached and not reloaded after add_column.  So, the assign and save of a record resulted in error.  To solve the problem, after add_column, do a reset_column_information.  i.e.

  def self.up
    add_column :records, :valuation_date, :date

    Record.reset_column_information

    Record.find_each do |record|
      record.valuation_date = ...
      record.save
    end
  end


Problem solved!

No comments:

Post a Comment

Note: Only a member of this blog may post a comment.