Skip to content
代码片段 群组 项目
未验证 提交 dad02267 编辑于 作者: Aakriti Gupta's avatar Aakriti Gupta 提交者: GitLab
浏览文件

Merge branch 'new-backup-logger' into 'master'

Improve backup logging by log levels

See merge request https://gitlab.com/gitlab-org/gitlab/-/merge_requests/149137



Merged-by: default avatarAakriti Gupta <agupta@gitlab.com>
Approved-by: default avatarIan Baum <ibaum@gitlab.com>
Approved-by: default avatarAakriti Gupta <agupta@gitlab.com>
Reviewed-by: default avatarIan Baum <ibaum@gitlab.com>
Co-authored-by: default avatarShubham Kumar <shubhamkrai123@gmail.com>
No related branches found
No related tags found
无相关合并请求
......@@ -2,13 +2,15 @@
module Backup
class Manager
include ::Gitlab::TaskHelpers
FILE_NAME_SUFFIX = '_gitlab_backup.tar'
MANIFEST_NAME = 'backup_information.yml'
# Use the content from stdin instead of an actual filepath (used by tar as input or output)
USE_STDIN = '-'
attr_reader :progress, :remote_storage, :options
attr_reader :remote_storage, :options, :logger, :progress
def initialize(progress, backup_tasks: nil)
@progress = progress
......@@ -16,7 +18,8 @@ def initialize(progress, backup_tasks: nil)
@options = Backup::Options.new
@metadata = Backup::Metadata.new(manifest_filepath)
@options.extract_from_env! # preserve existing behavior
@remote_storage = Backup::RemoteStorage.new(progress: progress, options: options)
@logger = Gitlab::BackupLogger.new(progress)
@remote_storage = Backup::RemoteStorage.new(logger: logger, options: options)
end
# @return [Boolean] whether all tasks succeeded
......@@ -27,10 +30,10 @@ def create
unpack(previous_backup) if options.incremental?
create_all_tasks_result = run_all_create_tasks
puts_time "Warning: Your gitlab.rb and gitlab-secrets.json files contain sensitive data \n" \
logger.warn "Warning: Your gitlab.rb and gitlab-secrets.json files contain sensitive data \n" \
"and are not included in this backup. You will need these files to restore a backup.\n" \
"Please back them up manually.".color(:red)
puts_time "Backup #{backup_id} is done."
"Please back them up manually."
logger.info "Backup #{backup_id} is done."
create_all_tasks_result
end
......@@ -40,22 +43,22 @@ def run_create_task(task)
build_backup_information
unless task.enabled?
puts_time "Dumping #{task.human_name} ... ".color(:blue) + "[DISABLED]".color(:cyan)
logger.info "Dumping #{task.human_name} ... " + "[DISABLED]"
return true
end
if options.skip_task?(task.id)
puts_time "Dumping #{task.human_name} ... ".color(:blue) + "[SKIPPED]".color(:cyan)
logger.info "Dumping #{task.human_name} ... " + "[SKIPPED]"
return true
end
puts_time "Dumping #{task.human_name} ... ".color(:blue)
logger.info "Dumping #{task.human_name} ... "
task.backup!(backup_path, backup_id)
puts_time "Dumping #{task.human_name} ... ".color(:blue) + "done".color(:green)
logger.info "Dumping #{task.human_name} ... " + "done"
true
rescue Backup::DatabaseBackupError, Backup::FileBackupError => e
puts_time "Dumping #{task.human_name} failed: #{e.message}".color(:red)
logger.error "Dumping #{task.human_name} failed: #{e.message}"
false
end
......@@ -63,9 +66,9 @@ def restore
unpack(options.backup_id)
run_all_restore_tasks
puts_time "Warning: Your gitlab.rb and gitlab-secrets.json files contain sensitive data \n" \
"and are not included in this backup. You will need to restore these files manually.".color(:red)
puts_time "Restore task is done."
logger.warn "Warning: Your gitlab.rb and gitlab-secrets.json files contain sensitive data \n" \
"and are not included in this backup. You will need to restore these files manually."
logger.info "Restore task is done."
end
# @param [Gitlab::Backup::Tasks::Task] task
......@@ -73,30 +76,30 @@ def run_restore_task(task)
read_backup_information
unless task.enabled?
puts_time "Restoring #{task.human_name} ... ".color(:blue) + "[DISABLED]".color(:cyan)
logger.info "Restoring #{task.human_name} ... " + "[DISABLED]"
return
end
puts_time "Restoring #{task.human_name} ... ".color(:blue)
logger.info "Restoring #{task.human_name} ... "
warning = task.pre_restore_warning
if warning.present?
puts_time warning.color(:red)
logger.warn warning
Gitlab::TaskHelpers.ask_to_continue
end
task.restore!(backup_path, backup_id)
puts_time "Restoring #{task.human_name} ... ".color(:blue) + "done".color(:green)
logger.info "Restoring #{task.human_name} ... done"
warning = task.post_restore_warning
if warning.present?
puts_time warning.color(:red)
logger.warn warning
Gitlab::TaskHelpers.ask_to_continue
end
rescue Gitlab::TaskAbortedByUserError
puts_time "Quitting...".color(:red)
rescue ::Gitlab::TaskAbortedByUserError
logger.error "Quitting..."
exit 1
end
......@@ -241,7 +244,7 @@ def backup_information
def pack
Dir.chdir(backup_path) do
# create archive
puts_time "Creating backup archive: #{tar_file} ... ".color(:blue)
logger.info "Creating backup archive: #{tar_file} ... "
tar_utils = ::Gitlab::Backup::Cli::Utils::Tar.new
tar_command = tar_utils.pack_cmd(
......@@ -256,9 +259,9 @@ def pack
result = tar_command.run_single_pipeline!(output: archive_file)
if result.status.success?
puts_time "Creating backup archive: #{tar_file} ... ".color(:blue) + 'done'.color(:green)
logger.info "Creating backup archive: #{tar_file} ... done"
else
puts_time "Creating archive #{tar_file} failed".color(:red)
logger.error "Creating archive #{tar_file} failed"
raise Backup::Error, 'Backup failed'
end
end
......@@ -269,30 +272,30 @@ def upload
end
def cleanup
puts_time "Deleting tar staging files ... ".color(:blue)
logger.info "Deleting tar staging files ... "
remove_backup_path(MANIFEST_NAME)
backup_tasks.each_value do |task|
remove_backup_path(task.cleanup_path || task.destination_path)
end
puts_time "Deleting tar staging files ... ".color(:blue) + 'done'.color(:green)
logger.info "Deleting tar staging files ... done"
end
def remove_backup_path(path)
absolute_path = backup_path.join(path)
return unless File.exist?(absolute_path)
puts_time "Cleaning up #{absolute_path}"
logger.info "Cleaning up #{absolute_path}"
FileUtils.rm_rf(absolute_path)
end
def remove_tmp
# delete tmp inside backups
puts_time "Deleting backups/tmp ... ".color(:blue)
logger.info "Deleting backups/tmp ... "
FileUtils.rm_rf(backup_path.join('tmp'))
puts_time "Deleting backups/tmp ... ".color(:blue) + "done".color(:green)
logger.info "Deleting backups/tmp ... " + "done"
end
def remove_old
......@@ -300,11 +303,11 @@ def remove_old
keep_time = Gitlab.config.backup.keep_time.to_i
if keep_time <= 0
puts_time "Deleting old backups ... ".color(:blue) + "[SKIPPED]".color(:cyan)
logger.info "Deleting old backups ... [SKIPPED]"
return
end
puts_time "Deleting old backups ... ".color(:blue)
logger.info "Deleting old backups ... "
removed = 0
Dir.chdir(backup_path) do
......@@ -324,26 +327,26 @@ def remove_old
FileUtils.rm(file)
removed += 1
rescue StandardError => e
puts_time "Deleting #{file} failed: #{e.message}".color(:red)
logger.error "Deleting #{file} failed: #{e.message}"
end
end
end
puts_time "Deleting old backups ... ".color(:blue) + "done. (#{removed} removed)".color(:green)
logger.info "Deleting old backups ... done. (#{removed} removed)"
end
def verify_backup_version
Dir.chdir(backup_path) do
# restoring mismatching backups can lead to unexpected problems
if backup_information[:gitlab_version] != Gitlab::VERSION
progress.puts(<<~HEREDOC.color(:red))
logger.error(<<~HEREDOC)
GitLab version mismatch:
Your current GitLab version (#{Gitlab::VERSION}) differs from the GitLab version in the backup!
Please switch to the following version and try again:
version: #{backup_information[:gitlab_version]}
HEREDOC
progress.puts
progress.puts "Hint: git checkout v#{backup_information[:gitlab_version]}"
logger.error ""
logger.error "Hint: git checkout v#{backup_information[:gitlab_version]}"
exit 1
end
end
......@@ -351,33 +354,33 @@ def verify_backup_version
def puts_available_timestamps
available_timestamps.each do |available_timestamp|
puts_time " " + available_timestamp
logger.info " " + available_timestamp
end
end
def unpack(source_backup_id)
if source_backup_id.blank? && non_tarred_backup?
puts_time "Non tarred backup found in #{backup_path}, using that"
logger.info "Non tarred backup found in #{backup_path}, using that"
return
end
Dir.chdir(backup_path) do
# check for existing backups in the backup dir
if backup_file_list.empty?
puts_time "No backups found in #{backup_path}"
puts_time "Please make sure that file name ends with #{FILE_NAME_SUFFIX}"
logger.error "No backups found in #{backup_path}"
logger.error "Please make sure that file name ends with #{FILE_NAME_SUFFIX}"
exit 1
elsif backup_file_list.many? && source_backup_id.nil?
puts_time 'Found more than one backup:'
logger.warn 'Found more than one backup:'
# print list of available backups
puts_available_timestamps
if options.incremental?
puts_time 'Please specify which one you want to create an incremental backup for:'
puts_time 'rake gitlab:backup:create INCREMENTAL=true PREVIOUS_BACKUP=timestamp_of_backup'
logger.info 'Please specify which one you want to create an incremental backup for:'
logger.info 'rake gitlab:backup:create INCREMENTAL=true PREVIOUS_BACKUP=timestamp_of_backup'
else
puts_time 'Please specify which one you want to restore:'
puts_time 'rake gitlab:backup:restore BACKUP=timestamp_of_backup'
logger.info 'Please specify which one you want to restore:'
logger.info 'rake gitlab:backup:restore BACKUP=timestamp_of_backup'
end
exit 1
......@@ -390,16 +393,16 @@ def unpack(source_backup_id)
end
unless File.exist?(tar_file)
puts_time "The backup file #{tar_file} does not exist!"
logger.error "The backup file #{tar_file} does not exist!"
exit 1
end
puts_time 'Unpacking backup ... '.color(:blue)
logger.info 'Unpacking backup ... '
if Kernel.system(*%W[tar -xf #{tar_file}])
puts_time 'Unpacking backup ... '.color(:blue) + 'done'.color(:green)
logger.info 'Unpacking backup ... ' + 'done'
else
puts_time 'Unpacking backup failed'.color(:red)
logger.error 'Unpacking backup failed'
exit 1
end
end
......@@ -464,11 +467,6 @@ def backup_id
"#{backup_information[:backup_created_at].strftime('%s_%Y_%m_%d_')}#{backup_information[:gitlab_version]}"
end
end
def puts_time(msg)
progress.puts "#{Time.current} -- #{msg}"
Gitlab::BackupLogger.info(message: "#{Rainbow.uncolor(msg)}")
end
end
end
......
......@@ -2,10 +2,10 @@
module Backup
class RemoteStorage
attr_reader :progress, :options, :backup_information
attr_reader :options, :backup_information, :logger
def initialize(progress:, options:)
@progress = progress
def initialize(logger:, options:)
@logger = logger
@options = options
end
......@@ -16,26 +16,24 @@ def upload(backup_information:)
if connection_settings.blank? ||
options.skippable_operations.remote_storage ||
options.skippable_operations.archive
puts_time "Uploading backup archive to remote storage #{remote_directory} ... ".color(:blue) +
"[SKIPPED]".color(:cyan)
logger.info "Uploading backup archive to remote storage #{remote_directory} ... [SKIPPED]"
return
end
puts_time "Uploading backup archive to remote storage #{remote_directory} ... ".color(:blue)
logger.info "Uploading backup archive to remote storage #{remote_directory} ... "
directory = connect_to_remote_directory
upload = directory.files.create(create_attributes)
if upload
if upload.respond_to?(:encryption) && upload.encryption
puts_time "Uploading backup archive to remote storage #{remote_directory} ... ".color(:blue) +
"done (encrypted with #{upload.encryption})".color(:green)
logger.info "Uploading backup archive to remote storage #{remote_directory} ... " \
"done (encrypted with #{upload.encryption})"
else
puts_time "Uploading backup archive to remote storage #{remote_directory} ... ".color(:blue) +
"done".color(:green)
logger.info "Uploading backup archive to remote storage #{remote_directory} ... done"
end
else
puts_time "Uploading backup to #{remote_directory} failed".color(:red)
logger.error "Uploading backup to #{remote_directory} failed"
raise Backup::Error, 'Backup failed'
end
end
......@@ -127,13 +125,6 @@ def object_storage_config
@object_storage_config ||= ObjectStorage::Config.new(Gitlab.config.backup.upload)
end
# TODO: This is a temporary workaround for bad design in Backup::Manager
# Output related code would be moved to a new location
def puts_time(msg)
progress.puts "#{Time.current} -- #{msg}"
Gitlab::BackupLogger.info(message: Rainbow.uncolor(msg))
end
# TODO: This is a temporary workaround for bad design in Backup::Manager
def tar_file
@tar_file ||= "#{backup_id}#{Backup::Manager::FILE_NAME_SUFFIX}"
......
......@@ -7,7 +7,8 @@ module Targets
class Database < Target
extend ::Gitlab::Utils::Override
include Backup::Helper
attr_reader :force, :errors
attr_reader :force, :errors, :logger
IGNORED_ERRORS = [
# Ignore warnings
......@@ -24,6 +25,7 @@ def initialize(progress, options:)
@errors = []
@force = options.force?
@logger = Gitlab::BackupLogger.new(progress)
end
override :dump
......@@ -39,7 +41,7 @@ def dump(destination_dir, _)
dump_file_name = file_name(destination_dir, backup_connection.connection_name)
FileUtils.rm_f(dump_file_name)
progress.print "Dumping PostgreSQL database #{pg_database_name} ... "
logger.info "Dumping PostgreSQL database #{pg_database_name} ... "
schemas = []
......@@ -61,8 +63,7 @@ def dump(destination_dir, _)
raise DatabaseBackupError.new(active_record_config, dump_file_name) unless success
report_success(success)
progress.flush
logger.flush
end
ensure
if multiple_databases?
......@@ -96,12 +97,12 @@ def restore(destination_dir, _)
unless File.exist?(db_file_name)
raise(Backup::Error, "Source database file does not exist #{db_file_name}") if main_database?(database_name)
progress.puts "Source backup for the database #{database_name} doesn't exist. Skipping the task"
logger.info "Source backup for the database #{database_name} doesn't exist. Skipping the task"
return false
end
unless force
progress.puts 'Removing all tables. Press `Ctrl-C` within 5 seconds to abort'.color(:yellow)
logger.info 'Removing all tables. Press `Ctrl-C` within 5 seconds to abort'
sleep(5)
end
......@@ -119,7 +120,7 @@ def restore(destination_dir, _)
status, tracked_errors =
case config[:adapter]
when "postgresql" then
progress.print "Restoring PostgreSQL database #{database} ... "
logger.info "Restoring PostgreSQL database #{database} ... "
execute_and_track_errors(pg_restore_cmd(database), decompress_rd)
end
decompress_rd.close
......@@ -129,9 +130,9 @@ def restore(destination_dir, _)
end
unless tracked_errors.empty?
progress.print "------ BEGIN ERRORS -----\n".color(:yellow)
progress.print tracked_errors.join.color(:yellow)
progress.print "------ END ERRORS -------\n".color(:yellow)
logger.error "------ BEGIN ERRORS -----\n"
logger.error tracked_errors.join
logger.error "------ END ERRORS -------\n"
@errors += tracked_errors
end
......@@ -191,17 +192,13 @@ def execute_and_track_errors(cmd, decompress_rd)
end
def report_success(success)
if success
progress.puts '[DONE]'.color(:green)
else
progress.puts '[FAILED]'.color(:red)
end
success ? logger.info('[DONE]') : logger.error('[FAILED]')
end
private
def drop_tables(database_name)
puts_time 'Cleaning the database ... '.color(:blue)
logger.info 'Cleaning the database ... '
if Rake::Task.task_defined? "gitlab:db:drop_tables:#{database_name}"
Rake::Task["gitlab:db:drop_tables:#{database_name}"].invoke
......@@ -210,7 +207,7 @@ def drop_tables(database_name)
Rake::Task["gitlab:db:drop_tables"].invoke
end
puts_time 'done'.color(:green)
logger.info 'done'
end
# @deprecated This will be removed when restore operation is refactored to use extended_env directly
......
......@@ -20,6 +20,7 @@ def initialize(progress, strategy:, options:, storages: [], paths: [], skip_path
@storages = storages
@paths = paths
@skip_paths = skip_paths
@logger = Gitlab::BackupLogger.new(progress)
end
override :dump
......@@ -49,7 +50,7 @@ def restore(destination_path, backup_id)
private
attr_reader :strategy, :storages, :paths, :skip_paths
attr_reader :strategy, :storages, :paths, :skip_paths, :logger
def remove_all_repositories
return if paths.present?
......@@ -125,10 +126,10 @@ def skipped_path_relation
def restore_object_pools
PoolRepository.includes(:source_project).find_each do |pool|
progress.puts " - Object pool #{pool.disk_path}..."
logger.info " - Object pool #{pool.disk_path}..."
unless pool.source_project
progress.puts " - Object pool #{pool.disk_path}... " + "[SKIPPED]".color(:cyan)
logger.info " - Object pool #{pool.disk_path}... [SKIPPED]"
next
end
......
......@@ -25,15 +25,6 @@ def dump(path, backup_id)
def restore(path, backup_id)
raise NotImplementedError
end
private
attr_reader :progress
def puts_time(msg)
progress.puts "#{Time.zone.now} -- #{msg}"
Gitlab::BackupLogger.info(message: Rainbow.uncolor(msg).to_s)
end
end
end
end
......@@ -4,6 +4,34 @@ module Gitlab
class BackupLogger < Gitlab::JsonLogger
exclude_context!
attr_reader :progress
def initialize(progress)
@progress = progress
end
def warn(message)
progress.puts "#{Time.zone.now} -- #{message}".color(:yellow)
super
end
def info(message)
progress.puts "#{Time.zone.now} -- #{message}".color(:cyan)
super
end
def error(message)
progress.puts "#{Time.zone.now} -- #{message}".color(:red)
super
end
def flush
progress.flush
end
def self.file_name_noext
'backup_json'
end
......
此差异已折叠。
......@@ -9,6 +9,7 @@
let(:one_database_configured?) { base_models_for_backup.one? }
let(:force) { true }
let(:backup_options) { Backup::Options.new(force: force) }
let(:logger) { subject.logger }
let(:timeout_service) do
instance_double(Gitlab::Database::TransactionTimeoutSettings, restore_timeouts: nil, disable_timeouts: nil)
end
......
......@@ -9,6 +9,8 @@
%w[db repo uploads builds artifacts pages lfs terraform_state registry packages ci_secure_files]
end
let(:progress) { StringIO.new }
let(:backup_task_ids) do
%w[db repositories uploads builds artifacts pages lfs terraform_state registry packages ci_secure_files]
end
......@@ -298,6 +300,9 @@ def reenable_backup_sub_tasks
context 'with specific backup tasks' do
before do
stub_env('SKIP', 'db')
allow_next_instance_of(Gitlab::BackupLogger) do |instance|
allow(instance).to receive(:info).and_call_original
end
end
it 'prints a progress message to stdout' do
......@@ -307,27 +312,29 @@ def reenable_backup_sub_tasks
end
it 'logs the progress to log file' do
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping database ... [SKIPPED]")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping repositories ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping repositories ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping uploads ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping uploads ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping builds ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping builds ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping artifacts ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping artifacts ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping pages ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping pages ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping lfs objects ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping lfs objects ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping terraform states ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping terraform states ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping container registry images ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping container registry images ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping packages ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping packages ... done")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping ci secure files ... ")
expect(Gitlab::BackupLogger).to receive(:info).with(message: "Dumping ci secure files ... done")
expect_logger_to_receive_messages([
"Dumping database ... [SKIPPED]",
"Dumping repositories ... ",
"Dumping repositories ... done",
"Dumping uploads ... ",
"Dumping uploads ... done",
"Dumping builds ... ",
"Dumping builds ... done",
"Dumping artifacts ... ",
"Dumping artifacts ... done",
"Dumping pages ... ",
"Dumping pages ... done",
"Dumping lfs objects ... ",
"Dumping lfs objects ... done",
"Dumping terraform states ... ",
"Dumping terraform states ... done",
"Dumping container registry images ... ",
"Dumping container registry images ... done",
"Dumping packages ... ",
"Dumping packages ... done",
"Dumping ci secure files ... ",
"Dumping ci secure files ... done"
])
backup_rake_task_names.each do |task|
run_rake_task("gitlab:backup:#{task}:create")
......@@ -718,5 +725,13 @@ def reenable_backup_sub_tasks
expect(backup_tar).to match(/\d+_\d{4}_\d{2}_\d{2}_\d+\.\d+\.\d+.*_gitlab_backup.tar$/)
end
end
def expect_logger_to_receive_messages(messages)
expect_any_instance_of(Gitlab::BackupLogger) do |logger|
messages.each do |message|
allow(logger).to receive(:info).with(message).ordered
end
end
end
end
# gitlab:app namespace
0% 加载中 .
You are about to add 0 people to the discussion. Proceed with caution.
先完成此消息的编辑!
想要评论请 注册