Add logger and custom errors for epic syncing

This refactors the `SyncAsWorkItem` concern and adds a
`SyncAsWorkItemError` to easily filter epic to work item syncing errors.
In addition, we added a custom logger for errors that could happen when
an epic gets synced as a work item.

doc/administration/logs/index.md

@@ -1070,6 +1070,21 @@ This file is located at:
 - `/var/log/gitlab/gitlab-rails/llm.log` on Linux package installations.
 - `/home/git/gitlab/log/llm.log` on self-compiled installations.
 
+## `epic_work_item_sync.log`
+
+DETAILS:
+**Tier:** Premium, Ultimate
+**Offering:** Self-Managed, SaaS
+
+> - [Introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/120506) in GitLab 16.9.
+
+The `epic_work_item_sync.log` file logs information related to syncing and migrating epics as work items.
+
+This file is located at:
+
+- `/var/log/gitlab/gitlab-rails/epic_work_item_sync.log` on Linux package installations.
+- `/home/git/gitlab/log/epic_work_item_sync.log` on self-compiled installations.
+
 ## Registry logs
 
 For Linux package installations, container registry logs are in `/var/log/gitlab/registry/current`.

ee/app/services/concerns/epics/sync_as_work_item.rb

@@ -2,28 +2,26 @@
 
 module Epics
   module SyncAsWorkItem
+    SyncAsWorkItemError = Class.new(StandardError)
+
     ALLOWED_PARAMS = %i[
       title description confidential author created_at updated_at updated_by_id
       last_edited_by_id last_edited_at closed_by_id closed_at state_id external_key
     ].freeze
 
-    def create_work_item_for(epic)
-      create_params = params.to_h.with_indifferent_access.slice(*ALLOWED_PARAMS)
-      work_item_params = {
-        work_item_type: WorkItems::Type.default_by_type(:epic),
-        iid: epic.iid,
-        created_at: epic.created_at,
-        extra_params: { synced_work_item: true }
-      }
-
-      work_item_params[:title_html] = epic.title_html if params[:title].present?
-      work_item_params[:description_html] = epic.description_html if params[:description].present?
+    def create_work_item_for!(epic)
+      return unless work_item_sync_enabled?
 
-      ::WorkItems::CreateService.new(
+      service_response = ::WorkItems::CreateService.new(
         container: epic.group,
         current_user: current_user,
-        params: create_params.merge(work_item_params)
+        params: create_params(epic)
       ).execute_without_rate_limiting
+
+      handle_response!(:create, service_response, epic)
+
+      epic.issue_id = service_response.payload[:work_item].id
+      epic.save!
     end
 
     def update_work_item_for!(epic)
@@ -36,18 +34,31 @@ def update_work_item_for!(epic)
         params: update_params(epic)
       ).execute(epic.work_item)
 
-      return true if service_response[:status] == :success
-
-      error_message = service_response.payload[:errors]&.full_messages&.join(', ')
-      log_error("Unable to sync work item: #{error_message}. Group ID: #{group.id}")
-      raise StandardError, error_message
+      handle_response!(:update, service_response, epic)
     end
 
     private
 
+    def filtered_params
+      params.to_h.with_indifferent_access.slice(*ALLOWED_PARAMS)
+    end
+
+    def create_params(epic)
+      create_params = filtered_params.merge(
+        work_item_type: WorkItems::Type.default_by_type(:epic),
+        iid: epic.iid,
+        created_at: epic.created_at,
+        extra_params: { synced_work_item: true }
+      )
+
+      create_params[:title_html] = epic.title_html if params[:title].present?
+      create_params[:description_html] = epic.description_html if params[:description].present?
+
+      create_params
+    end
+
     def update_params(epic)
-      work_item_params = params.to_h.with_indifferent_access.slice(*ALLOWED_PARAMS)
-      work_item_params = work_item_params.merge({
+      update_params = filtered_params.merge({
         updated_by: epic.updated_by,
         updated_at: epic.updated_at,
         last_edited_at: epic.last_edited_at,
@@ -55,10 +66,22 @@ def update_params(epic)
         extra_params: { synced_work_item: true }
       })
 
-      work_item_params[:title_html] = epic.title_html if params[:title].present?
-      work_item_params[:description_html] = epic.description_html if params[:description].present?
+      update_params[:title_html] = epic.title_html if params[:title].present?
+      update_params[:description_html] = epic.description_html if params[:description].present?
+
+      update_params
+    end
+
+    def handle_response!(action, service_response, epic)
+      return true if service_response[:status] == :success
+
+      error_message = Array.wrap(service_response[:message])
+      Gitlab::EpicWorkItemSync::Logger.error(
+        message: "Not able to #{action} epic work item", error_message: error_message, group_id: group.id,
+        epic_id: epic.id
+      )
 
-      work_item_params
+      raise SyncAsWorkItemError, error_message.join(", ")
     end
 
     def work_item_sync_enabled?

ee/app/services/epics/create_service.rb

@@ -21,16 +21,7 @@ def transaction_create(epic)
       super.tap do |save_result|
         break save_result unless save_result && work_item_sync_enabled?
 
-        service_response = create_work_item_for(epic)
-
-        if service_response.success?
-          epic.issue_id = service_response.payload[:work_item].id
-          epic.save
-        else
-          error_message = service_response.payload[:errors]&.full_messages&.join(', ')
-          log_error("Unable create synced work item: #{error_message}. Group ID: #{group.id}")
-          raise StandardError, error_message
-        end
+        create_work_item_for!(epic)
       end
     end
 

ee/lib/gitlab/epic_work_item_sync/logger.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module EpicWorkItemSync
+    class Logger < ::Gitlab::JsonLogger
+      def self.file_name_noext
+        'epic_work_item_sync'
+      end
+    end
+  end
+end

ee/spec/lib/gitlab/epic_work_item_sync/logger_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe Gitlab::EpicWorkItemSync::Logger, feature_category: :team_planning do
+  describe '.build' do
+    it 'builds an instance' do
+      expect(described_class.build).to be_an_instance_of(described_class)
+    end
+  end
+
+  describe '.file_name_noext' do
+    it 'sets correct filename' do
+      expect(described_class.file_name_noext).to eq('epic_work_item_sync')
+    end
+  end
+end

ee/spec/services/concerns/epics/sync_as_work_item_spec.rb

@@ -7,7 +7,11 @@
   let_it_be(:group) { create(:group) }
   let_it_be(:params) { { title: 'foo', confidential: true, start_date: 1.day.ago, due_date: 5.days.from_now } }
 
-  describe '#create_work_item_for' do
+  before_all do
+    group.add_developer(user)
+  end
+
+  describe '#create_work_item_for!' do
     let(:epics_create_service) do
       Class.new do
         attr_accessor :group, :current_user, :params
@@ -23,7 +27,7 @@ def initialize(group: nil, current_user: nil, params: {})
         def execute
           epic = group.epics.new(params.merge({ group: group, author: current_user }))
           epic.save!
-          create_work_item_for(epic)
+          create_work_item_for!(epic)
         end
       end
     end
@@ -38,10 +42,6 @@ def execute
     end
 
     it 'calls WorkItems::CreateService with allowed params' do
-      allow_next_instance_of(::WorkItems::CreateService) do |instance|
-        allow(instance).to receive(:execute_without_rate_limiting).and_return({ status: :success })
-      end
-
       expect(::WorkItems::CreateService).to receive(:new)
         .with(
           container: group,
@@ -55,9 +55,9 @@ def execute
             work_item_type: WorkItems::Type.default_by_type(:epic),
             extra_params: { synced_work_item: true }
           }
-        )
+        ).and_call_original
 
-      service.execute
+      expect(service.execute).to eq true
     end
   end
 
@@ -102,7 +102,7 @@ def execute(epic)
         expect(instance).to receive(:execute).with(epic.work_item).and_return({ status: :success })
       end
 
-      service.execute(epic)
+      expect(service.execute(epic)).to eq true
     end
   end
 end

ee/spec/services/epics/create_service_spec.rb

@@ -84,19 +84,21 @@
 
       context 'when work item creation fails' do
         it 'does not create epic' do
-          error_msg = 'error 1, error 2'
-          allow_next_instance_of(Epics::CreateService) do |instance|
-            allow(instance).to receive(:create_work_item_for).and_return(
-              instance_double(
-                ServiceResponse,
-                success?: false,
-                payload: { errors: instance_double(ActiveModel::Errors, full_messages: error_msg.split(", ")) })
-            )
+          error_message = ['error 1', 'error 2']
+          allow_next_instance_of(WorkItems::CreateService) do |instance|
+            allow(instance).to receive(:execute).and_return(ServiceResponse.error(message: error_message))
           end
 
-          expect(Gitlab::AppLogger).to receive(:error)
-                                   .with("Unable create synced work item: #{error_msg}. Group ID: #{group.id}")
-          expect { subject }.to raise_error(StandardError, error_msg).and not_change { Epic.count }
+          expect(Gitlab::EpicWorkItemSync::Logger).to receive(:error)
+            .with({
+              message: "Not able to create epic work item",
+              error_message: error_message,
+              group_id: group.id,
+              epic_id: an_instance_of(Integer)
+            })
+
+          expect { subject }.to raise_error(Epics::SyncAsWorkItem::SyncAsWorkItemError)
+            .and not_change { Epic.count }
         end
       end
 

ee/spec/services/epics/update_service_spec.rb

@@ -806,22 +806,30 @@ def update_issuable(update_params)
         end
 
         context 'when work item update errors' do
-          let(:error_message) { "error 1, error 2" }
+          let(:error_message) { ["error 1", "error 2"] }
 
           before do
             allow_next_instance_of(WorkItems::UpdateService) do |instance|
               allow(instance).to receive(:execute).and_return(
-                ServiceResponse.error(message: 'error', payload: {
-                  errors: instance_double(ActiveModel::Errors, full_messages: error_message.split(", "))
-                })
+                {
+                  status: :error,
+                  message: error_message
+                }
               )
             end
           end
 
           it 'does not propagate the update to the work item and resets the epic udpates' do
-            expect(Gitlab::AppLogger).to receive(:error)
-              .with("Unable to sync work item: #{error_message}. Group ID: #{group.id}")
-            expect { update_epic({ title: 'New title' }) }.to raise_error(StandardError)
+            expect(Gitlab::EpicWorkItemSync::Logger).to receive(:error)
+              .with({
+                message: "Not able to update epic work item",
+                error_message: error_message,
+                group_id: group.id,
+                epic_id: epic.id
+              })
+
+            expect { update_epic({ title: 'New title' }) }
+              .to raise_error(Epics::SyncAsWorkItem::SyncAsWorkItemError)
               .and not_change { work_item.reload }
               .and not_change { epic.reload }
           end