From eca8a29ae450fb2b1a5dcd53d7dfe0ecd483f7fa Mon Sep 17 00:00:00 2001 From: Nathan Broadbent Date: Sat, 17 Oct 2026 12:28:08 +1300 Subject: [PATCH 1/3] Type error classes as strings in the generated TypeScript The TypeScript generator mapped T.class_of(StandardError) to string but not T.class_of(Exception), the type Log::Error's error_class has now, so the generated error_class became `any`. --- tools/codegen/helpers.rb | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/tools/codegen/helpers.rb b/tools/codegen/helpers.rb index ae43a477..bd77baa6 100644 --- a/tools/codegen/helpers.rb +++ b/tools/codegen/helpers.rb @@ -27,7 +27,8 @@ def ts_type(sorbet) when "T::Array[T::Boolean]" then "boolean[]" when "T::Array[T.untyped]" then "unknown[]" when "T.any(Integer, String)" then "number | string" - when "T.class_of(StandardError)" then "string" + # Error classes are logged by name + when "T.class_of(StandardError)", "T.class_of(Exception)" then "string" else "any" end end From cb72612c8831890e56fc82509d35ab9bfcc77684 Mon Sep 17 00:00:00 2001 From: Nathan Broadbent Date: Sat, 17 Oct 2026 12:28:18 +1300 Subject: [PATCH 2/3] Log Sidekiq and Puma errors with typed fields Sidekiq's job error line and Puma's request error line put their fields (Sidekiq's context, the job ID and class, queue and retry count; Puma's context, method and path) in additional_data, which is only for fields LogStruct doesn't know about. They're new events with schema fields now: Log::Sidekiq::Error and Log::Puma::Error, with a new error_context field for what Sidekiq or Puma was doing. Log::Sidekiq becomes Log::Sidekiq::Log. The Sidekiq error line has the job's ID and class in ctx, like the lines logged while the job ran, so a query on ctx.jid finds the error too. Sidekiq calls its error handlers after the job's middleware has finished, so the line is logged with the same tags. Puma's request errors that aren't StandardErrors are logged too. --- docs/lib/log-generation/log-generator.ts | 27 +++++++- docs/lib/log-generation/sample-data.ts | 1 + docs/lib/log-structure-descriptions.ts | 6 +- lib/log_struct/enums/log_field.rb | 2 + lib/log_struct/integrations/puma.rb | 15 ++--- lib/log_struct/integrations/sidekiq.rb | 38 +++++------ lib/log_struct/integrations/sidekiq/logger.rb | 4 +- lib/log_struct/log/puma.rb | 1 + lib/log_struct/log/puma/error.rb | 63 +++++++++++++++++++ lib/log_struct/log/sidekiq.rb | 48 +------------- lib/log_struct/log/sidekiq/error.rb | 58 +++++++++++++++++ lib/log_struct/log/sidekiq/log.rb | 54 ++++++++++++++++ schemas/log_sources/puma.yml | 19 ++++++ schemas/log_sources/sidekiq.yml | 18 ++++++ schemas/meta/log-fields.json | 1 + .../log_struct/integrations/puma_unit_test.rb | 19 +++++- test/log_struct/integrations/sidekiq_test.rb | 5 +- 17 files changed, 299 insertions(+), 80 deletions(-) create mode 100644 lib/log_struct/log/puma/error.rb create mode 100644 lib/log_struct/log/sidekiq/error.rb create mode 100644 lib/log_struct/log/sidekiq/log.rb diff --git a/docs/lib/log-generation/log-generator.ts b/docs/lib/log-generation/log-generator.ts index b65f9981..7b938e3d 100644 --- a/docs/lib/log-generation/log-generator.ts +++ b/docs/lib/log-generation/log-generator.ts @@ -114,8 +114,20 @@ export class LogGenerator extends RandomDataGenerator { } } - case LogType.SIDEKIQ: - return Sidekiq.SidekiqLog.random(this).serialize(); + case LogType.SIDEKIQ: { + switch (evt ?? this.sample([Event.Log, Event.Error])) { + case Event.Error: + return Sidekiq.SidekiqError.random(this, { + level: Level.Warn, + error_class: 'ArgumentError', + message: 'Template not found', + error_context: 'Job raised exception', + queue_name: 'default', + }).serialize(); + default: + return Sidekiq.SidekiqLog.random(this).serialize(); + } + } case LogType.ACTIVESTORAGE: { switch ( @@ -202,9 +214,18 @@ export class LogGenerator extends RandomDataGenerator { } case LogType.PUMA: { - switch (evt ?? this.sample([Event.Start, Event.Shutdown])) { + switch (evt ?? this.sample([Event.Start, Event.Shutdown, Event.Error])) { case Event.Shutdown: return Puma.PumaShutdown.random(this).serialize(); + case Event.Error: + return Puma.PumaError.random(this, { + level: Level.Error, + error_class: 'Puma::HttpParserError', + message: 'Invalid HTTP format, parsing fails.', + error_context: 'HTTP parse error, malformed request', + http_method: 'GET', + path: '/', + }).serialize(); default: return Puma.PumaStart.random(this, { listening_addresses: [`tcp://127.0.0.1:${this.randomInt(3000, 3999)}`], diff --git a/docs/lib/log-generation/sample-data.ts b/docs/lib/log-generation/sample-data.ts index 91dc93e1..4451a71e 100644 --- a/docs/lib/log-generation/sample-data.ts +++ b/docs/lib/log-generation/sample-data.ts @@ -239,6 +239,7 @@ export const SampleByLogField: Readonly unk [LogField.Priority]: (gen: RandomGen) => gen.randomInt(0, 100), [LogField.Vars]: (_gen: RandomGen) => ['API_KEY'], [LogField.ErrorMessage]: (_gen: RandomGen) => 'Something failed', + [LogField.ErrorContext]: (_gen: RandomGen) => 'Job raised exception', [LogField.ProcessId]: SampleHelpers.processId, [LogField.Snapshot]: (_gen: RandomGen) => true, [LogField.Context]: (_gen: RandomGen) => ({ ctx: 'demo' }), diff --git a/docs/lib/log-structure-descriptions.ts b/docs/lib/log-structure-descriptions.ts index 373ad195..e988c6e6 100644 --- a/docs/lib/log-structure-descriptions.ts +++ b/docs/lib/log-structure-descriptions.ts @@ -24,14 +24,14 @@ export const LOG_STRUCTURE_DESCRIPTIONS: Record = { Url: 'URL generation event for a stored file (ActiveStorage)', Shrine: 'For Shrine file upload events', CarrierWave: 'For CarrierWave upload events', - Sidekiq: 'For Sidekiq job processing', + Sidekiq: "For Sidekiq's own log lines and failed jobs", Security: 'For security-related events', BlockedHost: 'Request blocked by ActionDispatch::HostAuthorization (host not on the allowed list)', CSRFViolation: 'Request rejected due to a CSRF token violation', IPSpoof: 'Request rejected because the IP address spoofing check failed', GoodJob: "For GoodJob's own log lines and thread errors", - Log: 'Structured GoodJob log output captured from the worker process', + Log: "A log line: a plain message, or a line from GoodJob's, Sidekiq's or Ahoy's own logger", SQL: 'For ActiveRecord SQL query events and performance metrics', ActiveModelSerializers: 'For render events produced by ActiveModelSerializers (serializer, adapter, resource, duration)', @@ -42,7 +42,7 @@ export const LOG_STRUCTURE_DESCRIPTIONS: Record = { Restore: 'dotenv-rails restore event rolling back to the last saved state', Save: 'dotenv-rails save event persisting environment variables', Update: 'dotenv-rails update event after manipulating environment values', - Puma: 'For Puma server lifecycle events', + Puma: 'For Puma server lifecycle events and request errors', Shutdown: 'Puma server shutdown event', }; diff --git a/lib/log_struct/enums/log_field.rb b/lib/log_struct/enums/log_field.rb index 1cde243f..ea0d717d 100644 --- a/lib/log_struct/enums/log_field.rb +++ b/lib/log_struct/enums/log_field.rb @@ -91,6 +91,8 @@ class LogField < T::Enum Priority = new(:priority) CronKey = new(:cron_key) ErrorMessage = new(:error_message) + # What the integration was doing when the error happened, e.g. Sidekiq's "Job raised exception" + ErrorContext = new(:error_context) Result = new(:result) EnqueueCaller = new(:enqueue_caller) diff --git a/lib/log_struct/integrations/puma.rb b/lib/log_struct/integrations/puma.rb index 1ab27e6a..2a9df380 100644 --- a/lib/log_struct/integrations/puma.rb +++ b/lib/log_struct/integrations/puma.rb @@ -392,16 +392,17 @@ module ErrorLoggerPatch sig { params(options: T::Hash[Symbol, T.untyped]).returns(T.untyped) } def info(options = {}) error = options[:error] - # Log::Error only takes a StandardError - return super unless error.is_a?(StandardError) + return super unless error.is_a?(Exception) env = options[:req]&.env - details = { - context: options[:text], - method: env&.dig("REQUEST_METHOD"), + ::LogStruct.error(::LogStruct::Log::Puma::Error.new( + error_class: error.class, + message: error.message, + backtrace: error.backtrace, + error_context: options[:text]&.to_s, + http_method: env&.dig("REQUEST_METHOD"), path: env && (env["REQUEST_PATH"] || env["PATH_INFO"]) - }.compact - ::LogStruct.error(::LogStruct::Log.from_exception(::LogStruct::Source::Puma, error, details)) + )) nil rescue => e ::LogStruct::Integrations::Puma.handle_integration_error(e) diff --git a/lib/log_struct/integrations/sidekiq.rb b/lib/log_struct/integrations/sidekiq.rb index 30a1a4e6..3ba623b5 100644 --- a/lib/log_struct/integrations/sidekiq.rb +++ b/lib/log_struct/integrations/sidekiq.rb @@ -86,6 +86,8 @@ def self.replace_default_error_handler(sidekiq_config) handlers.unshift(JOB_ERROR_HANDLER) end + # The line has the job's ID and class in ctx, like the lines logged while the job ran (Sidekiq + # calls its error handlers after the job's middleware has finished). sig { params(error: Exception, context: T::Hash[T.untyped, T.untyped]).void } def self.log_job_error(error, context) job = context[:job] @@ -93,26 +95,26 @@ def self.log_job_error(error, context) # LogStruct's ActiveJob integration already logs the errors of ActiveJob jobs return if job&.key?("wrapped") && LogStruct.config.integrations.enable_activejob - - details = { - context: context[:context], - jid: job&.dig("jid"), - job_class: job && (job["wrapped"] || job["class"]), - queue: job&.dig("queue"), + error_context = context[:context] + + line = Log::Sidekiq::Error.new( + error_class: error.class, + message: error.message, + backtrace: error.backtrace, + error_context: error_context&.to_s, + queue_name: job&.dig("queue")&.to_s, retry_count: job&.dig("retry_count") - }.compact - - if error.is_a?(StandardError) - ::Rails.logger.warn(Log.from_exception(Source::Sidekiq, error, details)) - else - # Log::Error only takes a StandardError; Sidekiq also reports others (e.g. NoMemoryError) - ::Rails.logger.warn(Log::Sidekiq.new( - level: Level::Warn, - event: Event::Error, - message: "#{error.class.name}: #{error.message}", - context: details - )) + ) + if job.nil? + ::Rails.logger.warn(line) + return end + + job_context = { + jid: job["jid"], + class: job["display_class"] || job["wrapped"] || job["class"] + }.compact + ::SemanticLogger.named_tagged(sidekiq_context: job_context) { ::Rails.logger.warn(line) } end JOB_ERROR_HANDLER = T.let( diff --git a/lib/log_struct/integrations/sidekiq/logger.rb b/lib/log_struct/integrations/sidekiq/logger.rb index ad7531b6..166f1190 100644 --- a/lib/log_struct/integrations/sidekiq/logger.rb +++ b/lib/log_struct/integrations/sidekiq/logger.rb @@ -16,7 +16,7 @@ def self.tid Thread.current["sidekiq_tid"] ||= (Thread.current.object_id ^ ::Process.pid).to_s(36) end - # Custom Logger for Sidekiq that creates LogStruct::Log::Sidekiq entries + # Custom Logger for Sidekiq that creates LogStruct::Log::Sidekiq::Log entries class Logger < LogStruct::SemanticLogger::Logger extend T::Sig @@ -31,7 +31,7 @@ class Logger < LogStruct::SemanticLogger::Logger end # Create a Sidekiq log struct with the message - log_struct = Log::Sidekiq.new( + log_struct = Log::Sidekiq::Log.new( level: LogStruct::Level.from_severity(level.to_s.upcase), event: Event::Log, message: msg, diff --git a/lib/log_struct/log/puma.rb b/lib/log_struct/log/puma.rb index 20fa31bf..4972f08d 100644 --- a/lib/log_struct/log/puma.rb +++ b/lib/log_struct/log/puma.rb @@ -8,3 +8,4 @@ require_relative "puma/start" require_relative "puma/shutdown" +require_relative "puma/error" diff --git a/lib/log_struct/log/puma/error.rb b/lib/log_struct/log/puma/error.rb new file mode 100644 index 00000000..eb10cbf9 --- /dev/null +++ b/lib/log_struct/log/puma/error.rb @@ -0,0 +1,63 @@ +# typed: strict +# frozen_string_literal: true + +# AUTO-GENERATED: DO NOT EDIT +# Generated by scripts/generate_structs.rb +# Schemas dir: schemas/log_sources/ +# Template: tools/codegen/templates/sorbet/event.rb.erb + +require "log_struct/shared/interfaces/common_fields" +require "log_struct/shared/interfaces/additional_data_field" +require "log_struct/shared/interfaces/request_fields" +require "log_struct/shared/serialize_common" +require "log_struct/shared/merge_additional_data_fields" +require "log_struct/shared/add_request_fields" +require_relative "../../enums/source" +require_relative "../../enums/event" +require_relative "../../enums/level" +require_relative "../../enums/log_field" + +module LogStruct + module Log + class Puma + class Error < T::Struct + extend T::Sig + + # Shared/common fields + const :source, Source::Puma, default: Source::Puma + const :event, Event, default: Event::Error + const :timestamp, Time, factory: -> { Time.now } + const :level, Level, default: Level::Info + + # Event-specific fields + const :error_class, T.class_of(Exception) + const :message, String + const :backtrace, T.nilable(T::Array[String]), default: nil + const :error_context, T.nilable(String), default: nil + const :http_method, T.nilable(String), default: nil + const :path, T.nilable(String), default: nil + + # Additional data + include LogStruct::Log::Interfaces::AdditionalDataField + const :additional_data, T.nilable(T::Hash[T.any(String, Symbol), T.untyped]), default: nil + include LogStruct::Log::Shared::MergeAdditionalDataFields + + # Serialize shared fields + include LogStruct::Log::Interfaces::CommonFields + include LogStruct::Log::Shared::SerializeCommon + + sig { returns(T::Hash[LogStruct::LogField, T.untyped]) } + def to_h + h = T.let({}, T::Hash[LogStruct::LogField, T.untyped]) + h[LogField::ErrorClass] = error_class + h[LogField::Message] = message + h[LogField::Backtrace] = backtrace unless backtrace.nil? + h[LogField::ErrorContext] = error_context unless error_context.nil? + h[LogField::HttpMethod] = http_method unless http_method.nil? + h[LogField::Path] = path unless path.nil? + h + end + end + end + end +end diff --git a/lib/log_struct/log/sidekiq.rb b/lib/log_struct/log/sidekiq.rb index 05cb940d..0833e8c0 100644 --- a/lib/log_struct/log/sidekiq.rb +++ b/lib/log_struct/log/sidekiq.rb @@ -4,49 +4,7 @@ # AUTO-GENERATED: DO NOT EDIT # Generated by scripts/generate_structs.rb # Schemas dir: schemas/log_sources/ -# Template: tools/codegen/templates/sorbet/event.rb.erb +# Template: tools/codegen/templates/sorbet/source_parent.rb.erb -require "log_struct/shared/interfaces/common_fields" -require "log_struct/shared/interfaces/additional_data_field" -require "log_struct/shared/interfaces/request_fields" -require "log_struct/shared/serialize_common" -require "log_struct/shared/merge_additional_data_fields" -require "log_struct/shared/add_request_fields" -require_relative "../enums/source" -require_relative "../enums/event" -require_relative "../enums/level" -require_relative "../enums/log_field" - -module LogStruct - module Log - class Sidekiq < T::Struct - extend T::Sig - - # Shared/common fields - const :source, Source::Sidekiq, default: Source::Sidekiq - const :event, Event, default: Event::Log - const :timestamp, Time, factory: -> { Time.now } - const :level, Level, default: Level::Info - - # Event-specific fields - const :message, T.nilable(String), default: nil - const :context, T.nilable(T::Hash[Symbol, T.untyped]), default: nil - const :process_id, T.nilable(Integer), default: nil - const :thread_id, T.nilable(T.any(Integer, String)), default: nil - - # Serialize shared fields - include LogStruct::Log::Interfaces::CommonFields - include LogStruct::Log::Shared::SerializeCommon - - sig { returns(T::Hash[LogStruct::LogField, T.untyped]) } - def to_h - h = T.let({}, T::Hash[LogStruct::LogField, T.untyped]) - h[LogField::Message] = message unless message.nil? - h[LogField::Context] = context unless context.nil? - h[LogField::ProcessId] = process_id unless process_id.nil? - h[LogField::ThreadId] = thread_id unless thread_id.nil? - h - end - end - end -end +require_relative "sidekiq/log" +require_relative "sidekiq/error" diff --git a/lib/log_struct/log/sidekiq/error.rb b/lib/log_struct/log/sidekiq/error.rb new file mode 100644 index 00000000..48f2a904 --- /dev/null +++ b/lib/log_struct/log/sidekiq/error.rb @@ -0,0 +1,58 @@ +# typed: strict +# frozen_string_literal: true + +# AUTO-GENERATED: DO NOT EDIT +# Generated by scripts/generate_structs.rb +# Schemas dir: schemas/log_sources/ +# Template: tools/codegen/templates/sorbet/event.rb.erb + +require "log_struct/shared/interfaces/common_fields" +require "log_struct/shared/interfaces/additional_data_field" +require "log_struct/shared/interfaces/request_fields" +require "log_struct/shared/serialize_common" +require "log_struct/shared/merge_additional_data_fields" +require "log_struct/shared/add_request_fields" +require_relative "../../enums/source" +require_relative "../../enums/event" +require_relative "../../enums/level" +require_relative "../../enums/log_field" + +module LogStruct + module Log + class Sidekiq + class Error < T::Struct + extend T::Sig + + # Shared/common fields + const :source, Source::Sidekiq, default: Source::Sidekiq + const :event, Event, default: Event::Error + const :timestamp, Time, factory: -> { Time.now } + const :level, Level, default: Level::Info + + # Event-specific fields + const :error_class, T.class_of(Exception) + const :message, String + const :backtrace, T.nilable(T::Array[String]), default: nil + const :error_context, T.nilable(String), default: nil + const :queue_name, T.nilable(String), default: nil + const :retry_count, T.nilable(Integer), default: nil + + # Serialize shared fields + include LogStruct::Log::Interfaces::CommonFields + include LogStruct::Log::Shared::SerializeCommon + + sig { returns(T::Hash[LogStruct::LogField, T.untyped]) } + def to_h + h = T.let({}, T::Hash[LogStruct::LogField, T.untyped]) + h[LogField::ErrorClass] = error_class + h[LogField::Message] = message + h[LogField::Backtrace] = backtrace unless backtrace.nil? + h[LogField::ErrorContext] = error_context unless error_context.nil? + h[LogField::QueueName] = queue_name unless queue_name.nil? + h[LogField::RetryCount] = retry_count unless retry_count.nil? + h + end + end + end + end +end diff --git a/lib/log_struct/log/sidekiq/log.rb b/lib/log_struct/log/sidekiq/log.rb new file mode 100644 index 00000000..d4e34da6 --- /dev/null +++ b/lib/log_struct/log/sidekiq/log.rb @@ -0,0 +1,54 @@ +# typed: strict +# frozen_string_literal: true + +# AUTO-GENERATED: DO NOT EDIT +# Generated by scripts/generate_structs.rb +# Schemas dir: schemas/log_sources/ +# Template: tools/codegen/templates/sorbet/event.rb.erb + +require "log_struct/shared/interfaces/common_fields" +require "log_struct/shared/interfaces/additional_data_field" +require "log_struct/shared/interfaces/request_fields" +require "log_struct/shared/serialize_common" +require "log_struct/shared/merge_additional_data_fields" +require "log_struct/shared/add_request_fields" +require_relative "../../enums/source" +require_relative "../../enums/event" +require_relative "../../enums/level" +require_relative "../../enums/log_field" + +module LogStruct + module Log + class Sidekiq + class Log < T::Struct + extend T::Sig + + # Shared/common fields + const :source, Source::Sidekiq, default: Source::Sidekiq + const :event, Event, default: Event::Log + const :timestamp, Time, factory: -> { Time.now } + const :level, Level, default: Level::Info + + # Event-specific fields + const :message, T.nilable(String), default: nil + const :context, T.nilable(T::Hash[Symbol, T.untyped]), default: nil + const :process_id, T.nilable(Integer), default: nil + const :thread_id, T.nilable(T.any(Integer, String)), default: nil + + # Serialize shared fields + include LogStruct::Log::Interfaces::CommonFields + include LogStruct::Log::Shared::SerializeCommon + + sig { returns(T::Hash[LogStruct::LogField, T.untyped]) } + def to_h + h = T.let({}, T::Hash[LogStruct::LogField, T.untyped]) + h[LogField::Message] = message unless message.nil? + h[LogField::Context] = context unless context.nil? + h[LogField::ProcessId] = process_id unless process_id.nil? + h[LogField::ThreadId] = thread_id unless thread_id.nil? + h + end + end + end + end +end diff --git a/schemas/log_sources/puma.yml b/schemas/log_sources/puma.yml index f853c8cd..3abe5365 100644 --- a/schemas/log_sources/puma.yml +++ b/schemas/log_sources/puma.yml @@ -22,3 +22,22 @@ events: default_required: false fields: ProcessId: Integer + + # Puma's ErrorLogger reported a request error (an exception the app didn't handle, a + # malformed request, an SSL error) + Error: + fields: + ErrorClass: 'T.class_of(Exception)' + Message: String + Backtrace: + type: 'T::Array[String]' + required: false + ErrorContext: + type: String + required: false + HttpMethod: + type: String + required: false + Path: + type: String + required: false diff --git a/schemas/log_sources/sidekiq.yml b/schemas/log_sources/sidekiq.yml index 21540c47..ec684cee 100644 --- a/schemas/log_sources/sidekiq.yml +++ b/schemas/log_sources/sidekiq.yml @@ -11,3 +11,21 @@ events: Context: 'T::Hash[Symbol, T.untyped]' ProcessId: Integer ThreadId: 'T.any(Integer, String)' + # A job (or Sidekiq itself) raised an error. The job's ID and class are in ctx, as on the + # job's other lines. + Error: + fields: + ErrorClass: 'T.class_of(Exception)' + Message: String + Backtrace: + type: 'T::Array[String]' + required: false + ErrorContext: + type: String + required: false + QueueName: + type: String + required: false + RetryCount: + type: Integer + required: false diff --git a/schemas/meta/log-fields.json b/schemas/meta/log-fields.json index 56a63835..b35942d3 100644 --- a/schemas/meta/log-fields.json +++ b/schemas/meta/log-fields.json @@ -36,6 +36,7 @@ "EnqueueCaller", "Environment", "ErrorClass", + "ErrorContext", "ErrorMessage", "Event", "ExceptionExecutions", diff --git a/test/log_struct/integrations/puma_unit_test.rb b/test/log_struct/integrations/puma_unit_test.rb index b0101c25..a65d428e 100644 --- a/test/log_struct/integrations/puma_unit_test.rb +++ b/test/log_struct/integrations/puma_unit_test.rb @@ -91,11 +91,28 @@ def test_request_errors_are_logged_as_structured_lines_without_the_query_string assert_nil error_logger.written, "Puma's plain text line was written too" log = logged.fetch(0) + assert_instance_of LogStruct::Log::Puma::Error, log assert_equal [LogStruct::Source::Puma, RuntimeError, "boom"], [log.source, log.error_class, log.message] - assert_equal({context: "Rack app", method: "GET", path: "/submissions/abc"}, log.additional_data) + assert_equal ["Rack app", "GET", "/submissions/abc"], [log.error_context, log.http_method, log.path] + assert_nil log.additional_data + assert_equal({src: "puma", evt: "error", error_context: "Rack app", method: "GET", path: "/submissions/abc"}, + log.serialize.slice(:src, :evt, :error_context, :method, :path)) refute_includes log.serialize.to_s, "token=secret" end + def test_request_errors_other_than_standard_errors_are_logged_too + logged = [] + error = NotImplementedError.new("not yet") + error_logger = FakeErrorLogger.new + + LogStruct.stub(:error, ->(log) { logged << log }) do + error_logger.info(error: error, req: FakeRequest.new({"REQUEST_METHOD" => "POST", "PATH_INFO" => "/x"}), text: "Rack app") + end + + assert_nil error_logger.written + assert_equal NotImplementedError, logged.fetch(0).error_class + end + private def feed_boot_lines diff --git a/test/log_struct/integrations/sidekiq_test.rb b/test/log_struct/integrations/sidekiq_test.rb index 3702e740..a2c7cd44 100644 --- a/test/log_struct/integrations/sidekiq_test.rb +++ b/test/log_struct/integrations/sidekiq_test.rb @@ -119,7 +119,10 @@ class SidekiqTest < ActiveSupport::TestCase assert_equal ["error", "warn"], [line["evt"], line["lvl"]] assert_equal ["ArgumentError", "Template not found"], [line["error_class"], line["msg"]] - assert_equal ["abc123", "HardJob", "default", 2], [line["jid"], line["job_class"], line["queue"], line["retry_count"]] + # The job's ID and class are in ctx, as on the lines logged while the job ran + assert_equal({"jid" => "abc123", "class" => "HardJob"}, line["ctx"]) + assert_equal ["Job raised exception", "default", 2], [line["error_context"], line["queue_name"], line["retry_count"]] + refute line.key?("jid") refute_includes @io.string, "secret@example.com" end From 2bb51df26769417513687dc9c8985058a2b2f04d Mon Sep 17 00:00:00 2001 From: Nathan Broadbent Date: Sat, 17 Oct 2026 12:28:38 +1300 Subject: [PATCH 3/3] Log an ActiveJob job's Sidekiq error unless ActiveJob logged it Sidekiq's error handler skipped every ActiveJob job's error, leaving it to the ActiveJob integration. An error raised before ActiveJob ran the job, such as the NameError for a job class a deploy removed, was then in no log line. The handler now skips only the errors the ActiveJob integration logged (LogStruct::LoggedErrors), as the GoodJob integration does. --- lib/log_struct/integrations/sidekiq.rb | 8 ++++--- test/log_struct/integrations/sidekiq_test.rb | 23 ++++++++++++++++++-- 2 files changed, 26 insertions(+), 5 deletions(-) diff --git a/lib/log_struct/integrations/sidekiq.rb b/lib/log_struct/integrations/sidekiq.rb index 3ba623b5..be031636 100644 --- a/lib/log_struct/integrations/sidekiq.rb +++ b/lib/log_struct/integrations/sidekiq.rb @@ -90,11 +90,13 @@ def self.replace_default_error_handler(sidekiq_config) # calls its error handlers after the job's middleware has finished). sig { params(error: Exception, context: T::Hash[T.untyped, T.untyped]).void } def self.log_job_error(error, context) + # LogStruct's ActiveJob integration logs the errors it sees an ActiveJob job raise. An + # error raised before ActiveJob ran the job (a job class a deploy removed, say) is logged + # here. + return if LogStruct::LoggedErrors.logged?(error) + job = context[:job] job = nil unless job.is_a?(Hash) - - # LogStruct's ActiveJob integration already logs the errors of ActiveJob jobs - return if job&.key?("wrapped") && LogStruct.config.integrations.enable_activejob error_context = context[:context] line = Log::Sidekiq::Error.new( diff --git a/test/log_struct/integrations/sidekiq_test.rb b/test/log_struct/integrations/sidekiq_test.rb index a2c7cd44..92469433 100644 --- a/test/log_struct/integrations/sidekiq_test.rb +++ b/test/log_struct/integrations/sidekiq_test.rb @@ -126,12 +126,31 @@ class SidekiqTest < ActiveSupport::TestCase refute_includes @io.string, "secret@example.com" end - test "ActiveJob jobs' errors are left to the ActiveJob integration" do + test "an ActiveJob job's error that ActiveJob didn't log is logged" do + sidekiq_config = ::Sidekiq::Config.new + sidekiq_config.logger = Sidekiq::Logger.new("Sidekiq-Server") + Sidekiq.send(:replace_default_error_handler, sidekiq_config) + # e.g. the job's class was removed in a deploy, so ActiveJob couldn't deserialize it + error = NameError.new("uninitialized constant RemovedJob") + job = {"jid" => "def456", "class" => "Sidekiq::ActiveJob::Wrapper", "wrapped" => "RemovedJob", "queue" => "default"} + + sidekiq_config.error_handlers.each { |handler| handler.call(error, {context: "Job raised exception", job: job}, sidekiq_config) } + ::SemanticLogger.flush + + line = T.must(sidekiq_lines.first) + + assert_equal ["error", "NameError"], [line["evt"], line["error_class"]] + assert_equal({"jid" => "def456", "class" => "RemovedJob"}, line["ctx"]) + end + + test "errors the ActiveJob integration logged aren't logged again" do sidekiq_config = ::Sidekiq::Config.new Sidekiq.send(:replace_default_error_handler, sidekiq_config) job = {"jid" => "abc123", "class" => "Sidekiq::ActiveJob::Wrapper", "wrapped" => "HardJob"} + error = ArgumentError.new("boom") + LogStruct::LoggedErrors.mark(error) - sidekiq_config.error_handlers.each { |handler| handler.call(ArgumentError.new("boom"), {job: job}, sidekiq_config) } + sidekiq_config.error_handlers.each { |handler| handler.call(error, {job: job}, sidekiq_config) } ::SemanticLogger.flush assert_empty sidekiq_lines