Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove internal retries from archiving #144

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .rubocop_todo.yml
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
# This configuration was generated by
# `rubocop --auto-gen-config`
# on 2017-07-12 12:14:56 -0400 using RuboCop version 0.49.1.
# on 2017-07-17 10:48:36 -0400 using RuboCop version 0.49.1.
# The point is for the user to remove these configuration records
# one by one as the offenses are removed from the code base.
# Note that changes in the inspected code, or installation of new
Expand Down
169 changes: 64 additions & 105 deletions lib/travis/logs/services/archive_log.rb
Original file line number Diff line number Diff line change
@@ -1,8 +1,5 @@
# frozen_string_literal: true

require 'uri'

require 'active_support/core_ext/object/try'
require 'active_support/core_ext/numeric/time'
require 'multi_json'

Expand Down Expand Up @@ -41,97 +38,79 @@ def initialize(
end

def run
return unless fetch
mark_as_archiving
return if content_blank?
store
verify
confirm
Travis.logger.debug(
'archived log',
action: 'archive', id: log_id, job_id: job_id, result: 'successful'
)
queue_purge
ensure
mark_as_archiving(false)
end

def log
@log ||= begin
log = database.log_for_id(log_id)
unless log
Travis.logger.warn(
'log not found',
action: 'archive', id: log_id, result: 'not_found'
)
mark('log.not_found')
end
log
if log.nil?
Travis.logger.warn(
'log not found',
action: 'archive', id: log_id, result: 'not_found'
)
mark('log.not_found')
return
end
end
alias fetch log

def mark_as_archiving(archiving = true)
database.update_archiving_status(log_id, archiving)
end

def content_blank?
if content.blank?
Travis.logger.warn(
'content empty',
action: 'archive', id: log_id, result: 'empty'
action: 'archive', id: log_id, job_id: job_id, result: 'empty'
)
mark('log.empty')
true
else
false
return
end
end

def store
retrying(:store) do
measure('store') do
storage_service.store(content, target_url)
end
end
archive
end

def verify
retrying(:verify) do
measure('verify') do
actual = archived_content_length
expected = content.bytesize
unless actual == expected
Travis.logger.error(
'error while verifying',
action: 'archive', id: log_id, result: 'verification-failed',
expected: expected, actual: actual
)
raise VerificationFailed.new(
log_id, target_url, expected, actual
)
end
end
end
end
attr_reader :storage_service, :database
private :storage_service
private :database

private def archive
database.update_archiving_status(log_id, true)

measure('store') { store }
measure('verify') { verify }

def confirm
database.mark_archive_verified(log_id)

queue_purge if purge?

Travis.logger.debug(
'archived log',
action: 'archive', id: log_id, job_id: job_id, result: 'successful'
)
ensure
database.update_archiving_status(log_id, false)
end

def queue_purge
return unless Travis::Logs.config.logs.purge?
delay = Travis::Logs.config.logs.intervals.purge
Travis::Logs::Sidekiq::Purge.perform_at(delay.hours.from_now, log_id)
private def queue_purge
Travis::Logs::Sidekiq::Purge.perform_at(purge_at, log_id)
end

def target_url
private def target_url
"http://#{hostname}/jobs/#{job_id}/log.txt"
end

attr_reader :storage_service, :database
private :storage_service
private :database
private def log
@log ||= database.log_for_id(log_id)
end

private def store
storage_service.store(content, target_url)
end

private def verify
actual = archived_content_length
expected = content.bytesize
return if actual == expected

Travis.logger.error(
'error while verifying',
action: 'archive', id: log_id, result: 'verification-failed',
expected: expected, actual: actual
)
raise VerificationFailed.new(
log_id, target_url, expected, actual
)
end

private def archived_content_length
storage_service.content_length(target_url)
Expand All @@ -148,40 +127,20 @@ def target_url
attr_writer :content
private :content

private def config
Travis::Logs.config.to_h
end

private def hostname
Travis.config.s3.hostname
end

private def retrying(header, times: retry_times)
yield
rescue => e
count ||= 0
count += 1
if times > count
Travis.logger.debug(
'error while archiving',
action: 'archive', retrying: header,
error: MultiJson.dump(e.backtrace), type: e.class.name
)
Travis.logger.warn(
'error while archiving',
action: 'archive', retrying: header,
reason: e.message, id: log_id, job_id: job_id
)
sleep count * 1
retry
else
Travis.logger.error(
'error while archiving',
action: 'archive', retrying: header, exceeded: times,
error: e.backtrace.first, type: e.class.name
)
raise
end
config[:s3][:hostname]
end

private def purge?
config[:logs][:purge]
end

private def retry_times
@retry_times ||= 5
private def purge_at
config[:logs][:intervals][:purge].hours.from_now
end
end
end
Expand Down
94 changes: 84 additions & 10 deletions spec/unit/travis/logs/services/archive_log_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -38,29 +38,60 @@ def debug(*); end
describe Travis::Logs::Services::ArchiveLog do
let(:content) { 'Hello, world!' }
let(:log) { { id: 1, job_id: 2, content: content } }
let(:database) { double('database', update_archiving_status: nil, mark_archive_verified: nil, log_for_id: log) }
let(:storage_service) { FakeStorageService.new }
let(:service) { described_class.new(log[:id], storage_service: storage_service, database: database) }

let(:config) do
{
s3: {
hostname: 'archive-test.travis-ci.org'
},
logs: {
purge: true,
intervals: {
purge: 1
}
}
}
end

let(:database) do
double(
'database',
update_archiving_status: nil,
mark_archive_verified: nil,
log_for_id: log
)
end

subject(:service) do
described_class.new(
log[:id], storage_service: storage_service, database: database
)
end

before do
allow(service).to receive(:retry_times).and_return(0)
allow(Travis::Logs).to receive(:config).and_return(config)
allow(Travis::Logs::Sidekiq::Purge).to receive(:perform_at)
end

it 'pushes the log to S3' do
service.run
subject.run

expect(storage_service.objects["http://archive-test.travis-ci.org/jobs/#{log[:job_id]}/log.txt"]).to eq(log[:content])
key = "http://archive-test.travis-ci.org/jobs/#{log[:job_id]}/log.txt"
expect(storage_service.objects[key]).to eql(log[:content])
end

it 'marks the log as archiving, then unmarks' do
expect(database).to receive(:update_archiving_status).with(log[:id], true).ordered
expect(database).to receive(:update_archiving_status).with(log[:id], false).ordered
expect(database).to receive(:update_archiving_status)
.with(log[:id], true).ordered
expect(database).to receive(:update_archiving_status)
.with(log[:id], false).ordered

service.run
subject.run
end

it 'marks the archive as verified' do
service.run
subject.run

expect(database).to have_received(:mark_archive_verified).with(log[:id])
end
Expand All @@ -69,7 +100,50 @@ def debug(*); end
it 'raises an error' do
storage_service.return_incorrect_content_length!

expect { service.run }.to raise_error(Travis::Logs::Services::ArchiveLog::VerificationFailed)
expect { subject.run }
.to raise_error(Travis::Logs::Services::ArchiveLog::VerificationFailed)
end
end

context 'when the log is not found' do
let(:log) { nil }

subject(:service) do
described_class.new(
8, storage_service: storage_service, database: database
)
end

it 'exits early' do
expect(database).to_not receive(:update_archiving_status)
.with(8, true)
subject.run
end

it 'marks log.not_found' do
expect(subject).to receive(:mark).with('log.not_found')
subject.run
end
end

context 'when the log content is empty' do
let(:log) { { id: 9, job_id: 4, content: '' } }

subject(:service) do
described_class.new(
9, storage_service: storage_service, database: database
)
end

it 'exits early' do
expect(database).to_not receive(:update_archiving_status)
.with(9, true)
subject.run
end

it 'marks log.empty' do
expect(subject).to receive(:mark).with('log.empty')
subject.run
end
end
end