From bb5fd3ca0906bb72b32d0c291f6e1f5a7ddf5373 Mon Sep 17 00:00:00 2001 From: Jason Raitz Date: Fri, 13 Feb 2026 16:39:23 -0500 Subject: [PATCH 1/3] AP-513 improving order of operations - co-authored with @danschmidt5189 - some logs were still not getting request_id logged - we believe there an issue with when the two around_performs were called - this commit should eliminate that problem --- app/jobs/application_job.rb | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-) diff --git a/app/jobs/application_job.rb b/app/jobs/application_job.rb index 76d43bdb..aadce01a 100644 --- a/app/jobs/application_job.rb +++ b/app/jobs/application_job.rb @@ -1,24 +1,27 @@ class ApplicationJob < ActiveJob::Base - attr_reader :request_id - before_enqueue do arguments << { request_id: Current.request_id } if Current.request_id end - around_perform do |job, block| - @request_id = job.arguments.pop[:request_id] if job.arguments.last.is_a?(Hash) && job.arguments.last.key?(:request_id) - block.call - end + before_perform :log_job_metadata - around_perform :log_job_metadata + def request_id + if !defined? @request_id + if arguments.last.is_a?(Hash) && arguments.last.key?(:request_id) + @request_id = arguments.pop[:request_id] + else + @request_id = nil + end + end + @request_id + end def today @today ||= Time.zone.now.strftime('%Y%m%d') end def log_job_metadata - logger.with_fields = { activejob_id: job_id, request_id: @request_id } - yield + logger.with_fields = { activejob_id: job_id, request_id: } end # Log an exception From 5c9b1e551e11913ac8b90f679ecb9e6086f4b940 Mon Sep 17 00:00:00 2001 From: Jason Raitz Date: Tue, 17 Feb 2026 11:05:26 -0500 Subject: [PATCH 2/3] better request_id removal from args - replaces the positional removal with a destructuring and reassignment. --- app/jobs/application_job.rb | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/app/jobs/application_job.rb b/app/jobs/application_job.rb index aadce01a..4b2de030 100644 --- a/app/jobs/application_job.rb +++ b/app/jobs/application_job.rb @@ -1,4 +1,8 @@ class ApplicationJob < ActiveJob::Base + # This is a little unorthodox, but we want the request_id to be available as an instance variable on the job, + # so we add it to the arguments before the job is enqueued and then pull it out in a before_perform callback. + # Admittedly, the request_id method mutates the arguments as a side effect of pulling the request_id out. + before_enqueue do arguments << { request_id: Current.request_id } if Current.request_id end @@ -6,13 +10,9 @@ class ApplicationJob < ActiveJob::Base before_perform :log_job_metadata def request_id - if !defined? @request_id - if arguments.last.is_a?(Hash) && arguments.last.key?(:request_id) - @request_id = arguments.pop[:request_id] - else - @request_id = nil - end - end + r_id_hash, rest = arguments.partition { |arg| arg.is_a?(Hash) && arg.key?(:request_id) } unless defined? @request_id + self.arguments = rest if rest.any? + @request_id = r_id_hash.first[:request_id] if r_id_hash.any? @request_id end From 68e4764a7800ef177f5fea133c9f1241404bf7ee Mon Sep 17 00:00:00 2001 From: Jason Raitz Date: Tue, 17 Feb 2026 16:42:38 -0500 Subject: [PATCH 3/3] serializes request_id when queued --- app/jobs/application_job.rb | 30 ++++++++++++++++++------------ spec/jobs/application_job_spec.rb | 21 ++++++++++----------- 2 files changed, 28 insertions(+), 23 deletions(-) diff --git a/app/jobs/application_job.rb b/app/jobs/application_job.rb index 4b2de030..5fdcdcac 100644 --- a/app/jobs/application_job.rb +++ b/app/jobs/application_job.rb @@ -1,27 +1,33 @@ class ApplicationJob < ActiveJob::Base - # This is a little unorthodox, but we want the request_id to be available as an instance variable on the job, - # so we add it to the arguments before the job is enqueued and then pull it out in a before_perform callback. - # Admittedly, the request_id method mutates the arguments as a side effect of pulling the request_id out. + attr_accessor :request_id - before_enqueue do - arguments << { request_id: Current.request_id } if Current.request_id + before_enqueue do |job| + job.request_id = Current.request_id end - before_perform :log_job_metadata + before_perform :restore_request_id, :log_job_metadata - def request_id - r_id_hash, rest = arguments.partition { |arg| arg.is_a?(Hash) && arg.key?(:request_id) } unless defined? @request_id - self.arguments = rest if rest.any? - @request_id = r_id_hash.first[:request_id] if r_id_hash.any? - @request_id + def serialize + super.merge('request_id' => request_id) + end + + def deserialize(job_data) + super + self.request_id = job_data['request_id'] end def today @today ||= Time.zone.now.strftime('%Y%m%d') end + private + + def restore_request_id + self.request_id ||= Current.request_id + end + def log_job_metadata - logger.with_fields = { activejob_id: job_id, request_id: } + logger.with_fields = { activejob_id: job_id, request_id: request_id } end # Log an exception diff --git a/spec/jobs/application_job_spec.rb b/spec/jobs/application_job_spec.rb index 47f1c5dc..cac2ae8f 100644 --- a/spec/jobs/application_job_spec.rb +++ b/spec/jobs/application_job_spec.rb @@ -22,19 +22,15 @@ def perform(*args); end it 'enqueues the job with the request_id' do expect do TestJob.perform_later('some_arg') - end.to have_enqueued_job(TestJob).with('some_arg', { request_id: request_id }) - end - - it 'sets @request_id and removes it from the arguments' do - job = TestJob.new('some_arg', { request_id: request_id }) - perform_enqueued_jobs { job.perform_now } + end.to have_enqueued_job(TestJob) - expect(job.instance_variable_get(:@request_id)).to eq(request_id) - expect(job.arguments).to eq(['some_arg']) + enqueued_job = ActiveJob::Base.queue_adapter.enqueued_jobs.last + expect(enqueued_job[:args]).to eq(['some_arg']) + expect(enqueued_job['request_id']).to eq(request_id) end it 'logs the activejob_id and request_id' do - job = TestJob.new('some_arg', { request_id: request_id }) + job = TestJob.new('some_arg') allow(job.logger).to receive(:with_fields=) perform_enqueued_jobs { job.perform_now } @@ -50,14 +46,17 @@ def perform(*args); end expect do TestJob.perform_later('some_arg') end.to have_enqueued_job(TestJob).with('some_arg') + + enqueued_job = ActiveJob::Base.queue_adapter.enqueued_jobs.last + expect(enqueued_job['request_id']).to be_nil end - it 'does not set @request_id if not provided' do + it 'does not set request_id if not provided' do job = TestJob.new('some_arg') perform_enqueued_jobs { job.perform_now } - expect(job.instance_variable_get(:@request_id)).to be_nil expect(job.arguments).to eq(['some_arg']) + expect(job.request_id).to be_nil end it 'logs the activejob_id without a request_id' do