add simple logging to UpdateMergeRequestsWorker#perform

this is to try to debug #35914

2 files changed, 18 insertions, 1 deletions

diff --git a/app/workers/update_merge_requests_worker.rb b/app/workers/update_merge_requests_worker.rb
index 89ae17cef37..d8d818aee8e 100644
--- a/app/workers/update_merge_requests_worker.rb
+++ b/app/workers/update_merge_requests_worker.rb
@@ -9,6 +9,17 @@ class UpdateMergeRequestsWorker
     user = User.find_by(id: user_id)
     return unless user
 
-    MergeRequests::RefreshService.new(project, user).execute(oldrev, newrev, ref)
+    # TODO: remove this benchmarking when we have rich logging
+    time = Benchmark.measure do
+      MergeRequests::RefreshService.new(project, user).execute(oldrev, newrev, ref)
+    end
+
+    log_args = ["elapsed=#{time.real}"]
+    method(__method__).parameters.map do |_, p|
+      pname = p.to_s
+      log_args << [pname, binding.local_variable_get(pname)].join('=')
+    end
+
+    Rails.logger.info("UpdateMergeRequestsWorker#perform #{log_args.join(',')}")
   end
 end
diff --git a/spec/workers/update_merge_requests_worker_spec.rb b/spec/workers/update_merge_requests_worker_spec.rb
index 558ff9109ec..5c711399cd5 100644
--- a/spec/workers/update_merge_requests_worker_spec.rb
+++ b/spec/workers/update_merge_requests_worker_spec.rb
@@ -23,5 +23,11 @@ describe UpdateMergeRequestsWorker do
 
       perform
     end
+
+    it 'logs performance' do
+      expect(Rails.logger).to receive(:info).with(a_string_matching(/\AUpdateMergeRequestsWorker#perform.*project_id=#{project.id},user_id=#{user.id},oldrev=#{oldrev},newrev=#{newrev},ref=#{ref}/))
+
+      perform
+    end
   end
 end