From a22e6c4bb47dc9097f0446f39481b152c3871de1 Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 09:49:53 +0200 Subject: [PATCH 1/8] feat(observability): enrich ActiveJob error logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Context Production incident INC-157 (Redis OOM) caused Sidekiq client pushes to be silently rejected. We had no queryable Loki/Grafana record of either enqueue failures or perform failures with enough metadata to reconcile lost jobs — only Sentry traces (sampled, slow to search) and Sidekiq dead jobs (also lossy). The existing JSON log subscriber already covered the log surface, but error entries lacked the fields needed to correlate failures with affected organizations and jobs. ## Description Error log entries emitted by ActiveJob::JsonLogSubscriber are now enriched with: - `arguments`: the formatted job arguments (respecting `log_arguments?`), truncated to 1000 chars with a `"… (truncated)"` suffix when the formatted string exceeds the cap. - `attempt_count`: `job.executions` on perform error, retry stopped, and discard events. The previous `retries` key on `retry_stopped` was renamed to `attempt_count` for consistency across error events. - `organization_id`: best-effort extraction from `job.arguments` — hash with `:organization_id`/`"organization_id"`, an `Organization` instance, or any arg responding to `organization_id`. The key is omitted when extraction returns nil and the whole lookup is wrapped to never raise. - `exception.backtrace`: first 10 frames of the exception backtrace. The key is omitted entirely when the backtrace is nil or empty. - `job_id` and `queue` added to enqueue error and discard log entries respectively. The exception payload construction was extracted into a private `exception_payload(ex)` helper used at every error site. --- lib/active_job/json_log_subscriber.rb | 97 ++++++-- .../active_job/json_log_subscriber_spec.rb | 229 +++++++++++++++++- 2 files changed, 295 insertions(+), 31 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 630bd519706..7c2d41add75 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -9,6 +9,9 @@ class JsonLogSubscriber < ActiveSupport::LogSubscriber # :nodoc: class_attribute :backtrace_cleaner, default: ActiveSupport::BacktraceCleaner.new # rubocop:enable ThreadSafety/ClassAndModuleAttributes + ARGUMENTS_MAX_LENGTH = 1000 + BACKTRACE_MAX_FRAMES = 10 + def enqueue(event) job = event.payload[:job] ex = event.payload[:exception_object] || job.enqueue_error @@ -93,7 +96,7 @@ def perform(event) if ex error do - { + payload = { level: "error", event: "perform", status: "error", @@ -101,11 +104,11 @@ def perform(event) duration: event.duration.round(2), job_id: job.job_id, queue: job.queue_name, - exception: { - class: ex.class.name, - message: ex.message - } - }.to_json + arguments: args_info(job), + attempt_count: job.executions, + exception: exception_payload(ex) + } + merge_organization_id(payload, job).to_json end elsif event.payload[:aborted] info do @@ -175,19 +178,18 @@ def retry_stopped(event) ex = event.payload[:error] error do - { + payload = { level: "error", event: "retry", status: "stopped", job: job.class.name, job_id: job.job_id, queue: job.queue_name, - retries: job.executions, - exception: { - class: ex.class.name, - message: ex.message - } - }.to_json + arguments: args_info(job), + attempt_count: job.executions, + exception: exception_payload(ex) + } + merge_organization_id(payload, job).to_json end end subscribe_log_level :retry_stopped, :error @@ -197,17 +199,18 @@ def discard(event) ex = event.payload[:error] error do - { + payload = { level: "error", event: "discard", status: "error", job: job.class.name, job_id: job.job_id, - exception: { - class: ex.class.name, - message: ex.message - } - }.to_json + queue: job.queue_name, + arguments: args_info(job), + attempt_count: job.executions, + exception: exception_payload(ex) + } + merge_organization_id(payload, job).to_json end end subscribe_log_level :discard, :error @@ -216,7 +219,12 @@ def discard(event) def args_info(job) if job.class.log_arguments? && job.arguments.any? - job.arguments.map { |arg| format(arg).inspect }.join(", ") + formatted = job.arguments.map { |arg| format(arg).inspect }.join(", ") + if formatted.length > ARGUMENTS_MAX_LENGTH + "#{formatted[0, ARGUMENTS_MAX_LENGTH]}… (truncated)" + else + formatted + end else {} end @@ -243,17 +251,17 @@ def scheduled_at(job) def enqueue_error(job, ex) error do - { + payload = { level: "error", event: "enqueue", status: "error", job: job.class.name, + job_id: job.job_id, queue: job.queue_name, - exception: { - class: ex.class.name, - message: ex.message - } - }.to_json + arguments: args_info(job), + exception: exception_payload(ex) + } + merge_organization_id(payload, job).to_json end end @@ -271,6 +279,43 @@ def enqueue_success(job, **extra) }.to_json end end + + def exception_payload(ex) + payload = {class: ex.class.name, message: ex.message} + backtrace = ex.backtrace + if backtrace && !backtrace.empty? + payload[:backtrace] = backtrace.first(BACKTRACE_MAX_FRAMES) + end + payload + end + + def merge_organization_id(payload, job) + org_id = organization_id_from(job) + if org_id + payload[:organization_id] = org_id + end + payload + end + + def organization_id_from(job) + job.arguments.each do |arg| + case arg + when Hash + value = arg[:organization_id] || arg["organization_id"] + return value if value + else + if defined?(Organization) && arg.is_a?(Organization) + return arg.id + elsif arg.respond_to?(:organization_id) + value = arg.organization_id + return value if value + end + end + end + nil + rescue StandardError + nil + end end end diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index 7cfc3b98786..b04532786f6 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -10,6 +10,13 @@ def perform(*) end end +class TestLogJobWithArgs < ApplicationJob + self.log_arguments = true + + def perform(*) + end +end + RSpec.describe ActiveJob::JsonLogSubscriber do subject(:subscriber) { described_class.new } @@ -88,7 +95,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "test-job-id", "queue" => "default", + "arguments" => {}, "exception" => {"class" => "RuntimeError", "message" => "redis down"} }) end @@ -109,7 +118,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "test-job-id", "queue" => "low_priority", + "arguments" => {}, "exception" => {"class" => "ArgumentError", "message" => "invalid args"} }) end @@ -174,8 +185,8 @@ def parsed_log_lines context "when there is a global exception" do it "logs an error entry with all expected attributes for each job" do - job1 = build_job(queue_name: "billing") - job2 = build_job(queue_name: "default") + job1 = build_job(job_id: "id-1", queue_name: "billing") + job2 = build_job(job_id: "id-2", queue_name: "default") exception = RuntimeError.new("connection failed") event = build_event("enqueue_all.active_job", {jobs: [job1, job2], exception_object: exception}) @@ -194,7 +205,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "id-1", "queue" => "billing", + "arguments" => {}, "exception" => expected_exception }) @@ -203,7 +216,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "id-2", "queue" => "default", + "arguments" => {}, "exception" => expected_exception }) end @@ -229,7 +244,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "id-fail", "queue" => "default", + "arguments" => {}, "exception" => {"class" => "ArgumentError", "message" => "queue full"} }) @@ -284,7 +301,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "test-job-id", "queue" => "default", + "arguments" => {}, "exception" => {"class" => "RuntimeError", "message" => "global failure"} }) end @@ -331,7 +350,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "test-job-id", "queue" => "default", + "arguments" => {}, "exception" => {"class" => "RuntimeError", "message" => "redis down"} }) end @@ -352,7 +373,9 @@ def parsed_log_lines "event" => "enqueue", "status" => "error", "job" => "TestLogJob", + "job_id" => "test-job-id", "queue" => "low_priority", + "arguments" => {}, "exception" => {"class" => "ArgumentError", "message" => "invalid args"} }) end @@ -450,7 +473,7 @@ def parsed_log_lines context "when the job raises an exception" do it "logs an error entry with all expected attributes" do exception = RuntimeError.new("something broke") - job = build_job(job_id: "abc-123") + job = build_job(job_id: "abc-123", executions: 2) event = build_event("perform.active_job", {job: job, exception_object: exception}) allow(event).to receive(:duration).and_return(45.678) @@ -466,9 +489,106 @@ def parsed_log_lines "duration" => 45.68, "job_id" => "abc-123", "queue" => "default", + "arguments" => {}, + "attempt_count" => 2, "exception" => {"class" => "RuntimeError", "message" => "something broke"} }) end + + context "when the exception has a backtrace" do + it "truncates the backtrace to the first 10 frames" do + exception = RuntimeError.new("boom") + exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) + end + end + + context "when the exception has an empty backtrace" do + it "omits the backtrace key" do + exception = RuntimeError.new("boom") + exception.set_backtrace([]) + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.first["exception"]).not_to have_key("backtrace") + end + end + + context "when the exception has a nil backtrace" do + it "omits the backtrace key" do + exception = RuntimeError.new("boom") + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.first["exception"]).not_to have_key("backtrace") + end + end + + context "when the job arguments contain an organization_id" do + it "includes the organization_id in the log entry" do + exception = RuntimeError.new("boom") + job = TestLogJobWithArgs.new(organization_id: "org-42") + job.job_id = "abc-123" + job.queue_name = "default" + job.executions = 1 + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.first["organization_id"]).to eq("org-42") + end + end + + context "when no argument carries an organization_id" do + it "omits the organization_id key" do + exception = RuntimeError.new("boom") + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.first).not_to have_key("organization_id") + end + end + + context "when arguments string exceeds the maximum length" do + it "truncates the arguments string with a suffix" do + exception = RuntimeError.new("boom") + long_arg = "a" * 2000 + job = TestLogJobWithArgs.new(long_arg) + job.job_id = "abc-123" + job.queue_name = "default" + job.executions = 1 + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + arguments = logs.first["arguments"] + expect(arguments.length).to eq(1000 + "… (truncated)".length) + expect(arguments).to end_with("… (truncated)") + end + end end context "when the job is aborted" do @@ -557,16 +677,33 @@ def parsed_log_lines "job" => "TestLogJob", "job_id" => "abc-123", "queue" => "default", - "retries" => 5, + "arguments" => {}, + "attempt_count" => 5, "exception" => {"class" => "RuntimeError", "message" => "permanent failure"} }) end + + context "when the job arguments contain an organization_id" do + it "includes the organization_id in the log entry" do + exception = RuntimeError.new("permanent failure") + job = TestLogJobWithArgs.new(organization_id: "org-77") + job.job_id = "abc-123" + job.queue_name = "default" + job.executions = 5 + event = build_event("retry_stopped.active_job", {job: job, error: exception}) + + subscriber.retry_stopped(event) + + logs = parsed_log_lines + expect(logs.first["organization_id"]).to eq("org-77") + end + end end describe "#discard" do it "logs a discard entry with all expected attributes" do exception = RuntimeError.new("unrecoverable error") - job = build_job(job_id: "abc-123") + job = build_job(job_id: "abc-123", executions: 2) event = build_event("discard.active_job", {job: job, error: exception}) subscriber.discard(event) @@ -579,8 +716,90 @@ def parsed_log_lines "status" => "error", "job" => "TestLogJob", "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 2, "exception" => {"class" => "RuntimeError", "message" => "unrecoverable error"} }) end + + context "when the job arguments contain an organization_id" do + it "includes the organization_id in the log entry" do + exception = RuntimeError.new("unrecoverable") + job = TestLogJobWithArgs.new(organization_id: "org-99") + job.job_id = "abc-123" + job.queue_name = "default" + job.executions = 1 + event = build_event("discard.active_job", {job: job, error: exception}) + + subscriber.discard(event) + + logs = parsed_log_lines + expect(logs.first["organization_id"]).to eq("org-99") + end + end + end + + describe "organization_id extraction" do + let(:exception) { RuntimeError.new("boom") } + + def perform_event(job) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + event + end + + context "when an argument is a hash with a symbol :organization_id key" do + it "extracts the organization_id" do + job = TestLogJobWithArgs.new(organization_id: "org-symbol") + job.job_id = "abc" + job.queue_name = "default" + job.executions = 1 + + subscriber.perform(perform_event(job)) + + expect(parsed_log_lines.first["organization_id"]).to eq("org-symbol") + end + end + + context "when an argument is a hash with a string 'organization_id' key" do + it "extracts the organization_id" do + job = TestLogJobWithArgs.new({"organization_id" => "org-string"}) + job.job_id = "abc" + job.queue_name = "default" + job.executions = 1 + + subscriber.perform(perform_event(job)) + + expect(parsed_log_lines.first["organization_id"]).to eq("org-string") + end + end + + context "when an argument responds to organization_id" do + it "extracts the organization_id" do + org_carrier = Struct.new(:organization_id).new("org-from-method") + job = TestLogJobWithArgs.new(org_carrier) + job.job_id = "abc" + job.queue_name = "default" + job.executions = 1 + + subscriber.perform(perform_event(job)) + + expect(parsed_log_lines.first["organization_id"]).to eq("org-from-method") + end + end + + context "when no argument carries an organization_id" do + it "omits the organization_id key" do + job = TestLogJobWithArgs.new("plain-string", 42) + job.job_id = "abc" + job.queue_name = "default" + job.executions = 1 + + subscriber.perform(perform_event(job)) + + expect(parsed_log_lines.first).not_to have_key("organization_id") + end + end end end From 745c5f8661a6fbef232b6797d35854737df49991 Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 10:00:56 +0200 Subject: [PATCH 2/8] fix(observability): preserve falsy organization_id values ## Context The `organization_id_from` helper used `||` and `if value` checks to short-circuit the lookup. When a hash argument carried `organization_id: false` or `organization_id: 0`, the lookup silently fell through to the next argument or returned `nil`, producing wrong-value or missing-key log entries. The downstream `merge_organization_id` helper had the same problem and dropped non-nil falsy values from the payload. The spec file also introduced a top-level `describe "organization_id extraction"` block sitting outside the per-method describes, and several new contexts asserted on individual keys (`logs.first["organization_id"]`, `logs.first["exception"].not_to have_key("backtrace")`) instead of the full-hash `eq({...})` shape used everywhere else in the file. Job-setup boilerplate was repeated across the new contexts. ## Description The `organization_id_from` helper now distinguishes "key present but the value is nil" from "key absent" using `Hash#key?` and an explicit `unless value.nil?` guard on every return path, including the `respond_to?(:organization_id)` branch. An explicit `return nil if job.arguments.nil?` guard was added at the top. The existing `rescue StandardError` is kept as a final safety net. The `merge_organization_id` helper switches from `if org_id` to `unless org_id.nil?` so that a deliberate `false` or `0` is preserved in the log entry while `nil` continues to skip the key. The new organization_id contexts in the spec were consolidated into `describe "#perform"` (alongside the existing per-method contexts in `#retry_stopped` and `#discard`) and the standalone top-level block was removed. Every new assertion now compares the full log entry against a single expected hash, matching the convention established by the other tests. A `build_job_with_args` helper was added next to `build_job` to replace the repeated `TestLogJobWithArgs.new(...).tap { ... }` boilerplate. Coverage for the falsy-value contract was added: `organization_id: false` (preserved), `organization_id: 0` (preserved), and `organization_id: nil` (falls through to the next argument). --- lib/active_job/json_log_subscriber.rb | 15 +- .../active_job/json_log_subscriber_spec.rb | 366 +++++++++++++----- 2 files changed, 279 insertions(+), 102 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 7c2d41add75..2be9024e657 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -291,24 +291,31 @@ def exception_payload(ex) def merge_organization_id(payload, job) org_id = organization_id_from(job) - if org_id + unless org_id.nil? payload[:organization_id] = org_id end payload end def organization_id_from(job) + return nil if job.arguments.nil? + job.arguments.each do |arg| case arg when Hash - value = arg[:organization_id] || arg["organization_id"] - return value if value + if arg.key?(:organization_id) + value = arg[:organization_id] + return value unless value.nil? + elsif arg.key?("organization_id") + value = arg["organization_id"] + return value unless value.nil? + end else if defined?(Organization) && arg.is_a?(Organization) return arg.id elsif arg.respond_to?(:organization_id) value = arg.organization_id - return value if value + return value unless value.nil? end end end diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index b04532786f6..b674f2c7de6 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -49,6 +49,14 @@ def build_job( end end + def build_job_with_args(*args, job_id: "test-job-id", queue_name: "default", executions: 0) + TestLogJobWithArgs.new(*args).tap do |job| + job.job_id = job_id + job.queue_name = queue_name + job.executions = executions + end + end + def build_event(name, payload) ActiveSupport::Notifications::Event.new(name, nil, nil, "transaction_id", payload) end @@ -496,7 +504,7 @@ def parsed_log_lines end context "when the exception has a backtrace" do - it "truncates the backtrace to the first 10 frames" do + it "logs an error entry with the backtrace truncated to the first 10 frames" do exception = RuntimeError.new("boom") exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) job = build_job(job_id: "abc-123") @@ -506,12 +514,28 @@ def parsed_log_lines subscriber.perform(event) logs = parsed_log_lines - expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJob", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 0, + "exception" => { + "class" => "RuntimeError", + "message" => "boom", + "backtrace" => (1..10).map { |i| "frame_#{i}" } + } + }) end end context "when the exception has an empty backtrace" do - it "omits the backtrace key" do + it "logs an error entry without the backtrace key" do exception = RuntimeError.new("boom") exception.set_backtrace([]) job = build_job(job_id: "abc-123") @@ -521,12 +545,24 @@ def parsed_log_lines subscriber.perform(event) logs = parsed_log_lines - expect(logs.first["exception"]).not_to have_key("backtrace") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJob", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 0, + "exception" => {"class" => "RuntimeError", "message" => "boom"} + }) end end context "when the exception has a nil backtrace" do - it "omits the backtrace key" do + it "logs an error entry without the backtrace key" do exception = RuntimeError.new("boom") job = build_job(job_id: "abc-123") event = build_event("perform.active_job", {job: job, exception_object: exception}) @@ -535,29 +571,187 @@ def parsed_log_lines subscriber.perform(event) logs = parsed_log_lines - expect(logs.first["exception"]).not_to have_key("backtrace") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJob", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 0, + "exception" => {"class" => "RuntimeError", "message" => "boom"} + }) + end + end + + context "when an argument is a hash with a symbol :organization_id key" do + it "logs an error entry with the extracted organization_id" do + exception = RuntimeError.new("boom") + job = build_job_with_args({organization_id: "org-symbol"}, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-symbol\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => "org-symbol" + }) + end + end + + context "when an argument is a hash with a string 'organization_id' key" do + it "logs an error entry with the extracted organization_id" do + exception = RuntimeError.new("boom") + job = build_job_with_args({"organization_id" => "org-string"}, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{\"organization_id\" => \"org-string\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => "org-string" + }) + end + end + + context "when an argument responds to organization_id" do + it "logs an error entry with the extracted organization_id" do + exception = RuntimeError.new("boom") + org_carrier = Struct.new(:organization_id).new("org-from-method") + job = build_job_with_args(org_carrier, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => org_carrier.inspect, + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => "org-from-method" + }) end end - context "when the job arguments contain an organization_id" do - it "includes the organization_id in the log entry" do + context "when an argument hash has organization_id: false" do + it "logs an error entry with the false organization_id rather than falling through" do exception = RuntimeError.new("boom") - job = TestLogJobWithArgs.new(organization_id: "org-42") - job.job_id = "abc-123" - job.queue_name = "default" - job.executions = 1 + job = build_job_with_args({organization_id: false}, {organization_id: "fallback"}, job_id: "abc-123", executions: 1) event = build_event("perform.active_job", {job: job, exception_object: exception}) allow(event).to receive(:duration).and_return(1.0) subscriber.perform(event) logs = parsed_log_lines - expect(logs.first["organization_id"]).to eq("org-42") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: false}, {organization_id: \"fallback\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => false + }) + end + end + + context "when an argument hash has organization_id: 0" do + it "logs an error entry with the zero organization_id rather than falling through" do + exception = RuntimeError.new("boom") + job = build_job_with_args({organization_id: 0}, {organization_id: "fallback"}, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: 0}, {organization_id: \"fallback\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => 0 + }) + end + end + + context "when an argument hash has organization_id: nil" do + it "logs an error entry with the next argument's organization_id" do + exception = RuntimeError.new("boom") + job = build_job_with_args({organization_id: nil}, {organization_id: "fallback"}, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: nil}, {organization_id: \"fallback\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"}, + "organization_id" => "fallback" + }) end end context "when no argument carries an organization_id" do - it "omits the organization_id key" do + it "logs an error entry without the organization_id key" do exception = RuntimeError.new("boom") job = build_job(job_id: "abc-123") event = build_event("perform.active_job", {job: job, exception_object: exception}) @@ -566,27 +760,48 @@ def parsed_log_lines subscriber.perform(event) logs = parsed_log_lines - expect(logs.first).not_to have_key("organization_id") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJob", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 0, + "exception" => {"class" => "RuntimeError", "message" => "boom"} + }) end end context "when arguments string exceeds the maximum length" do - it "truncates the arguments string with a suffix" do + it "logs an error entry with the arguments string truncated and a suffix" do exception = RuntimeError.new("boom") long_arg = "a" * 2000 - job = TestLogJobWithArgs.new(long_arg) - job.job_id = "abc-123" - job.queue_name = "default" - job.executions = 1 + job = build_job_with_args(long_arg, job_id: "abc-123", executions: 1) event = build_event("perform.active_job", {job: job, exception_object: exception}) allow(event).to receive(:duration).and_return(1.0) subscriber.perform(event) + truncated_arguments = "\"#{"a" * 999}" + "… (truncated)" + logs = parsed_log_lines - arguments = logs.first["arguments"] - expect(arguments.length).to eq(1000 + "… (truncated)".length) - expect(arguments).to end_with("… (truncated)") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJobWithArgs", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => truncated_arguments, + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "boom"} + }) end end end @@ -684,18 +899,27 @@ def parsed_log_lines end context "when the job arguments contain an organization_id" do - it "includes the organization_id in the log entry" do + it "logs a stopped entry with the extracted organization_id" do exception = RuntimeError.new("permanent failure") - job = TestLogJobWithArgs.new(organization_id: "org-77") - job.job_id = "abc-123" - job.queue_name = "default" - job.executions = 5 + job = build_job_with_args({organization_id: "org-77"}, job_id: "abc-123", executions: 5) event = build_event("retry_stopped.active_job", {job: job, error: exception}) subscriber.retry_stopped(event) logs = parsed_log_lines - expect(logs.first["organization_id"]).to eq("org-77") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "retry", + "status" => "stopped", + "job" => "TestLogJobWithArgs", + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-77\"}", + "attempt_count" => 5, + "exception" => {"class" => "RuntimeError", "message" => "permanent failure"}, + "organization_id" => "org-77" + }) end end end @@ -724,81 +948,27 @@ def parsed_log_lines end context "when the job arguments contain an organization_id" do - it "includes the organization_id in the log entry" do + it "logs a discard entry with the extracted organization_id" do exception = RuntimeError.new("unrecoverable") - job = TestLogJobWithArgs.new(organization_id: "org-99") - job.job_id = "abc-123" - job.queue_name = "default" - job.executions = 1 + job = build_job_with_args({organization_id: "org-99"}, job_id: "abc-123", executions: 1) event = build_event("discard.active_job", {job: job, error: exception}) subscriber.discard(event) logs = parsed_log_lines - expect(logs.first["organization_id"]).to eq("org-99") - end - end - end - - describe "organization_id extraction" do - let(:exception) { RuntimeError.new("boom") } - - def perform_event(job) - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - event - end - - context "when an argument is a hash with a symbol :organization_id key" do - it "extracts the organization_id" do - job = TestLogJobWithArgs.new(organization_id: "org-symbol") - job.job_id = "abc" - job.queue_name = "default" - job.executions = 1 - - subscriber.perform(perform_event(job)) - - expect(parsed_log_lines.first["organization_id"]).to eq("org-symbol") - end - end - - context "when an argument is a hash with a string 'organization_id' key" do - it "extracts the organization_id" do - job = TestLogJobWithArgs.new({"organization_id" => "org-string"}) - job.job_id = "abc" - job.queue_name = "default" - job.executions = 1 - - subscriber.perform(perform_event(job)) - - expect(parsed_log_lines.first["organization_id"]).to eq("org-string") - end - end - - context "when an argument responds to organization_id" do - it "extracts the organization_id" do - org_carrier = Struct.new(:organization_id).new("org-from-method") - job = TestLogJobWithArgs.new(org_carrier) - job.job_id = "abc" - job.queue_name = "default" - job.executions = 1 - - subscriber.perform(perform_event(job)) - - expect(parsed_log_lines.first["organization_id"]).to eq("org-from-method") - end - end - - context "when no argument carries an organization_id" do - it "omits the organization_id key" do - job = TestLogJobWithArgs.new("plain-string", 42) - job.job_id = "abc" - job.queue_name = "default" - job.executions = 1 - - subscriber.perform(perform_event(job)) - - expect(parsed_log_lines.first).not_to have_key("organization_id") + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "discard", + "status" => "error", + "job" => "TestLogJobWithArgs", + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-99\"}", + "attempt_count" => 1, + "exception" => {"class" => "RuntimeError", "message" => "unrecoverable"}, + "organization_id" => "org-99" + }) end end end From be18437f545ced316f495b070597807cffc8426b Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 10:06:58 +0200 Subject: [PATCH 3/8] test(observability): cover ActiveJob error log edge cases ## Context The ING-136 enrichments to `ActiveJob::JsonLogSubscriber` add `arguments`, `attempt_count`, `organization_id`, and truncated `backtrace` fields to every error log path (enqueue, enqueue_all per-job, enqueue_at, perform, retry_stopped, discard). Several defensive guards and boundary conditions in the implementation lacked regression coverage. ## Description Additional specs were added to pin the previously untested behaviours: - Boundary tests for `ARGUMENTS_MAX_LENGTH = 1000` (exactly 1000 chars passes through, 1001 chars triggers truncation). - Boundary tests for `BACKTRACE_MAX_FRAMES = 10` (exactly 10 frames is not truncated, 11 frames is truncated to 10). - `organization_id` extraction from an `Organization` instance argument via `arg.id`. - Multi-argument walking when the first argument does not carry an `organization_id` and a later one does. - The `rescue StandardError` path when an argument's `organization_id` accessor raises (log is still emitted without the key). - The explicit `job.arguments.nil?` guard. - Cross-event enrichment coverage for `enqueue` error, `enqueue_at` error, the per-job `enqueue_error` branch inside `enqueue_all`, plus backtrace truncation on `retry_stopped` and `discard`. --- .../active_job/json_log_subscriber_spec.rb | 262 ++++++++++++++++++ 1 file changed, 262 insertions(+) diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index b674f2c7de6..63cb60e2acf 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -152,6 +152,30 @@ def parsed_log_lines }) end end + + context "when the job has an exception and an argument carries an organization_id" do + it "logs an error entry enriched with the organization_id" do + exception = RuntimeError.new("redis down") + job = build_job_with_args({organization_id: "org-enq"}, job_id: "abc-123") + event = build_event("enqueue.active_job", {job: job, exception_object: exception}) + + subscriber.enqueue(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "enqueue", + "status" => "error", + "job" => "TestLogJobWithArgs", + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-enq\"}", + "exception" => {"class" => "RuntimeError", "message" => "redis down"}, + "organization_id" => "org-enq" + }) + end + end end describe "#enqueue_all" do @@ -316,6 +340,34 @@ def parsed_log_lines }) end end + + context "when an individual job's enqueue_error happens and its arguments carry an organization_id" do + it "logs an error entry enriched with arguments and organization_id" do + error = ArgumentError.new("queue full") + failed_job = TestLogJobWithArgs.new({organization_id: "org-bulk"}).tap do |j| + j.job_id = "id-fail" + j.queue_name = "default" + j.enqueue_error = error + end + event = build_event("enqueue_all.active_job", {jobs: [failed_job], exception_object: nil}) + + subscriber.enqueue_all(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "enqueue", + "status" => "error", + "job" => "TestLogJobWithArgs", + "job_id" => "id-fail", + "queue" => "default", + "arguments" => "{organization_id: \"org-bulk\"}", + "exception" => {"class" => "ArgumentError", "message" => "queue full"}, + "organization_id" => "org-bulk" + }) + end + end end describe "#enqueue_at" do @@ -407,6 +459,30 @@ def parsed_log_lines }) end end + + context "when the job has an exception and an argument carries an organization_id" do + it "logs an error entry enriched with the organization_id" do + exception = RuntimeError.new("redis down") + job = build_job_with_args({organization_id: "org-enq-at"}, job_id: "abc-123") + event = build_event("enqueue_at.active_job", {job: job, exception_object: exception}) + + subscriber.enqueue_at(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "enqueue", + "status" => "error", + "job" => "TestLogJobWithArgs", + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-enq-at\"}", + "exception" => {"class" => "RuntimeError", "message" => "redis down"}, + "organization_id" => "org-enq-at" + }) + end + end end describe "#perform_start" do @@ -804,6 +880,162 @@ def parsed_log_lines }) end end + + context "when arguments string is exactly the maximum length" do + it "logs the arguments string without truncation" do + exception = RuntimeError.new("boom") + # Inspected string of a 998-char string is 1000 chars (two surrounding quotes). + arg = "a" * 998 + job = build_job_with_args(arg, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["arguments"]).to eq("\"#{arg}\"") + expect(logs.first["arguments"].length).to eq(1000) + end + end + + context "when arguments string exceeds the maximum length by one character" do + it "truncates to ARGUMENTS_MAX_LENGTH characters plus the suffix" do + exception = RuntimeError.new("boom") + # Inspected string of a 999-char string is 1001 chars. + arg = "a" * 999 + job = build_job_with_args(arg, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["arguments"]).to eq("\"#{"a" * 999}" + "… (truncated)") + end + end + + context "when the exception has exactly the maximum number of backtrace frames" do + it "logs all frames without truncation" do + exception = RuntimeError.new("boom") + exception.set_backtrace((1..10).map { |i| "frame_#{i}" }) + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "perform", + "status" => "error", + "job" => "TestLogJob", + "duration" => 1.0, + "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, + "attempt_count" => 0, + "exception" => { + "class" => "RuntimeError", + "message" => "boom", + "backtrace" => (1..10).map { |i| "frame_#{i}" } + } + }) + end + end + + context "when the exception has one more than the maximum number of backtrace frames" do + it "truncates the backtrace to the first 10 frames" do + exception = RuntimeError.new("boom") + exception.set_backtrace((1..11).map { |i| "frame_#{i}" }) + job = build_job(job_id: "abc-123") + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) + end + end + + context "when an argument is an Organization instance" do + it "logs an error entry with the Organization id as organization_id" do + exception = RuntimeError.new("boom") + organization = build(:organization) + job = build_job_with_args(organization, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["organization_id"]).to eq(organization.id) + end + end + + context "when the first argument does not carry an organization_id and a later argument does" do + it "walks past the first argument and extracts the later organization_id" do + exception = RuntimeError.new("boom") + plain = Struct.new(:name).new("nothing") + org_carrier = Struct.new(:organization_id).new("org-later") + job = build_job_with_args(plain, org_carrier, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["organization_id"]).to eq("org-later") + end + end + + context "when an argument's organization_id accessor raises" do + it "logs an error entry without the organization_id key" do + exception = RuntimeError.new("boom") + raising_arg = Class.new do + def organization_id + raise "kaboom" + end + + def inspect + "#" + end + end.new + job = build_job_with_args(raising_arg, job_id: "abc-123", executions: 1) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).not_to have_key("organization_id") + expect(logs.first["exception"]).to eq({"class" => "RuntimeError", "message" => "boom"}) + end + end + + context "when the job arguments collection is nil" do + it "logs an error entry without the organization_id key" do + exception = RuntimeError.new("boom") + job = build_job(job_id: "abc-123") + allow(job).to receive(:arguments).and_return(nil) + event = build_event("perform.active_job", {job: job, exception_object: exception}) + allow(event).to receive(:duration).and_return(1.0) + + subscriber.perform(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).not_to have_key("organization_id") + end + end end context "when the job is aborted" do @@ -922,6 +1154,21 @@ def parsed_log_lines }) end end + + context "when the exception has more than the maximum number of backtrace frames" do + it "logs a stopped entry with the backtrace truncated to the first 10 frames" do + exception = RuntimeError.new("permanent failure") + exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) + job = build_job(job_id: "abc-123", executions: 5) + event = build_event("retry_stopped.active_job", {job: job, error: exception}) + + subscriber.retry_stopped(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) + end + end end describe "#discard" do @@ -971,5 +1218,20 @@ def parsed_log_lines }) end end + + context "when the exception has more than the maximum number of backtrace frames" do + it "logs a discard entry with the backtrace truncated to the first 10 frames" do + exception = RuntimeError.new("unrecoverable") + exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) + job = build_job(job_id: "abc-123", executions: 2) + event = build_event("discard.active_job", {job: job, error: exception}) + + subscriber.discard(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) + end + end end end From b1e9023354d248af50192a7f84b70922b3b854ae Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 10:43:42 +0200 Subject: [PATCH 4/8] fix(observability): keep retries key in retry_stopped logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Context The previous commit renamed the `retries` key in the `retry_stopped` JSON log entry to `attempt_count` for vocabulary consistency with the other error events (`#perform` error, `#discard`). External Loki / Grafana dashboards and alerts may already read the `retries` key, so renaming it is a breaking change to a public log surface that the codebase cannot fully verify from the inside. ## Description The `retry_stopped` payload reverts to `retries: job.executions`, restoring backward compatibility for any downstream consumer. The `#perform` error and `#discard` events keep their new `attempt_count` field — those keys did not exist before this branch, so adding them is purely additive. The vocabulary inconsistency between `retries` (on retry_stopped) and `attempt_count` (on perform / discard) is accepted in exchange for not silently breaking existing dashboards. Spec assertions for `retry_stopped` updated accordingly. --- lib/active_job/json_log_subscriber.rb | 2 +- spec/lib/active_job/json_log_subscriber_spec.rb | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 2be9024e657..365cdeda192 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -186,7 +186,7 @@ def retry_stopped(event) job_id: job.job_id, queue: job.queue_name, arguments: args_info(job), - attempt_count: job.executions, + retries: job.executions, exception: exception_payload(ex) } merge_organization_id(payload, job).to_json diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index 63cb60e2acf..ddc58948972 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -1125,7 +1125,7 @@ def inspect "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 5, + "retries" => 5, "exception" => {"class" => "RuntimeError", "message" => "permanent failure"} }) end @@ -1148,7 +1148,7 @@ def inspect "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: \"org-77\"}", - "attempt_count" => 5, + "retries" => 5, "exception" => {"class" => "RuntimeError", "message" => "permanent failure"}, "organization_id" => "org-77" }) From 6a444db7a7c89a32b2ff21304dc8152cf8f10946 Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 10:47:32 +0200 Subject: [PATCH 5/8] fix(observability): use retries key on all error events ## Context The first commit introduced an `attempt_count` field on `#perform` error and `#discard` logs while keeping the existing `retries` key on `#retry_stopped`. The vocabulary split (`retries` on one event, `attempt_count` on others) was inconsistent and unnecessary. ## Description The `#perform` error, `#retry_stopped`, and `#discard` payloads now all emit `retries: job.executions`, matching the key name that `#retry_stopped` already used before this branch. Backward compatibility for external dashboards reading `retries` is preserved, and consumers reading the new error events get a uniform vocabulary across all error-status entries. Spec assertions updated to match. --- lib/active_job/json_log_subscriber.rb | 4 +-- .../active_job/json_log_subscriber_spec.rb | 30 +++++++++---------- 2 files changed, 17 insertions(+), 17 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 365cdeda192..cdea6cc4fb4 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -105,7 +105,7 @@ def perform(event) job_id: job.job_id, queue: job.queue_name, arguments: args_info(job), - attempt_count: job.executions, + retries: job.executions, exception: exception_payload(ex) } merge_organization_id(payload, job).to_json @@ -207,7 +207,7 @@ def discard(event) job_id: job.job_id, queue: job.queue_name, arguments: args_info(job), - attempt_count: job.executions, + retries: job.executions, exception: exception_payload(ex) } merge_organization_id(payload, job).to_json diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index ddc58948972..87df007d413 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -574,7 +574,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 2, + "retries" => 2, "exception" => {"class" => "RuntimeError", "message" => "something broke"} }) end @@ -600,7 +600,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 0, + "retries" => 0, "exception" => { "class" => "RuntimeError", "message" => "boom", @@ -631,7 +631,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 0, + "retries" => 0, "exception" => {"class" => "RuntimeError", "message" => "boom"} }) end @@ -657,7 +657,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 0, + "retries" => 0, "exception" => {"class" => "RuntimeError", "message" => "boom"} }) end @@ -683,7 +683,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: \"org-symbol\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => "org-symbol" }) @@ -710,7 +710,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => "{\"organization_id\" => \"org-string\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => "org-string" }) @@ -738,7 +738,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => org_carrier.inspect, - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => "org-from-method" }) @@ -765,7 +765,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: false}, {organization_id: \"fallback\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => false }) @@ -792,7 +792,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: 0}, {organization_id: \"fallback\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => 0 }) @@ -819,7 +819,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: nil}, {organization_id: \"fallback\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, "organization_id" => "fallback" }) @@ -846,7 +846,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 0, + "retries" => 0, "exception" => {"class" => "RuntimeError", "message" => "boom"} }) end @@ -875,7 +875,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => truncated_arguments, - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"} }) end @@ -937,7 +937,7 @@ def parsed_log_lines "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 0, + "retries" => 0, "exception" => { "class" => "RuntimeError", "message" => "boom", @@ -1189,7 +1189,7 @@ def inspect "job_id" => "abc-123", "queue" => "default", "arguments" => {}, - "attempt_count" => 2, + "retries" => 2, "exception" => {"class" => "RuntimeError", "message" => "unrecoverable error"} }) end @@ -1212,7 +1212,7 @@ def inspect "job_id" => "abc-123", "queue" => "default", "arguments" => "{organization_id: \"org-99\"}", - "attempt_count" => 1, + "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "unrecoverable"}, "organization_id" => "org-99" }) From 35e49c4029855f448cd3571cfb5116396ccfbb1b Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 10:54:31 +0200 Subject: [PATCH 6/8] chore(observability): drop args and backtrace truncation ## Context The first commit added an `ARGUMENTS_MAX_LENGTH`-based truncation on the formatted arguments string and a `BACKTRACE_MAX_FRAMES`-based truncation on the exception backtrace. Both belong to a separate follow-up that should also decide on the truncation thresholds, the scrubbing policy for sensitive payload fields, and whether the backtrace should be included on error log entries at all. ## Description The two constants and the truncation branches in `args_info` and `exception_payload` are removed. `args_info` reverts to the original behaviour (formatted string with no length cap). `exception_payload` returns only the `class` and `message` keys; the `backtrace` is no longer added. The corresponding spec contexts (argument length boundaries, backtrace truncation on `#perform` / `#retry_stopped` / `#discard`, and the empty-/nil-backtrace omissions) are removed. 38 examples, 0 failures. --- lib/active_job/json_log_subscriber.rb | 17 +- .../active_job/json_log_subscriber_spec.rb | 223 ------------------ 2 files changed, 2 insertions(+), 238 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index cdea6cc4fb4..0fe5d265ef2 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -9,9 +9,6 @@ class JsonLogSubscriber < ActiveSupport::LogSubscriber # :nodoc: class_attribute :backtrace_cleaner, default: ActiveSupport::BacktraceCleaner.new # rubocop:enable ThreadSafety/ClassAndModuleAttributes - ARGUMENTS_MAX_LENGTH = 1000 - BACKTRACE_MAX_FRAMES = 10 - def enqueue(event) job = event.payload[:job] ex = event.payload[:exception_object] || job.enqueue_error @@ -219,12 +216,7 @@ def discard(event) def args_info(job) if job.class.log_arguments? && job.arguments.any? - formatted = job.arguments.map { |arg| format(arg).inspect }.join(", ") - if formatted.length > ARGUMENTS_MAX_LENGTH - "#{formatted[0, ARGUMENTS_MAX_LENGTH]}… (truncated)" - else - formatted - end + job.arguments.map { |arg| format(arg).inspect }.join(", ") else {} end @@ -281,12 +273,7 @@ def enqueue_success(job, **extra) end def exception_payload(ex) - payload = {class: ex.class.name, message: ex.message} - backtrace = ex.backtrace - if backtrace && !backtrace.empty? - payload[:backtrace] = backtrace.first(BACKTRACE_MAX_FRAMES) - end - payload + {class: ex.class.name, message: ex.message} end def merge_organization_id(payload, job) diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index 87df007d413..4d20a043ddf 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -579,90 +579,6 @@ def parsed_log_lines }) end - context "when the exception has a backtrace" do - it "logs an error entry with the backtrace truncated to the first 10 frames" do - exception = RuntimeError.new("boom") - exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) - job = build_job(job_id: "abc-123") - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first).to eq({ - "level" => "error", - "event" => "perform", - "status" => "error", - "job" => "TestLogJob", - "duration" => 1.0, - "job_id" => "abc-123", - "queue" => "default", - "arguments" => {}, - "retries" => 0, - "exception" => { - "class" => "RuntimeError", - "message" => "boom", - "backtrace" => (1..10).map { |i| "frame_#{i}" } - } - }) - end - end - - context "when the exception has an empty backtrace" do - it "logs an error entry without the backtrace key" do - exception = RuntimeError.new("boom") - exception.set_backtrace([]) - job = build_job(job_id: "abc-123") - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first).to eq({ - "level" => "error", - "event" => "perform", - "status" => "error", - "job" => "TestLogJob", - "duration" => 1.0, - "job_id" => "abc-123", - "queue" => "default", - "arguments" => {}, - "retries" => 0, - "exception" => {"class" => "RuntimeError", "message" => "boom"} - }) - end - end - - context "when the exception has a nil backtrace" do - it "logs an error entry without the backtrace key" do - exception = RuntimeError.new("boom") - job = build_job(job_id: "abc-123") - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first).to eq({ - "level" => "error", - "event" => "perform", - "status" => "error", - "job" => "TestLogJob", - "duration" => 1.0, - "job_id" => "abc-123", - "queue" => "default", - "arguments" => {}, - "retries" => 0, - "exception" => {"class" => "RuntimeError", "message" => "boom"} - }) - end - end - context "when an argument is a hash with a symbol :organization_id key" do it "logs an error entry with the extracted organization_id" do exception = RuntimeError.new("boom") @@ -852,117 +768,6 @@ def parsed_log_lines end end - context "when arguments string exceeds the maximum length" do - it "logs an error entry with the arguments string truncated and a suffix" do - exception = RuntimeError.new("boom") - long_arg = "a" * 2000 - job = build_job_with_args(long_arg, job_id: "abc-123", executions: 1) - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - truncated_arguments = "\"#{"a" * 999}" + "… (truncated)" - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first).to eq({ - "level" => "error", - "event" => "perform", - "status" => "error", - "job" => "TestLogJobWithArgs", - "duration" => 1.0, - "job_id" => "abc-123", - "queue" => "default", - "arguments" => truncated_arguments, - "retries" => 1, - "exception" => {"class" => "RuntimeError", "message" => "boom"} - }) - end - end - - context "when arguments string is exactly the maximum length" do - it "logs the arguments string without truncation" do - exception = RuntimeError.new("boom") - # Inspected string of a 998-char string is 1000 chars (two surrounding quotes). - arg = "a" * 998 - job = build_job_with_args(arg, job_id: "abc-123", executions: 1) - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first["arguments"]).to eq("\"#{arg}\"") - expect(logs.first["arguments"].length).to eq(1000) - end - end - - context "when arguments string exceeds the maximum length by one character" do - it "truncates to ARGUMENTS_MAX_LENGTH characters plus the suffix" do - exception = RuntimeError.new("boom") - # Inspected string of a 999-char string is 1001 chars. - arg = "a" * 999 - job = build_job_with_args(arg, job_id: "abc-123", executions: 1) - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first["arguments"]).to eq("\"#{"a" * 999}" + "… (truncated)") - end - end - - context "when the exception has exactly the maximum number of backtrace frames" do - it "logs all frames without truncation" do - exception = RuntimeError.new("boom") - exception.set_backtrace((1..10).map { |i| "frame_#{i}" }) - job = build_job(job_id: "abc-123") - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first).to eq({ - "level" => "error", - "event" => "perform", - "status" => "error", - "job" => "TestLogJob", - "duration" => 1.0, - "job_id" => "abc-123", - "queue" => "default", - "arguments" => {}, - "retries" => 0, - "exception" => { - "class" => "RuntimeError", - "message" => "boom", - "backtrace" => (1..10).map { |i| "frame_#{i}" } - } - }) - end - end - - context "when the exception has one more than the maximum number of backtrace frames" do - it "truncates the backtrace to the first 10 frames" do - exception = RuntimeError.new("boom") - exception.set_backtrace((1..11).map { |i| "frame_#{i}" }) - job = build_job(job_id: "abc-123") - event = build_event("perform.active_job", {job: job, exception_object: exception}) - allow(event).to receive(:duration).and_return(1.0) - - subscriber.perform(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) - end - end - context "when an argument is an Organization instance" do it "logs an error entry with the Organization id as organization_id" do exception = RuntimeError.new("boom") @@ -1155,20 +960,6 @@ def inspect end end - context "when the exception has more than the maximum number of backtrace frames" do - it "logs a stopped entry with the backtrace truncated to the first 10 frames" do - exception = RuntimeError.new("permanent failure") - exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) - job = build_job(job_id: "abc-123", executions: 5) - event = build_event("retry_stopped.active_job", {job: job, error: exception}) - - subscriber.retry_stopped(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) - end - end end describe "#discard" do @@ -1219,19 +1010,5 @@ def inspect end end - context "when the exception has more than the maximum number of backtrace frames" do - it "logs a discard entry with the backtrace truncated to the first 10 frames" do - exception = RuntimeError.new("unrecoverable") - exception.set_backtrace((1..20).map { |i| "frame_#{i}" }) - job = build_job(job_id: "abc-123", executions: 2) - event = build_event("discard.active_job", {job: job, error: exception}) - - subscriber.discard(event) - - logs = parsed_log_lines - expect(logs.size).to eq(1) - expect(logs.first["exception"]["backtrace"]).to eq((1..10).map { |i| "frame_#{i}" }) - end - end end end From 57212ece93018b1420679ee1d7973bda1d03cd99 Mon Sep 17 00:00:00 2001 From: Yohan Robert <7434196+groyoh@users.noreply.github.com> Date: Mon, 18 May 2026 11:03:07 +0200 Subject: [PATCH 7/8] feat(observability): enrich enqueue_retry and Organization helper ## Context The earlier commits enriched the error-status entries on `#enqueue`, `#perform`, `#retry_stopped`, and `#discard`, but `#enqueue_retry` was left untouched. The retry log is fired with an active error context (`event.payload[:error]`) on every retry attempt, so it matters as much as the other error events for reconciliation. It was also missing `queue`, `arguments`, and `organization_id`. The `organization_id_from` walker also had a special-case branch for `Organization` instances (`arg.is_a?(Organization) ? arg.id`) that disappears once `Organization` itself exposes `#organization_id` the same way it already exposes `#organization`. ## Description `Organization#organization_id` is added next to the existing `#organization` self-returning helper. The walker drops the `is_a?(Organization)` branch and uniformly relies on `respond_to?(:organization_id)`, which `Organization` now satisfies. The Hash lookup is collapsed to `arg[:organization_id].presence || arg["organization_id"].presence` and the walker itself is rewritten around `Array#find`. The spec context that pinned `false` as a valid organization_id is updated to reflect the `.presence` semantics (blank values fall through to the next argument). `#enqueue_retry` now emits `queue`, `arguments`, and `organization_id` on both its error and success branches, sourced through the same `args_info` / `exception_payload` / `merge_organization_id` helpers used by the other error events. The `execution` key is kept untouched on this event (it's a per-retry counter, distinct from the `retries` total on terminal events). Existing spec assertions updated and a new context added for the organization_id extraction on retry-error logs. --- app/models/organization.rb | 6 +++ lib/active_job/json_log_subscriber.rb | 52 ++++++++----------- .../active_job/json_log_subscriber_spec.rb | 34 +++++++++++- spec/models/organization_spec.rb | 6 +++ 4 files changed, 66 insertions(+), 32 deletions(-) diff --git a/app/models/organization.rb b/app/models/organization.rb index 7f48b16fe0d..5844f271217 100644 --- a/app/models/organization.rb +++ b/app/models/organization.rb @@ -268,6 +268,12 @@ def organization self end + # Same intent as #organization: a uniform interface so callers walking an arbitrary + # object can ask for the organization_id without special-casing Organization itself. + def organization_id + id + end + def maximum_wallets_per_customer max_wallets if events_targeting_wallets_enabled? end diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 0fe5d265ef2..74dccf768ba 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -142,29 +142,32 @@ def enqueue_retry(event) info do if ex - { + payload = { level: "error", event: "retry", status: "error", job: job.class.name, job_id: job.job_id, + queue: job.queue_name, + arguments: args_info(job), execution: job.executions, wait: wait.to_i, - exception: { - class: ex.class.name, - message: ex.message - } - }.to_json + exception: exception_payload(ex) + } + merge_organization_id(payload, job).to_json else - { + payload = { level: "info", event: "retry", status: "success", job: job.class.name, job_id: job.job_id, + queue: job.queue_name, + arguments: args_info(job), execution: job.executions, wait: wait.to_i - }.to_json + } + merge_organization_id(payload, job).to_json end end end @@ -285,31 +288,20 @@ def merge_organization_id(payload, job) end def organization_id_from(job) - return nil if job.arguments.nil? - - job.arguments.each do |arg| - case arg - when Hash - if arg.key?(:organization_id) - value = arg[:organization_id] - return value unless value.nil? - elsif arg.key?("organization_id") - value = arg["organization_id"] - return value unless value.nil? - end - else - if defined?(Organization) && arg.is_a?(Organization) - return arg.id - elsif arg.respond_to?(:organization_id) - value = arg.organization_id - return value unless value.nil? - end - end - end - nil + arg = job.arguments&.find { |a| !organization_id_in(a).nil? } + organization_id_in(arg) if arg rescue StandardError nil end + + def organization_id_in(arg) + case arg + when Hash + arg[:organization_id].presence || arg["organization_id"].presence + else + arg.organization_id if arg.respond_to?(:organization_id) + end + end end end diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index 4d20a043ddf..4b2b1bb8dbd 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -662,7 +662,7 @@ def parsed_log_lines end context "when an argument hash has organization_id: false" do - it "logs an error entry with the false organization_id rather than falling through" do + it "treats false as blank and falls through to the next argument's organization_id" do exception = RuntimeError.new("boom") job = build_job_with_args({organization_id: false}, {organization_id: "fallback"}, job_id: "abc-123", executions: 1) event = build_event("perform.active_job", {job: job, exception_object: exception}) @@ -683,7 +683,7 @@ def parsed_log_lines "arguments" => "{organization_id: false}, {organization_id: \"fallback\"}", "retries" => 1, "exception" => {"class" => "RuntimeError", "message" => "boom"}, - "organization_id" => false + "organization_id" => "fallback" }) end end @@ -883,11 +883,39 @@ def inspect "status" => "error", "job" => "TestLogJob", "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, "execution" => 3, "wait" => 30, "exception" => {"class" => "RuntimeError", "message" => "transient failure"} }) end + + context "when the job arguments contain an organization_id" do + it "logs a retry error entry with the extracted organization_id" do + exception = RuntimeError.new("transient failure") + job = build_job_with_args({organization_id: "org-retry"}, job_id: "abc-123", executions: 3) + event = build_event("enqueue_retry.active_job", {job: job, error: exception, wait: 30.5}) + + subscriber.enqueue_retry(event) + + logs = parsed_log_lines + expect(logs.size).to eq(1) + expect(logs.first).to eq({ + "level" => "error", + "event" => "retry", + "status" => "error", + "job" => "TestLogJobWithArgs", + "job_id" => "abc-123", + "queue" => "default", + "arguments" => "{organization_id: \"org-retry\"}", + "execution" => 3, + "wait" => 30, + "exception" => {"class" => "RuntimeError", "message" => "transient failure"}, + "organization_id" => "org-retry" + }) + end + end end context "when there is no error" do @@ -905,6 +933,8 @@ def inspect "status" => "success", "job" => "TestLogJob", "job_id" => "abc-123", + "queue" => "default", + "arguments" => {}, "execution" => 1, "wait" => 5 }) diff --git a/spec/models/organization_spec.rb b/spec/models/organization_spec.rb index b5c75193264..4bb43882b58 100644 --- a/spec/models/organization_spec.rb +++ b/spec/models/organization_spec.rb @@ -561,6 +561,12 @@ end end + describe "#organization_id" do + it "returns the organization id" do + expect(organization.organization_id).to eq(organization.id) + end + end + # this requires double confirmation: value on the org + premium integration describe "#maximum_wallets_per_customer", :premium do subject { organization.maximum_wallets_per_customer } From 5d1971ca3e40b099eb48e0fb5d7fdf6b4e7643b5 Mon Sep 17 00:00:00 2001 From: "Yohan R." <7434196+groyoh@users.noreply.github.com> Date: Tue, 26 May 2026 18:26:23 +0200 Subject: [PATCH 8/8] style(observability): satisfy rubocop on log subscriber --- lib/active_job/json_log_subscriber.rb | 11 +++++------ spec/lib/active_job/json_log_subscriber_spec.rb | 2 -- 2 files changed, 5 insertions(+), 8 deletions(-) diff --git a/lib/active_job/json_log_subscriber.rb b/lib/active_job/json_log_subscriber.rb index 74dccf768ba..bf1b0f667d0 100644 --- a/lib/active_job/json_log_subscriber.rb +++ b/lib/active_job/json_log_subscriber.rb @@ -141,8 +141,8 @@ def enqueue_retry(event) wait = event.payload[:wait] info do - if ex - payload = { + payload = if ex + { level: "error", event: "retry", status: "error", @@ -154,9 +154,8 @@ def enqueue_retry(event) wait: wait.to_i, exception: exception_payload(ex) } - merge_organization_id(payload, job).to_json else - payload = { + { level: "info", event: "retry", status: "success", @@ -167,8 +166,8 @@ def enqueue_retry(event) execution: job.executions, wait: wait.to_i } - merge_organization_id(payload, job).to_json end + merge_organization_id(payload, job).to_json end end subscribe_log_level :enqueue_retry, :info @@ -290,7 +289,7 @@ def merge_organization_id(payload, job) def organization_id_from(job) arg = job.arguments&.find { |a| !organization_id_in(a).nil? } organization_id_in(arg) if arg - rescue StandardError + rescue nil end diff --git a/spec/lib/active_job/json_log_subscriber_spec.rb b/spec/lib/active_job/json_log_subscriber_spec.rb index 4b2b1bb8dbd..0156f72cdc8 100644 --- a/spec/lib/active_job/json_log_subscriber_spec.rb +++ b/spec/lib/active_job/json_log_subscriber_spec.rb @@ -989,7 +989,6 @@ def inspect }) end end - end describe "#discard" do @@ -1039,6 +1038,5 @@ def inspect }) end end - end end