Skip to content

Migrations cannot be run in specific circumstances (mostly when RAILS_ENV=test) due to validations relying on columns not yet migrated

TLDR;

There is a possible vicious circle when:

  1. A migration adds a column to application_settings
  2. A validation relying on this new column is added in ApplicationSetting

Problem

I tried to run a spec file as follow:

› bundle exec rake db:migrate RAILS_ENV=test
/Users/remy/.gem/ruby/2.1.7/gems/activemodel-4.2.4/lib/active_model/attribute_methods.rb:433:in `method_missing': undefined method `sentry_enabled' for #<ApplicationSetting:0x007fb85c0e8938> (NoMethodError)
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:432:in `block in make_lambda'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:181:in `call'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:181:in `block (2 levels) in conditional'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:181:in `each'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:181:in `all?'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:181:in `block in conditional'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:504:in `call'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:504:in `block in call'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:504:in `each'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:504:in `call'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:778:in `_run_validate_callbacks'
	from /Users/remy/.gem/ruby/2.1.7/gems/activemodel-4.2.4/lib/active_model/validations.rb:398:in `run_validations!'
	from /Users/remy/.gem/ruby/2.1.7/gems/activemodel-4.2.4/lib/active_model/validations/callbacks.rb:113:in `block in run_validations!'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:88:in `__run_callbacks__'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/callbacks.rb:778:in `_run_validation_callbacks'
	from /Users/remy/.gem/ruby/2.1.7/gems/activemodel-4.2.4/lib/active_model/validations/callbacks.rb:113:in `run_validations!'
	from /Users/remy/.gem/ruby/2.1.7/gems/activemodel-4.2.4/lib/active_model/validations.rb:337:in `valid?'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/validations.rb:58:in `valid?'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/validations.rb:83:in `perform_validations'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/validations.rb:37:in `save'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/attribute_methods/dirty.rb:21:in `save'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:286:in `block (2 levels) in save'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status'
	from /Users/remy/.gem/ruby/2.1.7/gems/test_after_commit-0.4.2/lib/test_after_commit.rb:27:in `block in transaction_with_transactional_fixtures'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
	from /Users/remy/.gem/ruby/2.1.7/gems/test_after_commit-0.4.2/lib/test_after_commit.rb:21:in `transaction_with_transactional_fixtures'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:220:in `transaction'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:348:in `with_transaction_returning_status'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:286:in `block in save'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:301:in `rollback_active_record_state!'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/transactions.rb:285:in `save'
	from /Users/remy/.gem/ruby/2.1.7/gems/activerecord-4.2.4/lib/active_record/persistence.rb:34:in `create'
	from /Volumes/Code/GitLab/gdk/gitlab/app/models/application_setting.rb:130:in `create_from_defaults'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/current_settings.rb:8:in `current_application_settings'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/metrics.rb:11:in `settings'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/metrics.rb:22:in `enabled?'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/metrics.rb:75:in `<module:Metrics>'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/metrics.rb:2:in `<module:Gitlab>'
	from /Volumes/Code/GitLab/gdk/gitlab/lib/gitlab/metrics.rb:1:in `<top (required)>'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:457:in `load'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:457:in `block in load_file'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:647:in `new_constants_in'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:456:in `load_file'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:354:in `require_or_load'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:494:in `load_missing_constant'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:184:in `const_missing'
	from /Volumes/Code/GitLab/gdk/gitlab/config/initializers/metrics.rb:1:in `<top (required)>'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:268:in `load'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:268:in `block in load'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:240:in `load_dependency'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/dependencies.rb:268:in `load'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/engine.rb:652:in `block in load_config_initializer'
	from /Users/remy/.gem/ruby/2.1.7/gems/activesupport-4.2.4/lib/active_support/notifications.rb:166:in `instrument'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/engine.rb:651:in `load_config_initializer'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/engine.rb:616:in `block (2 levels) in <class:Engine>'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/engine.rb:615:in `each'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/engine.rb:615:in `block in <class:Engine>'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:30:in `instance_exec'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:30:in `run'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:55:in `block in run_initializers'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:226:in `block in tsort_each'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:348:in `block (2 levels) in each_strongly_connected_component'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:418:in `block (2 levels) in each_strongly_connected_component_from'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:427:in `each_strongly_connected_component_from'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:417:in `block in each_strongly_connected_component_from'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:44:in `each'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:44:in `tsort_each_child'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:411:in `call'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:411:in `each_strongly_connected_component_from'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:347:in `block in each_strongly_connected_component'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:345:in `each'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:345:in `call'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:345:in `each_strongly_connected_component'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:224:in `tsort_each'
	from /Users/remy/.rubies/ruby-2.1.7/lib/ruby/2.1.0/tsort.rb:205:in `tsort_each'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/initializable.rb:54:in `run_initializers'
	from /Users/remy/.gem/ruby/2.1.7/gems/railties-4.2.4/lib/rails/application.rb:352:in `initialize!'
	from /Volumes/Code/GitLab/gdk/gitlab/config/environment.rb:5:in `<top (required)>'
	from /Volumes/Code/GitLab/gdk/gitlab/spec/spec_helper.rb:13:in `require'
	from /Volumes/Code/GitLab/gdk/gitlab/spec/spec_helper.rb:13:in `<top (required)>'
	from /Volumes/Code/GitLab/gdk/gitlab/spec/features/notes_on_merge_requests_spec.rb:1:in `require'

The error is that the sentry_enabled column is missing so I thought: "How could it be since test schema is maintained automatically?"

Anyways, I tried to migrate the test DB and got the same error.

The thing is that when using USE_DB=false, it worked well:

› bundle exec rake db:migrate RAILS_ENV=test USE_DB=false
Instance method "run" is already defined in Object, use generic helper instead or set StateMachines::Machine.ignore_method_conflicts = true.
== 20160118155830 AddSentryToApplicationSettings: migrating ===================
-- change_table(:application_settings)
  -> 0.0487s
== 20160118155830 AddSentryToApplicationSettings: migrated (0.0488s) ==========

== 20160118232755 AddIpBlockingSettingsToApplicationSettings: migrating =======
-- add_column(:application_settings, :ip_blocking_enabled, :boolean, {:default=>false})
  -> 0.0039s
-- add_column(:application_settings, :dnsbl_servers_list, :text)
  -> 0.0006s
== 20160118232755 AddIpBlockingSettingsToApplicationSettings: migrated (0.0046s)

== 20160119145451 AddLdapEmailToUsers: migrating ==============================
-- add_column(:users, :ldap_email, :boolean, {:default=>false, :null=>false})
  -> 0.0169s
-- execute("\n        UPDATE users\n        SET ldap_email = TRUE\n        FROM identities\n        WHERE identities.user_id = users.id\n        AND users.email LIKE 'temp-email-for-oauth%'\n        AND identities.provider LIKE 'ldap%'\n        AND identities.extern_uid IS NOT NULL\n      ")
  -> 0.0126s
== 20160119145451 AddLdapEmailToUsers: migrated (0.0309s) =====================

If we follow the stack trace we have:

  1. Gitlab::Metrics' initializer checks if metrics are enabled with Gitlab::Metrics.enabled?
  2. This check needs current_application_settings
  3. Then since I don't have an ApplicationSetting.current, ApplicationSetting.create_from_defaults is called
  4. Which calls ApplicationSetting.create
  5. Which fails during the validation of sentry_dsn since sentry_enabled doesn't exist yet!

When using USE_DB=false, we end up using fake_application_settings which doesn't end up creating a DB record before running the migrations.

At that point, I noticed that this issue is safeguarded in two initializers:

  1. session_store.rb
  2. sentry.rb

But not in metrics.rb.

I found this commit that might have allowed this issue to arise. The motive was to avoid having the application use fake_application_settings when a migration was pending but it ends up preventing migrations from being run in some specific cases.

Solutions

That being said, I see two solutions:

  1. Use new(attrs).save(validate: false) in ApplicationSetting.create_from_defaults. This should be safe since we control the default settings we store in the DB. That said this could still lead to other issues such as incorrect default settings being stored in the DB but these faulty settings could only be added through a reviewed merge-request so it's pretty safe.
  2. Continue to use the safeguard-way, and add a safeguard in the metrics.rb initializer, allowing any other errors in the Gitlab::Metrics.enabled? call to end-up disabling metrics without explicitly telling why: if Gitlab::Metrics.enabled? rescue false

/cc @rspeicher @yorickpeterse @jnijhof