Commit 90bf205b authored by Shinya Maeda's avatar Shinya Maeda

Merge branch '21300-log-measurement-for-services' into 'master'

Log measurements for project Import export services

See merge request gitlab-org/gitlab!30977
parents 0cf0d5a5 c7ba513e
# frozen_string_literal: true
# In order to measure and log execution of our service, we just need to 'prepend Measurable' module
# Example:
# ```
# class DummyService
# prepend Measurable
#
# def execute
# # ...
# end
# end
# DummyService.prepend(Measurable)
# ```
#
# In case when we are prepending a module from the `EE` namespace with EE features
# we need to prepend Measurable after prepending `EE` module.
# This way Measurable will be at the bottom of the ancestor chain,
# in order to measure execution of `EE` features as well
# ```
# class DummyService
# def execute
# # ...
# end
# end
#
# DummyService.prepend_if_ee('EE::DummyService')
# DummyService.prepend(Measurable)
# ```
#
module Measurable
extend ::Gitlab::Utils::Override
override :execute
def execute(*args)
measuring? ? ::Gitlab::Utils::Measuring.new(base_log_data).with_measuring { super(*args) } : super(*args)
end
protected
# You can set extra attributes for performance measurement log.
def extra_attributes_for_measurement
defined?(super) ? super : {}
end
private
def measuring?
Feature.enabled?("gitlab_service_measuring_#{service_class}")
end
# These attributes are always present in log.
def base_log_data
extra_attributes_for_measurement.merge({ class: self.class.name })
end
def service_class
self.class.name.underscore.tr('/', '_')
end
end
...@@ -202,8 +202,19 @@ module Projects ...@@ -202,8 +202,19 @@ module Projects
end end
end end
def extra_attributes_for_measurement
{
current_user: current_user&.name,
project_full_path: "#{project_namespace&.full_path}/#{@params[:path]}"
}
end
private private
def project_namespace
@project_namespace ||= Namespace.find_by_id(@params[:namespace_id]) || current_user.namespace
end
def create_from_template? def create_from_template?
@params[:template_name].present? || @params[:template_project_id].present? @params[:template_name].present? || @params[:template_project_id].present?
end end
...@@ -224,4 +235,9 @@ module Projects ...@@ -224,4 +235,9 @@ module Projects
end end
end end
# rubocop: disable Cop/InjectEnterpriseEditionModule
Projects::CreateService.prepend_if_ee('EE::Projects::CreateService') Projects::CreateService.prepend_if_ee('EE::Projects::CreateService')
# rubocop: enable Cop/InjectEnterpriseEditionModule
# Measurable should be at the bottom of the ancestor chain, so it will measure execution of EE::Projects::CreateService as well
Projects::CreateService.prepend(Measurable)
...@@ -14,36 +14,16 @@ module Projects ...@@ -14,36 +14,16 @@ module Projects
@current_user, @params, @override_params = user, import_params.dup, override_params @current_user, @params, @override_params = user, import_params.dup, override_params
end end
def execute(options = {}) def execute
measurement_enabled = !!options[:measurement_enabled]
measurement_logger = options[:measurement_logger]
::Gitlab::Utils::Measuring.execute_with(measurement_enabled, measurement_logger, base_log_data) do
prepare_template_environment(template_file) prepare_template_environment(template_file)
prepare_import_params prepare_import_params
::Projects::CreateService.new(current_user, params).execute ::Projects::CreateService.new(current_user, params).execute
end end
end
private private
def base_log_data
base_log_data = {
class: self.class.name,
current_user: current_user.name,
project_full_path: project_path
}
if template_file
base_log_data[:import_type] = 'gitlab_project'
base_log_data[:file_path] = template_file.path
end
base_log_data
end
def overwrite_project? def overwrite_project?
overwrite? && project_with_same_full_path? overwrite? && project_with_same_full_path?
end end
......
...@@ -3,37 +3,39 @@ ...@@ -3,37 +3,39 @@
module Projects module Projects
module ImportExport module ImportExport
class ExportService < BaseService class ExportService < BaseService
def execute(after_export_strategy = nil, options = {}) prepend Measurable
unless project.template_source? || can?(current_user, :admin_project, project)
raise ::Gitlab::ImportExport::Error.permission_error(current_user, project) def initialize(*args)
end super
@shared = project.import_export_shared @shared = project.import_export_shared
end
measurement_enabled = !!options[:measurement_enabled] def execute(after_export_strategy = nil)
measurement_logger = options[:measurement_logger] unless project.template_source? || can?(current_user, :admin_project, project)
raise ::Gitlab::ImportExport::Error.permission_error(current_user, project)
end
::Gitlab::Utils::Measuring.execute_with(measurement_enabled, measurement_logger, base_log_data) do
save_all! save_all!
execute_after_export_action(after_export_strategy) execute_after_export_action(after_export_strategy)
end
ensure ensure
cleanup cleanup
end end
private protected
attr_accessor :shared
def base_log_data def extra_attributes_for_measurement
{ {
class: self.class.name, current_user: current_user&.name,
current_user: current_user.name, project_full_path: project&.full_path,
project_full_path: project.full_path,
file_path: shared.export_path file_path: shared.export_path
} }
end end
private
attr_accessor :shared
def execute_after_export_action(after_export_strategy) def execute_after_export_action(after_export_strategy)
return unless after_export_strategy return unless after_export_strategy
......
...@@ -37,6 +37,17 @@ module Projects ...@@ -37,6 +37,17 @@ module Projects
error(s_("ImportProjects|Error importing repository %{project_safe_import_url} into %{project_full_path} - %{message}") % { project_safe_import_url: project.safe_import_url, project_full_path: project.full_path, message: message }) error(s_("ImportProjects|Error importing repository %{project_safe_import_url} into %{project_full_path} - %{message}") % { project_safe_import_url: project.safe_import_url, project_full_path: project.full_path, message: message })
end end
protected
def extra_attributes_for_measurement
{
current_user: current_user&.name,
project_full_path: project&.full_path,
import_type: project&.import_type,
file_path: project&.import_source
}
end
private private
def after_execute_hook def after_execute_hook
...@@ -138,4 +149,9 @@ module Projects ...@@ -138,4 +149,9 @@ module Projects
end end
end end
# rubocop: disable Cop/InjectEnterpriseEditionModule
Projects::ImportService.prepend_if_ee('EE::Projects::ImportService') Projects::ImportService.prepend_if_ee('EE::Projects::ImportService')
# rubocop: enable Cop/InjectEnterpriseEditionModule
# Measurable should be at the bottom of the ancestor chain, so it will measure execution of EE::Projects::ImportService as well
Projects::ImportService.prepend(Measurable)
...@@ -9,7 +9,7 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker ...@@ -9,7 +9,7 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker
worker_resource_boundary :memory worker_resource_boundary :memory
urgency :throttled urgency :throttled
def perform(current_user_id, project_id, after_export_strategy = {}, params = {}, options = {}) def perform(current_user_id, project_id, after_export_strategy = {}, params = {})
current_user = User.find(current_user_id) current_user = User.find(current_user_id)
project = Project.find(project_id) project = Project.find(project_id)
export_job = project.export_jobs.safe_find_or_create_by(jid: self.jid) export_job = project.export_jobs.safe_find_or_create_by(jid: self.jid)
...@@ -17,7 +17,7 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker ...@@ -17,7 +17,7 @@ class ProjectExportWorker # rubocop:disable Scalability/IdempotentWorker
export_job&.start export_job&.start
::Projects::ImportExport::ExportService.new(project, current_user, params).execute(after_export, options) ::Projects::ImportExport::ExportService.new(project, current_user, params).execute(after_export)
export_job&.finish export_job&.finish
rescue ActiveRecord::RecordNotFound, Gitlab::ImportExport::AfterExportStrategyBuilder::StrategyNotFoundError => e rescue ActiveRecord::RecordNotFound, Gitlab::ImportExport::AfterExportStrategyBuilder::StrategyNotFoundError => e
......
# frozen_string_literal: true
Gitlab::Utils::Measuring.logger = Gitlab::Services::Logger.build
...@@ -587,6 +587,8 @@ This file lives in `/var/log/gitlab/gitlab-rails/importer.log` for ...@@ -587,6 +587,8 @@ This file lives in `/var/log/gitlab/gitlab-rails/importer.log` for
Omnibus GitLab packages or in `/home/git/gitlab/log/importer.log` for Omnibus GitLab packages or in `/home/git/gitlab/log/importer.log` for
installations from source. installations from source.
It logs the progress of the import process.
## `auth.log` ## `auth.log`
> Introduced in GitLab 12.0. > Introduced in GitLab 12.0.
...@@ -741,6 +743,23 @@ Each line contains a JSON line that can be ingested by Elasticsearch. For exampl ...@@ -741,6 +743,23 @@ Each line contains a JSON line that can be ingested by Elasticsearch. For exampl
} }
``` ```
## `service_measurement.log`
> Introduced in GitLab 13.0.
This file lives in `/var/log/gitlab/gitlab-rails/service_measurement.log` for
Omnibus GitLab packages or in `/home/git/gitlab/log/service_measurement.log` for
installations from source.
It contain only a single structured log with measurements for each service execution.
It will contain measurement such as: number of sql calls, execution_time, gc_stats, memory usage, etc...
For example:
```json
{ "severity":"INFO", "time":"2020-04-22T16:04:50.691Z","correlation_id":"04f1366e-57a1-45b8-88c1-b00b23dc3616","class":"Projects::ImportExport::ExportService","current_user":"John Doe","project_full_path":"group1/test-export","file_path":"/path/to/archive","gc_stats":{"count":{"before":127,"after":127,"diff":0},"heap_allocated_pages":{"before":10369,"after":10369,"diff":0},"heap_sorted_length":{"before":10369,"after":10369,"diff":0},"heap_allocatable_pages":{"before":0,"after":0,"diff":0},"heap_available_slots":{"before":4226409,"after":4226409,"diff":0},"heap_live_slots":{"before":2542709,"after":2641420,"diff":98711},"heap_free_slots":{"before":1683700,"after":1584989,"diff":-98711},"heap_final_slots":{"before":0,"after":0,"diff":0},"heap_marked_slots":{"before":2542704,"after":2542704,"diff":0},"heap_eden_pages":{"before":10369,"after":10369,"diff":0},"heap_tomb_pages":{"before":0,"after":0,"diff":0},"total_allocated_pages":{"before":10369,"after":10369,"diff":0},"total_freed_pages":{"before":0,"after":0,"diff":0},"total_allocated_objects":{"before":24896308,"after":24995019,"diff":98711},"total_freed_objects":{"before":22353599,"after":22353599,"diff":0},"malloc_increase_bytes":{"before":140032,"after":6650240,"diff":6510208},"malloc_increase_bytes_limit":{"before":25804104,"after":25804104,"diff":0},"minor_gc_count":{"before":94,"after":94,"diff":0},"major_gc_count":{"before":33,"after":33,"diff":0},"remembered_wb_unprotected_objects":{"before":34284,"after":34284,"diff":0},"remembered_wb_unprotected_objects_limit":{"before":68568,"after":68568,"diff":0},"old_objects":{"before":2404725,"after":2404725,"diff":0},"old_objects_limit":{"before":4809450,"after":4809450,"diff":0},"oldmalloc_increase_bytes":{"before":140032,"after":6650240,"diff":6510208},"oldmalloc_increase_bytes_limit":{"before":68537556,"after":68537556,"diff":0}},"time_to_finish":0.12298400001600385,"number_of_sql_calls":70,"memory_usage":"0.0 MiB","label":"process_48616"}
```
## `geo.log` **(PREMIUM ONLY)** ## `geo.log` **(PREMIUM ONLY)**
> Introduced in 9.5. > Introduced in 9.5.
......
...@@ -61,10 +61,9 @@ Parameters: ...@@ -61,10 +61,9 @@ Parameters:
| `namespace_path` | string | yes | Namespace path | | `namespace_path` | string | yes | Namespace path |
| `project_path` | string | yes | Project name | | `project_path` | string | yes | Project name |
| `archive_path` | string | yes | Path to the exported project tarball you want to import | | `archive_path` | string | yes | Path to the exported project tarball you want to import |
| `measurement_enabled` | boolean | no | Measure execution time, number of SQL calls and GC count |
```shell ```shell
bundle exec rake "gitlab:import_export:import[root, root, testingprojectimport, /path/to/file.tar.gz, true]" bundle exec rake "gitlab:import_export:import[root, root, testingprojectimport, /path/to/file.tar.gz]"
``` ```
### Importing via the Rails console ### Importing via the Rails console
......
...@@ -7,7 +7,7 @@ module EE ...@@ -7,7 +7,7 @@ module EE
include ::Gitlab::Utils::StrongMemoize include ::Gitlab::Utils::StrongMemoize
override :execute override :execute
def execute(options = {}) def execute
super.tap do |project| super.tap do |project|
if project.saved? && custom_template if project.saved? && custom_template
custom_template.add_export_job(current_user: current_user, custom_template.add_export_job(current_user: current_user,
......
---
title: Measure project import and export service execution
merge_request: 30977
author:
type: added
...@@ -11,20 +11,12 @@ module Gitlab ...@@ -11,20 +11,12 @@ module Gitlab
@file_path = opts.fetch(:file_path) @file_path = opts.fetch(:file_path)
@namespace = Namespace.find_by_full_path(opts.fetch(:namespace_path)) @namespace = Namespace.find_by_full_path(opts.fetch(:namespace_path))
@current_user = User.find_by_username(opts.fetch(:username)) @current_user = User.find_by_username(opts.fetch(:username))
@measurement_enabled = opts.fetch(:measurement_enabled)
@logger = logger @logger = logger
end end
private private
attr_reader :project, :namespace, :current_user, :file_path, :project_path, :logger, :measurement_enabled attr_reader :project, :namespace, :current_user, :file_path, :project_path, :logger
def measurement_options
{
measurement_enabled: measurement_enabled,
measurement_logger: logger
}
end
def disable_upload_object_storage def disable_upload_object_storage
overwrite_uploads_setting('enabled', false) do overwrite_uploads_setting('enabled', false) do
......
...@@ -16,7 +16,7 @@ module Gitlab ...@@ -16,7 +16,7 @@ module Gitlab
with_export do with_export do
::Projects::ImportExport::ExportService.new(project, current_user) ::Projects::ImportExport::ExportService.new(project, current_user)
.execute(Gitlab::ImportExport::AfterExportStrategies::MoveFileStrategy.new(archive_path: file_path), measurement_options) .execute(Gitlab::ImportExport::AfterExportStrategies::MoveFileStrategy.new(archive_path: file_path))
end end
return error(project.import_export_shared.errors.join(', ')) if project.import_export_shared.errors.any? return error(project.import_export_shared.errors.join(', ')) if project.import_export_shared.errors.any?
......
...@@ -59,7 +59,7 @@ module Gitlab ...@@ -59,7 +59,7 @@ module Gitlab
import_params import_params
) )
service.execute(measurement_options) service.execute
end end
end end
......
# frozen_string_literal: true
module Gitlab
module Services
class Logger < ::Gitlab::JsonLogger
def self.file_name_noext
'service_measurement'
end
end
end
end
...@@ -6,19 +6,14 @@ module Gitlab ...@@ -6,19 +6,14 @@ module Gitlab
module Utils module Utils
class Measuring class Measuring
class << self class << self
def execute_with(measurement_enabled, logger, base_log_data) attr_writer :logger
measurement_enabled ? measuring(logger, base_log_data).with_measuring { yield } : yield
end
private
def measuring(logger, base_log_data) def logger
Gitlab::Utils::Measuring.new(logger: logger, base_log_data: base_log_data) @logger ||= Logger.new(STDOUT)
end end
end end
def initialize(logger: nil, base_log_data: {}) def initialize(base_log_data = {})
@logger = logger || Logger.new($stdout)
@base_log_data = base_log_data @base_log_data = base_log_data
end end
...@@ -45,7 +40,7 @@ module Gitlab ...@@ -45,7 +40,7 @@ module Gitlab
private private
attr_reader :gc_stats, :time_to_finish, :sql_calls_count, :logger, :base_log_data attr_reader :gc_stats, :time_to_finish, :sql_calls_count, :base_log_data
def with_count_queries(&block) def with_count_queries(&block)
@sql_calls_count = 0 @sql_calls_count = 0
...@@ -76,21 +71,8 @@ module Gitlab ...@@ -76,21 +71,8 @@ module Gitlab
def log_info(details) def log_info(details)
details = base_log_data.merge(details) details = base_log_data.merge(details)
details = details.to_yaml if ActiveSupport::Logger.logger_outputs_to?(logger, STDOUT) details = details.to_yaml if ActiveSupport::Logger.logger_outputs_to?(Measuring.logger, STDOUT)
logger.info(details) Measuring.logger.info(details)
end
def duration_in_numbers(duration_in_seconds)
milliseconds = duration_in_seconds.in_milliseconds % 1.second.in_milliseconds
seconds = duration_in_seconds % 1.minute
minutes = (duration_in_seconds / 1.minute) % (1.hour / 1.minute)
hours = duration_in_seconds / 1.hour
if hours == 0
"%02d:%02d:%03d" % [minutes, seconds, milliseconds]
else
"%02d:%02d:%02d:%03d" % [hours, minutes, seconds, milliseconds]
end
end end
end end
end end
......
...@@ -3,12 +3,12 @@ ...@@ -3,12 +3,12 @@
# Export project to archive # Export project to archive
# #
# @example # @example
# bundle exec rake "gitlab:import_export:export[root, root, project_to_export, /path/to/file.tar.gz, true]" # bundle exec rake "gitlab:import_export:export[root, root, project_to_export, /path/to/file.tar.gz]"
# #
namespace :gitlab do namespace :gitlab do
namespace :import_export do namespace :import_export do
desc 'GitLab | Import/Export | EXPERIMENTAL | Export large project archives' desc 'GitLab | Import/Export | EXPERIMENTAL | Export large project archives'
task :export, [:username, :namespace_path, :project_path, :archive_path, :measurement_enabled] => :gitlab_environment do |_t, args| task :export, [:username, :namespace_path, :project_path, :archive_path] => :gitlab_environment do |_t, args|
# Load it here to avoid polluting Rake tasks with Sidekiq test warnings # Load it here to avoid polluting Rake tasks with Sidekiq test warnings
require 'sidekiq/testing' require 'sidekiq/testing'
...@@ -18,6 +18,7 @@ namespace :gitlab do ...@@ -18,6 +18,7 @@ namespace :gitlab do
warn_user_is_not_gitlab warn_user_is_not_gitlab
if ENV['EXPORT_DEBUG'].present? if ENV['EXPORT_DEBUG'].present?
Gitlab::Utils::Measuring.logger = logger
ActiveRecord::Base.logger = logger ActiveRecord::Base.logger = logger
logger.level = Logger::DEBUG logger.level = Logger::DEBUG
else else
...@@ -29,7 +30,6 @@ namespace :gitlab do ...@@ -29,7 +30,6 @@ namespace :gitlab do
project_path: args.project_path, project_path: args.project_path,
username: args.username, username: args.username,
file_path: args.archive_path, file_path: args.archive_path,
measurement_enabled: Gitlab::Utils.to_boolean(args.measurement_enabled),
logger: logger logger: logger
) )
......
...@@ -7,12 +7,12 @@ ...@@ -7,12 +7,12 @@
# 2. Performs Sidekiq job synchronously # 2. Performs Sidekiq job synchronously
# #
# @example # @example
# bundle exec rake "gitlab:import_export:import[root, root, imported_project, /path/to/file.tar.gz, true]" # bundle exec rake "gitlab:import_export:import[root, root, imported_project, /path/to/file.tar.gz]"
# #
namespace :gitlab do namespace :gitlab do
namespace :import_export do namespace :import_export do
desc 'GitLab | Import/Export | EXPERIMENTAL | Import large project archives' desc 'GitLab | Import/Export | EXPERIMENTAL | Import large project archives'
task :import, [:username, :namespace_path, :project_path, :archive_path, :measurement_enabled] => :gitlab_environment do |_t, args| task :import, [:username, :namespace_path, :project_path, :archive_path] => :gitlab_environment do |_t, args|
# Load it here to avoid polluting Rake tasks with Sidekiq test warnings # Load it here to avoid polluting Rake tasks with Sidekiq test warnings
require 'sidekiq/testing' require 'sidekiq/testing'
...@@ -22,6 +22,7 @@ namespace :gitlab do ...@@ -22,6 +22,7 @@ namespace :gitlab do
warn_user_is_not_gitlab warn_user_is_not_gitlab
if ENV['IMPORT_DEBUG'].present? if ENV['IMPORT_DEBUG'].present?
Gitlab::Utils::Measuring.logger = logger
ActiveRecord::Base.logger = logger ActiveRecord::Base.logger = logger
logger.level = Logger::DEBUG logger.level = Logger::DEBUG
else else
...@@ -33,7 +34,6 @@ namespace :gitlab do ...@@ -33,7 +34,6 @@ namespace :gitlab do
project_path: args.project_path, project_path: args.project_path,
username: args.username, username: args.username,
file_path: args.archive_path, file_path: args.archive_path,
measurement_enabled: Gitlab::Utils.to_boolean(args.measurement_enabled),
logger: logger logger: logger
) )
......
...@@ -39,8 +39,6 @@ describe Gitlab::ImportExport::Project::ImportTask, :request_store do ...@@ -39,8 +39,6 @@ describe Gitlab::ImportExport::Project::ImportTask, :request_store do
expect(project.milestones.count).to be > 0 expect(project.milestones.count).to be > 0
expect(project.import_state.status).to eq('finished') expect(project.import_state.status).to eq('finished')
end end
it_behaves_like 'measurable'
end end
context 'when project import is invalid' do context 'when project import is invalid' do
......
...@@ -3,62 +3,15 @@ ...@@ -3,62 +3,15 @@
require 'fast_spec_helper' require 'fast_spec_helper'
describe Gitlab::Utils::Measuring do describe Gitlab::Utils::Measuring do
describe '.execute_with' do
let(:measurement_logger) { double(:logger) }
let(:base_log_data) do
{
class: described_class.name
}
end
let(:result_block) { 'result' }
subject { described_class.execute_with(measurement_enabled, measurement_logger, base_log_data) { result_block } }
context 'when measurement is enabled' do
let(:measurement_enabled) { true }
let!(:measurement) { described_class.new(logger: measurement_logger, base_log_data: base_log_data) }
before do
allow(measurement_logger).to receive(:info)
end
it 'measure execution with Gitlab::Utils::Measuring instance', :aggregate_failure do
expect(described_class).to receive(:new).with(logger: measurement_logger, base_log_data: base_log_data) { measurement }
expect(measurement).to receive(:with_measuring)
subject
end
it 'returns result from yielded block' do
is_expected.to eq(result_block)
end
end
context 'when measurement is disabled' do
let(:measurement_enabled) { false }
it 'does not measure service execution' do
expect(Gitlab::Utils::Measuring).not_to receive(:new)
subject
end
it 'returns result from yielded block' do
is_expected.to eq(result_block)
end
end
end
describe '#with_measuring' do describe '#with_measuring' do
let(:logger) { double(:logger) }
let(:base_log_data) { {} } let(:base_log_data) { {} }
let(:result) { "result" } let(:result) { "result" }
before do before do
allow(logger).to receive(:info) allow(ActiveSupport::Logger).to receive(:logger_outputs_to?).with(Gitlab::Utils::Measuring.logger, STDOUT).and_return(false)
end end
let(:measurement) { described_class.new(logger: logger, base_log_data: base_log_data) } let(:measurement) { described_class.new(base_log_data) }
subject do subject do
measurement.with_measuring { result } measurement.with_measuring { result }
...@@ -69,7 +22,7 @@ describe Gitlab::Utils::Measuring do ...@@ -69,7 +22,7 @@ describe Gitlab::Utils::Measuring do
expect(measurement).to receive(:with_count_queries).and_call_original expect(measurement).to receive(:with_count_queries).and_call_original
expect(measurement).to receive(:with_gc_stats).and_call_original expect(measurement).to receive(:with_gc_stats).and_call_original
expect(logger).to receive(:info).with(including(:gc_stats, :time_to_finish, :number_of_sql_calls, :memory_usage, :label)) expect(described_class.logger).to receive(:info).with(include(:gc_stats, :time_to_finish, :number_of_sql_calls, :memory_usage, :label))
is_expected.to eq(result) is_expected.to eq(result)
end end
...@@ -78,7 +31,7 @@ describe Gitlab::Utils::Measuring do ...@@ -78,7 +31,7 @@ describe Gitlab::Utils::Measuring do
let(:base_log_data) { { test: "data" } } let(:base_log_data) { { test: "data" } }
it 'logs includes base data' do it 'logs includes base data' do
expect(logger).to receive(:info).with(including(:test, :gc_stats, :time_to_finish, :number_of_sql_calls, :memory_usage, :label)) expect(described_class.logger).to receive(:info).with(include(:test, :gc_stats, :time_to_finish, :number_of_sql_calls, :memory_usage, :label))
subject subject
end end
......
...@@ -411,7 +411,9 @@ describe API::ProjectExport, :clean_gitlab_redis_cache do ...@@ -411,7 +411,9 @@ describe API::ProjectExport, :clean_gitlab_redis_cache do
it 'starts', :sidekiq_might_not_need_inline do it 'starts', :sidekiq_might_not_need_inline do
params = { description: "Foo" } params = { description: "Foo" }
expect_any_instance_of(Projects::ImportExport::ExportService).to receive(:execute) expect_next_instance_of(Projects::ImportExport::ExportService) do |service|
expect(service).to receive(:execute)
end
post api(path, project.owner), params: params post api(path, project.owner), params: params
expect(response).to have_gitlab_http_status(:accepted) expect(response).to have_gitlab_http_status(:accepted)
......
...@@ -489,6 +489,27 @@ describe Projects::CreateService, '#execute' do ...@@ -489,6 +489,27 @@ describe Projects::CreateService, '#execute' do
end end
end end
it_behaves_like 'measurable service' do
before do
opts.merge!(
current_user: user,
path: 'foo'
)
end
let(:base_log_data) do
{
class: Projects::CreateService.name,
current_user: user.name,
project_full_path: "#{user.namespace.full_path}/#{opts[:path]}"
}
end
after do
create_project(user, opts)
end
end
def create_project(user, opts) def create_project(user, opts)
Projects::CreateService.new(user, opts).execute Projects::CreateService.new(user, opts).execute
end end
......
...@@ -7,9 +7,10 @@ describe Projects::ImportExport::ExportService do ...@@ -7,9 +7,10 @@ describe Projects::ImportExport::ExportService do
let!(:user) { create(:user) } let!(:user) { create(:user) }
let(:project) { create(:project) } let(:project) { create(:project) }
let(:shared) { project.import_export_shared } let(:shared) { project.import_export_shared }
let(:service) { described_class.new(project, user) }
let!(:after_export_strategy) { Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy.new } let!(:after_export_strategy) { Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy.new }
subject(:service) { described_class.new(project, user) }
before do before do
project.add_maintainer(user) project.add_maintainer(user)
end end
...@@ -184,7 +185,7 @@ describe Projects::ImportExport::ExportService do ...@@ -184,7 +185,7 @@ describe Projects::ImportExport::ExportService do
end end
end end
context 'when measurable params are provided' do it_behaves_like 'measurable service' do
let(:base_log_data) do let(:base_log_data) do
{ {
class: described_class.name, class: described_class.name,
...@@ -194,44 +195,8 @@ describe Projects::ImportExport::ExportService do ...@@ -194,44 +195,8 @@ describe Projects::ImportExport::ExportService do
} }
end end
subject(:service) { described_class.new(project, user) } after do
service.execute(after_export_strategy)
context 'when measurement is enabled' do
let(:logger) { double(:logger) }
let(:measurable_options) do
{
measurement_enabled: true,
measurement_logger: logger
}
end
before do
allow(logger).to receive(:info)
end
it 'measure service execution with Gitlab::Utils::Measuring' do
expect(Gitlab::Utils::Measuring).to receive(:execute_with).with(true, logger, base_log_data).and_call_original
expect_next_instance_of(Gitlab::Utils::Measuring) do |measuring|
expect(measuring).to receive(:with_measuring).and_call_original
end
service.execute(after_export_strategy, measurable_options)
end
end
context 'when measurement is disabled' do
let(:measurable_options) do
{
measurement_enabled: false
}
end
it 'does not measure service execution' do
expect(Gitlab::Utils::Measuring).to receive(:execute_with).with(false, nil, base_log_data).and_call_original
expect(Gitlab::Utils::Measuring).not_to receive(:new)
service.execute(after_export_strategy, measurable_options)
end
end end
end end
end end
......
...@@ -264,13 +264,33 @@ describe Projects::ImportService do ...@@ -264,13 +264,33 @@ describe Projects::ImportService do
it 'fails with port 25' do it 'fails with port 25' do
project.import_url = "https://github.com:25/vim/vim.git" project.import_url = "https://github.com:25/vim/vim.git"
result = described_class.new(project, user).execute result = subject.execute
expect(result[:status]).to eq :error expect(result[:status]).to eq :error
expect(result[:message]).to include('Only allowed ports are 80, 443') expect(result[:message]).to include('Only allowed ports are 80, 443')
end end
end end
it_behaves_like 'measurable service' do
let(:base_log_data) do
{
class: described_class.name,
current_user: user.name,
project_full_path: project.full_path,
import_type: project.import_type,
file_path: project.import_source
}
end
before do
project.import_type = 'github'
end
after do
subject.execute
end
end
def stub_github_omniauth_provider def stub_github_omniauth_provider
provider = OpenStruct.new( provider = OpenStruct.new(
'name' => 'github', 'name' => 'github',
......
...@@ -53,56 +53,4 @@ RSpec.shared_examples 'gitlab projects import validations' do ...@@ -53,56 +53,4 @@ RSpec.shared_examples 'gitlab projects import validations' do
end end
end end
end end
context 'when measurable params are provided' do
let(:base_log_data) do
base_log_data = {
class: described_class.name,
current_user: namespace.owner.name,
project_full_path: "#{namespace.full_path}/#{path}"
}
base_log_data.merge!({ import_type: 'gitlab_project', file_path: import_params[:file].path }) if import_params[:file]
base_log_data
end
subject { described_class.new(namespace.owner, import_params) }
context 'when measurement is enabled' do
let(:logger) { double(:logger) }
let(:measurable_options) do
{
measurement_enabled: true,
measurement_logger: logger
}
end
before do
allow(logger).to receive(:info)
end
it 'measure service execution with Gitlab::Utils::Measuring' do
expect(Gitlab::Utils::Measuring).to receive(:execute_with).with(true, logger, base_log_data).and_call_original
expect_next_instance_of(Gitlab::Utils::Measuring) do |measuring|
expect(measuring).to receive(:with_measuring).and_call_original
end
subject.execute(measurable_options)
end
end
context 'when measurement is disabled' do
let(:measurable_options) do
{
measurement_enabled: false
}
end
it 'does not measure service execution' do
expect(Gitlab::Utils::Measuring).to receive(:execute_with).with(false, nil, base_log_data).and_call_original
expect(Gitlab::Utils::Measuring).not_to receive(:new)
subject.execute(measurable_options)
end
end
end
end end
# frozen_string_literal: true
RSpec.shared_examples 'measurable service' do
context 'when measurement is enabled' do
let!(:measuring) { Gitlab::Utils::Measuring.new(base_log_data) }
before do
stub_feature_flags(feature_flag => true)
end
it 'measure service execution with Gitlab::Utils::Measuring', :aggregate_failures do
expect(Gitlab::Utils::Measuring).to receive(:new).with(base_log_data).and_return(measuring)
expect(measuring).to receive(:with_measuring).and_call_original
end
end
context 'when measurement is disabled' do
it 'does not measure service execution' do
stub_feature_flags(feature_flag => false)
expect(Gitlab::Utils::Measuring).not_to receive(:new)
end
end
def feature_flag
"gitlab_service_measuring_#{described_class_name}"
end
def described_class_name
described_class.name.underscore.tr('/', '_')
end
end
# frozen_string_literal: true
RSpec.shared_examples 'measurable' do
context 'when measurement is enabled' do
let(:measurement_enabled) { true }
it 'prints measurement results' do
expect { subject }.to output(including('time_to_finish')).to_stdout
end
end
context 'when measurement is not enabled' do
let(:measurement_enabled) { false }
it 'does not output measurement results' do
expect { subject }.not_to output(/time_to_finish/).to_stdout
end
end
context 'when measurement is not provided' do
let(:measurement_enabled) { nil }
it 'does not output measurement results' do
expect { subject }.not_to output(/time_to_finish/).to_stdout
end
it 'does not raise any exception' do
expect { subject }.not_to raise_error
end
end
end
...@@ -24,20 +24,6 @@ describe ProjectExportWorker do ...@@ -24,20 +24,6 @@ describe ProjectExportWorker do
subject.perform(user.id, project.id, { 'klass' => 'Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy' }) subject.perform(user.id, project.id, { 'klass' => 'Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy' })
end end
context 'with measurement options provided' do
it 'calls the ExportService with measurement options' do
measurement_options = { measurement_enabled: true }
params = {}
after_export_strategy = { 'klass' => 'Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy' }
expect_next_instance_of(::Projects::ImportExport::ExportService) do |service|
expect(service).to receive(:execute).with(instance_of(Gitlab::ImportExport::AfterExportStrategies::DownloadNotificationStrategy), measurement_options)
end
subject.perform(user.id, project.id, after_export_strategy, params, measurement_options)
end
end
context 'export job' do context 'export job' do
before do before do
allow_next_instance_of(::Projects::ImportExport::ExportService) do |service| allow_next_instance_of(::Projects::ImportExport::ExportService) do |service|
...@@ -69,7 +55,7 @@ describe ProjectExportWorker do ...@@ -69,7 +55,7 @@ describe ProjectExportWorker do
context 'when it fails' do context 'when it fails' do
it 'does not raise an exception when strategy is invalid' do it 'does not raise an exception when strategy is invalid' do
expect_any_instance_of(::Projects::ImportExport::ExportService).not_to receive(:execute) expect(::Projects::ImportExport::ExportService).not_to receive(:new)
expect { subject.perform(user.id, project.id, { 'klass' => 'Whatever' }) }.not_to raise_error expect { subject.perform(user.id, project.id, { 'klass' => 'Whatever' }) }.not_to raise_error
end end
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment