External MergeRequestDiff is failling to do the background migration to Object Storage

When trying out to enable external merge request diffs to use object storage, I've noticed that its still being stored on local disk.

After some investigation I noticed that we have a special worker that performs this second upload step, but that was failing with the following error:

{"severity":"WARN","time":"2019-10-16T18:49:17.837Z","message":"NoMethodError: undefined method `log_geo_deleted_event' for #\u003cMergeRequestDiff:0x00007fdc54f9aca8\u003e"}
{"severity":"WARN","time":"2019-10-16T18:49:17.837Z","message":"/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activemodel-5.2.3/lib/active_model/attribute_methods.rb:430:in `method_missing'\n/opt/gitlab/embedded/service/gitlab-rails/ee/ap
p/uploaders/ee/object_storage.rb:15:in `log_geo_deleted_event'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/carrierwave-1.3.1/lib/carrierwave/uploader/callbacks.rb:16:in `block in with_callbacks'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.
0/gems/carrierwave-1.3.1/lib/carrierwave/uploader/callbacks.rb:16:in `each'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/carrierwave-1.3.1/lib/carrierwave/uploader/callbacks.rb:16:in `with_callbacks'\n/opt/gitlab/embedded/service/gitlab
-rails/app/uploaders/object_storage.rb:432:in `unsafe_migrate!'\n/opt/gitlab/embedded/service/gitlab-rails/app/uploaders/object_storage.rb:262:in `block in migrate!'\n/opt/gitlab/embedded/service/gitlab-rails/app/uploaders/object_storage.
rb:411:in `with_exclusive_lease'\n/opt/gitlab/embedded/service/gitlab-rails/app/uploaders/object_storage.rb:261:in `migrate!'\n/opt/gitlab/embedded/service/gitlab-rails/app/workers/object_storage/background_move_worker.rb:20: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/gi
tlab/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/instrumentation_logger.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.5.2/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:20: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/metrics.rb:23:in `block in call'\n/opt/gitlab/embedded/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'\n/opt/gitlab/embedded/service/gitla
b-rails/lib/gitlab/sidekiq_middleware/metrics.rb:22: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-rave
n-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/s
idekiq/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 `bl
ock (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.2.3/lib/active_support/execution_wrapper.rb
:87:in `wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.2.3/lib/active_support/reloader.rb:73:in `block in wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.2.3/lib/active_support/execution_wrapper.
rb:87:in `wrap'\n/opt/gitlab/embedded/lib/ruby/gems/2.6.0/gems/activesupport-5.2.3/lib/active_support/reloader.rb:72: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/emb
edded/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/rub
y/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/sidek
iq-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/l
ib/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'"}

This is failing because we are probably missing a method somewhere. No tests have found this issue, which is clearly a problem, as we are probably not even running this section of the code base on any specs (my guess here is that we are again mocking everything which is hiding problems).

Edited Oct 16, 2019 by Gabriel Mazetto
Assignee Loading
Time tracking Loading