Store trace files outside of a database transaction

Disable carrierwave callbacks and add new callbacks to ensure
file storage of the artifact trace happens after the job
artifact record is saved inside a transaction.

Changelog: changed

app/controllers/projects/jobs_controller.rb

@@ -133,9 +133,9 @@ class Projects::JobsController < Projects::ApplicationController
   end
 
   def raw
-    if trace_artifact_file
+    if @build.trace.archived_trace_exist?
       workhorse_set_content_type!
-      send_upload(trace_artifact_file,
+      send_upload(@build.job_artifacts_trace.file,
                   send_params: raw_send_params,
                   redirect_params: raw_redirect_params)
     else
@@ -219,10 +219,6 @@ class Projects::JobsController < Projects::ApplicationController
     params.permit(job_variables_attributes: %i[key secret_value])
   end
 
-  def trace_artifact_file
-    @trace_artifact_file ||= @build.job_artifacts_trace&.file
-  end
-
   def find_job_as_build
     @build = project.builds.find(params[:id])
   end

app/models/ci/job_artifact.rb

@@ -10,6 +10,7 @@ module Ci
     include Artifactable
     include FileStoreMounter
     include EachBatch
+    include Gitlab::Utils::StrongMemoize
 
     TEST_REPORT_FILE_TYPES = %w[junit].freeze
     COVERAGE_REPORT_FILE_TYPES = %w[cobertura].freeze
@@ -121,6 +122,9 @@ module Ci
 
     mount_file_store_uploader JobArtifactUploader
 
+    skip_callback :save, :after, :store_file!, if: :store_after_commit?
+    after_commit :store_file_after_commit!, on: [:create, :update], if: :store_after_commit?
+
     validates :file_format, presence: true, unless: :trace?, on: :create
     validate :validate_file_format!, unless: :trace?, on: :create
     before_save :set_size, if: :file_changed?
@@ -335,8 +339,23 @@ module Ci
       }
     end
 
+    def store_after_commit?
+      strong_memoize(:store_after_commit) do
+        trace? &&
+          JobArtifactUploader.direct_upload_enabled? &&
+          Feature.enabled?(:ci_store_trace_outside_transaction, project, default_enabled: :yaml)
+      end
+    end
+
     private
 
+    def store_file_after_commit!
+      return unless previous_changes.key?(:file)
+
+      store_file!
+      update_file_store
+    end
+
     def set_size
       self.size = file.size
     end

app/models/concerns/file_store_mounter.rb

@@ -7,15 +7,13 @@ module FileStoreMounter
     def mount_file_store_uploader(uploader)
       mount_uploader(:file, uploader)
 
+      # This hook is a no-op when the file is uploaded after_commit
       after_save :update_file_store, if: :saved_change_to_file?
     end
   end
 
-  private
-
   def update_file_store
-    # The file.object_store is set during `uploader.store!`
-    # which happens after object is inserted/updated
-    self.update_column(:file_store, file.object_store)
+    # The file.object_store is set during `uploader.store!` and `uploader.migrate!`
+    update_column(:file_store, file.object_store)
   end
 end

config/feature_flags/development/ci_store_trace_outside_transaction.yml

+---
+name: ci_store_trace_outside_transaction
+introduced_by_url: https://gitlab.com/gitlab-org/gitlab/-/merge_requests/66203
+rollout_issue_url: https://gitlab.com/gitlab-org/gitlab/-/issues/336280
+milestone: '15.4'
+type: development
+group: group::pipeline execution
+default_enabled: false

lib/gitlab/ci/trace.rb

@@ -78,7 +78,7 @@ module Gitlab
       end
 
       def archived_trace_exist?
-        trace_artifact&.exists?
+        archived?
       end
 
       def live_trace_exist?
@@ -156,7 +156,7 @@ module Gitlab
 
       def read_stream
         stream = Gitlab::Ci::Trace::Stream.new do
-          if trace_artifact
+          if archived?
             trace_artifact.open
           elsif job.trace_chunks.any?
             Gitlab::Ci::Trace::ChunkedIO.new(job)
@@ -174,7 +174,7 @@ module Gitlab
 
       def unsafe_write!(mode, &blk)
         stream = Gitlab::Ci::Trace::Stream.new do
-          if trace_artifact
+          if archived?
             raise AlreadyArchivedError, 'Could not write to the archived trace'
           elsif current_path
             File.open(current_path, mode)
@@ -195,7 +195,7 @@ module Gitlab
       def unsafe_archive!
         raise ArchiveError, 'Job is not finished yet' unless job.complete?
 
-        already_archived?.tap do |archived|
+        archived?.tap do |archived|
           destroy_any_orphan_trace_data!
           raise AlreadyArchivedError, 'Could not archive again' if archived
         end
@@ -218,7 +218,7 @@ module Gitlab
         end
       end
 
-      def already_archived?
+      def archived?
         # TODO check checksum to ensure archive completed successfully
         # See https://gitlab.com/gitlab-org/gitlab/-/issues/259619
         trace_artifact&.archived_trace_exists?
@@ -227,11 +227,12 @@ module Gitlab
       def destroy_any_orphan_trace_data!
         return unless trace_artifact
 
-        if already_archived?
-          # An archive already exists, so make sure to remove the trace chunks
+        if archived?
+          # An archive file exists, so remove the trace chunks
           erase_trace_chunks!
         else
-          # An archive already exists, but its associated file does not, so remove it
+          # A trace artifact record exists with no archive file
+          # but an archive was attempted, so cleanup the associated record
           trace_artifact.destroy!
         end
       end

spec/controllers/projects/jobs_controller_spec.rb

@@ -463,12 +463,25 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
         end
       end
 
-      context 'when job has trace' do
+      context 'when job has live trace' do
         let(:job) { create(:ci_build, :running, :trace_live, pipeline: pipeline) }
 
-        it "has_trace is true" do
+        it 'has_trace is true' do
           get_show_json
 
+          expect(response).to have_gitlab_http_status(:ok)
+          expect(response).to match_response_schema('job/job_details')
+          expect(json_response['has_trace']).to be true
+        end
+      end
+
+      context 'when has live trace and unarchived artifact' do
+        let(:job) { create(:ci_build, :running, :trace_live, :unarchived_trace_artifact, pipeline: pipeline) }
+
+        it 'has_trace is true' do
+          get_show_json
+
+          expect(response).to have_gitlab_http_status(:ok)
           expect(response).to match_response_schema('job/job_details')
           expect(json_response['has_trace']).to be true
         end
@@ -631,15 +644,25 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
       end
     end
 
-    context 'when job has a trace' do
+    context 'when job has a live trace' do
       let(:job) { create(:ci_build, :trace_live, pipeline: pipeline) }
 
+      shared_examples_for 'returns trace' do
         it 'returns a trace' do
           expect(response).to have_gitlab_http_status(:ok)
           expect(response).to match_response_schema('job/build_trace')
           expect(json_response['id']).to eq job.id
           expect(json_response['status']).to eq job.status
-        expect(json_response['lines']).to eq [{ 'content' => [{ 'text' => 'BUILD TRACE' }], 'offset' => 0 }]
+          expect(json_response['lines']).to match_array [{ 'content' => [{ 'text' => 'BUILD TRACE' }], 'offset' => 0 }]
+        end
+      end
+
+      it_behaves_like 'returns trace'
+
+      context 'when job has unarchived artifact' do
+        let(:job) { create(:ci_build, :trace_live, :unarchived_trace_artifact, pipeline: pipeline) }
+
+        it_behaves_like 'returns trace'
       end
 
       context 'when job is running' do
@@ -1055,9 +1078,7 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
       post_erase
     end
 
-    context 'when job is erasable' do
-      let(:job) { create(:ci_build, :erasable, :trace_artifact, pipeline: pipeline) }
-
+    shared_examples_for 'erases' do
       it 'redirects to the erased job page' do
         expect(response).to have_gitlab_http_status(:found)
         expect(response).to redirect_to(namespace_project_job_path(id: job.id))
@@ -1073,7 +1094,19 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
       end
     end
 
-    context 'when job is not erasable' do
+    context 'when job is successful and has artifacts' do
+      let(:job) { create(:ci_build, :erasable, :trace_artifact, pipeline: pipeline) }
+
+      it_behaves_like 'erases'
+    end
+
+    context 'when job has live trace and unarchived artifact' do
+      let(:job) { create(:ci_build, :success, :trace_live, :unarchived_trace_artifact, pipeline: pipeline) }
+
+      it_behaves_like 'erases'
+    end
+
+    context 'when job is erased' do
       let(:job) { create(:ci_build, :erased, pipeline: pipeline) }
 
       it 'returns unprocessable_entity' do
@@ -1165,9 +1198,10 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
       end
     end
 
-    context "when job has a trace file" do
+    context 'when job has a live trace' do
       let(:job) { create(:ci_build, :trace_live, pipeline: pipeline) }
 
+      shared_examples_for 'sends live trace' do
         it 'sends a trace file' do
           response = subject
 
@@ -1178,6 +1212,15 @@ RSpec.describe Projects::JobsController, :clean_gitlab_redis_shared_state do
         end
       end
 
+      it_behaves_like 'sends live trace'
+
+      context 'and when job has unarchived artifact' do
+        let(:job) { create(:ci_build, :trace_live, :unarchived_trace_artifact, pipeline: pipeline) }
+
+        it_behaves_like 'sends live trace'
+      end
+    end
+
     context "when job has a trace in database" do
       let(:job) { create(:ci_build, pipeline: pipeline) }
 

spec/factories/ci/builds.rb

@@ -282,6 +282,12 @@ FactoryBot.define do
       end
     end
 
+    trait :unarchived_trace_artifact do
+      after(:create) do |build, evaluator|
+        create(:ci_job_artifact, :unarchived_trace_artifact, job: build)
+      end
+    end
+
     trait :trace_with_duplicate_sections do
       after(:create) do |build, evaluator|
         trace = File.binread(

spec/factories/ci/job_artifacts.rb

@@ -87,6 +87,17 @@ FactoryBot.define do
       end
     end
 
+    trait :unarchived_trace_artifact do
+      file_type { :trace }
+      file_format { :raw }
+
+      after(:build) do |artifact, evaluator|
+        file = double('file', path: '/path/to/job.log')
+        artifact.file = file
+        allow(artifact.file).to receive(:file).and_return(CarrierWave::SanitizedFile.new(file))
+      end
+    end
+
     trait :junit do
       file_type { :junit }
       file_format { :gzip }

spec/features/projects/jobs/user_browses_job_spec.rb

@@ -36,8 +36,18 @@ RSpec.describe 'User browses a job', :js do
     expect(page).to have_content('Job has been erased')
   end
 
-  context 'with a failed job' do
-    let!(:build) { create(:ci_build, :failed, :trace_artifact, pipeline: pipeline) }
+  context 'with unarchived trace artifact' do
+    let!(:build) { create(:ci_build, :success, :unarchived_trace_artifact, :coverage, pipeline: pipeline) }
+
+    it 'shows no trace message', :js do
+      wait_for_requests
+
+      expect(page).to have_content('This job does not have a trace.')
+    end
+  end
+
+  context 'with a failed job and live trace' do
+    let!(:build) { create(:ci_build, :failed, :trace_live, pipeline: pipeline) }
 
     it 'displays the failure reason' do
       wait_for_all_requests
@@ -46,6 +56,18 @@ RSpec.describe 'User browses a job', :js do
           ".build-job > a[title='test - failed - (unknown failure)']")
       end
     end
+
+    context 'with unarchived trace artifact' do
+      let!(:artifact) { create(:ci_job_artifact, :unarchived_trace_artifact, job: build) }
+
+      it 'displays the failure reason from the live trace' do
+        wait_for_all_requests
+        within('.builds-container') do
+          expect(page).to have_selector(
+            ".build-job > a[title='test - failed - (unknown failure)']")
+        end
+      end
+    end
   end
 
   context 'when a failed job has been retried' do

spec/lib/gitlab/ci/trace/archive_spec.rb

@@ -3,6 +3,7 @@
 require 'spec_helper'
 
 RSpec.describe Gitlab::Ci::Trace::Archive do
+  context 'with transactional fixtures' do
     let_it_be(:job) { create(:ci_build, :success, :trace_live) }
     let_it_be_with_reload(:trace_metadata) { create(:ci_build_trace_metadata, build: job) }
     let_it_be(:src_checksum) do
@@ -35,7 +36,6 @@ RSpec.describe Gitlab::Ci::Trace::Archive do
 
           it 'skips validation' do
             subject.execute!(stream)
-
             expect(trace_metadata.checksum).to eq(src_checksum)
             expect(trace_metadata.remote_checksum).to be_nil
             expect(metrics)
@@ -98,4 +98,39 @@ RSpec.describe Gitlab::Ci::Trace::Archive do
         end
       end
     end
+  end
+
+  context 'without transactional fixtures', :delete do
+    let(:job) { create(:ci_build, :success, :trace_live) }
+    let(:trace_metadata) { create(:ci_build_trace_metadata, build: job) }
+    let(:stream) { StringIO.new('abc', 'rb') }
+
+    describe '#execute!' do
+      subject(:execute) do
+        ::Gitlab::Ci::Trace::Archive.new(job, trace_metadata).execute!(stream)
+      end
+
+      before do
+        stub_artifacts_object_storage(direct_upload: true)
+      end
+
+      it 'does not upload the trace inside a database transaction', :delete do
+        expect(Ci::ApplicationRecord.connection.transaction_open?).to be_falsey
+
+        allow_next_instance_of(Ci::JobArtifact) do |artifact|
+          artifact.job_id = job.id
+
+          expect(artifact)
+            .to receive(:store_file!)
+            .and_wrap_original do |store_method, *args|
+            expect(Ci::ApplicationRecord.connection.transaction_open?).to be_falsey
+
+            store_method.call(*args)
+          end
+        end
+
+        execute
+      end
+    end
+  end
 end

spec/lib/gitlab/ci/trace_spec.rb

@@ -25,16 +25,6 @@ RSpec.describe Gitlab::Ci::Trace, :clean_gitlab_redis_shared_state, factory_defa
       artifact1.file.migrate!(ObjectStorage::Store::REMOTE)
     end
 
-    it 'reloads the trace after is it migrated' do
-      stub_const('Gitlab::HttpIO::BUFFER_SIZE', test_data.length)
-
-      expect_next_instance_of(Gitlab::HttpIO) do |http_io|
-        expect(http_io).to receive(:get_chunk).and_return(test_data, "")
-      end
-
-      expect(artifact2.job.trace.raw).to eq(test_data)
-    end
-
     it 'reloads the trace in case of a chunk error' do
       chunk_error = described_class::ChunkedIO::FailedToGetChunkError
 

spec/models/ci/job_artifact_spec.rb

@@ -351,6 +351,21 @@ RSpec.describe Ci::JobArtifact do
     end
   end
 
+  context 'when updating any field except the file' do
+    let(:artifact) { create(:ci_job_artifact, :unarchived_trace_artifact, file_store: 2) }
+
+    before do
+      stub_artifacts_object_storage(direct_upload: true)
+      artifact.file.object_store = 1
+    end
+
+    it 'the `after_commit` hook does not update `file_store`' do
+      artifact.update!(expire_at: Time.current)
+
+      expect(artifact.file_store).to be(2)
+    end
+  end
+
   describe 'validates file format' do
     subject { artifact }
 
@@ -507,6 +522,53 @@ RSpec.describe Ci::JobArtifact do
     end
   end
 
+  describe '#store_after_commit?' do
+    let(:file_type) { :archive }
+    let(:artifact) { build(:ci_job_artifact, file_type) }
+
+    context 'when direct upload is enabled' do
+      before do
+        stub_artifacts_object_storage(direct_upload: true)
+      end
+
+      context 'when the artifact is a trace' do
+        let(:file_type) { :trace }
+
+        context 'when ci_store_trace_outside_transaction is enabled' do
+          it 'returns true' do
+            expect(artifact.store_after_commit?).to be_truthy
+          end
+        end
+
+        context 'when ci_store_trace_outside_transaction is disabled' do
+          before do
+            stub_feature_flags(ci_store_trace_outside_transaction: false)
+          end
+
+          it 'returns false' do
+            expect(artifact.store_after_commit?).to be_falsey
+          end
+        end
+      end
+
+      context 'when the artifact is not a trace' do
+        it 'returns false' do
+          expect(artifact.store_after_commit?).to be_falsey
+        end
+      end
+    end
+
+    context 'when direct upload is disabled' do
+      before do
+        stub_artifacts_object_storage(direct_upload: false)
+      end
+
+      it 'returns false' do
+        expect(artifact.store_after_commit?).to be_falsey
+      end
+    end
+  end
+
   describe 'file is being stored' do
     subject { create(:ci_job_artifact, :archive) }
 

spec/requests/api/ci/jobs_spec.rb

@@ -308,6 +308,7 @@ RSpec.describe API::Ci::Jobs do
         it 'returns no artifacts nor trace data' do
           json_job = json_response.first
 
+          expect(response).to have_gitlab_http_status(:ok)
           expect(json_job['artifacts_file']).to be_nil
           expect(json_job['artifacts']).to be_an Array
           expect(json_job['artifacts']).to be_empty
@@ -426,6 +427,22 @@ RSpec.describe API::Ci::Jobs do
         expect(response).to have_gitlab_http_status(:unauthorized)
       end
     end
+
+    context 'when trace artifact record exists with no stored file', :skip_before_request do
+      before do
+        create(:ci_job_artifact, :unarchived_trace_artifact, job: job, project: job.project)
+      end
+
+      it 'returns no artifacts nor trace data' do
+        get api("/projects/#{project.id}/jobs/#{job.id}", api_user)
+
+        expect(response).to have_gitlab_http_status(:ok)
+        expect(json_response['artifacts']).to be_an Array
+        expect(json_response['artifacts'].size).to eq(1)
+        expect(json_response['artifacts'][0]['file_type']).to eq('trace')
+        expect(json_response['artifacts'][0]['filename']).to eq('job.log')
+      end
+    end
   end
 
   describe 'DELETE /projects/:id/jobs/:job_id/artifacts' do
@@ -1024,7 +1041,16 @@ RSpec.describe API::Ci::Jobs do
         end
       end
 
-      context 'when trace is file' do
+      context 'when live trace and uploadless trace artifact' do
+        let(:job) { create(:ci_build, :trace_live, :unarchived_trace_artifact, pipeline: pipeline) }
+
+        it 'returns specific job trace' do
+          expect(response).to have_gitlab_http_status(:ok)
+          expect(response.body).to eq(job.trace.raw)
+        end
+      end
+
+      context 'when trace is live' do
         let(:job) { create(:ci_build, :trace_live, pipeline: pipeline) }
 
         it 'returns specific job trace' do
@@ -1032,6 +1058,28 @@ RSpec.describe API::Ci::Jobs do
           expect(response.body).to eq(job.trace.raw)
         end
       end
+
+      context 'when no trace' do
+        let(:job) { create(:ci_build, pipeline: pipeline) }
+
+        it 'returns empty trace' do
+          expect(response).to have_gitlab_http_status(:ok)
+          expect(response.body).to be_empty
+        end
+      end
+
+      context 'when trace artifact record exists with no stored file' do
+        let(:job) { create(:ci_build, pipeline: pipeline) }
+
+        before do
+          create(:ci_job_artifact, :unarchived_trace_artifact, job: job, project: job.project)
+        end
+
+        it 'returns empty trace' do
+          expect(response).to have_gitlab_http_status(:ok)
+          expect(response.body).to be_empty
+        end
+      end
     end
 
     context 'unauthorized user' do
@@ -1143,9 +1191,7 @@ RSpec.describe API::Ci::Jobs do
       post api("/projects/#{project.id}/jobs/#{job.id}/erase", user)
     end
 
-    context 'job is erasable' do
-      let(:job) { create(:ci_build, :trace_artifact, :artifacts, :test_reports, :success, project: project, pipeline: pipeline) }
-
+    shared_examples_for 'erases job' do
       it 'erases job content' do
         expect(response).to have_gitlab_http_status(:created)
         expect(job.job_artifacts.count).to eq(0)
@@ -1154,6 +1200,12 @@ RSpec.describe API::Ci::Jobs do
         expect(job.artifacts_metadata.present?).to be_falsy
         expect(job.has_job_artifacts?).to be_falsy
       end
+    end
+
+    context 'job is erasable' do
+      let(:job) { create(:ci_build, :trace_artifact, :artifacts, :test_reports, :success, project: project, pipeline: pipeline) }
+
+      it_behaves_like 'erases job'
 
       it 'updates job' do
         job.reload
@@ -1163,6 +1215,12 @@ RSpec.describe API::Ci::Jobs do
       end
     end
 
+    context 'when job has an unarchived trace artifact' do
+      let(:job) { create(:ci_build, :success, :trace_live, :unarchived_trace_artifact, project: project, pipeline: pipeline) }
+
+      it_behaves_like 'erases job'
+    end
+
     context 'job is not erasable' do
       let(:job) { create(:ci_build, :trace_live, project: project, pipeline: pipeline) }
 

spec/support/matchers/access_matchers.rb

@@ -52,7 +52,7 @@ module AccessMatchers
       emulate_user(user, @membership)
       visit(url)
 
-      status_code == 200 && !current_path.in?([new_user_session_path, new_admin_session_path])
+      [200, 204].include?(status_code) && !current_path.in?([new_user_session_path, new_admin_session_path])
     end
 
     chain :of do |membership|

spec/support/shared_examples/lib/gitlab/ci/ci_trace_shared_examples.rb

@@ -808,7 +808,19 @@ RSpec.shared_examples 'trace with enabled live trace feature' do
         create(:ci_job_artifact, :trace, job: build)
       end
 
-      it { is_expected.to be_truthy }
+      it 'is truthy' do
+        is_expected.to be_truthy
+      end
+    end
+
+    context 'when archived trace record exists but file is not stored' do
+      before do
+        create(:ci_job_artifact, :unarchived_trace_artifact, job: build)
+      end
+
+      it 'is falsy' do
+        is_expected.to be_falsy
+      end
     end
 
     context 'when live trace exists' do
@@ -872,13 +884,35 @@ RSpec.shared_examples 'trace with enabled live trace feature' do
 
         build.reload
         expect(build.trace.exist?).to be_truthy
-        expect(build.job_artifacts_trace).to be_nil
         Gitlab::Ci::Trace::ChunkedIO.new(build) do |stream|
           expect(stream.read).to eq(trace_raw)
         end
       end
     end
 
+    shared_examples 'a pre-commit error' do |error:|
+      it_behaves_like 'source trace in ChunkedIO stays intact', error: error
+
+      it 'does not save the trace artifact' do
+        expect { subject }.to raise_error(error)
+
+        build.reload
+        expect(build.job_artifacts_trace).to be_nil
+      end
+    end
+
+    shared_examples 'a post-commit error' do |error:|
+      it_behaves_like 'source trace in ChunkedIO stays intact', error: error
+
+      it 'saves the trace artifact but not the file' do
+        expect { subject }.to raise_error(error)
+
+        build.reload
+        expect(build.job_artifacts_trace).to be_present
+        expect(build.job_artifacts_trace.file.exists?).to be_falsy
+      end
+    end
+
     context 'when job does not have trace artifact' do
       context 'when trace is stored in ChunkedIO' do
         let!(:build) { create(:ci_build, :success, :trace_live) }
@@ -892,7 +926,7 @@ RSpec.shared_examples 'trace with enabled live trace feature' do
             allow(IO).to receive(:copy_stream).and_return(0)
           end
 
-          it_behaves_like 'source trace in ChunkedIO stays intact', error: Gitlab::Ci::Trace::ArchiveError
+          it_behaves_like 'a pre-commit error', error: Gitlab::Ci::Trace::ArchiveError
         end
 
         context 'when failed to create job artifact record' do
@@ -902,7 +936,16 @@ RSpec.shared_examples 'trace with enabled live trace feature' do
               .and_return(%w[Error Error])
           end
 
-          it_behaves_like 'source trace in ChunkedIO stays intact', error: ActiveRecord::RecordInvalid
+          it_behaves_like 'a pre-commit error', error: ActiveRecord::RecordInvalid
+        end
+
+        context 'when storing the file raises an error' do
+          before do
+            stub_artifacts_object_storage(direct_upload: true)
+            allow_any_instance_of(Ci::JobArtifact).to receive(:store_file!).and_raise(Excon::Error::BadGateway, 'S3 is down lol')
+          end
+
+          it_behaves_like 'a post-commit error', error: Excon::Error::BadGateway
         end
       end
     end