Skip to content
Snippets Groups Projects
Commit 828d81ee authored by Kamil Trzcińśki's avatar Kamil Trzcińśki Committed by Rémy Coutable
Browse files

Optimise trace handling code to use streaming instead of full read

parent 514dc1a0
No related branches found
No related tags found
No related merge requests found
Showing
with 381 additions and 307 deletions
Loading
Loading
@@ -84,10 +84,10 @@ window.Build = (function() {
var removeRefreshStatuses = ['success', 'failed', 'canceled', 'skipped'];
 
return $.ajax({
url: this.buildUrl,
url: this.pageUrl + "/trace.json",
dataType: 'json',
success: function(buildData) {
$('.js-build-output').html(buildData.trace_html);
$('.js-build-output').html(buildData.html);
gl.utils.setCiStatusFavicon(`${this.pageUrl}/status.json`);
if (window.location.hash === DOWN_BUILD_TRACE) {
$("html,body").scrollTop(this.$buildTrace.height());
Loading
Loading
Loading
Loading
@@ -31,25 +31,25 @@ class Projects::BuildsController < Projects::ApplicationController
@builds = @project.pipelines.find_by_sha(@build.sha).builds.order('id DESC')
@builds = @builds.where("id not in (?)", @build.id)
@pipeline = @build.pipeline
respond_to do |format|
format.html
format.json do
render json: {
id: @build.id,
status: @build.status,
trace_html: @build.trace_html
}
end
end
end
 
def trace
respond_to do |format|
format.json do
state = params[:state].presence
render json: @build.trace_with_state(state: state).
merge!(id: @build.id, status: @build.status)
build.trace.read do |stream|
respond_to do |format|
format.json do
result = {
id: @build.id, status: @build.status, complete: @build.complete?
}
if stream.valid?
stream.limit
state = params[:state].presence
trace = stream.html_with_state(state)
result.merge!(trace.to_h)
end
render json: result
end
end
end
end
Loading
Loading
@@ -86,10 +86,12 @@ class Projects::BuildsController < Projects::ApplicationController
end
 
def raw
if @build.has_trace_file?
send_file @build.trace_file_path, type: 'text/plain; charset=utf-8', disposition: 'inline'
else
render_404
build.trace.read do |stream|
if stream.file?
send_file stream.path, type: 'text/plain; charset=utf-8', disposition: 'inline'
else
render_404
end
end
end
 
Loading
Loading
Loading
Loading
@@ -171,19 +171,6 @@ module Ci
latest_builds.where('stage_idx < ?', stage_idx)
end
 
def trace_html(**args)
trace_with_state(**args)[:html] || ''
end
def trace_with_state(state: nil, last_lines: nil)
trace_ansi = trace(last_lines: last_lines)
if trace_ansi.present?
Ci::Ansi2html.convert(trace_ansi, state)
else
{}
end
end
def timeout
project.build_timeout
end
Loading
Loading
@@ -244,136 +231,35 @@ module Ci
end
 
def update_coverage
coverage = extract_coverage(trace, coverage_regex)
coverage = trace.extract_coverage(coverage_regex)
update_attributes(coverage: coverage) if coverage.present?
end
 
def extract_coverage(text, regex)
return unless regex
matches = text.scan(Regexp.new(regex)).last
matches = matches.last if matches.is_a?(Array)
coverage = matches.gsub(/\d+(\.\d+)?/).first
if coverage.present?
coverage.to_f
end
rescue
# if bad regex or something goes wrong we dont want to interrupt transition
# so we just silentrly ignore error for now
end
def has_trace_file?
File.exist?(path_to_trace) || has_old_trace_file?
def trace
Gitlab::Ci::Trace.new(self)
end
 
def has_trace?
raw_trace.present?
trace.exist?
end
 
def raw_trace(last_lines: nil)
if File.exist?(trace_file_path)
Gitlab::Ci::TraceReader.new(trace_file_path).
read(last_lines: last_lines)
else
# backward compatibility
read_attribute :trace
end
def trace=(data)
raise NotImplementedError
end
 
##
# Deprecated
#
# This is a hotfix for CI build data integrity, see #4246
def has_old_trace_file?
project.ci_id && File.exist?(old_path_to_trace)
end
def trace(last_lines: nil)
hide_secrets(raw_trace(last_lines: last_lines))
def old_trace
read_attribute(:trace)
end
 
def trace_length
if raw_trace
raw_trace.bytesize
else
0
end
end
def trace=(trace)
recreate_trace_dir
trace = hide_secrets(trace)
File.write(path_to_trace, trace)
end
def recreate_trace_dir
unless Dir.exist?(dir_to_trace)
FileUtils.mkdir_p(dir_to_trace)
end
end
private :recreate_trace_dir
def append_trace(trace_part, offset)
recreate_trace_dir
touch if needs_touch?
trace_part = hide_secrets(trace_part)
File.truncate(path_to_trace, offset) if File.exist?(path_to_trace)
File.open(path_to_trace, 'ab') do |f|
f.write(trace_part)
end
def erase_old_trace!
write_attribute(:trace, nil)
save
end
 
def needs_touch?
Time.now - updated_at > 15.minutes.to_i
end
 
def trace_file_path
if has_old_trace_file?
old_path_to_trace
else
path_to_trace
end
end
def dir_to_trace
File.join(
Settings.gitlab_ci.builds_path,
created_at.utc.strftime("%Y_%m"),
project.id.to_s
)
end
def path_to_trace
"#{dir_to_trace}/#{id}.log"
end
##
# Deprecated
#
# This is a hotfix for CI build data integrity, see #4246
# Should be removed in 8.4, after CI files migration has been done.
#
def old_dir_to_trace
File.join(
Settings.gitlab_ci.builds_path,
created_at.utc.strftime("%Y_%m"),
project.ci_id.to_s
)
end
##
# Deprecated
#
# This is a hotfix for CI build data integrity, see #4246
# Should be removed in 8.4, after CI files migration has been done.
#
def old_path_to_trace
"#{old_dir_to_trace}/#{id}.log"
end
##
# Deprecated
#
Loading
Loading
@@ -555,6 +441,15 @@ module Ci
options[:dependencies]&.empty?
end
 
def hide_secrets(trace)
return unless trace
trace = trace.dup
Ci::MaskSecret.mask!(trace, project.runners_token) if project
Ci::MaskSecret.mask!(trace, token)
trace
end
private
 
def update_artifacts_size
Loading
Loading
@@ -566,7 +461,7 @@ module Ci
end
 
def erase_trace!
self.trace = nil
trace.erase!
end
 
def update_erased!(user = nil)
Loading
Loading
@@ -628,15 +523,6 @@ module Ci
pipeline.config_processor.build_attributes(name)
end
 
def hide_secrets(trace)
return unless trace
trace = trace.dup
Ci::MaskSecret.mask!(trace, project.runners_token) if project
Ci::MaskSecret.mask!(trace, token)
trace
end
def update_project_statistics
return unless project
 
Loading
Loading
Loading
Loading
@@ -137,6 +137,6 @@
- if build.has_trace?
%td{ colspan: "2", style: "font-family:'Helvetica Neue',Helvetica,Arial,sans-serif;padding:0 0 15px;" }
%pre{ style: "font-family:Monaco,'Lucida Console','Courier New',Courier,monospace;background-color:#fafafa;border-radius:3px;overflow:hidden;white-space:pre-wrap;word-break:break-all;font-size:13px;line-height:1.4;padding:12px;color:#333333;margin:0;" }
= build.trace_html(last_lines: 10).html_safe
= build.trace.html(last_lines: 10).html_safe
- else
%td{ colspan: "2" }
Loading
Loading
@@ -35,7 +35,7 @@ had <%= failed.size %> failed <%= 'build'.pluralize(failed.size) %>.
Stage: <%= build.stage %>
Name: <%= build.name %>
<% if build.has_trace? -%>
Trace: <%= build.trace_with_state(last_lines: 10)[:text] %>
Trace: <%= build.trace.raw(last_lines: 10) %>
<% end -%>
 
<% end -%>
Loading
Loading
@@ -68,7 +68,7 @@
- elsif @build.runner
\##{@build.runner.id}
.btn-group.btn-group-justified{ role: :group }
- if @build.has_trace_file?
- if @build.has_trace?
= link_to 'Raw', raw_namespace_project_build_path(@project.namespace, @project, @build), class: 'btn btn-sm btn-default'
- if @build.active?
= link_to "Cancel", cancel_namespace_project_build_path(@project.namespace, @project, @build), class: 'btn btn-sm btn-default', method: :post
Loading
Loading
Loading
Loading
@@ -130,7 +130,7 @@ class Gitlab::Seeder::Pipelines
 
def setup_build_log(build)
if %w(running success failed).include?(build.status)
build.trace = FFaker::Lorem.paragraphs(6).join("\n\n")
build.trace.set(FFaker::Lorem.paragraphs(6).join("\n\n"))
end
end
 
Loading
Loading
Loading
Loading
@@ -22,9 +22,9 @@ class Spinach::Features::ProjectBuildsSummary < Spinach::FeatureSteps
end
 
step 'recent build has been erased' do
expect(@build).not_to have_trace
expect(@build.artifacts_file.exists?).to be_falsy
expect(@build.artifacts_metadata.exists?).to be_falsy
expect(@build.trace).to be_empty
end
 
step 'recent build summary does not have artifacts widget' do
Loading
Loading
Loading
Loading
@@ -47,7 +47,7 @@ module SharedBuilds
end
 
step 'recent build has a build trace' do
@build.trace = 'job trace'
@build.trace.set('job trace')
end
 
step 'download of build artifacts archive starts' do
Loading
Loading
Loading
Loading
@@ -118,7 +118,7 @@ module API
content_type 'text/plain'
env['api.format'] = :binary
 
trace = build.trace
trace = build.trace.raw
body trace
end
 
Loading
Loading
Loading
Loading
@@ -115,7 +115,7 @@ module API
put '/:id' do
job = authenticate_job!
 
job.update_attributes(trace: params[:trace]) if params[:trace]
job.trace.set(params[:trace]) if params[:trace]
 
Gitlab::Metrics.add_event(:update_build,
project: job.project.path_with_namespace)
Loading
Loading
@@ -145,16 +145,14 @@ module API
content_range = request.headers['Content-Range']
content_range = content_range.split('-')
 
current_length = job.trace_length
unless current_length == content_range[0].to_i
return error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{current_length}" })
stream_size = job.trace.append(request.body.read, content_range[0].to_i)
if stream_size < 0
return error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{-stream_size}" })
end
 
job.append_trace(request.body.read, content_range[0].to_i)
status 202
header 'Job-Status', job.status
header 'Range', "0-#{job.trace_length}"
header 'Range', "0-#{stream_size}"
end
 
desc 'Authorize artifacts uploading for job' do
Loading
Loading
Loading
Loading
@@ -120,7 +120,7 @@ module API
content_type 'text/plain'
env['api.format'] = :binary
 
trace = build.trace
trace = build.trace.raw
body trace
end
 
Loading
Loading
Loading
Loading
@@ -132,34 +132,54 @@ module Ci
 
STATE_PARAMS = [:offset, :n_open_tags, :fg_color, :bg_color, :style_mask].freeze
 
def convert(raw, new_state)
def convert(stream, new_state)
reset_state
restore_state(raw, new_state) if new_state.present?
start = @offset
ansi = raw[@offset..-1]
restore_state(new_state, stream) if new_state.present?
append = false
truncated = false
cur_offset = stream.tell
if cur_offset > @offset
@offset = cur_offset
truncated = true
else
stream.seek(@offset)
append = @offset > 0
end
start_offset = @offset
 
open_new_tag
 
s = StringScanner.new(ansi)
until s.eos?
if s.scan(/\e([@-_])(.*?)([@-~])/)
handle_sequence(s)
elsif s.scan(/\e(([@-_])(.*?)?)?$/)
break
elsif s.scan(/</)
@out << '&lt;'
elsif s.scan(/\r?\n/)
@out << '<br>'
else
@out << s.scan(/./m)
stream.each_line do |line|
s = StringScanner.new(line)
until s.eos?
if s.scan(/\e([@-_])(.*?)([@-~])/)
handle_sequence(s)
elsif s.scan(/\e(([@-_])(.*?)?)?$/)
break
elsif s.scan(/</)
@out << '&lt;'
elsif s.scan(/\r?\n/)
@out << '<br>'
else
@out << s.scan(/./m)
end
@offset += s.matched_size
end
@offset += s.matched_size
end
 
close_open_tags()
 
{ state: state, html: @out, text: ansi[0, @offset - start], append: start > 0 }
OpenStruct.new(
html: @out,
state: state,
append: append,
truncated: truncated,
offset: start_offset,
size: stream.tell - start_offset,
total: stream.size
)
end
 
def handle_sequence(s)
Loading
Loading
@@ -240,10 +260,10 @@ module Ci
Base64.urlsafe_encode64(state.to_json)
end
 
def restore_state(raw, new_state)
def restore_state(new_state, stream)
state = Base64.urlsafe_decode64(new_state)
state = JSON.parse(state, symbolize_names: true)
return if state[:offset].to_i > raw.length
return if state[:offset].to_i > stream.size
 
STATE_PARAMS.each do |param|
send("#{param}=".to_sym, state[param])
Loading
Loading
Loading
Loading
@@ -61,7 +61,7 @@ module Ci
 
update_runner_info
 
build.update_attributes(trace: params[:trace]) if params[:trace]
build.trace.set(params[:trace]) if params[:trace]
 
Gitlab::Metrics.add_event(:update_build,
project: build.project.path_with_namespace)
Loading
Loading
@@ -92,16 +92,14 @@ module Ci
content_range = request.headers['Content-Range']
content_range = content_range.split('-')
 
current_length = build.trace_length
unless current_length == content_range[0].to_i
return error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{current_length}" })
stream_size = build.trace.append(request.body.read, content_range[0].to_i)
if stream_size < 0
return error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{-stream_size}" })
end
 
build.append_trace(request.body.read, content_range[0].to_i)
status 202
header 'Build-Status', build.status
header 'Range', "0-#{build.trace_length}"
header 'Range', "0-#{stream_size}"
end
 
# Authorize artifacts uploading for build - Runners only
Loading
Loading
module Gitlab
module Ci
class Trace
attr_reader :job
delegate :old_trace, to: :job
def initialize(job)
@job = job
end
def html(last_lines: nil)
read do |stream|
stream.html(last_lines: last_lines)
end
end
def raw(last_lines: nil)
read do |stream|
stream.raw(last_lines: last_lines)
end
end
def extract_coverage(regex)
read do |stream|
stream.extract_coverage(regex)
end
end
def set(data)
write do |stream|
data = job.hide_secrets(data)
stream.set(data)
end
end
def append(data, offset)
write do |stream|
current_length = stream.size
return -current_length unless current_length == offset
data = job.hide_secrets(data)
stream.append(data, offset)
stream.size
end
end
def exist?
current_path.present? || old_trace.present?
end
def read
stream = Gitlab::Ci::Trace::Stream.new do
if current_path
File.open(current_path, "rb")
elsif old_trace
StringIO.new(old_trace)
end
end
yield stream
ensure
stream&.close
end
def write
stream = Gitlab::Ci::Trace::Stream.new do
File.open(ensure_path, "a+b")
end
yield(stream).tap do
job.touch if job.needs_touch?
end
ensure
stream&.close
end
def erase!
paths.each do |trace_path|
FileUtils.rm(trace_path, force: true)
end
job.erase_old_trace!
end
private
def ensure_path
return current_path if current_path
ensure_directory
default_path
end
def ensure_directory
unless Dir.exist?(default_directory)
FileUtils.mkdir_p(default_directory)
end
end
def current_path
@current_path ||= paths.find do |trace_path|
File.exist?(trace_path)
end
end
def paths
[
default_path,
deprecated_path
].compact
end
def default_directory
File.join(
Settings.gitlab_ci.builds_path,
job.created_at.utc.strftime("%Y_%m"),
job.project_id.to_s
)
end
def default_path
File.join(default_directory, "#{job.id}.log")
end
def deprecated_path
File.join(
Settings.gitlab_ci.builds_path,
job.created_at.utc.strftime("%Y_%m"),
job.project.ci_id.to_s,
"#{job.id}.log"
) if job.project&.ci_id
end
end
end
end
module Gitlab
module Ci
class Trace
# This was inspired from: http://stackoverflow.com/a/10219411/1520132
class Stream
BUFFER_SIZE = 4096
LIMIT_SIZE = 50.kilobytes
attr_reader :stream
delegate :close, :tell, :seek, :size, :path, :truncate, to: :stream, allow_nil: true
delegate :valid?, to: :stream, as: :present?, allow_nil: true
def initialize
@stream = yield
end
def valid?
self.stream.present?
end
def file?
self.path.present?
end
def limit(last_bytes = LIMIT_SIZE)
stream_size = size
if stream_size < last_bytes
last_bytes = stream_size
end
stream.seek(-last_bytes, IO::SEEK_END)
end
def append(data, offset)
stream.truncate(offset)
stream.seek(0, IO::SEEK_END)
stream.write(data)
stream.flush()
end
def set(data)
truncate(0)
stream.write(data)
stream.flush()
end
def raw(last_lines: nil)
return unless valid?
if last_lines.to_i > 0
read_last_lines(last_lines)
else
stream.read
end
end
def html_with_state(state = nil)
::Ci::Ansi2html.convert(stream, state)
end
def html(last_lines: nil)
text = raw(last_lines: last_lines)
stream = StringIO.new(text)
::Ci::Ansi2html.convert(stream).html
end
def extract_coverage(regex)
return unless valid?
return unless regex
regex = Regexp.new(regex)
match = ""
stream.each_line do |line|
matches = line.scan(regex)
next unless matches.is_a?(Array)
match = matches.flatten.last
coverage = match.gsub(/\d+(\.\d+)?/).first
return coverage.to_f if coverage.present?
end
rescue
# if bad regex or something goes wrong we dont want to interrupt transition
# so we just silentrly ignore error for now
end
private
def read_last_lines(last_lines)
chunks = []
pos = lines = 0
max = stream.size
# We want an extra line to make sure fist line has full contents
while lines <= last_lines && pos < max
pos += BUFFER_SIZE
buf =
if pos <= max
stream.seek(-pos, IO::SEEK_END)
stream.read(BUFFER_SIZE)
else # Reached the head, read only left
stream.seek(0)
stream.read(BUFFER_SIZE - (pos - max))
end
lines += buf.count("\n")
chunks.unshift(buf)
end
chunks.join.lines.last(last_lines).join
.force_encoding(Encoding.default_external)
end
end
end
end
end
module Gitlab
module Ci
# This was inspired from: http://stackoverflow.com/a/10219411/1520132
class TraceReader
BUFFER_SIZE = 4096
attr_accessor :path, :buffer_size
def initialize(new_path, buffer_size: BUFFER_SIZE)
self.path = new_path
self.buffer_size = Integer(buffer_size)
end
def read(last_lines: nil)
if last_lines
read_last_lines(last_lines)
else
File.read(path)
end
end
def read_last_lines(max_lines)
File.open(path) do |file|
chunks = []
pos = lines = 0
max = file.size
# We want an extra line to make sure fist line has full contents
while lines <= max_lines && pos < max
pos += buffer_size
buf = if pos <= max
file.seek(-pos, IO::SEEK_END)
file.read(buffer_size)
else # Reached the head, read only left
file.seek(0)
file.read(buffer_size - (pos - max))
end
lines += buf.count("\n")
chunks.unshift(buf)
end
chunks.join.lines.last(max_lines).join
.force_encoding(Encoding.default_external)
end
end
end
end
end
Loading
Loading
@@ -111,7 +111,7 @@ FactoryGirl.define do
 
trait :trace do
after(:create) do |build, evaluator|
build.trace = 'BUILD TRACE'
build.trace.set('BUILD TRACE')
end
end
 
Loading
Loading
Loading
Loading
@@ -205,21 +205,13 @@ feature 'Builds', :feature do
it 'loads job trace' do
expect(page).to have_content 'BUILD TRACE'
 
build.append_trace(' and more trace', 11)
build.trace.write do |stream|
stream.append(' and more trace', 11)
end
 
expect(page).to have_content 'BUILD TRACE and more trace'
end
end
context 'when build does not have an initial trace' do
let(:build) { create(:ci_build, pipeline: pipeline) }
it 'loads new trace' do
build.append_trace('build trace', 0)
expect(page).to have_content 'build trace'
end
end
end
 
feature 'Variables' do
Loading
Loading
@@ -390,7 +382,7 @@ feature 'Builds', :feature do
it 'sends the right headers' do
expect(page.status_code).to eq(200)
expect(page.response_headers['Content-Type']).to eq('text/plain; charset=utf-8')
expect(page.response_headers['X-Sendfile']).to eq(build.path_to_trace)
expect(page.response_headers['X-Sendfile']).to eq(build.trace.send(:current_path))
end
end
 
Loading
Loading
@@ -409,43 +401,24 @@ feature 'Builds', :feature do
 
context 'storage form' do
let(:existing_file) { Tempfile.new('existing-trace-file').path }
let(:non_existing_file) do
file = Tempfile.new('non-existing-trace-file')
path = file.path
file.unlink
path
end
 
context 'when build has trace in file' do
before do
Capybara.current_session.driver.header('X-Sendfile-Type', 'X-Sendfile')
build.run!
visit namespace_project_build_path(project.namespace, project, build)
before do
Capybara.current_session.driver.header('X-Sendfile-Type', 'X-Sendfile')
 
allow_any_instance_of(Project).to receive(:ci_id).and_return(nil)
allow_any_instance_of(Ci::Build).to receive(:path_to_trace).and_return(existing_file)
allow_any_instance_of(Ci::Build).to receive(:old_path_to_trace).and_return(non_existing_file)
build.run!
 
page.within('.js-build-sidebar') { click_link 'Raw' }
end
allow_any_instance_of(Gitlab::Ci::Trace).to receive(:paths)
.and_return(paths)
 
it 'sends the right headers' do
expect(page.status_code).to eq(200)
expect(page.response_headers['Content-Type']).to eq('text/plain; charset=utf-8')
expect(page.response_headers['X-Sendfile']).to eq(existing_file)
end
visit namespace_project_build_path(project.namespace, project, build)
end
 
context 'when build has trace in old file' do
before do
Capybara.current_session.driver.header('X-Sendfile-Type', 'X-Sendfile')
build.run!
visit namespace_project_build_path(project.namespace, project, build)
allow_any_instance_of(Project).to receive(:ci_id).and_return(999)
allow_any_instance_of(Ci::Build).to receive(:path_to_trace).and_return(non_existing_file)
allow_any_instance_of(Ci::Build).to receive(:old_path_to_trace).and_return(existing_file)
context 'when build has trace in file' do
let(:paths) do
[existing_file]
end
 
before do
page.within('.js-build-sidebar') { click_link 'Raw' }
end
 
Loading
Loading
@@ -457,20 +430,10 @@ feature 'Builds', :feature do
end
 
context 'when build has trace in DB' do
before do
Capybara.current_session.driver.header('X-Sendfile-Type', 'X-Sendfile')
build.run!
visit namespace_project_build_path(project.namespace, project, build)
allow_any_instance_of(Project).to receive(:ci_id).and_return(nil)
allow_any_instance_of(Ci::Build).to receive(:path_to_trace).and_return(non_existing_file)
allow_any_instance_of(Ci::Build).to receive(:old_path_to_trace).and_return(non_existing_file)
page.within('.js-build-sidebar') { click_link 'Raw' }
end
let(:paths) { [] }
 
it 'sends the right headers' do
expect(page.status_code).to eq(404)
expect(page.status_code).not_to have_link('Raw')
end
end
end
Loading
Loading
Loading
Loading
@@ -72,12 +72,14 @@ describe('Build', () => {
it('displays the initial build trace', () => {
expect($.ajax.calls.count()).toBe(1);
const [{ url, dataType, success, context }] = $.ajax.calls.argsFor(0);
expect(url).toBe(`${BUILD_URL}.json`);
expect(url).toBe(
`${BUILD_URL}/trace.json`,
);
expect(dataType).toBe('json');
expect(success).toEqual(jasmine.any(Function));
spyOn(gl.utils, 'setCiStatusFavicon').and.callFake(() => {});
 
success.call(context, { trace_html: '<span>Example</span>', status: 'running' });
success.call(context, { html: '<span>Example</span>', status: 'running' });
 
expect($('#build-trace .js-build-output').text()).toMatch(/Example/);
});
Loading
Loading
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment