Add Project Export granular exporter timings

  - Update Project Export Service to add granular
    exporter timings for better observability

app/services/projects/import_export/export_service.rb

@@ -23,6 +23,13 @@ module Projects
         cleanup
       end
 
+      def exporters
+        [
+          version_saver, avatar_saver, project_tree_saver, uploads_saver,
+          repo_saver, wiki_repo_saver, lfs_saver, snippets_repo_saver, design_repo_saver
+        ]
+      end
+
       protected
 
       def extra_attributes_for_measurement
@@ -59,26 +66,19 @@ module Projects
       end
 
       def save_export_archive
-        Gitlab::ImportExport::Saver.save(exportable: project, shared: shared)
-      end
-
-      def exporters
-        [
-          version_saver, avatar_saver, project_tree_saver, uploads_saver,
-          repo_saver, wiki_repo_saver, lfs_saver, snippets_repo_saver, design_repo_saver
-        ]
+        @export_saver ||= Gitlab::ImportExport::Saver.save(exportable: project, shared: shared)
       end
 
       def version_saver
-        Gitlab::ImportExport::VersionSaver.new(shared: shared)
+        @version_saver ||= Gitlab::ImportExport::VersionSaver.new(shared: shared)
       end
 
       def avatar_saver
-        Gitlab::ImportExport::AvatarSaver.new(project: project, shared: shared)
+        @avatar_saver ||= Gitlab::ImportExport::AvatarSaver.new(project: project, shared: shared)
       end
 
       def project_tree_saver
-        tree_saver_class.new(project: project,
+        @project_tree_saver ||= tree_saver_class.new(project: project,
                                   current_user: current_user,
                                   shared: shared,
                                   params: params,
@@ -90,27 +90,31 @@ module Projects
       end
 
       def uploads_saver
-        Gitlab::ImportExport::UploadsSaver.new(project: project, shared: shared)
+        @uploads_saver ||= Gitlab::ImportExport::UploadsSaver.new(project: project, shared: shared)
       end
 
       def repo_saver
-        Gitlab::ImportExport::RepoSaver.new(exportable: project, shared: shared)
+        @repo_saver ||= Gitlab::ImportExport::RepoSaver.new(exportable: project, shared: shared)
       end
 
       def wiki_repo_saver
-        Gitlab::ImportExport::WikiRepoSaver.new(exportable: project, shared: shared)
+        @wiki_repo_saver ||= Gitlab::ImportExport::WikiRepoSaver.new(exportable: project, shared: shared)
       end
 
       def lfs_saver
-        Gitlab::ImportExport::LfsSaver.new(project: project, shared: shared)
+        @lfs_saver ||= Gitlab::ImportExport::LfsSaver.new(project: project, shared: shared)
       end
 
       def snippets_repo_saver
-        Gitlab::ImportExport::SnippetsRepoSaver.new(current_user: current_user, project: project, shared: shared)
+        @snippets_repo_saver ||= Gitlab::ImportExport::SnippetsRepoSaver.new(
+          current_user: current_user,
+          project: project,
+          shared: shared
+        )
       end
 
       def design_repo_saver
-        Gitlab::ImportExport::DesignRepoSaver.new(exportable: project, shared: shared)
+        @design_repo_saver ||= Gitlab::ImportExport::DesignRepoSaver.new(exportable: project, shared: shared)
       end
 
       def cleanup

app/workers/project_export_worker.rb

@@ -21,7 +21,10 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker
 
     export_job&.start
 
-    ::Projects::ImportExport::ExportService.new(project, current_user, params).execute(after_export)
+    export_service = ::Projects::ImportExport::ExportService.new(project, current_user, params)
+    export_service.execute(after_export)
+
+    log_exporters_duration(export_service)
 
     export_job&.finish
   rescue ActiveRecord::RecordNotFound => e
@@ -46,4 +49,13 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker
   def log_failure(project_id, ex)
     logger.error("Failed to export project #{project_id}: #{ex.message}")
   end
+
+  def log_exporters_duration(export_service)
+    export_service.exporters.each do |exporter|
+      exporter_key = "#{exporter.class.name.demodulize.underscore}_duration_s".to_sym # e.g. uploads_saver_duration_s
+      exporter_duration = exporter.duration_s&.round(6)
+
+      log_extra_metadata_on_done(exporter_key, exporter_duration)
+    end
+  end
 end

lib/gitlab/import_export/avatar_saver.rb

@@ -3,19 +3,23 @@
 module Gitlab
   module ImportExport
     class AvatarSaver
+      include DurationMeasuring
+
       def initialize(project:, shared:)
         @project = project
         @shared = shared
       end
 
       def save
-        return true unless @project.avatar.exists?
+        with_duration_measuring do
+          break true unless @project.avatar.exists?
 
           Gitlab::ImportExport::UploadsManager.new(
             project: @project,
             shared: @shared,
             relative_export_path: 'avatar'
           ).save
+        end
       rescue StandardError => e
         @shared.error(e)
         false

lib/gitlab/import_export/duration_measuring.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module ImportExport
+    module DurationMeasuring
+      extend ActiveSupport::Concern
+
+      included do
+        attr_reader :duration_s
+
+        def with_duration_measuring
+          result = nil
+
+          @duration_s = Benchmark.realtime do
+            result = yield
+          end
+
+          result
+        end
+      end
+    end
+  end
+end

lib/gitlab/import_export/lfs_saver.rb

@@ -4,6 +4,7 @@ module Gitlab
   module ImportExport
     class LfsSaver
       include Gitlab::ImportExport::CommandLineUtil
+      include DurationMeasuring
 
       attr_accessor :lfs_json, :project, :shared
 
@@ -16,6 +17,7 @@ module Gitlab
       end
 
       def save
+        with_duration_measuring do
           project.lfs_objects.find_in_batches(batch_size: BATCH_SIZE) do |batch|
             batch.each do |lfs_object|
               save_lfs_object(lfs_object)
@@ -27,6 +29,7 @@ module Gitlab
           write_lfs_json
 
           true
+        end
       rescue StandardError => e
         shared.error(e)
 

lib/gitlab/import_export/project/tree_saver.rb

@@ -4,6 +4,8 @@ module Gitlab
   module ImportExport
     module Project
       class TreeSaver
+        include DurationMeasuring
+
         attr_reader :full_path
 
         def initialize(project:, current_user:, shared:, params: {}, logger: Gitlab::Import::Logger)
@@ -15,9 +17,11 @@ module Gitlab
         end
 
         def save
+          with_duration_measuring do
             stream_export
 
             true
+          end
         rescue StandardError => e
           @shared.error(e)
           false

lib/gitlab/import_export/repo_saver.rb

@@ -4,6 +4,7 @@ module Gitlab
   module ImportExport
     class RepoSaver
       include Gitlab::ImportExport::CommandLineUtil
+      include DurationMeasuring
 
       attr_reader :exportable, :shared
 
@@ -13,10 +14,13 @@ module Gitlab
       end
 
       def save
-        return true unless repository_exists? # it's ok to have no repo
+        with_duration_measuring do
+          # it's ok to have no repo
+          break true unless repository_exists?
 
           bundle_to_disk
         end
+      end
 
       def repository
         @repository ||= @exportable.repository

lib/gitlab/import_export/snippets_repo_saver.rb

@@ -4,6 +4,7 @@ module Gitlab
   module ImportExport
     class SnippetsRepoSaver
       include Gitlab::ImportExport::CommandLineUtil
+      include DurationMeasuring
 
       def initialize(current_user:, project:, shared:)
         @project = project
@@ -12,6 +13,7 @@ module Gitlab
       end
 
       def save
+        with_duration_measuring do
           create_snippets_repo_directory
 
           @project.snippets.find_each.all? do |snippet|
@@ -21,6 +23,7 @@ module Gitlab
                                                   .save
           end
         end
+      end
 
       private
 

lib/gitlab/import_export/uploads_saver.rb

@@ -3,16 +3,20 @@
 module Gitlab
   module ImportExport
     class UploadsSaver
+      include DurationMeasuring
+
       def initialize(project:, shared:)
         @project = project
         @shared = shared
       end
 
       def save
+        with_duration_measuring do
           Gitlab::ImportExport::UploadsManager.new(
             project: @project,
             shared: @shared
           ).save
+        end
       rescue StandardError => e
         @shared.error(e)
         false

lib/gitlab/import_export/version_saver.rb

@@ -4,17 +4,20 @@ module Gitlab
   module ImportExport
     class VersionSaver
       include Gitlab::ImportExport::CommandLineUtil
+      include DurationMeasuring
 
       def initialize(shared:)
         @shared = shared
       end
 
       def save
+        with_duration_measuring do
           mkdir_p(@shared.export_path)
 
           File.write(version_file, Gitlab::ImportExport.version, mode: 'w')
           File.write(gitlab_version_file, Gitlab::VERSION, mode: 'w')
           File.write(gitlab_revision_file, Gitlab.revision, mode: 'w')
+        end
       rescue StandardError => e
         @shared.error(e)
         false

spec/lib/gitlab/import_export/duration_measuring_spec.rb

+# frozen_string_literal: true
+
+require 'fast_spec_helper'
+
+RSpec.describe Gitlab::ImportExport::DurationMeasuring do
+  subject do
+    Class.new do
+      include Gitlab::ImportExport::DurationMeasuring
+
+      def test
+        with_duration_measuring do
+          'test'
+        end
+      end
+    end.new
+  end
+
+  it 'measures method execution duration' do
+    subject.test
+
+    expect(subject.duration_s).not_to be_nil
+  end
+
+  describe '#with_duration_measuring' do
+    it 'yields control' do
+      expect { |block| subject.with_duration_measuring(&block) }.to yield_control
+    end
+
+    it 'returns result of the yielded block' do
+      return_value = 'return_value'
+
+      expect(subject.with_duration_measuring { return_value }).to eq(return_value)
+    end
+  end
+end

spec/workers/project_export_worker_spec.rb

@@ -4,4 +4,30 @@ require 'spec_helper'
 
 RSpec.describe ProjectExportWorker do
   it_behaves_like 'export worker'
+
+  context 'exporters duration measuring' do
+    let(:user) { create(:user) }
+    let(:project) { create(:project) }
+    let(:worker) { described_class.new }
+
+    subject { worker.perform(user.id, project.id) }
+
+    before do
+      project.add_owner(user)
+    end
+
+    it 'logs exporters execution duration' do
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:version_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:avatar_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:tree_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:uploads_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:repo_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:wiki_repo_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:lfs_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:snippets_repo_saver_duration_s, anything)
+      expect(worker).to receive(:log_extra_metadata_on_done).with(:design_repo_saver_duration_s, anything)
+
+      subject
+    end
+  end
 end