Merge branch 'feature/gb/trace-range-error-logging' into 'master'

Log trace range errors with additional metadata

See merge request gitlab-org/gitlab!46256

app/services/ci/append_build_trace_service.rb

+# frozen_string_literal: true
+
+module Ci
+  class AppendBuildTraceService
+    Result = Struct.new(:status, :stream_size, keyword_init: true)
+    TraceRangeError = Class.new(StandardError)
+
+    attr_reader :build, :params
+
+    def initialize(build, params)
+      @build = build
+      @params = params
+    end
+
+    def execute(body_data)
+      # TODO:
+      # it seems that `Content-Range` as formatted by runner is wrong,
+      # the `byte_end` should point to final byte, but it points byte+1
+      # that means that we have to calculate end of body,
+      # as we cannot use `content_length[1]`
+      # Issue: https://gitlab.com/gitlab-org/gitlab-runner/issues/3275
+
+      content_range = stream_range.split('-')
+      body_start = content_range[0].to_i
+      body_end = body_start + body_data.bytesize
+
+      stream_size = build.trace.append(body_data, body_start)
+
+      unless stream_size == body_end
+        log_range_error(stream_size, body_end)
+
+        return Result.new(status: 416, stream_size: stream_size)
+      end
+
+      Result.new(status: 202, stream_size: stream_size)
+    end
+
+    private
+
+    def stream_range
+      params.fetch(:content_range)
+    end
+
+    def log_range_error(stream_size, body_end)
+      extra = {
+        build_id: build.id,
+        body_end: body_end,
+        stream_size: stream_size,
+        stream_class: stream_size.class,
+        stream_range: stream_range
+      }
+
+      build.trace_chunks.last.try do |chunk|
+        extra.merge!(
+          chunk_index: chunk.chunk_index,
+          chunk_store: chunk.data_store,
+          chunks_count: build.trace_chunks.count
+        )
+      end
+
+      ::Gitlab::ErrorTracking
+        .log_exception(TraceRangeError.new, extra)
+    end
+  end
+end

lib/api/ci/runner.rb

@@ -207,27 +207,18 @@ module API
 
           error!('400 Missing header Content-Range', 400) unless request.headers.key?('Content-Range')
           content_range = request.headers['Content-Range']
-          content_range = content_range.split('-')
-
-          # TODO:
-          # it seems that `Content-Range` as formatted by runner is wrong,
-          # the `byte_end` should point to final byte, but it points byte+1
-          # that means that we have to calculate end of body,
-          # as we cannot use `content_length[1]`
-          # Issue: https://gitlab.com/gitlab-org/gitlab-runner/issues/3275
-
-          body_data = request.body.read
-          body_start = content_range[0].to_i
-          body_end = body_start + body_data.bytesize
-
-          stream_size = job.trace.append(body_data, body_start)
-          unless stream_size == body_end
-            break error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{stream_size}" })
+
+          result = ::Ci::AppendBuildTraceService
+            .new(job, content_range: content_range)
+            .execute(request.body.read)
+
+          if result.status == 416
+            break error!('416 Range Not Satisfiable', 416, { 'Range' => "0-#{result.stream_size}" })
           end
 
-          status 202
+          status result.status
           header 'Job-Status', job.status
-          header 'Range', "0-#{stream_size}"
+          header 'Range', "0-#{result.stream_size}"
           header 'X-GitLab-Trace-Update-Interval', job.trace.update_interval.to_s
         end
 

spec/services/ci/append_build_trace_service_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe Ci::AppendBuildTraceService do
+  let(:project) { create(:project) }
+  let(:pipeline) { create(:ci_pipeline, project: project) }
+  let(:build) { create(:ci_build, :running, pipeline: pipeline) }
+
+  before do
+    stub_feature_flags(ci_enable_live_trace: true)
+  end
+
+  context 'build trace append is successful' do
+    it 'returns a correct stream size and status code' do
+      stream_size = 192.kilobytes
+      body_data = 'x' * stream_size
+      content_range = "0-#{stream_size}"
+
+      result = described_class
+        .new(build, content_range: content_range)
+        .execute(body_data)
+
+      expect(result.status).to eq 202
+      expect(result.stream_size).to eq stream_size
+      expect(build.trace_chunks.count).to eq 2
+    end
+  end
+
+  context 'when could not correctly append to a trace' do
+    it 'responds with content range violation and data stored' do
+      allow(build).to receive_message_chain(:trace, :append) { 16 }
+
+      result = described_class
+        .new(build, content_range: '0-128')
+        .execute('x' * 128)
+
+      expect(result.status).to eq 416
+      expect(result.stream_size).to eq 16
+    end
+
+    it 'logs exception if build has live trace' do
+      build.trace.append('abcd', 0)
+
+      expect(::Gitlab::ErrorTracking)
+        .to receive(:log_exception)
+        .with(anything, hash_including(chunk_index: 0, chunk_store: 'redis'))
+
+      result = described_class
+        .new(build, content_range: '0-128')
+        .execute('x' * 128)
+
+      expect(result.status).to eq 416
+      expect(result.stream_size).to eq 4
+    end
+  end
+end