Lighthouse has a new layout. Prefer the old one? Return to the old layout, and switch back any time from the link at the top of each page.

This project is archived and is in readonly mode.

after_save callbacks are called before dirty tracking is updated

#5945

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

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

State: resolved
Milestone: none
Assigned to: José Valim José Valim
Importance: Low

Activity

  1. Ari Epstein
    Ari Epstein
    • Tag changed from active_model, active_record, callbacks, dirty to rails 3.0.1, active_model, active_record, callbacks, dirty

    November 10th, 2010 @ 06:06 PM

  2. Neeraj Singh
    Neeraj Singh
    • 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?

    November 10th, 2010 @ 09:08 PM

  3. Ari Epstein
    Ari Epstein

    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.

    November 10th, 2010 @ 09:59 PM

  4. Neeraj Singh
    Neeraj Singh

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

    November 10th, 2010 @ 10:29 PM

  5. Neeraj Singh
    Neeraj Singh
    • 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 :-)

    November 12th, 2010 @ 05:40 PM

  6. José Valim
    José Valim

    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?

    November 25th, 2010 @ 09:54 AM

  7. Neeraj Singh
    Neeraj Singh

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

    November 26th, 2010 @ 09:52 AM

  8. Ari Epstein
    Ari Epstein

    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.

    November 26th, 2010 @ 05:41 PM

  9. Neeraj Singh
    Neeraj Singh
    • 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

    November 26th, 2010 @ 05:58 PM