example.rb

# 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", "6.0.0"
  gem "sqlite3"
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.integer :status
  end

end

class Post < ActiveRecord::Base
  after_commit :log_changes, on: :update

  def log_changes
    puts "Post.log_changes after_commit is called"
  end
end

puts "> creating post"
post = Post.create!
post_id = post.id


puts "> first update"
post = Post.find(post_id)
post.update(status: 1)

puts "> second update"
post = Post.find(post_id)
post.update(status: 1)

log.md

rails migration

D, [2020-04-26T14:55:08.443196 #9614] DEBUG -- :    (0.8ms)  SELECT sqlite_version(*)
D, [2020-04-26T14:55:08.443619 #9614] DEBUG -- :    (0.1ms)  DROP TABLE IF EXISTS "posts"
D, [2020-04-26T14:55:08.444281 #9614] DEBUG -- :    (0.4ms)  CREATE TABLE "posts" ("id" integer PRIMARY KEY AUTOINCREMENT NOT NULL, "status" integer)
   -> 0.0055s
D, [2020-04-26T14:55:08.469658 #9614] DEBUG -- :    (0.2ms)  CREATE TABLE "ar_internal_metadata" ("key" varchar NOT NULL PRIMARY KEY, "value" varchar, "created_at" datetime(6) NOT NULL, "updated_at" datetime(6) NOT NULL)
D, [2020-04-26T14:55:08.480554 #9614] DEBUG -- :   ActiveRecord::InternalMetadata Load (0.1ms)  SELECT "ar_internal_metadata".* FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = ? LIMIT ?  [["key", "environment"], ["LIMIT", 1]]
D, [2020-04-26T14:55:08.484154 #9614] DEBUG -- :    (0.1ms)  begin transaction
D, [2020-04-26T14:55:08.484410 #9614] DEBUG -- :   ActiveRecord::InternalMetadata Create (0.1ms)  INSERT INTO "ar_internal_metadata" ("key", "value", "created_at", "updated_at") VALUES (?, ?, ?, ?)  [["key", "environment"], ["value", "default_env"], ["created_at", "2020-04-26 11:55:08.483768"], ["updated_at", "2020-04-26 11:55:08.483768"]]
D, [2020-04-26T14:55:08.484556 #9614] DEBUG -- :    (0.0ms)  commit transaction

creating the post

> creating post
D, [2020-04-26T14:55:08.487082 #9614] DEBUG -- :    (0.0ms)  begin transaction
D, [2020-04-26T14:55:08.487223 #9614] DEBUG -- :   Post Create (0.1ms)  INSERT INTO "posts" DEFAULT VALUES
D, [2020-04-26T14:55:08.487416 #9614] DEBUG -- :    (0.0ms)  commit transaction

doing first update

> first update
D, [2020-04-26T14:55:08.488134 #9614] DEBUG -- :   Post Load (0.1ms)  SELECT "posts".* FROM "posts" WHERE "posts"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
D, [2020-04-26T14:55:08.488772 #9614] DEBUG -- :    (0.0ms)  begin transaction
D, [2020-04-26T14:55:08.488950 #9614] DEBUG -- :   Post Update (0.1ms)  UPDATE "posts" SET "status" = ? WHERE "posts"."id" = ?  [["status", 1], ["id", 1]]
D, [2020-04-26T14:55:08.489114 #9614] DEBUG -- :    (0.0ms)  commit transaction
Post.log_changes after_commit is called

second update, same value

> second update
D, [2020-04-26T14:55:08.489373 #9614] DEBUG -- :   Post Load (0.1ms)  SELECT "posts".* FROM "posts" WHERE "posts"."id" = ? LIMIT ?  [["id", 1], ["LIMIT", 1]]
Post.log_changes after_commit is called

after commit is called while UPDATE query is not being executed and no COMMIT of transaction