Improve error handling of squash and rebase

Previously all Git-related exceptions in squash and rebase would quietly
go to `git_json.log`, but these messages should really be tracked in
Sentry and/or `exceptions_json.log`.

In addition, if the squash in progress check failed, the merge would get
stuck. This commit now handles that error gracefully and logs it.

In the future, we can likely remove `git_json.log` altogether.

app/services/concerns/git/logger.rb

-# frozen_string_literal: true
-
-module Git
-  module Logger
-    def log_error(message, save_message_on_model: false)
-      Gitlab::GitLogger.error("#{self.class.name} error (#{merge_request.to_reference(full: true)}): #{message}")
-      merge_request.update(merge_error: message) if save_message_on_model
-    end
-  end
-end

app/services/merge_requests/base_service.rb

@@ -114,6 +114,32 @@ module MergeRequests
         yield merge_request
       end
     end
+
+    def log_error(exception:, message:, save_message_on_model: false)
+      reference = merge_request.to_reference(full: true)
+      data = {
+        class: self.class.name,
+        message: message,
+        merge_request_id: merge_request.id,
+        merge_request: reference,
+        save_message_on_model: save_message_on_model
+      }
+
+      if exception
+        Gitlab::ErrorTracking.with_context(current_user) do
+          Gitlab::ErrorTracking.track_exception(exception, data)
+        end
+
+        data[:"exception.message"] = exception.message
+      end
+
+      # TODO: Deprecate Gitlab::GitLogger since ErrorTracking should suffice:
+      # https://gitlab.com/gitlab-org/gitlab/-/issues/216379
+      data[:message] = "#{self.class.name} error (#{reference}): #{message}"
+      Gitlab::GitLogger.error(data)
+
+      merge_request.update(merge_error: message) if save_message_on_model
+    end
   end
 end
 

app/services/merge_requests/rebase_service.rb

@@ -2,8 +2,6 @@
 
 module MergeRequests
   class RebaseService < MergeRequests::BaseService
-    include Git::Logger
-
     REBASE_ERROR = 'Rebase failed. Please rebase locally'
 
     attr_reader :merge_request
@@ -22,7 +20,7 @@ module MergeRequests
     def rebase
       # Ensure Gitaly isn't already running a rebase
       if source_project.repository.rebase_in_progress?(merge_request.id)
-        log_error('Rebase task canceled: Another rebase is already in progress', save_message_on_model: true)
+        log_error(exception: nil, message: 'Rebase task canceled: Another rebase is already in progress', save_message_on_model: true)
         return false
       end
 
@@ -30,8 +28,8 @@ module MergeRequests
 
       true
     rescue => e
-      log_error(REBASE_ERROR, save_message_on_model: true)
-      log_error(e.message)
+      log_error(exception: e, message: REBASE_ERROR, save_message_on_model: true)
+
       false
     ensure
       merge_request.update_column(:rebase_jid, nil)

app/services/merge_requests/squash_service.rb

@@ -2,7 +2,7 @@
 
 module MergeRequests
   class SquashService < MergeRequests::BaseService
-    include Git::Logger
+    SquashInProgressError = Class.new(RuntimeError)
 
     def execute
       # If performing a squash would result in no change, then
@@ -11,11 +11,13 @@ module MergeRequests
         return success(squash_sha: merge_request.diff_head_sha)
       end
 
-      if merge_request.squash_in_progress?
+      if squash_in_progress?
         return error(s_('MergeRequests|Squash task canceled: another squash is already in progress.'))
       end
 
       squash! || error(s_('MergeRequests|Failed to squash. Should be done manually.'))
+    rescue SquashInProgressError
+      error(s_('MergeRequests|An error occurred while checking whether another squash is in progress.'))
     end
 
     private
@@ -25,11 +27,19 @@ module MergeRequests
 
       success(squash_sha: squash_sha)
     rescue => e
-      log_error("Failed to squash merge request #{merge_request.to_reference(full: true)}:")
-      log_error(e.message)
+      log_error(exception: e, message: 'Failed to squash merge request')
+
       false
     end
 
+    def squash_in_progress?
+      merge_request.squash_in_progress?
+    rescue => e
+      log_error(exception: e, message: 'Failed to check squash in progress')
+
+      raise SquashInProgressError, e.message
+    end
+
     def repository
       target_project.repository
     end

changelogs/unreleased/sh-fix-squash-error-handling.yml

+---
+title: Improve error handling of squash and rebase
+merge_request: 23740
+author:
+type: other

locale/gitlab.pot

@@ -13051,6 +13051,9 @@ msgstr ""
 msgid "MergeRequests|Add a reply"
 msgstr ""
 
+msgid "MergeRequests|An error occurred while checking whether another squash is in progress."
+msgstr ""
+
 msgid "MergeRequests|An error occurred while saving the draft comment."
 msgstr ""
 

spec/services/merge_requests/rebase_service_spec.rb

@@ -72,12 +72,15 @@ describe MergeRequests::RebaseService do
     it_behaves_like 'sequence of failure and success'
 
     context 'when unexpected error occurs' do
+      let(:exception) { RuntimeError.new('Something went wrong') }
+      let(:merge_request_ref) { merge_request.to_reference(full: true) }
+
       before do
-        allow(repository).to receive(:gitaly_operation_client).and_raise('Something went wrong')
+        allow(repository).to receive(:gitaly_operation_client).and_raise(exception)
       end
 
       it 'saves a generic error message' do
-        subject.execute(merge_request)
+        service.execute(merge_request)
 
         expect(merge_request.reload.merge_error).to eq(described_class::REBASE_ERROR)
       end
@@ -86,6 +89,18 @@ describe MergeRequests::RebaseService do
         expect(service.execute(merge_request)).to match(status: :error,
                                                         message: described_class::REBASE_ERROR)
       end
+
+      it 'logs the error' do
+        expect(service).to receive(:log_error).with(exception: exception, message: described_class::REBASE_ERROR, save_message_on_model: true).and_call_original
+        expect(Gitlab::ErrorTracking).to receive(:track_exception).with(exception,
+          class: described_class.to_s,
+          merge_request: merge_request_ref,
+          merge_request_id: merge_request.id,
+          message: described_class::REBASE_ERROR,
+          save_message_on_model: true).and_call_original
+
+        service.execute(merge_request)
+      end
     end
 
     context 'with git command failure' do

spec/services/merge_requests/squash_service_spec.rb

@@ -141,15 +141,14 @@ describe MergeRequests::SquashService do
       let(:merge_request) { merge_request_with_only_new_files }
       let(:error) { 'A test error' }
 
-      context 'with gitaly enabled' do
+      context 'with an error in Gitaly UserSquash RPC' do
         before do
           allow(repository.gitaly_operation_client).to receive(:user_squash)
             .and_raise(Gitlab::Git::Repository::GitError, error)
         end
 
-        it 'logs the stage and output' do
-          expect(service).to receive(:log_error).with(log_error)
-          expect(service).to receive(:log_error).with(error)
+        it 'logs the error' do
+          expect(service).to receive(:log_error).with(exception: an_instance_of(Gitlab::Git::Repository::GitError), message: 'Failed to squash merge request')
 
           service.execute
         end
@@ -158,19 +157,42 @@ describe MergeRequests::SquashService do
           expect(service.execute).to match(status: :error, message: a_string_including('squash'))
         end
       end
+
+      context 'with an error in squash in progress check' do
+        before do
+          allow(repository).to receive(:squash_in_progress?)
+            .and_raise(Gitlab::Git::Repository::GitError, error)
+        end
+
+        it 'logs the stage and output' do
+          expect(service).to receive(:log_error).with(exception: an_instance_of(Gitlab::Git::Repository::GitError), message: 'Failed to check squash in progress')
+
+          service.execute
+        end
+
+        it 'returns an error' do
+          expect(service.execute).to match(status: :error, message: 'An error occurred while checking whether another squash is in progress.')
+        end
+      end
     end
 
     context 'when any other exception is thrown' do
       let(:merge_request) { merge_request_with_only_new_files }
-      let(:error) { 'A test error' }
+      let(:merge_request_ref) { merge_request.to_reference(full: true) }
+      let(:exception) { RuntimeError.new('A test error') }
 
       before do
-        allow(merge_request.target_project.repository).to receive(:squash).and_raise(error)
+        allow(merge_request.target_project.repository).to receive(:squash).and_raise(exception)
       end
 
-      it 'logs the MR reference and exception' do
-        expect(service).to receive(:log_error).with(a_string_including("#{project.full_path}#{merge_request.to_reference}"))
-        expect(service).to receive(:log_error).with(error)
+      it 'logs the error' do
+        expect(service).to receive(:log_error).with(exception: exception, message: 'Failed to squash merge request').and_call_original
+        expect(Gitlab::ErrorTracking).to receive(:track_exception).with(exception,
+          class: described_class.to_s,
+          merge_request: merge_request_ref,
+          merge_request_id: merge_request.id,
+          message: 'Failed to squash merge request',
+          save_message_on_model: false).and_call_original
 
         service.execute
       end