New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Migrations failing due to ConcurrentMigrationError while trying to release an already acquired lock #32622

Closed
ashu210890 opened this Issue Apr 18, 2018 · 3 comments

Comments

Projects
None yet
3 participants
@ashu210890
Copy link

ashu210890 commented Apr 18, 2018

Steps to reproduce

Run rake db:migrate

Expected behavior

Migration should run successfully

Actual behavior

ConcurrentMigrationError. The logs are follows:

00:04:44.795 04:31 deploy:migrating
00:04:44.795       01 ~/.rvm/bin/rvm default do bundle exec rake db:migrate
00:05:00.617       01 I, [2018-04-18T13:02:00.968642 #4344]  INFO -- sentry: ** [Raven] Raven 2.7.1 ready to catch errors
00:05:10.540       01 WARNING:  you don't own a lock of type ExclusiveLock
00:05:11.254       01 rake aborted!
00:05:11.254       01 ActiveRecord::ConcurrentMigrationError: 
00:05:11.254       01 
00:05:11.254       01 Failed to release advisory lock
00:05:11.254       01 
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1366:in `with_advisory_lock'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1210:in `migrate'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1036:in `up'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/migration.rb:1011:in `migrate'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/tasks/database_tasks.rb:172:in `migrate'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/railties/databases.rake:60:in `block (2 levels) in <top (required)>'
00:05:11.254       01 <app_root>/bundle/ruby/2.5.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli/exec.rb:75:in `load'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli/exec.rb:75:in `kernel_load'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli/exec.rb:28:in `run'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli.rb:424:in `exec'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/vendor/thor/lib/thor.rb:387:in `dispatch'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli.rb:27:in `dispatch'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/vendor/thor/lib/thor/base.rb:466:in `start'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/cli.rb:18:in `start'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/exe/bundle:30:in `block in <top (required)>'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/lib/bundler/friendly_errors.rb:122:in `with_friendly_errors'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/gems/bundler-1.16.1/exe/bundle:22:in `<top (required)>'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/bin/bundle:23:in `load'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/bin/bundle:23:in `<main>'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/bin/ruby_executable_hooks:15:in `eval'
00:05:11.254       01 <user_home>/.rvm/gems/ruby-2.5.1/bin/ruby_executable_hooks:15:in `<main>'
00:05:11.255       01 Tasks: TOP => db:migrate

System configuration

Rails version: 5.2.0
Ruby version: 2.5.1p57
**Database adapter: Postgres
** Postgres version: 9.5.3

This error happened while upgrading from Rails 5.1 to Rails 5.2. The migrate command ran fine on Rails 5.1 in the same environment. There were no migrations to run in this deployment.

@composerinteralia

This comment has been minimized.

Copy link
Member

composerinteralia commented Apr 19, 2018

Thanks, Ashu. To diagnose the problem, we will need a way to reproduce it. Can you provide either a test case using this template or a sample application with this behavior?

@ashu210890

This comment has been minimized.

Copy link

ashu210890 commented Apr 20, 2018

I finally figured that this is not a rails issue. Rails takes an advisory lock to prevent concurrent migrations on the same DB.
There is one crucial detail that I forgot to mention in the issue description, it's that we were using PgBouncer in transaction pooling mode. Since, in transaction pooling mode, different connections can be used for different transactions in the same session, it experiences issues with things like Advisory Locks.

After we switched from transaction pooling to session pooling in PGBouncer, the issue went away. The underlying problem can be attributed to the incompatibility between advisory looks and transaction pooling and thus testing it again on Rails 5.1 revealed that the same issue occurred there, only that Rails 5.2 started throwing exception if it failed to release the lock.
Sorry for wasting your time, I'll file an issue with PGBouncer and see if it's a problem that can be solved in transaction pooling mode.

@rails-bot

This comment has been minimized.

Copy link

rails-bot bot commented Jul 20, 2018

This issue has been automatically marked as stale because it has not been commented on for at least three months.
The resources of the Rails team are limited, and so we are asking for your help.
If you can still reproduce this error on the 5-2-stable branch or on master, please reply with all of the information you have about it in order to keep the issue open.
Thank you for all your contributions.

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