Reproduce rails transaction timeout error

transaction_fix_repro.rb

#!/usr/bin/env ruby

begin
  require "bundler/inline"
rescue LoadError => e
  $stderr.puts "Bundler version 1.10 or later is required. Please update your Bundler"
  raise e
end

gemfile(true) do
  source "https://rubygems.org"
  gem "rails", github: "rails/rails"
  gem "sqlite3"
  #gem "rails", path: "." # "5.0.0.1"
  #gem "pg"
end

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

# createdb transaction_fix_repro
#ActiveRecord::Base.establish_connection(adapter: "postgresql", database: "transaction_fix_repro", username: "xxx", password: "xxx")
ActiveRecord::Base.establish_connection(adapter: "sqlite3", database: ":memory:")
ActiveRecord::Base.logger = Logger.new(STDOUT)
ActiveRecord::Base.logger.level = Logger::WARN

ActiveRecord::Schema.define do
  create_table :posts, force: true do |t|
    t.integer :counter, default: 0
  end
end

class Post < ActiveRecord::Base
end

class BugTest < Minitest::Test
  INTERRUPTS = 100 # NOTE: 1 second each
  def test_association_stuff
    post = Post.create!
    interrupt_count = 0
    i = 0
    INTERRUPTS.times do |c|
      begin
        Timeout.timeout(1) do
          20_000.times do # local pg takes 650 - 750 times, sqlite takes 2k times
            post.update_attributes!(counter: (post.counter % 100_000) + 1)
          end
        end
      rescue Timeout::Error => e
        interrupt_count += 1
      end
      puts interrupt_count # status message
    end

    assert_equal INTERRUPTS, interrupt_count
  end
end

transaction_output.txt

Fetching git://github.com/rails/rails.git
Fetching gem metadata from https://rubygems.org/........
Fetching version metadata from https://rubygems.org/.
Resolving dependencies...
Using rake 12.0.0
Using concurrent-ruby 1.0.5 (was 1.0.4)
Using i18n 0.8.1
Using minitest 5.10.1 (was 5.3.3)
Using thread_safe 0.3.6 (was 0.3.5)
Using builder 3.2.3
Using erubi 1.6.0 (was 1.4.0)
Using mini_portile2 2.1.0
Using rack 2.0.1
Using nio4r 2.0.0
Using websocket-extensions 0.1.2
Using mime-types-data 3.2016.0521
Using arel 8.0.0
Using bundler 1.14.6
Using method_source 0.8.2
Using thor 0.19.4
Using sqlite3 1.3.13
Using tzinfo 1.2.2
Using nokogiri 1.7.0.1
Using rack-test 0.6.3
Using sprockets 3.7.1
Using websocket-driver 0.6.5 (was 0.6.4)
Using mime-types 3.1
Using activesupport 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using loofah 2.0.3
Using mail 2.6.4
Using rails-dom-testing 2.0.2
Using globalid 0.3.7
Using activemodel 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using rails-html-sanitizer 1.0.3
Using activejob 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using activerecord 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using actionview 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using actionpack 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using actioncable 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using actionmailer 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using railties 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
Using sprockets-rails 3.2.0
Using rails 5.1.0.beta1 from git://github.com/rails/rails.git (at master@f38de5a)
-- create_table(:posts, {:force=>true})
   -> 0.0184s
Run options: --seed 2189

# Running:

1
2
3
4
5
6
7
8
9
10
11
12
13
E

Finished in 15.486013s, 0.0646 runs/s, 0.0000 assertions/s.

  1) Error:
BugTest#test_association_stuff:
NoMethodError: undefined method `state' for nil:NilClass
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:201:in `rescue in ensure in within_new_transaction'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:198:in `ensure in within_new_transaction'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/connection_adapters/abstract/transaction.rb:198:in `within_new_transaction'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/connection_adapters/abstract/database_statements.rb:225:in `transaction'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/transactions.rb:210:in `transaction'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/transactions.rb:381:in `with_transaction_returning_status'
    /Users/kbrock/.gem/ruby/2.3.1/bundler/gems/rails-f38de5a7b4ea/activerecord/lib/active_record/persistence.rb:288:in `update!'
    ./transaction_fix_repro.rb:47:in `block (3 levels) in test_association_stuff'
    ./transaction_fix_repro.rb:46:in `times'
    ./transaction_fix_repro.rb:46:in `block (2 levels) in test_association_stuff'
    /opt/rubies/ruby-2.3.1/lib/ruby/2.3.0/timeout.rb:91:in `block in timeout'
    /opt/rubies/ruby-2.3.1/lib/ruby/2.3.0/timeout.rb:33:in `block in catch'
    /opt/rubies/ruby-2.3.1/lib/ruby/2.3.0/timeout.rb:33:in `catch'
    /opt/rubies/ruby-2.3.1/lib/ruby/2.3.0/timeout.rb:33:in `catch'
    /opt/rubies/ruby-2.3.1/lib/ruby/2.3.0/timeout.rb:106:in `timeout'
    ./transaction_fix_repro.rb:45:in `block in test_association_stuff'
    ./transaction_fix_repro.rb:43:in `times'
    ./transaction_fix_repro.rb:43:in `test_association_stuff'

1 runs, 0 assertions, 0 failures, 1 errors, 0 skips