Merge branch 'kassio/github-importer-logger-with-default-values' into 'master'

Add Gitlab::GithubImport::Logger with default values

See merge request gitlab-org/gitlab!65968

app/services/import/github_service.rb

@@ -111,7 +111,7 @@ module Import
     private
 
     def log_error(exception)
-      Gitlab::Import::Logger.error(
+      Gitlab::GithubImport::Logger.error(
         message: 'Import failed due to a GitHub error',
         status: exception.response_status,
         error: exception.response_body

app/workers/concerns/gitlab/github_import/object_importer.rb

@@ -17,10 +17,6 @@ module Gitlab
 
         feature_category :importers
         worker_has_external_dependencies!
-
-        def logger
-          @logger ||= Gitlab::Import::Logger.build
-        end
       end
 
       # project - An instance of `Project` to import the data into.
@@ -63,11 +59,11 @@ module Gitlab
       attr_accessor :github_id
 
       def info(project_id, extra = {})
-        logger.info(log_attributes(project_id, extra))
+        Logger.info(log_attributes(project_id, extra))
       end
 
       def error(project_id, exception, data = {})
-        logger.error(
+        Logger.error(
           log_attributes(
             project_id,
             message: 'importer failed',
@@ -78,13 +74,12 @@ module Gitlab
 
         Gitlab::ErrorTracking.track_and_raise_exception(
           exception,
-          log_attributes(project_id)
+          log_attributes(project_id, import_source: :github)
         )
       end
 
       def log_attributes(project_id, extra = {})
         extra.merge(
-          import_source: :github,
           project_id: project_id,
           importer: importer_class.name,
           github_id: github_id

app/workers/concerns/gitlab/github_import/queue.rb

@@ -17,7 +17,7 @@ module Gitlab
         sidekiq_options dead: false, retry: 5
 
         sidekiq_retries_exhausted do |msg, e|
-          Gitlab::Import::Logger.error(
+          Logger.error(
             event: :github_importer_exhausted,
             message: msg['error_message'],
             class: msg['class'],

app/workers/concerns/gitlab/github_import/stage_methods.rb

@@ -37,11 +37,11 @@ module Gitlab
       private
 
       def info(project_id, extra = {})
-        logger.info(log_attributes(project_id, extra))
+        Logger.info(log_attributes(project_id, extra))
       end
 
       def error(project_id, exception)
-        logger.error(
+        Logger.error(
           log_attributes(
             project_id,
             message: 'stage failed',
@@ -51,21 +51,16 @@ module Gitlab
 
         Gitlab::ErrorTracking.track_and_raise_exception(
           exception,
-          log_attributes(project_id)
+          log_attributes(project_id, import_source: :github)
         )
       end
 
       def log_attributes(project_id, extra = {})
         extra.merge(
-          import_source: :github,
           project_id: project_id,
           import_stage: self.class.name
         )
       end
-
-      def logger
-        @logger ||= Gitlab::Import::Logger.build
-      end
     end
   end
 end

doc/development/github_importer.md

@@ -237,6 +237,7 @@ The code for this resides in:
 
 > - [Introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/48512/diffs) in GitLab 13.7.
 > - Number of imported objects [introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/64256) in GitLab 14.1.
+> - `Gitlab::GithubImport::Logger` [introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/65968) in GitLab 14.2.
 
 The import progress can be checked in the `logs/importer.log` file. Each relevant import is logged
 with `"import_source": "github"` and the `"project_id"`.

lib/gitlab/github_import/logger.rb

+# frozen_string_literal: true
+
+module Gitlab
+  module GithubImport
+    class Logger < ::Gitlab::Import::Logger
+      def default_attributes
+        super.merge(import_source: :github)
+      end
+    end
+  end
+end

lib/gitlab/github_import/parallel_scheduling.rb

@@ -174,11 +174,11 @@ module Gitlab
       private
 
       def info(project_id, extra = {})
-        logger.info(log_attributes(project_id, extra))
+        Logger.info(log_attributes(project_id, extra))
       end
 
       def error(project_id, exception)
-        logger.error(
+        Logger.error(
           log_attributes(
             project_id,
             message: 'importer failed',
@@ -188,22 +188,17 @@ module Gitlab
 
         Gitlab::ErrorTracking.track_exception(
           exception,
-          log_attributes(project_id)
+          log_attributes(project_id, import_source: :github)
         )
       end
 
       def log_attributes(project_id, extra = {})
         extra.merge(
-          import_source: :github,
           project_id: project_id,
           importer: importer_class.name,
           parallel: parallel?
         )
       end
-
-      def logger
-        @logger ||= Gitlab::Import::Logger.build
-      end
     end
   end
 end

lib/gitlab/import/logger.rb

@@ -6,6 +6,10 @@ module Gitlab
       def self.file_name_noext
         'importer'
       end
+
+      def default_attributes
+        super.merge(feature_category: :importers)
+      end
     end
   end
 end

lib/gitlab/json_logger.rb

@@ -7,7 +7,7 @@ module Gitlab
     end
 
     def format_message(severity, timestamp, progname, message)
-      data = {}
+      data = default_attributes
       data[:severity] = severity
       data[:time] = timestamp.utc.iso8601(3)
       data[Labkit::Correlation::CorrelationId::LOG_KEY] = Labkit::Correlation::CorrelationId.current_id
@@ -21,5 +21,11 @@ module Gitlab
 
       Gitlab::Json.dump(data) + "\n"
     end
+
+    protected
+
+    def default_attributes
+      {}
+    end
   end
 end

spec/lib/gitlab/github_import/importer/lfs_objects_importer_spec.rb

@@ -61,18 +61,15 @@ RSpec.describe Gitlab::GithubImport::Importer::LfsObjectsImporter do
             .and_raise(exception)
         end
 
-        expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-          expect(logger)
-            .to receive(:error)
-            .with(
-              message: 'importer failed',
-              import_source: :github,
-              project_id: project.id,
-              parallel: false,
-              importer: 'Gitlab::GithubImport::Importer::LfsObjectImporter',
-              'error.message': 'Invalid Project URL'
-            )
-        end
+        expect(Gitlab::GithubImport::Logger)
+          .to receive(:error)
+          .with(
+            message: 'importer failed',
+            project_id: project.id,
+            parallel: false,
+            importer: 'Gitlab::GithubImport::Importer::LfsObjectImporter',
+            'error.message': 'Invalid Project URL'
+          )
 
         expect(Gitlab::ErrorTracking)
           .to receive(:track_exception)

spec/lib/gitlab/github_import/logger_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe Gitlab::GithubImport::Logger do
+  subject(:logger) { described_class.new('/dev/null') }
+
+  let(:now) { Time.zone.now }
+
+  describe '#format_message' do
+    before do
+      allow(Labkit::Correlation::CorrelationId).to receive(:current_id).and_return('new-correlation-id')
+    end
+
+    it 'formats strings' do
+      output = subject.format_message('INFO', now, 'test', 'Hello world')
+
+      expect(Gitlab::Json.parse(output)).to eq({
+        'severity' => 'INFO',
+        'time' => now.utc.iso8601(3),
+        'message' => 'Hello world',
+        'correlation_id' => 'new-correlation-id',
+        'feature_category' => 'importers',
+        'import_source' => 'github'
+      })
+    end
+
+    it 'formats hashes' do
+      output = subject.format_message('INFO', now, 'test', { hello: 1 })
+
+      expect(Gitlab::Json.parse(output)).to eq({
+        'severity' => 'INFO',
+        'time' => now.utc.iso8601(3),
+        'hello' => 1,
+        'correlation_id' => 'new-correlation-id',
+        'feature_category' => 'importers',
+        'import_source' => 'github'
+      })
+    end
+  end
+end

spec/lib/gitlab/github_import/parallel_scheduling_spec.rb

@@ -79,26 +79,23 @@ RSpec.describe Gitlab::GithubImport::ParallelScheduling do
         .to receive(:sequential_import)
         .and_return([])
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'starting importer',
-            import_source: :github,
-            parallel: false,
-            project_id: project.id,
-            importer: 'Class'
-          )
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'importer finished',
-            import_source: :github,
-            parallel: false,
-            project_id: project.id,
-            importer: 'Class'
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'starting importer',
+          parallel: false,
+          project_id: project.id,
+          importer: 'Class'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'importer finished',
+          parallel: false,
+          project_id: project.id,
+          importer: 'Class'
+        )
 
       importer.execute
     end
@@ -112,35 +109,32 @@ RSpec.describe Gitlab::GithubImport::ParallelScheduling do
         .to receive(:sequential_import)
         .and_raise(exception)
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'starting importer',
-            import_source: :github,
-            parallel: false,
-            project_id: project.id,
-            importer: 'Class'
-          )
-        expect(logger)
-          .to receive(:error)
-          .with(
-            message: 'importer failed',
-            import_source: :github,
-            project_id: project.id,
-            parallel: false,
-            importer: 'Class',
-            'error.message': 'some error'
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'starting importer',
+          parallel: false,
+          project_id: project.id,
+          importer: 'Class'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:error)
+        .with(
+          message: 'importer failed',
+          project_id: project.id,
+          parallel: false,
+          importer: 'Class',
+          'error.message': 'some error'
+        )
 
       expect(Gitlab::ErrorTracking)
         .to receive(:track_exception)
         .with(
           exception,
-          import_source: :github,
           parallel: false,
           project_id: project.id,
+          import_source: :github,
           importer: 'Class'
         )
         .and_call_original

spec/lib/gitlab/import/logger_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe Gitlab::Import::Logger do
+  subject { described_class.new('/dev/null') }
+
+  let(:now) { Time.zone.now }
+
+  describe '#format_message' do
+    before do
+      allow(Labkit::Correlation::CorrelationId).to receive(:current_id).and_return('new-correlation-id')
+    end
+
+    it 'formats strings' do
+      output = subject.format_message('INFO', now, 'test', 'Hello world')
+
+      expect(Gitlab::Json.parse(output)).to eq({
+        'severity' => 'INFO',
+        'time' => now.utc.iso8601(3),
+        'message' => 'Hello world',
+        'correlation_id' => 'new-correlation-id',
+        'feature_category' => 'importers'
+      })
+    end
+
+    it 'formats hashes' do
+      output = subject.format_message('INFO', now, 'test', { hello: 1 })
+
+      expect(Gitlab::Json.parse(output)).to eq({
+        'severity' => 'INFO',
+        'time' => now.utc.iso8601(3),
+        'hello' => 1,
+        'correlation_id' => 'new-correlation-id',
+        'feature_category' => 'importers'
+      })
+    end
+  end
+end

spec/workers/concerns/gitlab/github_import/object_importer_spec.rb

@@ -60,26 +60,23 @@ RSpec.describe Gitlab::GithubImport::ObjectImporter do
       expect(importer_instance)
         .to receive(:execute)
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            github_id: 1,
-            message: 'starting importer',
-            import_source: :github,
-            project_id: 1,
-            importer: 'klass_name'
-          )
-        expect(logger)
-          .to receive(:info)
-          .with(
-            github_id: 1,
-            message: 'importer finished',
-            import_source: :github,
-            project_id: 1,
-            importer: 'klass_name'
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          github_id: 1,
+          message: 'starting importer',
+          project_id: 1,
+          importer: 'klass_name'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          github_id: 1,
+          message: 'importer finished',
+          project_id: 1,
+          importer: 'klass_name'
+        )
 
       worker.import(project, client, { 'number' => 10, 'github_id' => 1 })
 
@@ -100,31 +97,28 @@ RSpec.describe Gitlab::GithubImport::ObjectImporter do
         .to receive(:execute)
         .and_raise(exception)
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            github_id: 1,
-            message: 'starting importer',
-            import_source: :github,
-            project_id: project.id,
-            importer: 'klass_name'
-          )
-        expect(logger)
-          .to receive(:error)
-          .with(
-            github_id:  1,
-            message: 'importer failed',
-            import_source: :github,
-            project_id: project.id,
-            importer: 'klass_name',
-            'error.message': 'some error',
-            'github.data': {
-              'github_id' => 1,
-              'number' => 10
-            }
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          github_id: 1,
+          message: 'starting importer',
+          project_id: project.id,
+          importer: 'klass_name'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:error)
+        .with(
+          github_id:  1,
+          message: 'importer failed',
+          project_id: project.id,
+          importer: 'klass_name',
+          'error.message': 'some error',
+          'github.data': {
+            'github_id' => 1,
+            'number' => 10
+          }
+        )
 
       expect(Gitlab::ErrorTracking)
         .to receive(:track_and_raise_exception)
@@ -143,21 +137,18 @@ RSpec.describe Gitlab::GithubImport::ObjectImporter do
     it 'logs error when representation does not have a github_id' do
       expect(importer_class).not_to receive(:new)
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:error)
-          .with(
-            github_id:  nil,
-            message: 'importer failed',
-            import_source: :github,
-            project_id: project.id,
-            importer: 'klass_name',
-            'error.message': 'key not found: :github_id',
-            'github.data': {
-              'number' => 10
-            }
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:error)
+        .with(
+          github_id:  nil,
+          message: 'importer failed',
+          project_id: project.id,
+          importer: 'klass_name',
+          'error.message': 'key not found: :github_id',
+          'github.data': {
+            'number' => 10
+          }
+        )
 
       expect(Gitlab::ErrorTracking)
         .to receive(:track_and_raise_exception)

spec/workers/concerns/gitlab/github_import/stage_methods_spec.rb

@@ -36,24 +36,21 @@ RSpec.describe Gitlab::GithubImport::StageMethods do
           an_instance_of(Project)
         )
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'starting stage',
-            import_source: :github,
-            project_id: project.id,
-            import_stage: 'DummyStage'
-          )
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'stage finished',
-            import_source: :github,
-            project_id: project.id,
-            import_stage: 'DummyStage'
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'starting stage',
+          project_id: project.id,
+          import_stage: 'DummyStage'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'stage finished',
+          project_id: project.id,
+          import_stage: 'DummyStage'
+        )
 
       worker.perform(project.id)
     end
@@ -70,25 +67,22 @@ RSpec.describe Gitlab::GithubImport::StageMethods do
         .to receive(:try_import)
         .and_raise(exception)
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'starting stage',
-            import_source: :github,
-            project_id: project.id,
-            import_stage: 'DummyStage'
-          )
-        expect(logger)
-          .to receive(:error)
-          .with(
-            message: 'stage failed',
-            import_source: :github,
-            project_id: project.id,
-            import_stage: 'DummyStage',
-            'error.message': 'some error'
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'starting stage',
+          project_id: project.id,
+          import_stage: 'DummyStage'
+        )
+
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:error)
+        .with(
+          message: 'stage failed',
+          project_id: project.id,
+          import_stage: 'DummyStage',
+          'error.message': 'some error'
+        )
 
       expect(Gitlab::ErrorTracking)
         .to receive(:track_and_raise_exception)

spec/workers/gitlab/github_import/stage/finish_import_worker_spec.rb

@@ -26,21 +26,18 @@ RSpec.describe Gitlab::GithubImport::Stage::FinishImportWorker do
         .to receive(:increment)
         .and_call_original
 
-      expect_next_instance_of(Gitlab::Import::Logger) do |logger|
-        expect(logger)
-          .to receive(:info)
-          .with(
-            message: 'GitHub project import finished',
-            import_stage: 'Gitlab::GithubImport::Stage::FinishImportWorker',
-            import_source: :github,
-            object_counts: {
-              'fetched' => {},
-              'imported' => {}
-            },
-            project_id: project.id,
-            duration_s: a_kind_of(Numeric)
-          )
-      end
+      expect(Gitlab::GithubImport::Logger)
+        .to receive(:info)
+        .with(
+          message: 'GitHub project import finished',
+          import_stage: 'Gitlab::GithubImport::Stage::FinishImportWorker',
+          object_counts: {
+            'fetched' => {},
+            'imported' => {}
+          },
+          project_id: project.id,
+          duration_s: a_kind_of(Numeric)
+        )
 
       worker.report_import_time(project)
     end