AR's before_last_save tracking wrong for nested callback

[MaxLap]

Nested callback executions in ActiveRecord (ex: a after_save does a update, which trigger another chain of callbacks) have a weird (IMO wrong) interaction with the saved_change_to_*?, saved_changes, *_before_last_save and friends.

The behavior changed in Rails 5.1. Rails 5.0's behavior was more intuitive.

Steps to reproduce

( I got repro scripts below )

0. A model with 2 attributes, ex: name and foo

1. Have a after_save (or any other after_something) that does an update to foo of the model (with a condition, so that you don't get infinite recursion). Ex: update(foo: 1) if foo != 1

2. Have another after_save (called after the one in (1)) which checks if the other attribute was changed. Ex: $saw_saved_change_to_name = true if saved_change_to_name?

3. Create an instance setting only the name: Ex: Post.create(name: 'hi')

The second callback will never see saved_change_to_name? as true, because the first callback, triggering anothere save, fully overwrites the tracking.

I added a print of the saved_changes in the test to show what's going on. There is a failing script for main and 5.1, and a passing one for 5.0.

Here is the failing case in main:

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  # Activate the gem you are reporting the issue against.
  gem "rails", github: "rails/rails", branch: "main"
  gem "sqlite3", '~> 1.4'
end

require "active_record"
require "minitest/autorun"
require "logger"

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true do |t|
    t.text :name
    t.integer :foo
  end
end

class Post < ActiveRecord::Base
  after_save :set_foo_after_save
  after_save :check_saved_change_to_name

  def set_foo_after_save
    update(foo: 1) if foo != 1
  end

  def check_saved_change_to_name
    puts "* Saved changes: #{saved_changes}"
    $saw_saved_change_to_name = true if saved_change_to_name?
  end
end

class BugTest < Minitest::Test
  def test_association_stuff
    post = Post.create!(name: 'hi')

    assert($saw_saved_change_to_name)
  end
end

* Saved changes: {"foo"=>[nil, 1]}
* Saved changes: {"foo"=>[nil, 1]}
Expected nil to be truthy

Here is the failing case in 5.1:

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  # Activate the gem you are reporting the issue against.
  gem "activerecord", "5.1.7"
  gem "sqlite3", '1.3.13'
end

require "active_record"
require "minitest/autorun"
require "logger"

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true do |t|
    t.text :name
    t.integer :foo
  end
end

class Post < ActiveRecord::Base
  after_save :set_foo_after_save
  after_save :check_saved_change_to_name_after_save

  def set_foo_after_save
    update(foo: 1) if foo != 1
  end

  def check_saved_change_to_name_after_save
    puts "* Saved changes: #{saved_changes}"
    $saw_saved_change_to_name = true if saved_change_to_name?
  end
end

class BugTest < Minitest::Test
  def test_association_stuff
    post = Post.create!(name: 'hi')

    assert($saw_saved_change_to_name)
  end
end

* Saved changes: {"foo"=>[nil, 1]}
* Saved changes: {"foo"=>[nil, 1]}
Expected nil to be truthy

And here is the passing case in 5.0, which was before Rails switched to saved_change_to_*? and friends:

# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  # Activate the gem you are reporting the issue against.
  gem "activerecord", "5.0.7.2"
  gem "sqlite3", '1.3.13'
end

require "active_record"
require "minitest/autorun"
require "logger"

# This connection will do for database-independent bug reports.
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)

ActiveRecord::Schema.define do
  create_table :posts, force: true do |t|
    t.text :name
    t.integer :foo
  end
end

class Post < ActiveRecord::Base
  after_create :set_foo_after_save
  after_save :check_saved_change_to_name_after_save

  def set_foo_after_save
    update(foo: 1) if foo != 1
  end

  def check_saved_change_to_name_after_save
    puts "* Saved changes: #{changes}"
    $saw_saved_change_to_name = true if name_changed?
  end
end

class BugTest < Minitest::Test
  def test_association_stuff
    post = Post.create!(name: 'hi')

    assert($saw_saved_change_to_name)
  end
end

* Saved changes: {"id"=>[nil, 1], "name"=>[nil, "hi"], "foo"=>[nil, 1]}
* Saved changes: {}
Passes the test

Expected behavior

I expect a after_* callback that reacts to saved_change_to_*? to be called at least once with said change of true when the attribute gets changed.

Actual behavior

The callback never gets called with saved_change_to_name? being true because the nested change

In my opinion, the priority should be on handling the 1st expected behavior

This means that if I make code with such a callback, everything could work, and someone doing a nested update in a different callback could completely break the first callback.

System configuration

Rails version: 5.1, main

Ruby version: 2.4 and 3.1

[nickborromeo]

This looks to be intentional behavior. There is more context on this in this commit 16ae3db

In the main PR #25337 there is a useful table that summarizes the changes.

[MaxLap]

I doubt it's intentional that a record's callback might never be called with a "X attribute has changed" when it does change.

I understand there were lots of changed and that can have unexpected side effects. But to me, it's still a bug.

[abhisheksarka]

I don't think this can be classified as a bug since the documentation states that nested callbacks of this sort are to be avoided

From the guides

Avoid updating or saving attributes in callbacks. For example, don't call update(attribute: "value")
within a callback. 
This can alter the state of the model and may result in unexpected side effects during commit.
Instead, you can safely assign values directly (for example, self.attribute = "value") in before_create / before_update or earlier callbacks.