Gitlab::BackgroundMigration::PruneOrphanedGeoEvents Did you mean? PruneOldEventsWorker
Summary
Omnibus GitLab-CE installation 12.0.3 Errors in /var/log/gitlab/gitlab-rails/sidekiq.log related to background_migration
Steps to reproduce
Our goal is to upgrade GitLab from v11.8.3 to v12.0.3. Our server was downgraded from EE to CE some time ago, so I followed steps from the issue:
- Make full backup
- Installed 11.11.3-ee
- Installed 12.0.3-ce
Upgrade was passed without errors, GitLab looks OK at the end, but we got a lot of WARN lines:
{"severity":"WARN","time":"2019-07-18T14:39:51.091Z","class":"BackgroundMigrationWorker","retry":3,"queue":"background_migration","jid":"7e716ce7e40b6c6a1fc1a647","created_at":"2019-07-18T14:15:32.453Z","correlation_id":"5c06ecbd-21da-4906-a35d-f3e51f4e0048","enqueued_at":"2019-07-18T14:39:51.000Z","error_message":"Sidekiq::JobRetry::Skip","error_class":"NameError","failed_at":"2019-07-18T14:17:02.563Z","retry_count":0,"pid":30739,"message":"BackgroundMigrationWorker JID-7e716ce7e40b6c6a1fc1a647: fail: 0.09 sec","job_status":"fail","duration":0.09,"completed_at":"2019-07-18T14:39:51.091Z","error":{},"error_backtrace":["/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:127:in `rescue in local'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:108:in `local'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:136:in `block (5 levels) in dispatch'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:43:in `block in call'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/execution_wrapper.rb:85:in `wrap'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/reloader.rb:68:in `block in wrap'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/execution_wrapper.rb:85:in `wrap'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/reloader.rb:67:in `wrap'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:42:in `call'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:132:in `block (4 levels) in dispatch'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:250:in `stats'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:127:in `block (3 levels) in dispatch'","/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_logging/structured_logger.rb:16:in `call'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:126:in `block (2 levels) in dispatch'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:74:in `global'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:125:in `block in dispatch'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:48:in `with_context'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:42:in `with_job_hash_context'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:124:in `dispatch'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:163:in `process'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:83:in `process_one'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:71:in `run'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:16:in `watchdog'","/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:25:in `block in safe_thread'"]}{"severity":"WARN","time":"2019-07-18T14:39:51.092Z","message":"{\"context\":\"Job raised exception\",\"job\":{\"class\":\"BackgroundMigrationWorker\",\"args\":[\"Gitlab::BackgroundMigration::PruneOrphanedGeoEvents\",\"geo_repositories_changed_events\"],\"retry\":3,\"queue\":\"background_migration\",\"jid\":\"7e716ce7e40b6c6a1fc1a647\",\"created_at\":1563459332.4537215,\"correlation_id\":\"5c06ecbd-21da-4906-a35d-f3e51f4e0048\",\"enqueued_at\":1563460791.0008795,\"error_message\":\"uninitialized constant Gitlab::BackgroundMigration::PruneOrphanedGeoEvents\\nDid you mean? PruneOldEventsWorker\",\"error_class\":\"NameError\",\"failed_at\":1563459422.5637114,\"retry_count\":0},\"jobstr\":\"{\\\"class\\\":\\\"BackgroundMigrationWorker\\\",\\\"args\\\":[\\\"Gitlab::BackgroundMigration::PruneOrphanedGeoEvents\\\",\\\"geo_repositories_changed_events\\\"],\\\"retry\\\":3,\\\"queue\\\":\\\"background_migration\\\",\\\"jid\\\":\\\"7e716ce7e40b6c6a1fc1a647\\\",\\\"created_at\\\":1563459332.4537215,\\\"correlation_id\\\":\\\"5c06ecbd-21da-4906-a35d-f3e51f4e0048\\\",\\\"enqueued_at\\\":1563460791.0008795,\\\"error_message\\\":\\\"uninitialized constant Gitlab::BackgroundMigration::PruneOrphanedGeoEvents\\\\nDid you mean? PruneOldEventsWorker\\\",\\\"error_class\\\":\\\"NameError\\\",\\\"failed_at\\\":1563459422.5637114,\\\"retry_count\\\":0}\"}"}
{"severity":"WARN","time":"2019-07-18T14:39:51.092Z","message":"NameError: uninitialized constant Gitlab::BackgroundMigration::PruneOrphanedGeoEvents\nDid you mean? PruneOldEventsWorker"}
{"severity":"WARN","time":"2019-07-18T14:39:51.092Z","message":"/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/background_migration.rb:81:in `const_get'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/background_migration.rb:81:in `migration_class_for'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/background_migration.rb:58:in `perform'\n/opt/gitlab/embedded/service/gitlab-rails/app/workers/background_migration_worker.rb:26:in `perform'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:192:in `execute_job'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:165:in `block (2 levels) in process'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_status/server_middleware.rb:7:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/correlation_logger.rb:10:in `block in call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/gitlab-labkit-0.3.0/lib/labkit/correlation/correlation_id.rb:18:in `use_id'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/correlation_logger.rb:9:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/batch_loader.rb:7:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/request_store_middleware.rb:8:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/memory_killer.rb:18:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sentry-raven-2.9.0/lib/raven/integrations/sidekiq.rb:9:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/middleware/chain.rb:133:in `invoke'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:164:in `block in process'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:137:in `block (6 levels) in dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:109:in `local'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:136:in `block (5 levels) in dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:43:in `block in call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/execution_wrapper.rb:85:in `wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/reloader.rb:68:in `block in wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/execution_wrapper.rb:85:in `wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.1.7/lib/active_support/reloader.rb:67:in `wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/rails.rb:42:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:132:in `block (4 levels) in dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:250:in `stats'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:127:in `block (3 levels) in dispatch'\n/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_logging/structured_logger.rb:16:in `call'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:126:in `block (2 levels) in dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/job_retry.rb:74:in `global'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:125:in `block in dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:48:in `with_context'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/logging.rb:42:in `with_job_hash_context'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:124:in `dispatch'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:163:in `process'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:83:in `process_one'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/processor.rb:71:in `run'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:16:in `watchdog'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/sidekiq-5.2.7/lib/sidekiq/util.rb:25:in `block in safe_thread'"}
It reoccures every minute. There are no such issues on Gitlab-CE 11.11 or Gitlab-EE. Gitlab-EE 12.0.3 got the same error.
Results of GitLab environment info
Expand for output related to GitLab environment info
System information System: Ubuntu 16.04 Current User: git Using RVM: no Ruby Version: 2.6.3p62 Gem Version: 2.7.9 Bundler Version:1.17.3 Rake Version: 12.3.2 Redis Version: 3.2.12 Git Version: 2.21.0 Sidekiq Version:5.2.7 Go Version: unknown
GitLab information Version: 12.0.3 Revision: 08a51a9db93 Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: PostgreSQL DB Version: 10.7 URL: https://git-demo.serv.test HTTP Clone URL: https://git-demo.serv.test/some-group/some-project.git SSH Clone URL: git@git-demo.serv.test:some-group/some-project.git Using LDAP: yes Using Omniauth: yes Omniauth Providers:
GitLab Shell
Version: 9.3.0 Repository storage paths:
- default: /var/opt/gitlab/git-data/repositories GitLab Shell path: /opt/gitlab/embedded/service/gitlab-shell Git: /opt/gitlab/embedded/bin/git
Proposed solution
Resurrect the code from https://gitlab.com/gitlab-org/gitlab-ee/blob/d5be3ec1fc0dcf2413419e21e4f2b9d48f74b1a6/ee/lib/gitlab/background_migration/prune_orphaned_geo_events.rb and make sure it works properly in CE & EE.