From 85c62a2c3ddff57b77725b811ddfbd965e30eecd Mon Sep 17 00:00:00 2001 From: Bolek Kurowski Date: Wed, 22 Feb 2017 16:09:17 -0500 Subject: [PATCH] Include JobID in all ActiveJob info logs Currently we provide the Job ID in logs only related to enqueuing a job. This adds the job id to the remaining ActiveJob logs when: - a job started performing - a job ended performing Providing the job id in those logs will ease searching logs by job id. --- activejob/lib/active_job/logging.rb | 4 ++-- activejob/test/cases/logging_test.rb | 12 ++++++------ 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/activejob/lib/active_job/logging.rb b/activejob/lib/active_job/logging.rb index aa97ab2e22..d7e2cd03e3 100644 --- a/activejob/lib/active_job/logging.rb +++ b/activejob/lib/active_job/logging.rb @@ -69,14 +69,14 @@ module ActiveJob def perform_start(event) info do job = event.payload[:job] - "Performing #{job.class.name} from #{queue_name(event)}" + args_info(job) + "Performing #{job.class.name} (Job ID: #{job.job_id}) from #{queue_name(event)}" + args_info(job) end end def perform(event) info do job = event.payload[:job] - "Performed #{job.class.name} from #{queue_name(event)} in #{event.duration.round(2)}ms" + "Performed #{job.class.name} (Job ID: #{job.job_id}) from #{queue_name(event)} in #{event.duration.round(2)}ms" end end diff --git a/activejob/test/cases/logging_test.rb b/activejob/test/cases/logging_test.rb index 954974b2a5..b37736f859 100644 --- a/activejob/test/cases/logging_test.rb +++ b/activejob/test/cases/logging_test.rb @@ -89,21 +89,21 @@ class LoggingTest < ActiveSupport::TestCase def test_perform_job_logging LoggingJob.perform_later "Dummy" - assert_match(/Performing LoggingJob from .*? with arguments:.*Dummy/, @logger.messages) + assert_match(/Performing LoggingJob \(Job ID: .*?\) from .*? with arguments:.*Dummy/, @logger.messages) assert_match(/Dummy, here is it: Dummy/, @logger.messages) - assert_match(/Performed LoggingJob from .*? in .*ms/, @logger.messages) + assert_match(/Performed LoggingJob \(Job ID: .*?\) from .*? in .*ms/, @logger.messages) end def test_perform_nested_jobs_logging NestedJob.perform_later assert_match(/\[LoggingJob\] \[.*?\]/, @logger.messages) assert_match(/\[ActiveJob\] Enqueued NestedJob \(Job ID: .*\) to/, @logger.messages) - assert_match(/\[ActiveJob\] \[NestedJob\] \[NESTED-JOB-ID\] Performing NestedJob from/, @logger.messages) + assert_match(/\[ActiveJob\] \[NestedJob\] \[NESTED-JOB-ID\] Performing NestedJob \(Job ID: .*?\) from/, @logger.messages) assert_match(/\[ActiveJob\] \[NestedJob\] \[NESTED-JOB-ID\] Enqueued LoggingJob \(Job ID: .*?\) to .* with arguments: "NestedJob"/, @logger.messages) - assert_match(/\[ActiveJob\].*\[LoggingJob\] \[LOGGING-JOB-ID\] Performing LoggingJob from .* with arguments: "NestedJob"/, @logger.messages) + assert_match(/\[ActiveJob\].*\[LoggingJob\] \[LOGGING-JOB-ID\] Performing LoggingJob \(Job ID: .*?\) from .* with arguments: "NestedJob"/, @logger.messages) assert_match(/\[ActiveJob\].*\[LoggingJob\] \[LOGGING-JOB-ID\] Dummy, here is it: NestedJob/, @logger.messages) - assert_match(/\[ActiveJob\].*\[LoggingJob\] \[LOGGING-JOB-ID\] Performed LoggingJob from .* in/, @logger.messages) - assert_match(/\[ActiveJob\] \[NestedJob\] \[NESTED-JOB-ID\] Performed NestedJob from .* in/, @logger.messages) + assert_match(/\[ActiveJob\].*\[LoggingJob\] \[LOGGING-JOB-ID\] Performed LoggingJob \(Job ID: .*?\) from .* in/, @logger.messages) + assert_match(/\[ActiveJob\] \[NestedJob\] \[NESTED-JOB-ID\] Performed NestedJob \(Job ID: .*?\) from .* in/, @logger.messages) end def test_enqueue_at_job_logging