This project is archived and is in readonly mode.

#5945 ✓resolved
Ari Epstein

after_save callbacks are called before dirty tracking is updated

Reported by Ari Epstein | November 10th, 2010 @ 06:05 PM

Issue:

Callbacks registered with after_save seem to be called before dirty tracking attributes are updated. Thusly, even though the record is saved, changed attributes still are recorded as changed while the after_save/after_create/after_update callbacks are utilized.

I don't know enough about the internals, but two possible issues here:

  1. Is the current behavior correct? If so, it would be nice to have it clearly documented that dirty caching is triggered after the callbacks have been called. This appears to be a change from Rails 2.3 series.
  2. If not, why is this happening? I don't know enough about the internals to fix it.

To reproduce, set up a new project with just this customization for the model:

class Simple < ActiveRecord::Base

  after_create :show_previous_changes

  def show_previous_changes
    puts "Previous changes: #{previous_changes}"
    puts "Changes: #{changes}"
  end

end

ate2@ari-g5:~/prj$ rails g model simple name:string
      invoke  active_record
      create    db/migrate/20101110174416_create_simples.rb
      create    app/models/simple.rb
      invoke    rspec
      create      spec/models/simple_spec.rb
ate2@ari-g5:~/prj$ rake db:migrate
(in /home/ate2/prj)
==  CreateSimples: migrating ==================================================
-- create_table(:simples)
   -> 0.0018s
==  CreateSimples: migrated (0.0020s) =========================================

ate2@ari-g5:~/prj$ rails c

irb(main):002:0> s=Simple.create :name => 'blah'
Previous changes: {}
Changes: {"name"=>[nil, "blah"], "created_at"=>[nil, Wed, 10 Nov 2010 17:47:07 UTC +00:00], "updated_at"=>[nil, Wed, 10 Nov 2010 17:47:07 UTC +00:00], "id"=>[nil, 1]}
=> #<Simple id: 1, name: "blah", created_at: "2010-11-10 17:47:07", updated_at: "2010-11-10 17:47:07">
irb(main):003:0> s.show_previous_changes
Previous changes: {"name"=>[nil, "blah"], "created_at"=>[nil, Wed, 10 Nov 2010 17:47:07 UTC +00:00], "updated_at"=>[nil, Wed, 10 Nov 2010 17:47:07 UTC +00:00], "id"=>[nil, 1]}
Changes: {}
=> nil

Comments and changes to this ticket

  • Ari Epstein

    Ari Epstein November 10th, 2010 @ 06:06 PM

    • Tag changed from active_model, active_record, callbacks, dirty to rails 3.0.1, active_model, active_record, callbacks, dirty
  • Neeraj Singh

    Neeraj Singh November 10th, 2010 @ 09:08 PM

    • Importance changed from “” to “Low”

    Yes it is a feature and it is documented.

    
        # Map of attributes that were changed when the model was saved.
        #   person.name # => 'bob'
        #   person.name = 'robert'
        #   person.save
        #   person.previous_changes # => {'name' => ['bob, 'robert']}
        def previous_changes
          @previously_changed
        end
    

    Does that answer your question?

  • Ari Epstein

    Ari Epstein November 10th, 2010 @ 09:59 PM

    No, does not answer my question. The question is when should @previously_changed be populated and changes be cleared? It appears that it is populated AFTER the after_save, after_create, etc. callbacks are called. In the 2.3 branch, the changes were cleared before the after_save callbacks. The behavior has changed. Is this intentional (if so, it doesn't seem right to me and certainly does not appear to be documented) or is this a bug? It seems like a bug to me.

  • Neeraj Singh

    Neeraj Singh November 10th, 2010 @ 10:29 PM

    I see what you are saying. I will try to get some info on this.

  • Neeraj Singh

    Neeraj Singh November 12th, 2010 @ 05:40 PM

    • Assigned user set to “José Valim”

    Assigning it to Mr. Valim because the question has more to do with historical context. And he has been around a long time :-)

  • José Valim

    José Valim November 25th, 2010 @ 09:54 AM

    Yes, this seems to be a bug. Maybe the order of callbacks is reversed? In other words:

    after_save :a after_save :b

    Should first execute :a and then :b. This may cause the callback that cleans up dirty attributes to come last.

    Neeraj, I think we had a ticket about this, right? Wasn't it fixed? Ari, in which Rails version have you tested?

  • Neeraj Singh

    Neeraj Singh November 26th, 2010 @ 09:52 AM

    Ari said:

    In the 2.3 branch, the changes were cleared before the after_save callbacks.

    I tested with Rails 2.3.10 and this is what I found.

    class User < ActiveRecord::Base
      after_save :show_previous_changes
    
      def show_previous_changes
        #puts "Previous changes: #{self.previous_changes}"
        puts "Changes: #{self.changes.inspect}"
      end  
    end
    
    u = Useree-1.8.7-2010.02 > u = User.first
      User Load (0.6ms)   SELECT * FROM "users" LIMIT 1
     => #<User id: 1, name: "john", created_at: "2010-11-26 09:31:07", updated_at: "2010-11-26 09:42:53"> 
    ree-1.8.7-2010.02 > u.name = 'john2'
    ree-1.8.7-2010.02 > u.save
    Changes: {"name"=>["john", "john2"], "updated_at"=>[Fri Nov 26 09:42:53 UTC 2010, Fri, 26 Nov 2010 09:43:21 UTC +00:00]}
    ree-1.8.7-2010.02 > u.show_previous_changes
    Changes: {}
    

    As you can see after_save callback in Rails 2.3.10 has changes NOT cleared.

    If I run the same code with rails edge this is what I get

    class User < ActiveRecord::Base
      after_save :show_previous_changes
    
      def show_previous_changes
        puts "Previous changes: #{self.previous_changes}"
        puts "Changes: #{self.changes.inspect}"
      end
    end
    
    ree-1.8.7-2010.02 > u = User.first
      User Load (0.8ms)  SELECT "users".* FROM "users" LIMIT 1
     => #<User id: 1, name: "john", created_at: "2010-11-26 09:33:47", updated_at: "2010-11-26 09:43:07"> 
    ree-1.8.7-2010.02 > u.name='john2'
    ree-1.8.7-2010.02 > u.save
    Previous changes: 
    Changes: {"name"=>["john", "john2"], "updated_at"=>[Fri, 26 Nov 2010 09:43:07 UTC +00:00, Fri, 26 Nov 2010 09:43:54 UTC +00:00]}
    ree-1.8.7-2010.02 > u.show_previous_changes
    Previous changes: namejohnjohn2updated_at2010-11-26 09:43:07 UTC2010-11-26 09:43:54 UTC
    Changes: {}
    

    It seems to me that both Rails edge and Rails 2.3.10 after_save callbacks keep the value of changes intact and there does not seem to be any discrepancy.

    It's 5 in the morning so I am sure I am missing something. :-)

  • Ari Epstein

    Ari Epstein November 26th, 2010 @ 05:41 PM

    Hmm... when I did my initial coding on an application where this matters, I could swear that changes got reset before after_save callbacks, but I'm finding this isn't the case with 2.3.5 or subsequent branches. So I guess this is not a bug if it's the intended behavior. Just want to make sure it's not going to change.

  • Neeraj Singh

    Neeraj Singh November 26th, 2010 @ 05:58 PM

    • State changed from “new” to “resolved”

    It is quite possible that behavior might have changed between 2.3.5 and 2.3.10. :-(

    However it seems current rails edge is consistent with 2.3.10 . Closing this ticket for now. Please feel free to add to it if you find anything new.

    Thanks

Create your profile

Help contribute to this project by taking a few moments to create your personal profile. Create your profile »

<h2 style="font-size: 14px">Tickets have moved to Github</h2>

The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>

Pages