Skip to content

Instantly share code, notes, and snippets.

@KeithP

KeithP/More connection locking #28777

Created April 18, 2017 09:30
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save KeithP/3fee4b8bb0815d13a3d001d7da504507 to your computer and use it in GitHub Desktop.
Save KeithP/3fee4b8bb0815d13a3d001d7da504507 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
More connection locking #28777
Failures:
1) Users::PasswordsController POST 'update' success should change the password
Failure/Error: @cond.wait(@monitor.instance_variable_get(:@mon_mutex), timeout)
fatal:
No live threads left. Deadlock?
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:374:in `block in lock_thread='
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb:368:in `lock_thread='
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/fixtures.rb:1012:in `block in teardown_fixtures'
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/fixtures.rb:1010:in `each'
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/fixtures.rb:1010:in `teardown_fixtures'
# /home/keithp/.rvm/gems/ruby-2.3.0@my_app/bundler/gems/rails-5de1e4f2c45e/activerecord/lib/active_record/fixtures.rb:857:in `after_teardown'
@KeithP
Copy link
Author

KeithP commented Apr 18, 2017 •
edited

  1. Run all tests, locally -> failed about half way thru and hung. Appears to be the same as eileencodes, same on build server.
  2. Run controllers test, locally -> got the above output.

Test.log tail is below - There is a lot of SAVEPOINT going on, is that expected? :

[ActiveJob] [ActionMailer::DeliveryJob] [32e9cf57-e987-493a-8d8e-25b728b7c165] Performed ActionMailer::DeliveryJob (Job ID: 32e9cf57-e987-493a-8d8e-25b728b7c165) from SuckerPunch(mailers) in 29.42ms
  [1m[35m (0.9ms)[0m  [1m[35mSAVEPOINT active_record_1[0m
  [1m[36mManage::Setting Load (0.7ms)[0m  [1m[34mSELECT  "settings".* FROM "settings" WHERE "settings"."user_id" = $1 LIMIT $2[0m  [["user_id", 4789], ["LIMIT", 1]]
  [1m[35mSQL (0.7ms)[0m  [1m[33mUPDATE "users" SET "reset_password_sent_at" = $1, "encrypted_password" = $2, "updated_at" = $3, "reset_password_token" = $4 WHERE "users"."id" = $5[0m  [["reset_password_sent_at", nil], ["encrypted_password", "$2a$04$5Z7VYp0eb2cYWAFXDqRgG.RImP7FBadV7/iIOKtc2QtA.DVcGracW"], ["updated_at", "2017-04-18 09:19:29.185544"], ["reset_password_token", nil], ["id", 4789]]
  [1m[35m (0.2ms)[0m  [1m[35mRELEASE SAVEPOINT active_record_1[0m
  [1m[35m (0.2ms)[0m  [1m[35mSAVEPOINT active_record_1[0m
  [1m[35m (0.2ms)[0m  [1m[35mRELEASE SAVEPOINT active_record_1[0m
  [1m[35m (0.2ms)[0m  [1m[35mSAVEPOINT active_record_1[0m
  [1m[35mSQL (0.6ms)[0m  [1m[33mUPDATE "users" SET "updated_at" = $1, "sign_in_count" = $2, "current_sign_in_at" = $3, "last_sign_in_at" = $4, "current_sign_in_ip" = $5, "last_sign_in_ip" = $6 WHERE "users"."id" = $7[0m  [["updated_at", "2017-04-18 09:19:29.194759"], ["sign_in_count", 1], ["current_sign_in_at", "2017-04-18 09:19:29.193481"], ["last_sign_in_at", "2017-04-18 09:19:29.193481"], ["current_sign_in_ip", "0.0.0.0/32"], ["last_sign_in_ip", "0.0.0.0/32"], ["id", 4789]]
  [1m[35m (0.2ms)[0m  [1m[35mRELEASE SAVEPOINT active_record_1[0m
Redirected to http://test.host/
Completed 302 Found in 42ms (ActiveRecord: 8.6ms)
  [1m[36mUser Load (0.5ms)[0m  [1m[34mSELECT  "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2[0m  [["id", 4789], ["LIMIT", 1]]
  [1m[35m (0.6ms)[0m  [1m[31mROLLBACK[0m

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment