after_commit is called after RELEASE SAVEPOINT

[yskkin]

Steps to reproduce

# frozen_string_literal: true

require "bundler/inline"

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

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

  gem "rails", github: "rails/rails"
  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|
  end
end

class Post < ActiveRecord::Base
  after_commit :after_commit

  def after_commit
    p 'after commit'
  end
end

class BugTest < Minitest::Test
  def test_association_stuff
    Post.transaction(joinable: false) do
      Post.transaction do
        Post.create!
      end
    end
  end
end

Expected behavior

"after commit" is outputted after COMMIT statement.

Actual behavior

"after commit" is outputted after RELEASE SAVEPOINT and before COMMIT statement.

# Running:

D, [2020-07-23T11:28:41.268893 #72669] DEBUG -- :   TRANSACTION (0.0ms)  begin transaction
D, [2020-07-23T11:28:41.269115 #72669] DEBUG -- :   TRANSACTION (0.1ms)  SAVEPOINT active_record_1
D, [2020-07-23T11:28:41.270360 #72669] DEBUG -- :   Post Create (0.1ms)  INSERT INTO "posts" DEFAULT VALUES
D, [2020-07-23T11:28:41.270500 #72669] DEBUG -- :   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
"after commit"
D, [2020-07-23T11:28:41.270740 #72669] DEBUG -- :   TRANSACTION (0.1ms)  commit transaction
.

Finished in 0.002930s, 341.2969 runs/s, 0.0000 assertions/s.
1 runs, 0 assertions, 0 failures, 0 errors, 0 skips

System configuration

Rails version:

Ruby version:

[tgxworld]

Based on my understanding, I don't think this is a bug. In the example you provided, the parent transaction is created with joinable: false which means the sub-transaction created is not merged into the parent transaction. In this case, the code is behaving correctly because the after_commit callbacks are run after RELEASE SAVEPOINT active_record_1 which is when the sub-transaction ends. If I change the test to

  def test_association_stuff
    puts "Start transaction"

    Post.transaction(joinable: false) do
      Post.transaction do
        Post.create!
      end

      Post.transaction do
        Post.create!
      end
    end
  end

You'll see that the after_commit hook is called twice, one for each sub transaction.

Start transaction
D, [2020-07-29T14:45:40.911476 #72345] DEBUG -- :   TRANSACTION (0.0ms)  begin transaction
D, [2020-07-29T14:45:40.911578 #72345] DEBUG -- :   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
D, [2020-07-29T14:45:40.912666 #72345] DEBUG -- :   Post Create (0.0ms)  INSERT INTO "posts" DEFAULT VALUES
D, [2020-07-29T14:45:40.912790 #72345] DEBUG -- :   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
after commit
D, [2020-07-29T14:45:40.913037 #72345] DEBUG -- :   TRANSACTION (0.0ms)  SAVEPOINT active_record_1
D, [2020-07-29T14:45:40.913122 #72345] DEBUG -- :   Post Create (0.0ms)  INSERT INTO "posts" DEFAULT VALUES
D, [2020-07-29T14:45:40.913212 #72345] DEBUG -- :   TRANSACTION (0.0ms)  RELEASE SAVEPOINT active_record_1
after commit
D, [2020-07-29T14:45:40.913297 #72345] DEBUG -- :   TRANSACTION (0.0ms)  commit transaction

[eugeneius]

Yes, exactly. The behaviour of the joinable option isn't documented, and it's not meant to be used by application code.

If your goal is to create a savepoint, you can pass requires_new: true in the inner transaction call, which is documented:

https://api.rubyonrails.org/v6.0.3.2/classes/ActiveRecord/ConnectionAdapters/DatabaseStatements.html#method-i-transaction-label-Nested+transactions+support

    Post.transaction do
      Post.transaction(requires_new: true) do
        Post.create!
      end
    end

[aleksandrs-ledovskis]

joinable option (...) is not meant to be used by application code.

There is no other option but to use it, if a DBMS error-proof wrapper is being constructed.

For example, say you use PostgreSQL and build an auditing library that wraps own transaction via around_action and later on that action (which at that point is outside library's control) internally catches ActiveRecord::StatementInvalid when calling #save. The outer transaction will be irrevocably busted ("PG::InFailedSqlTransaction: ERROR: current transaction is aborted, commands ignored until end of transaction block") unless it's created with joinable: false.

[FX-HAO]

This is a workaround

  class AfterCommit
    def initialize
      @callback = Proc.new
    end

    def self.transaction_open?
      ActiveRecord::Base.connection.transaction_open?
    end
    
    if Rails.env.test?
      class << self
        attr_writer :test_transaction

        def transaction_open?
          ActiveRecord::Base.connection.current_transaction != @test_transaction
        end
      end
    end

    def committed!(*)
      if self.class.transaction_open?
        # Nested transaction. Pass the callback to the parent
        ActiveRecord::Base.connection.add_transaction_record(self)
      else
        @callback.call
      end
    end

    def before_committed!(*); end

    def add_to_transaction(*); end

    def rolledback!(*); end

    def self.after_commit(connection: ActiveRecord::Base.connection)
      return yield unless AfterCommit.transaction_open?
  
      connection.add_transaction_record(AfterCommit.new(&Proc.new))
    end
  end

Usage

     context 'within nested joinable=false transactions' do
        let(:s) do
          s = ''

          ActiveRecord::Base.transaction(joinable: false, requires_new: true) do
            s += '1'
            ActiveRecord::Base.transaction(joinable: false, requires_new: true) do
              AfterCommit.after_commit { s += '4' }
              s += '2'
            end
            AfterCommit.after_commit { s += '5' }
            s += '3'
          end

          s
        end

        it 'executes after the outermost transaction is committed' do
          expect(s).to eq('12345')
        end
      end

this is taken from Discourse's PR

just curious, can we integrate this into Rails?